Jobsub ID 241334.17@dunegpschedd01.fnal.gov
| Jobsub ID | 241334.17@dunegpschedd01.fnal.gov |
| Workflow ID | 9374 |
| Stage ID | 1 |
| User name | ykermaid@fnal.gov |
| HTCondor Group | group_dune.prod_mcsim |
| Requested | Processors | 1 |
| GPU | No |
| RSS bytes | 4193255424 (3999 MiB) |
| Wall seconds limit | 18000 (5 hours) |
| Submitted time | 2025-10-31 07:50:43 |
| Site | NL_NIKHEF |
| Entry | VIRGO_NL_NIKHEF_klomp |
| Last heartbeat | 2025-10-31 08:03:28 |
| From worker node | Hostname | wn-sate-044.farm.nikhef.nl |
| cpuinfo | AMD EPYC 7551P 32-Core Processor |
| OS release | Scientific Linux release 7.9 (Nitrogen) |
| Processors | 1 |
| RSS bytes | 4194304000 (4000 MiB) |
| Wall seconds limit | 129600 (36 hours) |
| GPU | |
| Inner Apptainer? | True |
| Job state | jobscript_error |
| Started | 2025-10-31 07:51:20 |
| Input files | vd-protodune:np02vd_raw_run040266_0489_df-s03-d2_dw_0_20251025T105426.hdf5
|
| Jobscript | Exit code | 1 |
| Real time | 0m (0s) |
| CPU time | 0m (0s = 0%) |
| Max RSS bytes | 0 (0 MiB) |
| Outputting started | |
| Output files | |
| Finished | 2025-10-31 08:03:28 |
| Saved logs | justin-logs:241334.17-dunegpschedd01.fnal.gov.logs.tgz |
| List job events Cached HTCondor job logs |
Jobscript log (last 10,000 characters)
<FrameFanin:nfsp> EOS at call=5 with 8
[09:01:01.137] D [ glue ] frame sink sees EOS
[09:01:01.137] D [ pgraph ] <Pgrapher:> graph execution complete
[09:01:01.137] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.39 sec
[09:01:01.137] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.3 sec
[09:01:01.137] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.1 sec
[09:01:01.137] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.04 sec
[09:01:01.137] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.03 sec
[09:01:01.137] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.9 sec
[09:01:01.137] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.56 sec
[09:01:01.137] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.55 sec
[09:01:01.137] I [ timer ] Timer: WireCell::Aux::Resampler : 0.3 sec
[09:01:01.137] I [ timer ] Timer: WireCell::Aux::Resampler : 0.3 sec
[09:01:01.137] I [ timer ] Timer: WireCell::Aux::Resampler : 0.3 sec
[09:01:01.137] I [ timer ] Timer: WireCell::Aux::Resampler : 0.29 sec
[09:01:01.137] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[09:01:01.137] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[09:01:01.137] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[09:01:01.137] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0.01 sec
[09:01:01.137] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:01:01.137] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:01:01.137] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:01:01.137] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:01:01.137] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:01:01.137] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[09:01:01.137] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:01:01.137] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:01:01.137] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[09:01:01.137] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[09:01:01.137] I [ timer ] Timer: Total node execution : 73.12000086531043 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 32423 traces tagged "gauss"
FrameSaver: q=7.15464e+06 n=640452 tag=gauss
wclsFrameSaver: saving 40064 traces tagged "wiener"
FrameSaver: q=7.67169e+06 n=612549 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 52 XUs and 53 XVs -> 1 XUVs
C:0 T:1 1386 XUs and 1019 XVs -> 51 XUVs
C:0 T:2 793 XUs and 850 XVs -> 12 XUVs
C:0 T:3 1018 XUs and 1135 XVs -> 46 XUVs
C:0 T:4 403 XUs and 418 XVs -> 14 XUVs
C:0 T:5 369 XUs and 342 XVs -> 29 XUVs
C:0 T:6 7157 XUs and 8848 XVs -> 539 XUVs
C:0 T:7 74 XUs and 85 XVs -> 0 XUVs
C:0 T:8 938 XUs and 1560 XVs -> 55 XUVs
C:0 T:9 499 XUs and 471 XVs -> 11 XUVs
C:0 T:10 231 XUs and 350 XVs -> 17 XUVs
C:0 T:11 183 XUs and 216 XVs -> 16 XUVs
C:0 T:12 795 XUs and 779 XVs -> 27 XUVs
C:0 T:13 369 XUs and 440 XVs -> 41 XUVs
C:0 T:14 76 XUs and 86 XVs -> 4 XUVs
C:0 T:15 439 XUs and 448 XVs -> 29 XUVs
892 XUVs total
620 collection wire objects
892 potential space points
Neighbour search...
14442 tests to find 4948 neighbours
Iterating with no regularization...
Begin: 3.17656e+09
0 3.00467e+09
1 2.99903e+09
2 2.9987e+09
Now with regularization...
Begin: 2.91266e+09
0 2.91259e+09
RawFrameSource: got 12288 raw::RawDigit objects
input nticks=9280 keeping as is
[09:01:49.019] D [ main ] executing 1 apps, thread limit 0:
[09:01:49.019] D [ main ] executing 1 apps, thread limit 0:
[09:01:49.019] D [ main ] executing app: "Pgrapher"
[09:01:49.019] D [ pgraph ] <Pgrapher:> executing graph
[09:01:49.019] D [ pgraph ] executing with 26 nodes
[09:01:49.021] D [ glue ] <FrameFanout:nfsp> call=6: input: frame: ident=90266 time=11 tick=512 with 12288 traces. frame tags:[ "orig" ] 0 tagged trace sets:[ ] cmm:[ ] output 0: frame: ident=90266 time=11 tick=512 with 12288 traces. frame tags:[ "orig0" ] 0 tagged trace sets:[ ] cmm:[ ] output 1: frame: ident=90266 time=11 tick=512 with 12288 traces. frame tags:[ "orig1" ] 0 tagged trace sets:[ ] cmm:[ ] output 2: frame: ident=90266 time=11 tick=512 with 12288 traces. frame tags:[ "orig2" ] 0 tagged trace sets:[ ] cmm:[ ] output 3: frame: ident=90266 time=11 tick=512 with 12288 traces. frame tags:[ "orig3" ] 0 tagged trace sets:[ ] cmm:[ ] output 4: frame: ident=90266 time=11 tick=512 with 12288 traces. frame tags:[ "orig4" ] 0 tagged trace sets:[ ] cmm:[ ] output 5: frame: ident=90266 time=11 tick=512 with 12288 traces. frame tags:[ "orig5" ] 0 tagged trace sets:[ ] cmm:[ ] output 6: frame: ident=90266 time=11 tick=512 with 12288 traces. frame tags:[ "orig6" ] 0 tagged trace sets:[ ] cmm:[ ] output 7: frame: ident=90266 time=11 tick=512 with 12288 traces. frame tags:[ "orig7" ] 0 tagged trace sets:[ ] cmm:[ ]
[09:01:49.021] W [ glue ] <ChannelSelector:chsel7> Untagged summary not supported, summary will be dropped.
[09:01:49.022] D [ glue ] <ChannelSelector:chsel7> input frame: ident=90266 time=11 tick=512 with 12288 traces. frame tags:[ "orig7" ] 0 tagged trace sets:[ ] cmm:[ ] output: frame: ident=90266 time=11 tick=512 with 1536 traces. frame tags:[ "orig7" ] 0 tagged trace sets:[ ] cmm:[ ]
[09:01:49.022] D [sigproc ] <OmnibusSigProc:anode7sigproc7> call=6 input frame: frame: ident=90266 time=11 tick=512 with 1536 traces. frame tags:[ "orig7" ] 0 tagged trace sets:[ ] cmm:[ ]
[09:01:49.023] D [sigproc ] <OmnibusSigProc:anode7sigproc7> call=6 init nticks=9280 tbinmin=0 tbinmax=9280
[09:01:49.063] D [sigproc ] <OmnibusSigProc:anode7sigproc7> call=6 load plane index: 0, ntraces=1536, input bad regions: 0
[09:01:52.128] D [sigproc ] <OmnibusSigProc:anode7sigproc7> call=6 load plane index: 1, ntraces=1536, input bad regions: 0
[09:01:55.290] D [sigproc ] <OmnibusSigProc:anode7sigproc7> call=6 load plane index: 2, ntraces=1536, input bad regions: 0
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 9.4136e-05 139.585 253.287 152.527 93.2252 4
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 7.8698e-05 0.00012518 0.000248777 8.6622e-05 7.16295e-05 4
produce:tpcrawdecoder:PDVDTPCReader 15.7802 16.8988 17.761 17.0271 0.718357 4
produce:triggerrawdecoder:PDVDTriggerReader4 0.523979 0.554127 0.594061 0.549233 0.0260339 4
produce:pdvddaphne:DAPHNEReaderPDVD 0.000410771 0.000555172 0.00095363 0.000428143 0.000230159 4
produce:ophit:OpHitFinder 7.9579e-05 0.000253386 0.000743265 9.5349e-05 0.000282911 4
produce:opflash:OpFlashFinderVerticalDrift 5.839e-05 0.000167878 0.000487375 6.28725e-05 0.000184475 4
produce:wclsdatavd:WireCellToolkit 74.4602 99.0168 118.548 104.043 18.3461 3
produce:gaushit:GausHitFinder 1.03497 1.72475 2.28695 1.85234 0.519019 3
produce:nhitsfilter:NumberOfHitsFilter 0.000238288 0.000482643 0.000697098 0.000512542 0.000188498 3
produce:reco3d:SpacePointSolver 6.74702 14.785 21.9569 15.651 6.23954 3
produce:hitpdune:DisambigFromSpacePoints 0.107323 0.247285 0.398653 0.235879 0.119208 3
produce:pandora:StandardPandora 15.084 44.6958 81.9488 37.0547 27.827 3
produce:pandoraTrack:LArPandoraTrackCreation 0.687854 2.1573 3.60481 2.17924 1.19094 3
produce:pandoraGnocalo:GnocchiCalorimetry 0.0308602 0.0536258 0.0654582 0.064559 0.0161019 3
[art]:TriggerResults:TriggerResultInserter 5.2148e-05 7.84073e-05 0.000123291 5.9783e-05 3.18902e-05 3
end_path:out1:RootOutput 9.778e-06 1.91393e-05 3.4565e-05 1.3075e-05 1.09903e-05 3
end_path:out1:RootOutput(write) 5.13489 6.21159 6.84129 6.65859 0.764986 3
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 8589.53 MB
Peak resident set size usage (VmHWM): 6619.05 MB
Details saved in: 'mem.db'
====================================================================================================
%MSG-s ArtException: PostEndJob 31-Oct-2025 09:02:54 CET ModuleEndJob
---- EventProcessorFailure BEGIN
EventProcessor: an exception occurred during current event processing
---- ScheduleExecutionFailure BEGIN
Path: ProcessingStopped.
---- BadAlloc BEGIN
A bad_alloc exception was thrown while processing module WireCellToolkit/wclsdatavd run: 40266 subRun: 1 event: 90266
The job has probably exhausted the virtual memory available to the process.
---- BadAlloc END
Exception going through path produce
---- ScheduleExecutionFailure END
---- EventProcessorFailure END
%MSG
Art has completed and will exit with status 1.
Error in reco1 