justIN           Dashboard       Workflows       Jobs       AWT       Sites       Storages       Docs       Login

Jobsub ID 97029.78@justin-prod-sched02.dune.hep.ac.uk

Jobsub ID97029.78@justin-prod-sched02.dune.hep.ac.uk
Workflow ID4103
Stage ID1
User nameamoor@fnal.gov
HTCondor Groupgroup_dune
RequestedProcessors1
RSS bytes8388608000 (8000 MiB)
Wall seconds limit80000 (22 hours)
Submitted time2024-11-14 13:41:08
SiteUK_Edinburgh
EntryDUNE_UK_SGridECDF_ce1_multicore
Last heartbeat2024-11-14 14:26:30
From worker nodeHostnamenode3a05.ecdf.ed.ac.uk
cpuinfoIntel(R) Xeon(R) Gold 6242 CPU @ 2.80GHz
OS releaseScientific Linux release 7.9 (Nitrogen)
Processors1
RSS bytes8388608000 (8000 MiB)
Wall seconds limit171000 (47 hours)
Inner Apptainer?True
Job statejobscript_error
Allocator namejustin-allocator-pro.dune.hep.ac.uk
Started2024-11-14 14:25:10
Input filesusertests:000125_reco_data_2024-11-14T_092558Z.root
JobscriptExit code1
Real time0m (0s)
CPU time0m (0s = 0%)
Outputting started 
Output files
Finished2024-11-14 14:26:30
Saved logsjustin-logs:97029.78-justin-prod-sched02.dune.hep.ac.uk.logs.tgz
List job events     Wrapper job log

Jobscript log (last 10,000 characters)

2.gla.scotgrid.ac.uk:1094//cephfs/dune/RSE/usertests/27/2f/000125_reco_data_2024-11-14T_092558Z.root?xrdcl.requuid=852453a6-11f3-4510-be5c-e9d7e7acc333] Sending an open command
[2024-11-14 14:26:11.487707 +0000][Debug  ][ExDbgMsg          ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094] MsgHandler created: 0xb4d7730 (message: kXR_open (file: /cephfs/dune/RSE/usertests/27/2f/000125_reco_data_2024-11-14T_092558Z.root, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ) ).
[2024-11-14 14:26:11.487815 +0000][Debug  ][PostMaster        ][ 1127] Creating new channel to: root://cephc02.gla.scotgrid.ac.uk:1094
[2024-11-14 14:26:11.487848 +0000][Debug  ][PostMaster        ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094] Stream parameters: Network Stack: IPAuto, Connection Window: 30, ConnectionRetry: 5, Stream Error Window: 1800
[2024-11-14 14:26:11.487885 +0000][Debug  ][TaskMgr           ][ 1127] Registering task: "TickGeneratorTask for: root://cephc02.gla.scotgrid.ac.uk:1094" to be run at: [2024-11-14 14:26:26 +0000]
[2024-11-14 14:26:11.488738 +0000][Debug  ][PostMaster        ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094] Found 1 address(es): [::ffff:130.209.239.113]:1094
[2024-11-14 14:26:11.488780 +0000][Debug  ][AsyncSock         ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Attempting connection to [::ffff:130.209.239.113]:1094
[2024-11-14 14:26:11.488819 +0000][Debug  ][Poller            ][ 1127] Adding socket 0xb534860 to the poller
[2024-11-14 14:26:11.492998 +0000][Debug  ][AsyncSock         ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Async connection call returned
[2024-11-14 14:26:11.493174 +0000][Debug  ][XRootDTransport   ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Sending out the initial hand shake + kXR_protocol
[2024-11-14 14:26:11.497775 +0000][Debug  ][XRootDTransport   ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Got the server hand shake response (type: server [], protocol version 511)
[2024-11-14 14:26:11.497897 +0000][Debug  ][XRootDTransport   ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] kXR_protocol successful (type: server [], protocol version 511)
[2024-11-14 14:26:11.499400 +0000][Debug  ][XRootDTransport   ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Sending out kXR_login request, username: gl05pi6, cgi: xrd.cc=uk&xrd.tz=0&xrd.appname=lar&xrd.info=&xrd.hostname=node3a05.ecdf.ed.ac.uk&xrd.rn=v5.4.3, dual-stack: false, private IPv4: false, private IPv6: false
[2024-11-14 14:26:11.499436 +0000][Debug  ][AsyncSock         ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] TLS hand-shake exchange.
[2024-11-14 14:26:11.507388 +0000][Debug  ][AsyncSock         ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] TLS hand-shake exchange.
[2024-11-14 14:26:11.513355 +0000][Debug  ][AsyncSock         ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] TLS hand-shake exchange.
[2024-11-14 14:26:11.513497 +0000][Info   ][AsyncSock         ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] TLS hand-shake done.
[2024-11-14 14:26:11.517822 +0000][Debug  ][XRootDTransport   ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Logged in, session: a330040051ba3e007700000071840500
[2024-11-14 14:26:11.517834 +0000][Debug  ][XRootDTransport   ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Authentication is required: &P=ztn,0:4096:&P=gsi,v:10600,c:ssl,ca:530f7122.0|ffc3d59b.0
[2024-11-14 14:26:11.517845 +0000][Debug  ][XRootDTransport   ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Sending authentication data
Plugin version SecClnt v5.4.3 is incompatible with secztn v5.6.8 (must be <= 5.4.x) in sec.protocol libXrdSecztn-5.so
[2024-11-14 14:26:11.542000 +0000][Debug  ][XRootDTransport   ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Trying to authenticate using gsi
[2024-11-14 14:26:12.320061 +0000][Debug  ][XRootDTransport   ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Sending more authentication data for gsi
[2024-11-14 14:26:12.383738 +0000][Debug  ][XRootDTransport   ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Authenticated with gsi.
[2024-11-14 14:26:12.383804 +0000][Debug  ][PostMaster        ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094] Stream 0 connected.
[2024-11-14 14:26:12.383831 +0000][Debug  ][Utility           ][ 1127] Monitor library name not set. No monitoring
[2024-11-14 14:26:12.383950 +0000][Debug  ][ExDbgMsg          ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094] Moving MsgHandler: 0xb4d7730 (message: kXR_open (file: /cephfs/dune/RSE/usertests/27/2f/000125_reco_data_2024-11-14T_092558Z.root, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ) ) from out-queu to in-queue.
[2024-11-14 14:26:12.388029 +0000][Debug  ][ExDbgMsg          ][ 1127] [msg: 0xb59c690] Assigned MsgHandler: 0xb4d7730.
[2024-11-14 14:26:12.388078 +0000][Debug  ][ExDbgMsg          ][ 1127] [handler: 0xb4d7730] Removed MsgHandler: 0xb4d7730 from the in-queue.
[2024-11-14 14:26:12.388278 +0000][Debug  ][XRootD            ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094] Handling error while processing kXR_open (file: /cephfs/dune/RSE/usertests/27/2f/000125_reco_data_2024-11-14T_092558Z.root, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ): [ERROR] Error response: permission denied.
[2024-11-14 14:26:12.388412 +0000][Debug  ][ExDbgMsg          ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094] Calling MsgHandler: 0xb4d7730 (message: kXR_open (file: /cephfs/dune/RSE/usertests/27/2f/000125_reco_data_2024-11-14T_092558Z.root, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ) ) with status: [ERROR] Error response: permission denied.
[2024-11-14 14:26:12.388536 +0000][Debug  ][File              ][ 1127] [0xb500df0@root://cephc02.gla.scotgrid.ac.uk:1094//cephfs/dune/RSE/usertests/27/2f/000125_reco_data_2024-11-14T_092558Z.root?xrdcl.requuid=852453a6-11f3-4510-be5c-e9d7e7acc333] Open has returned with status [ERROR] Server responded with an error: [3010] Unable to open /cephfs/dune/RSE/usertests/27/2f/000125_reco_data_2024-11-14T_092558Z.root; permission denied
[2024-11-14 14:26:12.388570 +0000][Debug  ][File              ][ 1127] [0xb500df0@root://cephc02.gla.scotgrid.ac.uk:1094//cephfs/dune/RSE/usertests/27/2f/000125_reco_data_2024-11-14T_092558Z.root?xrdcl.requuid=852453a6-11f3-4510-be5c-e9d7e7acc333] Error while opening at cephc02.gla.scotgrid.ac.uk:1094: [ERROR] Server responded with an error: [3010] Unable to open /cephfs/dune/RSE/usertests/27/2f/000125_reco_data_2024-11-14T_092558Z.root; permission denied
[2024-11-14 14:26:12.388671 +0000][Debug  ][ExDbgMsg          ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094] Destroying MsgHandler: 0xb4d7730.
%MSG-i Root_Information:  TriggerResultInserter:TriggerResults@Construction  TNetXNGFile::Open() 14-Nov-2024 14:26:12 GMT ModuleConstruction
[ERROR] Server responded with an error: [3010] Unable to open /cephfs/dune/RSE/usertests/27/2f/000125_reco_data_2024-11-14T_092558Z.root; permission denied

ROOT severity: 3000
%MSG
%MSG-s ArtException:  TriggerResultInserter:TriggerResults@Construction  14-Nov-2024 14:26:12 GMT ModuleConstruction
cet::exception caught in art
---- FileOpenError BEGIN
  RootInputFileSequence::initFile(): Input file root://cephc02.gla.scotgrid.ac.uk:1094//cephfs/dune/RSE/usertests/27/2f/000125_reco_data_2024-11-14T_092558Z.root was not found or could not be opened.
---- FileOpenError END
%MSG
Art has completed and will exit with status 20.
[2024-11-14 14:26:12.521250 +0000][Debug  ][JobMgr            ][ 1127] Stopping the job manager...
[2024-11-14 14:26:12.522317 +0000][Debug  ][JobMgr            ][ 1127] Job manager stopped
[2024-11-14 14:26:12.522838 +0000][Debug  ][TaskMgr           ][ 1127] Stopping the task manager...
[2024-11-14 14:26:12.523110 +0000][Debug  ][TaskMgr           ][ 1127] Task manager stopped
[2024-11-14 14:26:12.523118 +0000][Debug  ][Poller            ][ 1127] Stopping the poller...
[2024-11-14 14:26:12.523299 +0000][Debug  ][TaskMgr           ][ 1127] Requesting unregistration of: "TickGeneratorTask for: root://cephc02.gla.scotgrid.ac.uk:1094"
[2024-11-14 14:26:12.523332 +0000][Debug  ][AsyncSock         ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Closing the socket
[2024-11-14 14:26:12.523362 +0000][Debug  ][Poller            ][ 1127] <[::ffff:192.41.104.59]:43272><--><[::ffff:130.209.239.113]:1094> Removing socket from the poller
[2024-11-14 14:26:12.523618 +0000][Debug  ][PostMaster        ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094] Destroying stream
[2024-11-14 14:26:12.523742 +0000][Debug  ][AsyncSock         ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Closing the socket
=== End last 100 lines of lar log file ===
lar exit code 0
Traceback (most recent call last):
  File "/cvmfs/dune.opensciencegrid.org/products/dune/duneutil/v09_75_03d00/bin/extractor_prod.py", line 434, in <module>
    main()
  File "/cvmfs/dune.opensciencegrid.org/products/dune/duneutil/v09_75_03d00/bin/extractor_prod.py", line 373, in main
    mddict = expSpecificMetadata.getmetadata()
  File "/cvmfs/dune.opensciencegrid.org/products/dune/duneutil/v09_75_03d00/bin/extractor_prod.py", line 344, in getmetadata
    jobt = self.get_job(proc)
  File "/cvmfs/dune.opensciencegrid.org/products/dune/duneutil/v09_75_03d00/bin/extractor_prod.py", line 69, in get_job
    raise RuntimeError('sam_metadata_dumper returned nonzero exit status {}.'.format(rc))
RuntimeError: sam_metadata_dumper returned nonzero exit status 1.
extractor_prod.py exit code 1
Error reading metadata from file: Expecting value: line 1 column 1 (char 0)
pdjson2metadata exit code 1
.:
total 84
-rw-r--r-- 1 gl05pi6 eddie_users 59548 Nov 14 14:26 000125_reco_data_2024-11-14T_092558Z_reco_2024-11-14T_142513Z.log
-rw-r--r-- 1 gl05pi6 eddie_users 13190 Nov 14 14:26 jobscript.log
-rw-r--r-- 1 gl05pi6 eddie_users   519 Nov 14 14:26 g4_hist.root
-rw-r--r-- 1 gl05pi6 eddie_users   104 Nov 14 14:25 all-input-dids.txt
-rw-r--r-- 1 gl05pi6 eddie_users     0 Nov 14 14:26 000125_reco_data_2024-11-14T_092558Z_reco_data_2024-11-14T_142513Z.root.ext.json
-rw-r--r-- 1 gl05pi6 eddie_users     0 Nov 14 14:26 000125_reco_data_2024-11-14T_092558Z_reco_data_2024-11-14T_142513Z.root.json
justIN time: 2024-11-22 10:42:50 UTC       justIN version: 01.01.09