21 July 2025: This instance at RAL is read-only. Please do not try submitting new workflows for now.
Jobsub ID 406601.1@justin-prod-sched01.dune.hep.ac.uk
| Jobsub ID | 406601.1@justin-prod-sched01.dune.hep.ac.uk | |
| Workflow ID | 7321 | |
| Stage ID | 1 | |
| User name | sergeym@fnal.gov | |
| HTCondor Group | group_dune | |
| Requested | Processors | 4 |
| GPU | No | |
| RSS bytes | 15728640000 (15000 MiB) | |
| Wall seconds limit | 80000 (22 hours) | |
| Submitted time | 2025-06-04 14:11:36 | |
| Site | US_FNAL-FermiGrid | |
| Entry | FNAL_GPGrid_ce04_mcore_op_duneonly | |
| Last heartbeat | 2025-06-05 13:40:12 | |
| From worker node | Hostname | dunegli-5572032-0-fnpc19117.fnal.gov |
| cpuinfo | AMD EPYC 7502 32-Core Processor | |
| OS release | Scientific Linux release 7.9 (Nitrogen) | |
| Processors | 4 | |
| RSS bytes | 15728640000 (15000 MiB) | |
| Wall seconds limit | 172800 (48 hours) | |
| GPU | ||
| Inner Apptainer? | True | |
| Job state | outputting_failed | |
| Allocator name | justin-allocator-pro.dune.hep.ac.uk | |
| Started | 2025-06-04 20:59:18 | |
| Input files | ||
| Jobscript | Exit code | 0 |
| Real time | 15h (57322s) | |
| CPU time | 15h (56750s = 99%) | |
| Max RSS bytes | 10075074560 (9608 MiB) | |
| Outputting started | 2025-06-05 12:54:42 | |
| Output files | ||
| Finished | 2025-06-05 13:40:12 | |
| List job events Wrapper job log | ||
Jobscript log (last 10,000 characters)
599 indices spanning [1600,3198] "loose_lf" [12:54:30.524] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 load plane index: 1, ntraces=2560, input bad regions: 0 [12:54:31.587] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 1, Qtot=60031954.86812079 Qloss=0, 3199 indices spanning [0,4797] "tight_lf" [12:54:31.828] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 1, Qtot=121997647.63492927 Qloss=0, 3201 indices spanning [1600,6399] "loose_lf" [12:54:32.448] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 load plane index: 2, ntraces=2560, input bad regions: 0 [12:54:33.564] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 2, Qtot=148650814.1884765 Qloss=0, 5118 indices spanning [0,8318] "tight_lf" [12:54:33.606] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 2, Qtot=148650814.1884765 Qloss=0, 5120 indices spanning [1600,10237] "loose_lf" [12:54:35.718] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 0, Qtot=159483294 Qloss=-6117907, 7462 indices spanning [86072,93533] "wiener" [12:54:35.881] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 0, Qtot=0.07551235379651189 Qloss=0, 800 indices spanning [93534,94333] "decon" [12:54:35.936] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 0, Qtot=150039741 Qloss=-2231239, 6441 indices spanning [94334,100774] "gauss" [12:54:36.474] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 1, Qtot=156652647 Qloss=-7875459, 9920 indices spanning [123106,133025] "wiener" [12:54:36.617] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 1, Qtot=-0.06058024847880006 Qloss=0, 1600 indices spanning [93534,133825] "decon" [12:54:36.660] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 1, Qtot=145350938 Qloss=-2791097, 7941 indices spanning [133826,141766] "gauss" [12:54:36.991] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 2, Qtot=151941724 Qloss=-4591229, 3602 indices spanning [149877,153478] "wiener" [12:54:37.286] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 2, Qtot=146847032.50155115 Qloss=0, 3518 indices spanning [93534,155396] "decon" [12:54:37.347] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 2, Qtot=148118470 Qloss=-690706, 2775 indices spanning [155397,158171] "gauss" [12:54:37.348] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 produce 158172 traces: 20984 wiener0, 3518 decon_charge0, 17157 gauss0, frame tag: sigproc [12:54:37.348] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 output frame: frame: ident=149 time=-250000 tick=500 with 158172 traces. frame tags:[ "sigproc" ] 12 tagged trace sets:[ "break_roi_1st0":12102 [0] "break_roi_2nd0":12116 [0] "cleanup_roi0":11268 [0] "decon_charge0":3518 [0] "extend_roi0":12833 [0] "gauss0":17157 [0] "loose_lf0":5120 [0] "mp2_roi0":38980 [0] "mp3_roi0":6874 [0] "shrink_roi0":12102 [0] "tight_lf0":5118 [0] "wiener0":20984 [20984] ] cmm:[ ] [12:54:37.453] D [ hio ] <HDF5FrameTap:hio_sp0> HDF5FrameTap: see frame #149 with 158172 traces with frame tags: "sigproc" and trace tags: "break_roi_1st0" "break_roi_2nd0" "cleanup_roi0" "decon_charge0" "extend_roi0" "gauss0" "loose_lf0" "mp2_roi0" "mp3_roi0" "shrink_roi0" "tight_lf0" "wiener0" looking for tags: "loose_lf0" "cleanup_roi0" "mp3_roi0" "mp2_roi0" [12:54:37.518] D [ hio ] <HDF5FrameTap:hio_sp0> gzip:0 chunks:[0,0] [12:54:37.744] D [ hio ] <HDF5FrameTap:hio_sp0> saved /149/frame_loose_lf0 with 2560 channels 6000 ticks @t=-0.25 ms qtot=406294140 [12:54:37.757] D [ hio ] <HDF5FrameTap:hio_sp0> gzip:0 chunks:[0,0] [12:54:37.945] D [ hio ] <HDF5FrameTap:hio_sp0> saved /149/frame_cleanup_roi0 with 2079 channels 5999 ticks @t=-0.25 ms qtot=481766660 [12:54:37.953] D [ hio ] <HDF5FrameTap:hio_sp0> gzip:0 chunks:[0,0] [12:54:38.093] D [ hio ] <HDF5FrameTap:hio_sp0> saved /149/frame_mp3_roi0 with 1483 channels 6000 ticks @t=-0.25 ms qtot=594484000 [12:54:38.104] D [ hio ] <HDF5FrameTap:hio_sp0> gzip:0 chunks:[0,0] [12:54:38.244] D [ hio ] <HDF5FrameTap:hio_sp0> saved /149/frame_mp2_roi0 with 1600 channels 6000 ticks @t=-0.25 ms qtot=2754600000 [12:54:38.245] D [ glue ] sink frame: #149 @-0.25 with 158172 traces, frame tags:[sigproc], trace tags:[break_roi_1st0, break_roi_2nd0, cleanup_roi0, decon_charge0, extend_roi0, gauss0, loose_lf0, mp2_roi0, mp3_roi0, shrink_roi0, tight_lf0, wiener0] [12:54:38.274] D [ gen ] <DepoTransform:depotransform-apa0> EOS at call=99 [12:54:38.274] D [ gen ] <Reframer:reframer-apa0> EOS at call=99 [12:54:38.274] D [ gen ] <IncoherentAddNoise:addnoise-empericalnoise-apa0> EOS at call=99 [12:54:38.274] D [ gen ] <Digitizer:digitizer-apa0> see EOS at call=99 [12:54:38.274] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=99 anode=0 [12:54:38.274] D [ hio ] <HDF5FrameTap:hio_sp0> EOS at call=99 [12:54:38.274] D [ glue ] frame sink sees EOS [12:54:38.274] D [ gen ] <DepoBagger:0> send bag #49 with 415533 depos followed by EOS [12:54:39.216] D [ gen ] <DepoFluxSplat:0> splat 49 ndepos=110967/415533/[0] ntraces=1723195 [12:54:39.351] D [ hio ] <HDF5FrameTap:hio_truth0> HDF5FrameTap: see frame #49 with 1723195 traces with frame tags: "deposplat0" and trace tags: looking for tags: "deposplat0" [12:54:39.641] D [ hio ] <HDF5FrameTap:hio_truth0> gzip:0 chunks:[0,0] [12:54:39.930] D [ hio ] <HDF5FrameTap:hio_truth0> saved /49/frame_deposplat0 with 2077 channels 6007 ticks @t=-0.3125 ms qtot=444045600 [12:54:39.947] D [ glue ] sink frame: #49 @-0.3125 with 1723195 traces, frame tags:[deposplat0], trace tags:[] [12:54:40.261] D [ gen ] <DepoFluxSplat:0> EOS at 99 [12:54:40.261] D [ hio ] <HDF5FrameTap:hio_truth0> EOS at call=99 [12:54:40.261] D [ glue ] frame sink sees EOS [12:54:40.261] D [ pgraph ] <Pgrapher:> graph execution complete [12:54:40.262] I [ timer ] Timer: WireCell::Gen::DepoTransform : 47.68 sec [12:54:40.262] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.59 sec [12:54:40.262] I [ timer ] Timer: WireCell::Gen::DepoFluxSplat : 6.74 sec [12:54:40.262] I [ timer ] Timer: WireCell::Hio::HDF5FrameTap : 6.72 sec [12:54:40.262] I [ timer ] Timer: WireCell::Gen::DepoBagger : 6.57 sec [12:54:40.262] I [ timer ] Timer: WireCell::Hio::HDF5FrameTap : 6.45 sec [12:54:40.262] I [ timer ] Timer: WireCell::Gen::Digitizer : 6.19 sec [12:54:40.262] I [ timer ] Timer: WireCell::Gen::IncoherentAddNoise : 6.12 sec [12:54:40.262] I [ timer ] Timer: WireCell::Gen::Retagger : 6.04 sec [12:54:40.262] I [ timer ] Timer: WireCell::Gen::DumpFrames : 5.97 sec [12:54:40.262] I [ timer ] Timer: WireCell::Gen::Reframer : 5.89 sec [12:54:40.262] I [ timer ] Timer: WireCell::Gen::DumpFrames : 5.81 sec [12:54:40.262] I [ timer ] Timer: WireCell::Gen::DepoBagger : 5.46 sec [12:54:40.262] I [ timer ] Timer: WireCell::Gen::Drifter : 4.29 sec [12:54:40.262] I [ timer ] Timer: WireCell::Gen::DepoFanout : 4.16 sec [12:54:40.262] I [ timer ] Timer: WireCell::Gen::DepoFanout : 3.37 sec [12:54:40.262] I [ timer ] Timer: wcls::SimDepoSource : 1.16 sec [12:54:40.262] I [ timer ] Timer: Total node execution : 143.20999920368195 sec 05-Jun-2025 12:54:41 UTC Closed output file "g4_deposplat.root" 05-Jun-2025 12:54:41 UTC Closed input file "g4.root" ================================================================================================================================ TimeTracker printout (sec) Min Avg Max Median RMS nEvts ================================================================================================================================ Full event 134.323 191.653 263.99 193.3 24.5373 50 -------------------------------------------------------------------------------------------------------------------------------- source:RootInput(read) 0.000345502 0.00322763 0.0183108 0.00217835 0.00352542 50 reco:rns:RandomNumberSaver 4.205e-05 4.81299e-05 0.000230752 4.42305e-05 2.61262e-05 50 reco:wirecell:WireCellToolkit 134.305 191.561 263.987 193.001 24.4509 50 [art]:TriggerResults:TriggerResultInserter 3.942e-05 4.78561e-05 0.000114841 4.49055e-05 1.10494e-05 50 end_path:out1:RootOutput 3.03e-06 5.52544e-06 2.2411e-05 5.455e-06 3.23713e-06 50 end_path:out1:RootOutput(write) 0.000155521 0.00685312 0.332203 0.000185086 0.0464787 50 ================================================================================================================================ ==================================================================================================== MemoryTracker summary (base-10 MB units used) Peak virtual memory usage (VmPeak) : 5688.71 MB Peak resident set size usage (VmHWM): 3498.53 MB Details saved in: 'mem.db' ==================================================================================================== [12:54:41.114] D [ main ] finalizing component: "HDF5FrameTap":"hio_truth0" [12:54:41.119] D [ main ] finalizing component: "HDF5FrameTap":"hio_sp0" ToolBasedRawDigitPrepService:dtor: Event count: 0 ToolBasedRawDigitPrepService:dtor: Call count: 0 ToolBasedRawDigitPrepService:dtor: Time report for 4 tools. ToolBasedRawDigitPrepService:dtor: digitReader: 0.00 sec ToolBasedRawDigitPrepService:dtor: adcSampleFiller: 0.00 sec ToolBasedRawDigitPrepService:dtor: adcScaleAdcToKe: 0.00 sec ToolBasedRawDigitPrepService:dtor: pdspTailPedRemovalZKe: 0.00 sec Art has completed and will exit with status 0.