Jobsub ID 235690.2@dunegpschedd02.fnal.gov
| Jobsub ID | 235690.2@dunegpschedd02.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 08:26:44 |
| Site | NL_NIKHEF |
| Entry | VIRGO_NL_NIKHEF_klomp |
| Last heartbeat | 2025-10-31 08:31:44 |
| 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 08:27:14 |
| Input files | vd-protodune:np02vd_raw_run040266_0642_df-s03-d0_dw_0_20251025T151257.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:31:44 |
| Saved logs | justin-logs:235690.2-dunegpschedd02.fnal.gov.logs.tgz |
| List job events Cached HTCondor job logs |
Jobscript log (last 10,000 characters)
graph execution complete
[09:28:58.689] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.64 sec
[09:28:58.689] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.25 sec
[09:28:58.689] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.7 sec
[09:28:58.689] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.53 sec
[09:28:58.689] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.52 sec
[09:28:58.689] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.09 sec
[09:28:58.689] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.65 sec
[09:28:58.689] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.59 sec
[09:28:58.689] I [ timer ] Timer: WireCell::Aux::Resampler : 0.24 sec
[09:28:58.689] I [ timer ] Timer: WireCell::Aux::Resampler : 0.24 sec
[09:28:58.689] I [ timer ] Timer: WireCell::Aux::Resampler : 0.24 sec
[09:28:58.689] I [ timer ] Timer: WireCell::Aux::Resampler : 0.24 sec
[09:28:58.689] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[09:28:58.689] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[09:28:58.689] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[09:28:58.689] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:28:58.689] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:28:58.689] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:28:58.689] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:28:58.689] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[09:28:58.689] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:28:58.689] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:28:58.689] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:28:58.689] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[09:28:58.689] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[09:28:58.689] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[09:28:58.689] I [ timer ] Timer: Total node execution : 52.960000244900584 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 51664 traces tagged "gauss"
FrameSaver: q=1.11998e+07 n=971174 tag=gauss
wclsFrameSaver: saving 65025 traces tagged "wiener"
FrameSaver: q=1.21207e+07 n=918236 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 1808 XUs and 1970 XVs -> 63 XUVs
C:0 T:1 1315 XUs and 1163 XVs -> 128 XUVs
C:0 T:2 955 XUs and 1182 XVs -> 57 XUVs
C:0 T:3 398 XUs and 543 XVs -> 30 XUVs
C:0 T:4 309 XUs and 350 XVs -> 31 XUVs
C:0 T:5 5396 XUs and 3829 XVs -> 265 XUVs
C:0 T:6 1726 XUs and 1633 XVs -> 93 XUVs
C:0 T:7 11502 XUs and 9632 XVs -> 800 XUVs
C:0 T:8 2214 XUs and 1907 XVs -> 149 XUVs
C:0 T:9 772 XUs and 773 XVs -> 45 XUVs
C:0 T:10 461 XUs and 394 XVs -> 21 XUVs
C:0 T:11 427 XUs and 508 XVs -> 34 XUVs
C:0 T:12 2939 XUs and 3513 XVs -> 215 XUVs
C:0 T:13 1422 XUs and 1900 XVs -> 84 XUVs
C:0 T:14 452 XUs and 459 XVs -> 15 XUVs
C:0 T:15 1383 XUs and 1397 XVs -> 95 XUVs
2125 XUVs total
1331 collection wire objects
2125 potential space points
Neighbour search...
56223 tests to find 19392 neighbours
Iterating with no regularization...
Begin: 3.20885e+09
0 2.91183e+09
1 2.90425e+09
2 2.90387e+09
Now with regularization...
Begin: 2.87098e+09
0 2.87082e+09
31-Oct-2025 09:29:42 CET Opened output file with pattern "%ifb_reco_stage1_%tc_keepup.root"
RawFrameSource: got 12288 raw::RawDigit objects
input nticks=9280 keeping as is
[09:30:11.672] D [ main ] executing 1 apps, thread limit 0:
[09:30:11.672] D [ main ] executing 1 apps, thread limit 0:
[09:30:11.672] D [ main ] executing app: "Pgrapher"
[09:30:11.672] D [ pgraph ] <Pgrapher:> executing graph
[09:30:11.672] D [ pgraph ] executing with 26 nodes
[09:30:11.673] D [ glue ] <FrameFanout:nfsp> call=2: input: frame: ident=118480 time=7 tick=512 with 12288 traces. frame tags:[ "orig" ] 0 tagged trace sets:[ ] cmm:[ ] output 0: frame: ident=118480 time=7 tick=512 with 12288 traces. frame tags:[ "orig0" ] 0 tagged trace sets:[ ] cmm:[ ] output 1: frame: ident=118480 time=7 tick=512 with 12288 traces. frame tags:[ "orig1" ] 0 tagged trace sets:[ ] cmm:[ ] output 2: frame: ident=118480 time=7 tick=512 with 12288 traces. frame tags:[ "orig2" ] 0 tagged trace sets:[ ] cmm:[ ] output 3: frame: ident=118480 time=7 tick=512 with 12288 traces. frame tags:[ "orig3" ] 0 tagged trace sets:[ ] cmm:[ ] output 4: frame: ident=118480 time=7 tick=512 with 12288 traces. frame tags:[ "orig4" ] 0 tagged trace sets:[ ] cmm:[ ] output 5: frame: ident=118480 time=7 tick=512 with 12288 traces. frame tags:[ "orig5" ] 0 tagged trace sets:[ ] cmm:[ ] output 6: frame: ident=118480 time=7 tick=512 with 12288 traces. frame tags:[ "orig6" ] 0 tagged trace sets:[ ] cmm:[ ] output 7: frame: ident=118480 time=7 tick=512 with 12288 traces. frame tags:[ "orig7" ] 0 tagged trace sets:[ ] cmm:[ ]
[09:30:11.674] W [ glue ] <ChannelSelector:chsel7> Untagged summary not supported, summary will be dropped.
[09:30:11.674] D [ glue ] <ChannelSelector:chsel7> input frame: ident=118480 time=7 tick=512 with 12288 traces. frame tags:[ "orig7" ] 0 tagged trace sets:[ ] cmm:[ ] output: frame: ident=118480 time=7 tick=512 with 1536 traces. frame tags:[ "orig7" ] 0 tagged trace sets:[ ] cmm:[ ]
[09:30:11.675] D [sigproc ] <OmnibusSigProc:anode7sigproc7> call=2 input frame: frame: ident=118480 time=7 tick=512 with 1536 traces. frame tags:[ "orig7" ] 0 tagged trace sets:[ ] cmm:[ ]
[09:30:11.675] D [sigproc ] <OmnibusSigProc:anode7sigproc7> call=2 init nticks=9280 tbinmin=0 tbinmax=9280
[09:30:11.705] D [sigproc ] <OmnibusSigProc:anode7sigproc7> call=2 load plane index: 0, ntraces=1536, input bad regions: 0
[09:30:14.002] D [sigproc ] <OmnibusSigProc:anode7sigproc7> call=2 load plane index: 1, ntraces=1536, input bad regions: 0
[09:30:16.210] 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.8299e-05 58.6689 117.338 58.6689 58.6689 2
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 5.8299e-05 0.000114599 0.0001709 0.000114599 5.63005e-05 2
produce:tpcrawdecoder:PDVDTPCReader 14.3173 17.8716 21.4258 17.8716 3.55425 2
produce:triggerrawdecoder:PDVDTriggerReader4 0.530578 0.568009 0.605439 0.568009 0.0374305 2
produce:pdvddaphne:DAPHNEReaderPDVD 0.000379833 0.000518488 0.000657143 0.000518488 0.000138655 2
produce:ophit:OpHitFinder 6.0884e-05 0.000263525 0.000466165 0.000263525 0.000202641 2
produce:opflash:OpFlashFinderVerticalDrift 5.2138e-05 0.000168075 0.000284013 0.000168075 0.000115937 2
produce:wclsdatavd:WireCellToolkit 53.852 53.852 53.852 53.852 0 1
produce:gaushit:GausHitFinder 1.26816 1.26816 1.26816 1.26816 0 1
produce:nhitsfilter:NumberOfHitsFilter 0.000569228 0.000569228 0.000569228 0.000569228 0 1
produce:reco3d:SpacePointSolver 14.1465 14.1465 14.1465 14.1465 0 1
produce:hitpdune:DisambigFromSpacePoints 0.211781 0.211781 0.211781 0.211781 0 1
produce:pandora:StandardPandora 26.6125 26.6125 26.6125 26.6125 0 1
produce:pandoraTrack:LArPandoraTrackCreation 1.3143 1.3143 1.3143 1.3143 0 1
produce:pandoraGnocalo:GnocchiCalorimetry 0.0509561 0.0509561 0.0509561 0.0509561 0 1
[art]:TriggerResults:TriggerResultInserter 0.000113654 0.000113654 0.000113654 0.000113654 0 1
end_path:out1:RootOutput 4.259e-05 4.259e-05 4.259e-05 4.259e-05 0 1
end_path:out1:RootOutput(write) 4.98403 4.98403 4.98403 4.98403 0 1
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 8589.93 MB
Peak resident set size usage (VmHWM): 6710.39 MB
Details saved in: 'mem.db'
====================================================================================================
%MSG-s ArtException: PostEndJob 31-Oct-2025 09:31:16 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: 118480
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 