Jobsub ID 97029.78@justin-prod-sched02.dune.hep.ac.uk
Jobsub ID | 97029.78@justin-prod-sched02.dune.hep.ac.uk |
Workflow ID | 4103 |
Stage ID | 1 |
User name | amoor@fnal.gov |
HTCondor Group | group_dune |
Requested | Processors | 1 |
RSS bytes | 8388608000 (8000 MiB) |
Wall seconds limit | 80000 (22 hours) |
Submitted time | 2024-11-14 13:41:08 |
Site | UK_Edinburgh |
Entry | DUNE_UK_SGridECDF_ce1_multicore |
Last heartbeat | 2024-11-14 14:26:30 |
From worker node | Hostname | node3a05.ecdf.ed.ac.uk |
cpuinfo | Intel(R) Xeon(R) Gold 6242 CPU @ 2.80GHz |
OS release | Scientific Linux release 7.9 (Nitrogen) |
Processors | 1 |
RSS bytes | 8388608000 (8000 MiB) |
Wall seconds limit | 171000 (47 hours) |
Inner Apptainer? | True |
Job state | jobscript_error |
Allocator name | justin-allocator-pro.dune.hep.ac.uk |
Started | 2024-11-14 14:25:10 |
Input files | usertests:000125_reco_data_2024-11-14T_092558Z.root
|
Jobscript | Exit code | 1 |
Real time | 0m (0s) |
CPU time | 0m (0s = 0%) |
Outputting started | |
Output files | |
Finished | 2024-11-14 14:26:30 |
Saved logs | justin-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