21 July 2025: This instance at RAL is read-only. Please do not try submitting new workflows for now.
Jobsub ID 212833.1@justin-prod-sched02.dune.hep.ac.uk
| Jobsub ID | 212833.1@justin-prod-sched02.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-01 04:44:22 | |
| Site | CERN | |
| Entry | CMSHTPC_T2_CH_CERN_ce510 | |
| Last heartbeat | 2025-06-02 12:51:44 | |
| From worker node | Hostname | b9g02p9532.cern.ch |
| cpuinfo | Intel(R) Xeon(R) Silver 4216 CPU @ 2.10GHz | |
| OS release | Scientific Linux release 7.9 (Nitrogen) | |
| Processors | 4 | |
| RSS bytes | 15728640000 (15000 MiB) | |
| Wall seconds limit | 343800 (95 hours) | |
| GPU | ||
| Inner Apptainer? | True | |
| Job state | outputting_failed | |
| Allocator name | justin-allocator-pro.dune.hep.ac.uk | |
| Started | 2025-06-01 04:45:21 | |
| Input files | monte-carlo-007321-000001 | |
| Jobscript | Exit code | 0 |
| Real time | 1d (115561s) | |
| CPU time | 1d (113882s = 98%) | |
| Max RSS bytes | 11514937344 (10981 MiB) | |
| Outputting started | 2025-06-02 12:51:23 | |
| Output files | ||
| Finished | 2025-06-02 12:51:44 | |
| List job events Wrapper job log | ||
Jobscript log (last 10,000 characters)
spanning [1600,3196] "loose_lf" [14:50:54.954] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 load plane index: 1, ntraces=2560, input bad regions: 0 [14:50:57.135] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 1, Qtot=79911058.11345312 Qloss=0, 3199 indices spanning [0,4795] "tight_lf" [14:50:57.609] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 1, Qtot=241763656.50461555 Qloss=0, 3196 indices spanning [1600,6394] "loose_lf" [14:50:58.791] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 load plane index: 2, ntraces=2560, input bad regions: 0 [14:51:01.873] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 2, Qtot=280106528.1555902 Qloss=0, 5117 indices spanning [0,8312] "tight_lf" [14:51:01.955] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 2, Qtot=280106528.1555902 Qloss=0, 5114 indices spanning [1600,10230] "loose_lf" [14:51:10.390] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 0, Qtot=284559236 Qloss=-11197317, 11174 indices spanning [139214,150387] "wiener" [14:51:10.731] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 0, Qtot=0.14414583169855177 Qloss=0, 800 indices spanning [150388,151187] "decon" [14:51:10.808] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 0, Qtot=272464425 Qloss=-5515313, 9719 indices spanning [151188,160906] "gauss" [14:51:12.068] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 1, Qtot=297144031 Qloss=-13187875, 13270 indices spanning [188287,201556] "wiener" [14:51:12.405] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 1, Qtot=0.058477962622419 Qloss=0, 1600 indices spanning [150388,202356] "decon" [14:51:12.482] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 1, Qtot=273679956 Qloss=-6247198, 10545 indices spanning [202357,212901] "gauss" [14:51:13.198] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 2, Qtot=285490506 Qloss=-10277706, 7179 indices spanning [228026,235204] "wiener" [14:51:13.834] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 2, Qtot=278069318.8810297 Qloss=0, 3518 indices spanning [150388,237122] "decon" [14:51:13.942] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 save plane index: 2, Qtot=277410951 Qloss=-1871846, 5122 indices spanning [237123,242244] "gauss" [14:51:13.948] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 produce 242245 traces: 31623 wiener0, 3518 decon_charge0, 25386 gauss0, frame tag: sigproc [14:51:13.948] D [sigproc ] <OmnibusSigProc:apa0sigproc0> call=98 output frame: frame: ident=149 time=-250000 tick=500 with 242245 traces. frame tags:[ "sigproc" ] 12 tagged trace sets:[ "break_roi_1st0":16178 [0] "break_roi_2nd0":16476 [0] "cleanup_roi0":14539 [0] "decon_charge0":3518 [0] "extend_roi0":17130 [0] "gauss0":25386 [0] "loose_lf0":5114 [0] "mp2_roi0":79215 [0] "mp3_roi0":11501 [0] "shrink_roi0":16448 [0] "tight_lf0":5117 [0] "wiener0":31623 [31623] ] cmm:[ ] [14:51:14.420] D [ hio ] <HDF5FrameTap:hio_sp0> HDF5FrameTap: see frame #149 with 242245 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" [14:51:14.627] D [ hio ] <HDF5FrameTap:hio_sp0> gzip:0 chunks:[0,0] [14:51:14.856] D [ hio ] <HDF5FrameTap:hio_sp0> saved /149/frame_loose_lf0 with 2560 channels 6000 ticks @t=-0.25 ms qtot=734289400 [14:51:14.876] D [ hio ] <HDF5FrameTap:hio_sp0> gzip:0 chunks:[0,0] [14:51:14.980] D [ hio ] <HDF5FrameTap:hio_sp0> saved /149/frame_cleanup_roi0 with 2081 channels 5999 ticks @t=-0.25 ms qtot=891510660 [14:51:14.998] D [ hio ] <HDF5FrameTap:hio_sp0> gzip:0 chunks:[0,0] [14:51:15.095] D [ hio ] <HDF5FrameTap:hio_sp0> saved /149/frame_mp3_roi0 with 1600 channels 5993 ticks @t=-0.25 ms qtot=1076388000 [14:51:15.132] D [ hio ] <HDF5FrameTap:hio_sp0> gzip:0 chunks:[0,0] [14:51:15.229] D [ hio ] <HDF5FrameTap:hio_sp0> saved /149/frame_mp2_roi0 with 1600 channels 5993 ticks @t=-0.25 ms qtot=7508846000 [14:51:15.231] D [ glue ] sink frame: #149 @-0.25 with 242245 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] [14:51:15.313] D [ gen ] <DepoTransform:depotransform-apa0> EOS at call=99 [14:51:15.313] D [ gen ] <Reframer:reframer-apa0> EOS at call=99 [14:51:15.313] D [ gen ] <IncoherentAddNoise:addnoise-empericalnoise-apa0> EOS at call=99 [14:51:15.313] D [ gen ] <Digitizer:digitizer-apa0> see EOS at call=99 [14:51:15.313] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=99 anode=0 [14:51:15.313] D [ hio ] <HDF5FrameTap:hio_sp0> EOS at call=99 [14:51:15.313] D [ glue ] frame sink sees EOS [14:51:15.313] D [ gen ] <DepoBagger:0> send bag #49 with 699400 depos followed by EOS [14:51:17.826] D [ gen ] <DepoFluxSplat:0> splat 49 ndepos=197842/699400/[0] ntraces=2921604 [14:51:18.364] D [ hio ] <HDF5FrameTap:hio_truth0> HDF5FrameTap: see frame #49 with 2921604 traces with frame tags: "deposplat0" and trace tags: looking for tags: "deposplat0" [14:51:19.040] D [ hio ] <HDF5FrameTap:hio_truth0> gzip:0 chunks:[0,0] [14:51:19.194] D [ hio ] <HDF5FrameTap:hio_truth0> saved /49/frame_deposplat0 with 2080 channels 6008 ticks @t=-0.3125 ms qtot=838040800 [14:51:19.252] D [ glue ] sink frame: #49 @-0.3125 with 2921604 traces, frame tags:[deposplat0], trace tags:[] [14:51:19.841] D [ gen ] <DepoFluxSplat:0> EOS at 99 [14:51:19.841] D [ hio ] <HDF5FrameTap:hio_truth0> EOS at call=99 [14:51:19.841] D [ glue ] frame sink sees EOS [14:51:19.841] D [ pgraph ] <Pgrapher:> graph execution complete [14:51:19.843] I [ timer ] Timer: WireCell::Gen::DepoTransform : 86.23 sec [14:51:19.843] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 28.41 sec [14:51:19.843] I [ timer ] Timer: WireCell::Gen::DepoFluxSplat : 7.76 sec [14:51:19.843] I [ timer ] Timer: WireCell::Gen::Drifter : 7.21 sec [14:51:19.843] I [ timer ] Timer: WireCell::Hio::HDF5FrameTap : 6.24 sec [14:51:19.843] I [ timer ] Timer: WireCell::Gen::DumpFrames : 6.19 sec [14:51:19.843] I [ timer ] Timer: WireCell::Hio::HDF5FrameTap : 6 sec [14:51:19.843] I [ timer ] Timer: WireCell::Gen::DepoBagger : 5.99 sec [14:51:19.844] I [ timer ] Timer: WireCell::Gen::Digitizer : 5.51 sec [14:51:19.844] I [ timer ] Timer: WireCell::Gen::Retagger : 5.41 sec [14:51:19.844] I [ timer ] Timer: WireCell::Gen::DepoBagger : 5.37 sec [14:51:19.844] I [ timer ] Timer: WireCell::Gen::Reframer : 5.31 sec [14:51:19.844] I [ timer ] Timer: WireCell::Gen::IncoherentAddNoise : 5.24 sec [14:51:19.844] I [ timer ] Timer: WireCell::Gen::DumpFrames : 5.09 sec [14:51:19.844] I [ timer ] Timer: WireCell::Gen::DepoFanout : 4.79 sec [14:51:19.844] I [ timer ] Timer: WireCell::Gen::DepoFanout : 3.47 sec [14:51:19.844] I [ timer ] Timer: wcls::SimDepoSource : 1.24 sec [14:51:19.844] I [ timer ] Timer: Total node execution : 195.46000289916992 sec 02-Jun-2025 14:51:21 CEST Closed output file "g4_deposplat.root" 02-Jun-2025 14:51:21 CEST Closed input file "g4.root" ================================================================================================================================ TimeTracker printout (sec) Min Avg Max Median RMS nEvts ================================================================================================================================ Full event 135.052 248.086 436.202 242.951 60.9313 50 -------------------------------------------------------------------------------------------------------------------------------- source:RootInput(read) 0.00109666 0.00455585 0.0189362 0.00345639 0.00325182 50 reco:rns:RandomNumberSaver 4.8194e-05 6.07862e-05 0.000297625 5.4487e-05 3.45788e-05 50 reco:wirecell:WireCellToolkit 135.049 247.892 436.198 240.799 60.963 50 [art]:TriggerResults:TriggerResultInserter 5.5391e-05 7.51926e-05 0.000482826 6.02835e-05 6.03926e-05 50 end_path:out1:RootOutput 5.444e-06 7.79142e-06 2.8699e-05 6.2075e-06 4.37295e-06 50 end_path:out1:RootOutput(write) 0.00021943 0.000332598 0.00116899 0.000308742 0.000153379 50 ================================================================================================================================ ==================================================================================================== MemoryTracker summary (base-10 MB units used) Peak virtual memory usage (VmPeak) : 6161.15 MB Peak resident set size usage (VmHWM): 3967.25 MB Details saved in: 'mem.db' ==================================================================================================== [14:51:21.474] D [ main ] finalizing component: "HDF5FrameTap":"hio_truth0" [14:51:21.481] 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.