Jobsub ID 97029.130@justin-prod-sched02.dune.hep.ac.uk
| Jobsub ID | 97029.130@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:30:22 |
| 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:29:03 |
| Input files | usertests:000605_reco_data_2024-11-14T_093232Z.root
|
| Jobscript | Exit code | 1 |
| Real time | 0m (0s) |
| CPU time | 0m (0s = 0%) |
| Outputting started | |
| Output files | |
| Finished | 2024-11-14 14:30:22 |
| Saved logs | justin-logs:97029.130-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/d9/7d/000605_reco_data_2024-11-14T_093232Z.root?xrdcl.requuid=7626c15b-fa6b-4b63-8d8f-b171b8f0e7e6] Sending an open command
[2024-11-14 14:30:04.314730 +0000][Debug ][ExDbgMsg ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094] MsgHandler created: 0xae72050 (message: kXR_open (file: /cephfs/dune/RSE/usertests/d9/7d/000605_reco_data_2024-11-14T_093232Z.root, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ) ).
[2024-11-14 14:30:04.314842 +0000][Debug ][PostMaster ][ 1127] Creating new channel to: root://cephc02.gla.scotgrid.ac.uk:1094
[2024-11-14 14:30:04.314875 +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:30:04.314912 +0000][Debug ][TaskMgr ][ 1127] Registering task: "TickGeneratorTask for: root://cephc02.gla.scotgrid.ac.uk:1094" to be run at: [2024-11-14 14:30:19 +0000]
[2024-11-14 14:30:04.316131 +0000][Debug ][PostMaster ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094] Found 1 address(es): [::ffff:130.209.239.113]:1094
[2024-11-14 14:30:04.316173 +0000][Debug ][AsyncSock ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Attempting connection to [::ffff:130.209.239.113]:1094
[2024-11-14 14:30:04.316215 +0000][Debug ][Poller ][ 1127] Adding socket 0xae9ffa0 to the poller
[2024-11-14 14:30:04.372344 +0000][Debug ][AsyncSock ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Async connection call returned
[2024-11-14 14:30:04.372564 +0000][Debug ][XRootDTransport ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Sending out the initial hand shake + kXR_protocol
[2024-11-14 14:30:04.427192 +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:30:04.427349 +0000][Debug ][XRootDTransport ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] kXR_protocol successful (type: server [], protocol version 511)
[2024-11-14 14:30:04.429025 +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:30:04.429087 +0000][Debug ][AsyncSock ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] TLS hand-shake exchange.
[2024-11-14 14:30:04.487204 +0000][Debug ][AsyncSock ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] TLS hand-shake exchange.
[2024-11-14 14:30:04.539738 +0000][Debug ][AsyncSock ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] TLS hand-shake exchange.
[2024-11-14 14:30:04.540103 +0000][Info ][AsyncSock ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] TLS hand-shake done.
[2024-11-14 14:30:04.590952 +0000][Debug ][XRootDTransport ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Logged in, session: e130040051ba3e0053000000c8840500
[2024-11-14 14:30:04.591021 +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:30:04.591049 +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:30:04.620902 +0000][Debug ][XRootDTransport ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Trying to authenticate using gsi
[2024-11-14 14:30:04.958561 +0000][Debug ][XRootDTransport ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Sending more authentication data for gsi
[2024-11-14 14:30:05.085121 +0000][Debug ][XRootDTransport ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Authenticated with gsi.
[2024-11-14 14:30:05.085223 +0000][Debug ][PostMaster ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094] Stream 0 connected.
[2024-11-14 14:30:05.085265 +0000][Debug ][Utility ][ 1127] Monitor library name not set. No monitoring
[2024-11-14 14:30:05.085466 +0000][Debug ][ExDbgMsg ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094] Moving MsgHandler: 0xae72050 (message: kXR_open (file: /cephfs/dune/RSE/usertests/d9/7d/000605_reco_data_2024-11-14T_093232Z.root, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ) ) from out-queu to in-queue.
[2024-11-14 14:30:05.142568 +0000][Debug ][ExDbgMsg ][ 1127] [msg: 0xaee7620] Assigned MsgHandler: 0xae72050.
[2024-11-14 14:30:05.142666 +0000][Debug ][ExDbgMsg ][ 1127] [handler: 0xae72050] Removed MsgHandler: 0xae72050 from the in-queue.
[2024-11-14 14:30:05.142930 +0000][Debug ][XRootD ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094] Handling error while processing kXR_open (file: /cephfs/dune/RSE/usertests/d9/7d/000605_reco_data_2024-11-14T_093232Z.root, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ): [ERROR] Error response: permission denied.
[2024-11-14 14:30:05.143056 +0000][Debug ][ExDbgMsg ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094] Calling MsgHandler: 0xae72050 (message: kXR_open (file: /cephfs/dune/RSE/usertests/d9/7d/000605_reco_data_2024-11-14T_093232Z.root, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ) ) with status: [ERROR] Error response: permission denied.
[2024-11-14 14:30:05.143183 +0000][Debug ][File ][ 1127] [0xae9aeb0@root://cephc02.gla.scotgrid.ac.uk:1094//cephfs/dune/RSE/usertests/d9/7d/000605_reco_data_2024-11-14T_093232Z.root?xrdcl.requuid=7626c15b-fa6b-4b63-8d8f-b171b8f0e7e6] Open has returned with status [ERROR] Server responded with an error: [3010] Unable to open /cephfs/dune/RSE/usertests/d9/7d/000605_reco_data_2024-11-14T_093232Z.root; permission denied
[2024-11-14 14:30:05.143216 +0000][Debug ][File ][ 1127] [0xae9aeb0@root://cephc02.gla.scotgrid.ac.uk:1094//cephfs/dune/RSE/usertests/d9/7d/000605_reco_data_2024-11-14T_093232Z.root?xrdcl.requuid=7626c15b-fa6b-4b63-8d8f-b171b8f0e7e6] Error while opening at cephc02.gla.scotgrid.ac.uk:1094: [ERROR] Server responded with an error: [3010] Unable to open /cephfs/dune/RSE/usertests/d9/7d/000605_reco_data_2024-11-14T_093232Z.root; permission denied
[2024-11-14 14:30:05.143326 +0000][Debug ][ExDbgMsg ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094] Destroying MsgHandler: 0xae72050.
%MSG-i Root_Information: TriggerResultInserter:TriggerResults@Construction TNetXNGFile::Open() 14-Nov-2024 14:30:05 GMT ModuleConstruction
[ERROR] Server responded with an error: [3010] Unable to open /cephfs/dune/RSE/usertests/d9/7d/000605_reco_data_2024-11-14T_093232Z.root; permission denied
ROOT severity: 3000
%MSG
%MSG-s ArtException: TriggerResultInserter:TriggerResults@Construction 14-Nov-2024 14:30:05 GMT ModuleConstruction
cet::exception caught in art
---- FileOpenError BEGIN
RootInputFileSequence::initFile(): Input file root://cephc02.gla.scotgrid.ac.uk:1094//cephfs/dune/RSE/usertests/d9/7d/000605_reco_data_2024-11-14T_093232Z.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:30:05.282180 +0000][Debug ][JobMgr ][ 1127] Stopping the job manager...
[2024-11-14 14:30:05.283280 +0000][Debug ][JobMgr ][ 1127] Job manager stopped
[2024-11-14 14:30:05.283770 +0000][Debug ][TaskMgr ][ 1127] Stopping the task manager...
[2024-11-14 14:30:05.284022 +0000][Debug ][TaskMgr ][ 1127] Task manager stopped
[2024-11-14 14:30:05.284097 +0000][Debug ][Poller ][ 1127] Stopping the poller...
[2024-11-14 14:30:05.284221 +0000][Debug ][TaskMgr ][ 1127] Requesting unregistration of: "TickGeneratorTask for: root://cephc02.gla.scotgrid.ac.uk:1094"
[2024-11-14 14:30:05.284267 +0000][Debug ][AsyncSock ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Closing the socket
[2024-11-14 14:30:05.284331 +0000][Debug ][Poller ][ 1127] <[::ffff:192.41.104.59]:55072><--><[::ffff:130.209.239.113]:1094> Removing socket from the poller
[2024-11-14 14:30:05.284552 +0000][Debug ][PostMaster ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094] Destroying stream
[2024-11-14 14:30:05.284623 +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:30 000605_reco_data_2024-11-14T_093232Z_reco_2024-11-14T_142906Z.log
-rw-r--r-- 1 gl05pi6 eddie_users 13190 Nov 14 14:30 jobscript.log
-rw-r--r-- 1 gl05pi6 eddie_users 519 Nov 14 14:30 g4_hist.root
-rw-r--r-- 1 gl05pi6 eddie_users 104 Nov 14 14:29 all-input-dids.txt
-rw-r--r-- 1 gl05pi6 eddie_users 0 Nov 14 14:30 000605_reco_data_2024-11-14T_093232Z_reco_data_2024-11-14T_142906Z.root.ext.json
-rw-r--r-- 1 gl05pi6 eddie_users 0 Nov 14 14:30 000605_reco_data_2024-11-14T_093232Z_reco_data_2024-11-14T_142906Z.root.json 