Jobsub ID 241335.18@dunegpschedd01.fnal.gov
| Jobsub ID | 241335.18@dunegpschedd01.fnal.gov |
| Workflow ID | 9405 |
| 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 07:59:55 |
| From worker node | Hostname | wn-sate-033.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:55:22 |
| Input files | vd-protodune:np02vd_raw_run040285_0000_df-s03-d3_dw_0_20251028T162127.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 07:59:55 |
| Saved logs | justin-logs:241335.18-dunegpschedd01.fnal.gov.logs.tgz |
| List job events Cached HTCondor job logs |
Jobscript log (last 10,000 characters)
[08:57:04.481] D [ glue ] frame sink sees EOS
[08:57:04.481] D [ pgraph ] <Pgrapher:> graph execution complete
[08:57:04.482] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.5 sec
[08:57:04.482] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.66 sec
[08:57:04.482] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.29 sec
[08:57:04.482] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.99 sec
[08:57:04.482] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.77 sec
[08:57:04.482] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.55 sec
[08:57:04.482] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.45 sec
[08:57:04.482] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.15 sec
[08:57:04.482] I [ timer ] Timer: WireCell::Aux::Resampler : 0.24 sec
[08:57:04.482] I [ timer ] Timer: WireCell::Aux::Resampler : 0.24 sec
[08:57:04.482] I [ timer ] Timer: WireCell::Aux::Resampler : 0.24 sec
[08:57:04.482] I [ timer ] Timer: WireCell::Aux::Resampler : 0.24 sec
[08:57:04.482] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[08:57:04.482] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[08:57:04.482] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[08:57:04.482] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0.01 sec
[08:57:04.482] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:57:04.482] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:57:04.482] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:57:04.482] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:57:04.482] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:57:04.482] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[08:57:04.482] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:57:04.482] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:57:04.482] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[08:57:04.482] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[08:57:04.482] I [ timer ] Timer: Total node execution : 50.359999634325504 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 37242 traces tagged "gauss"
FrameSaver: q=8.86875e+06 n=768375 tag=gauss
wclsFrameSaver: saving 46271 traces tagged "wiener"
FrameSaver: q=9.56527e+06 n=733176 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 2113 XUs and 2507 XVs -> 58 XUVs
C:0 T:1 2697 XUs and 2259 XVs -> 118 XUVs
C:0 T:2 838 XUs and 595 XVs -> 10 XUVs
C:0 T:3 1597 XUs and 1367 XVs -> 61 XUVs
C:0 T:4 9185 XUs and 11541 XVs -> 781 XUVs
C:0 T:5 53 XUs and 51 XVs -> 0 XUVs
C:0 T:6 558 XUs and 666 XVs -> 19 XUVs
C:0 T:7 36 XUs and 44 XVs -> 0 XUVs
C:0 T:8 654 XUs and 786 XVs -> 38 XUVs
C:0 T:9 570 XUs and 622 XVs -> 57 XUVs
C:0 T:10 75 XUs and 97 XVs -> 8 XUVs
C:0 T:11 743 XUs and 311 XVs -> 24 XUVs
C:0 T:12 364 XUs and 404 XVs -> 25 XUVs
C:0 T:13 1242 XUs and 1535 XVs -> 47 XUVs
C:0 T:14 765 XUs and 872 XVs -> 71 XUVs
C:0 T:15 415 XUs and 408 XVs -> 16 XUVs
1333 XUVs total
969 collection wire objects
1333 potential space points
Neighbour search...
30287 tests to find 8272 neighbours
Iterating with no regularization...
Begin: 1.59251e+10
0 1.5852e+10
1 1.58514e+10
Now with regularization...
Begin: 1.55418e+10
0 1.55417e+10
31-Oct-2025 08:57:36 CET Opened output file with pattern "%ifb_reco_stage1_%tc_keepup.root"
RawFrameSource: got 12288 raw::RawDigit objects
input nticks=8000 keeping as is
[08:57:56.379] D [ main ] executing 1 apps, thread limit 0:
[08:57:56.379] D [ main ] executing 1 apps, thread limit 0:
[08:57:56.379] D [ main ] executing app: "Pgrapher"
[08:57:56.379] D [ pgraph ] <Pgrapher:> executing graph
[08:57:56.379] D [ pgraph ] executing with 26 nodes
[08:57:56.381] D [ glue ] <FrameFanout:nfsp> call=2: input: frame: ident=11 time=5 tick=512 with 12288 traces. frame tags:[ "orig" ] 0 tagged trace sets:[ ] cmm:[ ] output 0: frame: ident=11 time=5 tick=512 with 12288 traces. frame tags:[ "orig0" ] 0 tagged trace sets:[ ] cmm:[ ] output 1: frame: ident=11 time=5 tick=512 with 12288 traces. frame tags:[ "orig1" ] 0 tagged trace sets:[ ] cmm:[ ] output 2: frame: ident=11 time=5 tick=512 with 12288 traces. frame tags:[ "orig2" ] 0 tagged trace sets:[ ] cmm:[ ] output 3: frame: ident=11 time=5 tick=512 with 12288 traces. frame tags:[ "orig3" ] 0 tagged trace sets:[ ] cmm:[ ] output 4: frame: ident=11 time=5 tick=512 with 12288 traces. frame tags:[ "orig4" ] 0 tagged trace sets:[ ] cmm:[ ] output 5: frame: ident=11 time=5 tick=512 with 12288 traces. frame tags:[ "orig5" ] 0 tagged trace sets:[ ] cmm:[ ] output 6: frame: ident=11 time=5 tick=512 with 12288 traces. frame tags:[ "orig6" ] 0 tagged trace sets:[ ] cmm:[ ] output 7: frame: ident=11 time=5 tick=512 with 12288 traces. frame tags:[ "orig7" ] 0 tagged trace sets:[ ] cmm:[ ]
[08:57:56.381] W [ glue ] <ChannelSelector:chsel7> Untagged summary not supported, summary will be dropped.
[08:57:56.382] D [ glue ] <ChannelSelector:chsel7> input frame: ident=11 time=5 tick=512 with 12288 traces. frame tags:[ "orig7" ] 0 tagged trace sets:[ ] cmm:[ ] output: frame: ident=11 time=5 tick=512 with 1536 traces. frame tags:[ "orig7" ] 0 tagged trace sets:[ ] cmm:[ ]
[08:57:56.382] D [sigproc ] <OmnibusSigProc:anode7sigproc7> call=2 input frame: frame: ident=11 time=5 tick=512 with 1536 traces. frame tags:[ "orig7" ] 0 tagged trace sets:[ ] cmm:[ ]
[08:57:56.382] D [sigproc ] <OmnibusSigProc:anode7sigproc7> call=2 init nticks=8000 tbinmin=0 tbinmax=8000
[08:57:56.410] D [sigproc ] <OmnibusSigProc:anode7sigproc7> call=2 load plane index: 0, ntraces=1536, input bad regions: 0
[08:57:57.765] D [sigproc ] <OmnibusSigProc:anode7sigproc7> call=2 load plane index: 1, ntraces=1536, input bad regions: 0
[08:57:59.181] D [sigproc ] <OmnibusSigProc:anode7sigproc7> call=2 load plane index: 2, ntraces=1536, input bad regions: 0
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 5.6596e-05 50.4513 100.903 50.4513 50.4513 2
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 5.6596e-05 0.000114855 0.000173114 0.000114855 5.8259e-05 2
produce:tpcrawdecoder:PDVDTPCReader 13.154 13.2716 13.3892 13.2716 0.117609 2
produce:triggerrawdecoder:PDVDTriggerReader4 0.29462 0.296947 0.299274 0.296947 0.0023273 2
produce:pdvddaphne:DAPHNEReaderPDVD 0.000419016 0.000552392 0.000685767 0.000552392 0.000133376 2
produce:ophit:OpHitFinder 5.9272e-05 0.000276414 0.000493556 0.000276414 0.000217142 2
produce:opflash:OpFlashFinderVerticalDrift 5.1487e-05 0.000179918 0.000308349 0.000179918 0.000128431 2
produce:wclsdatavd:WireCellToolkit 51.0341 51.0341 51.0341 51.0341 0 1
produce:gaushit:GausHitFinder 1.03111 1.03111 1.03111 1.03111 0 1
produce:nhitsfilter:NumberOfHitsFilter 0.000459873 0.000459873 0.000459873 0.000459873 0 1
produce:reco3d:SpacePointSolver 9.14947 9.14947 9.14947 9.14947 0 1
produce:hitpdune:DisambigFromSpacePoints 0.133946 0.133946 0.133946 0.133946 0 1
produce:pandora:StandardPandora 20.3049 20.3049 20.3049 20.3049 0 1
produce:pandoraTrack:LArPandoraTrackCreation 0.776733 0.776733 0.776733 0.776733 0 1
produce:pandoraGnocalo:GnocchiCalorimetry 0.0324759 0.0324759 0.0324759 0.0324759 0 1
[art]:TriggerResults:TriggerResultInserter 8.6693e-05 8.6693e-05 8.6693e-05 8.6693e-05 0 1
end_path:out1:RootOutput 2.4627e-05 2.4627e-05 2.4627e-05 2.4627e-05 0 1
end_path:out1:RootOutput(write) 4.71652 4.71652 4.71652 4.71652 0 1
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 8589.88 MB
Peak resident set size usage (VmHWM): 6707.13 MB
Details saved in: 'mem.db'
====================================================================================================
%MSG-s ArtException: PostEndJob 31-Oct-2025 08:59:28 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: 40285 subRun: 1 event: 11
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 