Jobsub ID 97029.35@justin-prod-sched02.dune.hep.ac.uk
Jobsub ID | 97029.35@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:21:50 |
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:20:31 |
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:21:50 |
Saved logs | justin-logs:97029.35-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=6abb72bf-b456-4e18-a85c-a0310440ecc9] Sending an open command
[2024-11-14 14:21:33.054279 +0000][Debug ][ExDbgMsg ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094] MsgHandler created: 0xabc6960 (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:21:33.054390 +0000][Debug ][PostMaster ][ 1127] Creating new channel to: root://cephc02.gla.scotgrid.ac.uk:1094
[2024-11-14 14:21:33.054431 +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:21:33.054468 +0000][Debug ][TaskMgr ][ 1127] Registering task: "TickGeneratorTask for: root://cephc02.gla.scotgrid.ac.uk:1094" to be run at: [2024-11-14 14:21:48 +0000]
[2024-11-14 14:21:33.056280 +0000][Debug ][PostMaster ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094] Found 1 address(es): [::ffff:130.209.239.113]:1094
[2024-11-14 14:21:33.056323 +0000][Debug ][AsyncSock ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Attempting connection to [::ffff:130.209.239.113]:1094
[2024-11-14 14:21:33.056365 +0000][Debug ][Poller ][ 1127] Adding socket 0xaa77e10 to the poller
[2024-11-14 14:21:33.060604 +0000][Debug ][AsyncSock ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Async connection call returned
[2024-11-14 14:21:33.060772 +0000][Debug ][XRootDTransport ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Sending out the initial hand shake + kXR_protocol
[2024-11-14 14:21:33.064804 +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:21:33.064895 +0000][Debug ][XRootDTransport ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] kXR_protocol successful (type: server [], protocol version 511)
[2024-11-14 14:21:33.066330 +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:21:33.066386 +0000][Debug ][AsyncSock ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] TLS hand-shake exchange.
[2024-11-14 14:21:33.077144 +0000][Debug ][AsyncSock ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] TLS hand-shake exchange.
[2024-11-14 14:21:33.083965 +0000][Debug ][AsyncSock ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] TLS hand-shake exchange.
[2024-11-14 14:21:33.084176 +0000][Info ][AsyncSock ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] TLS hand-shake done.
[2024-11-14 14:21:33.088393 +0000][Debug ][XRootDTransport ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Logged in, session: 5830040051ba3e008700000019840500
[2024-11-14 14:21:33.088425 +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:21:33.088445 +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:21:33.126743 +0000][Debug ][XRootDTransport ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Trying to authenticate using gsi
[2024-11-14 14:21:33.333307 +0000][Debug ][XRootDTransport ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Sending more authentication data for gsi
[2024-11-14 14:21:33.397641 +0000][Debug ][XRootDTransport ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Authenticated with gsi.
[2024-11-14 14:21:33.397710 +0000][Debug ][PostMaster ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094] Stream 0 connected.
[2024-11-14 14:21:33.397736 +0000][Debug ][Utility ][ 1127] Monitor library name not set. No monitoring
[2024-11-14 14:21:33.397855 +0000][Debug ][ExDbgMsg ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094] Moving MsgHandler: 0xabc6960 (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:21:33.401964 +0000][Debug ][ExDbgMsg ][ 1127] [msg: 0xac4b3e0] Assigned MsgHandler: 0xabc6960.
[2024-11-14 14:21:33.402026 +0000][Debug ][ExDbgMsg ][ 1127] [handler: 0xabc6960] Removed MsgHandler: 0xabc6960 from the in-queue.
[2024-11-14 14:21:33.402287 +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:21:33.402427 +0000][Debug ][ExDbgMsg ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094] Calling MsgHandler: 0xabc6960 (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:21:33.402557 +0000][Debug ][File ][ 1127] [0xabfee60@root://cephc02.gla.scotgrid.ac.uk:1094//cephfs/dune/RSE/usertests/d9/7d/000605_reco_data_2024-11-14T_093232Z.root?xrdcl.requuid=6abb72bf-b456-4e18-a85c-a0310440ecc9] 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:21:33.402592 +0000][Debug ][File ][ 1127] [0xabfee60@root://cephc02.gla.scotgrid.ac.uk:1094//cephfs/dune/RSE/usertests/d9/7d/000605_reco_data_2024-11-14T_093232Z.root?xrdcl.requuid=6abb72bf-b456-4e18-a85c-a0310440ecc9] 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:21:33.402698 +0000][Debug ][ExDbgMsg ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094] Destroying MsgHandler: 0xabc6960.
%MSG-i Root_Information: TriggerResultInserter:TriggerResults@Construction TNetXNGFile::Open() 14-Nov-2024 14:21:33 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:21:33 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:21:33.544970 +0000][Debug ][JobMgr ][ 1127] Stopping the job manager...
[2024-11-14 14:21:33.546066 +0000][Debug ][JobMgr ][ 1127] Job manager stopped
[2024-11-14 14:21:33.546594 +0000][Debug ][TaskMgr ][ 1127] Stopping the task manager...
[2024-11-14 14:21:33.546846 +0000][Debug ][TaskMgr ][ 1127] Task manager stopped
[2024-11-14 14:21:33.546918 +0000][Debug ][Poller ][ 1127] Stopping the poller...
[2024-11-14 14:21:33.547044 +0000][Debug ][TaskMgr ][ 1127] Requesting unregistration of: "TickGeneratorTask for: root://cephc02.gla.scotgrid.ac.uk:1094"
[2024-11-14 14:21:33.547074 +0000][Debug ][AsyncSock ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094.0] Closing the socket
[2024-11-14 14:21:33.547155 +0000][Debug ][Poller ][ 1127] <[::ffff:192.41.104.59]:54366><--><[::ffff:130.209.239.113]:1094> Removing socket from the poller
[2024-11-14 14:21:33.547465 +0000][Debug ][PostMaster ][ 1127] [cephc02.gla.scotgrid.ac.uk:1094] Destroying stream
[2024-11-14 14:21:33.547505 +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:21 000605_reco_data_2024-11-14T_093232Z_reco_2024-11-14T_142034Z.log
-rw-r--r-- 1 gl05pi6 eddie_users 13190 Nov 14 14:21 jobscript.log
-rw-r--r-- 1 gl05pi6 eddie_users 519 Nov 14 14:21 g4_hist.root
-rw-r--r-- 1 gl05pi6 eddie_users 104 Nov 14 14:20 all-input-dids.txt
-rw-r--r-- 1 gl05pi6 eddie_users 0 Nov 14 14:21 000605_reco_data_2024-11-14T_093232Z_reco_data_2024-11-14T_142034Z.root.ext.json
-rw-r--r-- 1 gl05pi6 eddie_users 0 Nov 14 14:21 000605_reco_data_2024-11-14T_093232Z_reco_data_2024-11-14T_142034Z.root.json