justIN           Dashboard       Workflows       Jobs       AWT       Sites       Storages       Docs       Login

Jobsub ID 269049.160@dunegpschedd01.fnal.gov

Jobsub ID269049.160@dunegpschedd01.fnal.gov
Workflow ID11251
Stage ID1
User nameykermaid@fnal.gov
HTCondor Groupgroup_dune.prod_mcsim
RequestedProcessors4
GPUNo
RSS bytes6815744000 (6500 MiB)
Wall seconds limit80000 (22 hours)
Submitted time2025-12-18 15:20:56
SiteUK_Sheffield
EntryDUNE_UK_Sheffield_lcgce2
Last heartbeat2025-12-18 15:56:07
From worker nodeHostnamewn034.hep
cpuinfoAMD EPYC 75F3 32-Core Processor
OS releaseScientific Linux release 7.9 (Nitrogen)
Processors4
RSS bytes7864320000 (7500 MiB)
Wall seconds limit257400 (71 hours)
GPU
Inner Apptainer?True
Job statefinished
Started2025-12-18 15:47:53
Input filesvd-protodune-top:3430_42_c_pvdt.test
JobscriptExit code0
Real time6m (401s)
CPU time5m (356s = 88%)
Max RSS bytes3012018176 (2872 MiB)
Outputting started2025-12-18 15:54:35
Output filesvd-protodune-det-reco:3430_42_c_pvdt_reco_stage1_20251218T155421_reco.root
Finished2025-12-18 15:56:07
Saved logsjustin-logs:269049.160-dunegpschedd01.fnal.gov.logs.tgz
List job events     Cached HTCondor job logs

Jobscript log (last 10,000 characters)

] D [sigproc ] <OmnibusSigProc:anode6sigproc6> EOS at call=9 anode=6 
[15:54:06.339] D [  glue  ] <ChannelSelector:chsel5> see EOS at call=4 
[15:54:06.339] D [sigproc ] <OmnibusNoiseFilter:nf5> EOS at call=9 
[15:54:06.339] D [sigproc ] <OmnibusSigProc:anode5sigproc5> EOS at call=9 anode=5 
[15:54:06.339] D [  glue  ] <ChannelSelector:chsel4> see EOS at call=4 
[15:54:06.339] D [sigproc ] <OmnibusNoiseFilter:nf4> EOS at call=9 
[15:54:06.339] D [sigproc ] <OmnibusSigProc:anode4sigproc4> EOS at call=9 anode=4 
[15:54:06.340] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=4 
[15:54:06.340] D [  aux   ] <Resampler:resmp3> EOS at call=9 
[15:54:06.340] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=9 
[15:54:06.340] D [sigproc ] <OmnibusSigProc:anode3sigproc3> EOS at call=9 anode=3 
[15:54:06.340] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=4 
[15:54:06.340] D [  aux   ] <Resampler:resmp2> EOS at call=9 
[15:54:06.340] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=9 
[15:54:06.340] D [sigproc ] <OmnibusSigProc:anode2sigproc2> EOS at call=9 anode=2 
[15:54:06.340] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=4 
[15:54:06.340] D [  aux   ] <Resampler:resmp1> EOS at call=9 
[15:54:06.340] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=9 
[15:54:06.340] D [sigproc ] <OmnibusSigProc:anode1sigproc1> EOS at call=9 anode=1 
[15:54:06.340] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=4 
[15:54:06.340] D [  aux   ] <Resampler:resmp0> EOS at call=9 
[15:54:06.340] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=9 
[15:54:06.340] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=9 anode=0 
[15:54:06.340] D [  glue  ] <FrameFanin:nfsp> EOS at call=9 with 8 
[15:54:06.340] D [  glue  ] frame sink sees EOS
[15:54:06.340] D [ pgraph ] <Pgrapher:> graph execution complete 
[15:54:06.340] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.72 sec
[15:54:06.340] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.61 sec
[15:54:06.340] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 6.73 sec
[15:54:06.340] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 6.21 sec
[15:54:06.340] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.16 sec
[15:54:06.340] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.14 sec
[15:54:06.340] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.14 sec
[15:54:06.340] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 1.89 sec
[15:54:06.340] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.39 sec
[15:54:06.340] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.38 sec
[15:54:06.340] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.33 sec
[15:54:06.340] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.22 sec
[15:54:06.340] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0.01 sec
[15:54:06.340] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[15:54:06.340] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[15:54:06.340] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[15:54:06.340] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[15:54:06.341] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[15:54:06.341] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[15:54:06.341] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:54:06.341] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[15:54:06.341] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[15:54:06.341] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[15:54:06.341] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:54:06.341] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:54:06.341] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:54:06.341] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:54:06.341] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[15:54:06.341] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:54:06.341] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:54:06.341] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:54:06.341] I [ timer  ] Timer: WireCell::Gen::Retagger : 0 sec
[15:54:06.341] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[15:54:06.341] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[15:54:06.341] I [ timer  ] Timer: Total node execution : 39.940000731498 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 6144 traces tagged "gauss"
FrameSaver: q=1.4173e+07 n=1032464 tag=gauss
wclsFrameSaver: saving 6144 traces tagged "wiener"
FrameSaver: q=1.42384e+07 n=1020375 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 2589 XUs and 2691 XVs -> 66 XUVs
C:0 T:1 668 XUs and 777 XVs -> 13 XUVs
C:0 T:2 628 XUs and 813 XVs -> 16 XUVs
C:0 T:3 320 XUs and 416 XVs -> 7 XUVs
C:0 T:4 778 XUs and 728 XVs -> 19 XUVs
C:0 T:5 375 XUs and 163 XVs -> 16 XUVs
C:0 T:6 185 XUs and 123 XVs -> 6 XUVs
C:0 T:7 643 XUs and 372 XVs -> 25 XUVs
168 XUVs total
151 collection wire objects
168 potential space points
Neighbour search...
614 tests to find 314 neighbours
Iterating with no regularization...
Begin: 6.80712e+09
0 6.78577e+09
1 6.78576e+09
Now with regularization...
Begin: 6.78029e+09
0 6.78028e+09
18-Dec-2025 15:54:21 GMT  Closed output file "3430_42_c_pvdt_reco_stage1_20251218T155421_reco.root"
DataPrepModule::endJob: # events processed: 5
DataPrepModule::endJob:   # events skipped: 0

==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                        41.101        61.4204       87.352        56.0502       15.5401         5     
----------------------------------------------------------------------------------------------------------------------------------
source:VDColdboxTDERawInput(read)               6.6977e-05     8.532e-05    0.000116711   8.2667e-05    1.69335e-05       5     
produce:caldata:DataPrepModule                   0.113797      0.258327      0.557773      0.207871      0.153994         5     
produce:wclsdatavd:WireCellToolkit                37.3795       43.9848       51.0606       41.4637       5.26586         5     
produce:gaushit:GausHitFinder                    0.237917       2.2248        3.60056       2.22332       1.23341         5     
produce:reco3d:SpacePointSolver                  0.579195       4.28811       9.07506       4.03706       2.79776         5     
produce:hitpdune:DisambigFromSpacePoints        0.00428815     0.0325937     0.0714924     0.0290308     0.0223428        5     
produce:pandora:StandardPandora                  0.656937       8.26951       20.3337       6.73656       6.54026         5     
produce:pandoraTrack:LArPandoraTrackCreation     0.0162471      0.10971       0.23856      0.102996      0.0752665        5     
produce:pandoraGnocalo:GnocchiCalorimetry       0.00445507     0.0135943     0.0249739     0.0143966    0.00727716        5     
[art]:TriggerResults:TriggerResultInserter      1.1312e-05    2.19594e-05   5.0906e-05     1.557e-05    1.47007e-05       5     
end_path:out1:RootOutput                         2.736e-06    6.6686e-06    1.9847e-05     3.787e-06    6.60273e-06       5     
end_path:out1:RootOutput(write)                   2.00975       2.2336        2.73828       2.06779      0.275645         5     
==================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 5357.09 MB
  Peak resident set size usage (VmHWM): 3012.02 MB
  Details saved in: 'mem.db'
====================================================================================================
ToolBasedRawDigitPrepService:dtor: Event count: 5
ToolBasedRawDigitPrepService:dtor:  Call count: 10
ToolBasedRawDigitPrepService:dtor: Time report for 3 tools.
ToolBasedRawDigitPrepService:dtor:                    digitReader:   0.08 sec/event
ToolBasedRawDigitPrepService:dtor:    vdcb_adcChannelRawRmsFiller:   0.15 sec/event
ToolBasedRawDigitPrepService:dtor:                adcSampleFiller:   0.00 sec/event
Art has completed and will exit with status 0.
Output files:
\tReco: 3430_42_c_pvdt_reco_stage1_20251218T155421_reco.root
Forming reco metadata
Successfully opened file 3430_42_c_pvdt_reco_stage1_20251218T155421_reco.root
Ran successfully
{
  "name": "3430_42_c_pvdt_reco_stage1_20251218T155421_reco.root",
  "namespace": "vd-protodune-det-reco",
  "metadata": {
    "core.file_format": "artroot",
    "core.application.name": "reco",
    "core.application.family": "dunesw",
    "core.application.version": "v10_14_01d00",
    "core.data_tier": "full-reconstructed",
    "dune.config_file": "tde_reco_stage1_protodunevd_keepup.fcl",
    "dune.campaign": "vd-protodune-top-det-reco",
    "core.start_time": 1766073263.0,
    "core.end_time": 1766073263.0,
    "core.events": [
      4923,
      4927,
      4931,
      4935,
      4939
    ],
    "core.event_count": 5,
    "core.first_event_number": 4923,
    "core.last_event_number": 4939,
    "core.data_stream": "cosmics",
    "core.file_type": "detector",
    "core.run_type": "vd-protodune-top",
    "core.runs": [
      3430
    ],
    "core.runs_subruns": [
      343000042
    ],
    "retention.status": "active",
    "retention.class": "physics"
  },
  "parents": [
    {
      "did": "vd-protodune-top:3430_42_c_pvdt.test"
    }
  ]
}
justIN time: 2025-12-19 05:25:44 UTC       justIN version: 01.05.03