justIN           Dashboard       Workflows       Jobs       AWT       Sites       Storages       Docs       Login

Jobsub ID 47608.2@dunegpschedd01.fnal.gov

Jobsub ID47608.2@dunegpschedd01.fnal.gov
Workflow ID2644
Stage ID1
User nameykermaid@fnal.gov
HTCondor Groupgroup_dune.prod_mcsim
RequestedProcessors1
GPUNo
RSS bytes4193255424 (3999 MiB)
Wall seconds limit18000 (5 hours)
Submitted time2025-09-17 16:08:23
SiteNL_NIKHEF
EntryVIRGO_NL_NIKHEF_dissel
Last heartbeat2025-09-17 17:20:29
From worker nodeHostnamewn-pep-010.farm.nikhef.nl
cpuinfoIntel(R) Xeon(R) Gold 6148 CPU @ 2.40GHz
OS releaseScientific Linux release 7.9 (Nitrogen)
Processors1
RSS bytes4194304000 (4000 MiB)
Wall seconds limit129600 (36 hours)
GPU
Inner Apptainer?True
Job statejobscript_error
Started2025-09-17 16:26:29
Input filesvd-protodune:np02vd_raw_run039353_0984_df-s05-d2_dw_0_20250916T114433.hdf5
JobscriptExit code1
Real time0m (0s)
CPU time0m (0s = 0%)
Max RSS bytes0 (0 MiB)
Outputting started 
Output files
Finished2025-09-17 17:20:29
Saved logsjustin-logs:47608.2-dunegpschedd01.fnal.gov.logs.tgz
List job events     Cached HTCondor job logs

Jobscript log (last 10,000 characters)

fsp> EOS at call=15 with 8 
[18:59:54.964] D [  glue  ] frame sink sees EOS
[18:59:54.964] D [ pgraph ] <Pgrapher:> graph execution complete 
[18:59:54.964] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.57 sec
[18:59:54.964] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.27 sec
[18:59:54.964] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.27 sec
[18:59:54.964] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.18 sec
[18:59:54.964] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.74 sec
[18:59:54.964] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.7 sec
[18:59:54.964] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.65 sec
[18:59:54.964] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.29 sec
[18:59:54.964] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.91 sec
[18:59:54.964] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.9 sec
[18:59:54.964] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.87 sec
[18:59:54.964] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.86 sec
[18:59:54.964] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.03 sec
[18:59:54.964] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[18:59:54.964] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.01 sec
[18:59:54.964] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:59:54.964] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:59:54.964] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:59:54.964] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:59:54.964] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:59:54.964] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[18:59:54.964] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:59:54.964] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:59:54.964] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[18:59:54.964] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[18:59:54.964] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[18:59:54.964] I [ timer  ] Timer: Total node execution : 75.27000009641051 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 42530 traces tagged "gauss"
FrameSaver: q=6.70232e+06 n=863956 tag=gauss
wclsFrameSaver: saving 51235 traces tagged "wiener"
FrameSaver: q=7.05348e+06 n=830212 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 1835 XUs and 1958 XVs -> 75 XUVs
C:0 T:1 203 XUs and 312 XVs -> 2 XUVs
C:0 T:2 1557 XUs and 1782 XVs -> 116 XUVs
C:0 T:3 303 XUs and 282 XVs -> 6 XUVs
C:0 T:4 253 XUs and 281 XVs -> 5 XUVs
C:0 T:5 131 XUs and 189 XVs -> 2 XUVs
C:0 T:6 218 XUs and 252 XVs -> 8 XUVs
C:0 T:7 683 XUs and 652 XVs -> 34 XUVs
C:0 T:8 4051 XUs and 2959 XVs -> 136 XUVs
C:0 T:9 520 XUs and 888 XVs -> 38 XUVs
C:0 T:10 2265 XUs and 2301 XVs -> 109 XUVs
C:0 T:11 1072 XUs and 1006 XVs -> 63 XUVs
C:0 T:12 1787 XUs and 3473 XVs -> 112 XUVs
C:0 T:13 984 XUs and 1575 XVs -> 77 XUVs
C:0 T:14 959 XUs and 1351 XVs -> 48 XUVs
C:0 T:15 2368 XUs and 2499 XVs -> 114 XUVs
945 XUVs total
838 collection wire objects
945 potential space points
Neighbour search...
4641 tests to find 1994 neighbours
Iterating with no regularization...
Begin: 2.75055e+08
0 2.70336e+08
1 2.70268e+08
Now with regularization...
Begin: 2.6553e+08
0 2.65525e+08
RawFrameSource: got 12288 raw::RawDigit objects
	input nticks=10000 keeping as is
[19:02:55.809] D [  main  ] executing 1 apps, thread limit 0:
[19:02:55.809] D [  main  ] executing 1 apps, thread limit 0:
[19:02:55.809] D [  main  ] executing app: "Pgrapher"
[19:02:55.809] D [ pgraph ] <Pgrapher:> executing graph 
[19:02:55.809] D [ pgraph ] executing with 26 nodes
[19:02:55.811] D [  glue  ] <FrameFanout:nfsp> call=16: input: frame: ident=75910 time=32 tick=512 with 12288 traces.  frame tags:[ "orig" ] 0 tagged trace sets:[ ] cmm:[ ] output 0: frame: ident=75910 time=32 tick=512 with 12288 traces.  frame tags:[ "orig0" ] 0 tagged trace sets:[ ] cmm:[ ] output 1: frame: ident=75910 time=32 tick=512 with 12288 traces.  frame tags:[ "orig1" ] 0 tagged trace sets:[ ] cmm:[ ] output 2: frame: ident=75910 time=32 tick=512 with 12288 traces.  frame tags:[ "orig2" ] 0 tagged trace sets:[ ] cmm:[ ] output 3: frame: ident=75910 time=32 tick=512 with 12288 traces.  frame tags:[ "orig3" ] 0 tagged trace sets:[ ] cmm:[ ] output 4: frame: ident=75910 time=32 tick=512 with 12288 traces.  frame tags:[ "orig4" ] 0 tagged trace sets:[ ] cmm:[ ] output 5: frame: ident=75910 time=32 tick=512 with 12288 traces.  frame tags:[ "orig5" ] 0 tagged trace sets:[ ] cmm:[ ] output 6: frame: ident=75910 time=32 tick=512 with 12288 traces.  frame tags:[ "orig6" ] 0 tagged trace sets:[ ] cmm:[ ] output 7: frame: ident=75910 time=32 tick=512 with 12288 traces.  frame tags:[ "orig7" ] 0 tagged trace sets:[ ] cmm:[ ]  
[19:02:55.812] W [  glue  ] <ChannelSelector:chsel7> Untagged summary not supported, summary will be dropped. 
[19:02:55.812] D [  glue  ] <ChannelSelector:chsel7> input frame: ident=75910 time=32 tick=512 with 12288 traces.  frame tags:[ "orig7" ] 0 tagged trace sets:[ ] cmm:[ ] output: frame: ident=75910 time=32 tick=512 with 1536 traces.  frame tags:[ "orig7" ] 0 tagged trace sets:[ ] cmm:[ ] 
[19:02:55.812] D [sigproc ] <OmnibusSigProc:anode7sigproc7> call=16 input frame: frame: ident=75910 time=32 tick=512 with 1536 traces.  frame tags:[ "orig7" ] 0 tagged trace sets:[ ] cmm:[ ] 
[19:02:55.813] D [sigproc ] <OmnibusSigProc:anode7sigproc7> call=16 init nticks=10048 tbinmin=0 tbinmax=10048 
[19:02:55.858] D [sigproc ] <OmnibusSigProc:anode7sigproc7> call=16 load plane index: 0, ntraces=1536, input bad regions: 0 
[19:02:58.730] D [sigproc ] <OmnibusSigProc:anode7sigproc7> call=16 load plane index: 1, ntraces=1536, input bad regions: 0 
[19:03:01.525] D [sigproc ] <OmnibusSigProc:anode7sigproc7> call=16 load plane index: 2, ntraces=1536, input bad regions: 0 

==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                      5.9214e-05       226.8        331.188       244.271       85.4829         9     
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read)                      5.7645e-05    6.88518e-05   0.000134478   6.1986e-05    2.32786e-05       9     
produce:tpcrawdecoder:PDVDTPCReader               85.8678       105.913       122.815       108.072       11.0957         9     
produce:triggerrawdecoder:PDVDTriggerReader4     0.289443      0.360693      0.424097      0.367457      0.0438552        9     
produce:pdvddaphne:DAPHNEReaderPDVD             0.000329868   0.000373005   0.000673498   0.000335249   0.000106344       9     
produce:ophit:OpHitFinder                       0.000110472   0.000195149   0.000744362   0.000116034   0.000195733       9     
produce:opflash:OpFlashFinderVerticalDrift      4.2423e-05    7.50454e-05   0.000292107   4.6569e-05    7.68334e-05       9     
produce:wclsdatavd:WireCellToolkit                74.2021       80.2036       88.2739       78.3196       4.90414         8     
produce:gaushit:GausHitFinder                    0.950877       1.32879       1.99192       1.30897      0.328072         8     
produce:nhitsfilter:NumberOfHitsFilter          0.000321255   0.000410169   0.000566124   0.000375666   9.39612e-05       8     
produce:reco3d:SpacePointSolver                   8.25175       12.3863       21.2573       11.8639       3.94303         8     
produce:hitpdune:DisambigFromSpacePoints         0.124486      0.190958      0.332027       0.17592      0.0627431        8     
produce:pandora:StandardPandora                   29.1215       49.4701       100.499       44.8018       20.5573         8     
produce:pandoraTrack:LArPandoraTrackCreation     0.471154       1.10912       1.85755       1.0893       0.456436         8     
produce:pandoraGnocalo:GnocchiCalorimetry        0.0187787     0.026657      0.0381779     0.0251767    0.00622834        8     
[art]:TriggerResults:TriggerResultInserter      2.1097e-05    2.87699e-05   5.7986e-05    2.49235e-05   1.12432e-05       8     
end_path:out1:RootOutput                         3.957e-06    7.89838e-06   1.8893e-05     7.167e-06    4.37269e-06       8     
end_path:out1:RootOutput(write)                   4.55726       4.8053        5.03923       4.77163      0.171198         8     
==================================================================================================================================

====================================================================================================
MemoryTracker summary (base-10 MB units used)

  Peak virtual memory usage (VmPeak)  : 8589.81 MB
  Peak resident set size usage (VmHWM): 6706.44 MB
  Details saved in: 'mem.db'
====================================================================================================
%MSG-s ArtException:  PostEndJob 17-Sep-2025 19:04:08 CEST 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: 39353 subRun: 1 event: 75910
      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
justIN time: 2025-09-18 23:59:34 UTC       justIN version: 01.05.00