justIN           Dashboard       Workflows       Jobs       AWT       Sites       Storages       Docs       Login

Jobsub ID 269049.133@dunegpschedd01.fnal.gov

Jobsub ID269049.133@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
SiteIT_CNAF
EntryCMSHTPC_T1_IT_CNAF_condor_ce02
Last heartbeat2025-12-18 16:22:48
From worker nodeHostnamewn-s04-05-32-01.cr.cnaf.infn.it
cpuinfoAMD EPYC 7313 16-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:46:19
Input filesvd-protodune-top:3430_10_b_pvdt.test
JobscriptExit code0
Real time30m (1846s)
CPU time24m (1492s = 80%)
Max RSS bytes3702640640 (3531 MiB)
Outputting started2025-12-18 16:17:05
Output filesvd-protodune-det-reco:3430_10_b_pvdt_reco_stage1_20251218T161659_reco.root
Finished2025-12-18 16:22:48
Saved logsjustin-logs:269049.133-dunegpschedd01.fnal.gov.logs.tgz
List job events     Cached HTCondor job logs

Jobscript log (last 10,000 characters)

] <ChannelSelector:chsel3> see EOS at call=29 
[17:14:51.496] D [  aux   ] <Resampler:resmp3> EOS at call=59 
[17:14:51.496] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=59 
[17:14:51.496] D [sigproc ] <OmnibusSigProc:anode3sigproc3> EOS at call=59 anode=3 
[17:14:51.496] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=29 
[17:14:51.496] D [  aux   ] <Resampler:resmp2> EOS at call=59 
[17:14:51.496] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=59 
[17:14:51.496] D [sigproc ] <OmnibusSigProc:anode2sigproc2> EOS at call=59 anode=2 
[17:14:51.496] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=29 
[17:14:51.496] D [  aux   ] <Resampler:resmp1> EOS at call=59 
[17:14:51.496] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=59 
[17:14:51.496] D [sigproc ] <OmnibusSigProc:anode1sigproc1> EOS at call=59 anode=1 
[17:14:51.496] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=29 
[17:14:51.496] D [  aux   ] <Resampler:resmp0> EOS at call=59 
[17:14:51.496] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=59 
[17:14:51.496] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=59 anode=0 
[17:14:51.496] D [  glue  ] <FrameFanin:nfsp> EOS at call=59 with 8 
[17:14:51.496] D [  glue  ] frame sink sees EOS
[17:14:51.496] D [ pgraph ] <Pgrapher:> graph execution complete 
[17:14:51.496] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 12.42 sec
[17:14:51.496] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 11.8 sec
[17:14:51.496] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 10.89 sec
[17:14:51.496] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.76 sec
[17:14:51.496] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.19 sec
[17:14:51.496] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.14 sec
[17:14:51.496] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.11 sec
[17:14:51.496] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.1 sec
[17:14:51.496] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.39 sec
[17:14:51.496] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.37 sec
[17:14:51.496] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.37 sec
[17:14:51.496] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.37 sec
[17:14:51.497] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[17:14:51.497] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[17:14:51.497] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[17:14:51.497] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[17:14:51.497] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[17:14:51.497] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[17:14:51.497] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[17:14:51.497] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[17:14:51.497] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[17:14:51.497] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[17:14:51.497] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[17:14:51.497] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:14:51.497] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[17:14:51.497] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:14:51.497] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:14:51.497] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:14:51.497] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[17:14:51.497] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[17:14:51.497] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:14:51.497] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:14:51.497] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[17:14:51.497] I [ timer  ] Timer: WireCell::Gen::Retagger : 0 sec
[17:14:51.497] I [ timer  ] Timer: Total node execution : 54.94000080041587 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 6144 traces tagged "gauss"
FrameSaver: q=7.05965e+06 n=2096405 tag=gauss
wclsFrameSaver: saving 6144 traces tagged "wiener"
FrameSaver: q=7.26467e+06 n=2032082 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 26912 XUs and 49720 XVs -> 7665 XUVs
C:0 T:1 32403 XUs and 58507 XVs -> 14666 XUVs
C:0 T:2 51830 XUs and 94117 XVs -> 16003 XUVs
C:0 T:3 22564 XUs and 38898 XVs -> 8301 XUVs
C:0 T:4 21650 XUs and 47704 XVs -> 9515 XUVs
C:0 T:5 19792 XUs and 37478 XVs -> 7895 XUVs
C:0 T:6 42950 XUs and 79768 XVs -> 14073 XUVs
C:0 T:7 38753 XUs and 62062 XVs -> 11815 XUVs
89933 XUVs total
6738 collection wire objects
89933 potential space points
Neighbour search...
13547241 tests to find 5911446 neighbours
Iterating with no regularization...
Begin: 2.72926e+08
0 1.81283e+08
1 1.74234e+08
2 1.72681e+08
3 1.72107e+08
4 1.71824e+08
5 1.7166e+08
Now with regularization...
Begin: 1.65435e+08
0 1.65267e+08
1 1.65151e+08
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Dec-2025 17:16:59 CET  Closed output file "3430_10_b_pvdt_reco_stage1_20251218T161659_reco.root"
DataPrepModule::endJob: # events processed: 30
DataPrepModule::endJob:   # events skipped: 0

==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                         33.11        47.8015       183.106       39.591        26.405         30     
----------------------------------------------------------------------------------------------------------------------------------
source:VDColdboxTDERawInput(read)               4.9883e-05    0.000107352   0.00028774    0.000108218   4.72492e-05      30     
produce:caldata:DataPrepModule                   0.127914      0.196432      0.398761      0.167565      0.063242        30     
produce:wclsdatavd:WireCellToolkit                27.6777       34.0752       56.097        31.0016       6.76475        30     
produce:gaushit:GausHitFinder                    0.278943       1.05847       3.39024      0.581081      0.826617        30     
produce:reco3d:SpacePointSolver                   1.50751       3.5442        27.352        2.54387       4.50921        30     
produce:hitpdune:DisambigFromSpacePoints        0.00646118     0.0331755     0.504602      0.0157255     0.0878177       30     
produce:pandora:StandardPandora                   1.24251       6.98043       91.6948       3.39384       15.9061        30     
produce:pandoraTrack:LArPandoraTrackCreation     0.0294814     0.103931       0.77715      0.0718461     0.128584        30     
produce:pandoraGnocalo:GnocchiCalorimetry       0.00357757     0.0107513     0.0548265    0.00903331    0.00880867       30     
[art]:TriggerResults:TriggerResultInserter      1.1902e-05    2.00323e-05   4.7259e-05    1.7533e-05    7.97158e-06      30     
end_path:out1:RootOutput                         3.106e-06    6.68353e-06   2.1461e-05    6.3515e-06    3.47548e-06      30     
end_path:out1:RootOutput(write)                   1.43833       1.78654       3.26976       1.58075      0.423341        30     
==================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 6025.7 MB
  Peak resident set size usage (VmHWM): 3684.43 MB
  Details saved in: 'mem.db'
====================================================================================================
ToolBasedRawDigitPrepService:dtor: Event count: 30
ToolBasedRawDigitPrepService:dtor:  Call count: 60
ToolBasedRawDigitPrepService:dtor: Time report for 3 tools.
ToolBasedRawDigitPrepService:dtor:                    digitReader:   0.07 sec/event
ToolBasedRawDigitPrepService:dtor:    vdcb_adcChannelRawRmsFiller:   0.11 sec/event
ToolBasedRawDigitPrepService:dtor:                adcSampleFiller:   0.00 sec/event
Art has completed and will exit with status 0.
Output files:
\tReco: 3430_10_b_pvdt_reco_stage1_20251218T161659_reco.root
Forming reco metadata
Successfully opened file 3430_10_b_pvdt_reco_stage1_20251218T161659_reco.root
Ran successfully
{
  "name": "3430_10_b_pvdt_reco_stage1_20251218T161659_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": 1766074620.0,
    "core.end_time": 1766074620.0,
    "core.events": [
      1082,
      1086,
      1090,
      1094,
      1098,
      1102,
      1106,
      1110,
      1114,
      1118,
      1122,
      1126,
      1130,
      1134,
      1138,
      1142,
      1146,
      1150,
      1154,
      1158,
      1162,
      1166,
      1170,
      1174,
      1178,
      1182,
      1186,
      1190,
      1194,
      1198
    ],
    "core.event_count": 30,
    "core.first_event_number": 1082,
    "core.last_event_number": 1198,
    "core.data_stream": "cosmics",
    "core.file_type": "detector",
    "core.run_type": "vd-protodune-top",
    "core.runs": [
      3430
    ],
    "core.runs_subruns": [
      343000010
    ],
    "retention.status": "active",
    "retention.class": "physics"
  },
  "parents": [
    {
      "did": "vd-protodune-top:3430_10_b_pvdt.test"
    }
  ]
}
justIN time: 2025-12-18 23:23:50 UTC       justIN version: 01.05.03