justIN           Dashboard       Workflows       Jobs       AWT       Sites       Storages       Docs       Login

Jobsub ID 269049.99@dunegpschedd01.fnal.gov

Jobsub ID269049.99@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:29:56
From worker nodeHostnamewn-f01-14-04-08.cr.cnaf.infn.it
cpuinfoIntel(R) Xeon(R) CPU E5-2697 v4 @ 2.30GHz
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:04
Input filesvd-protodune-top:3430_41_c_pvdt.test
JobscriptExit code0
Real time41m (2472s)
CPU time39m (2355s = 95%)
Max RSS bytes3474026496 (3313 MiB)
Outputting started2025-12-18 16:27:16
Output filesvd-protodune-det-reco:3430_41_c_pvdt_reco_stage1_20251218T162658_reco.root
Finished2025-12-18 16:29:56
Saved logsjustin-logs:269049.99-dunegpschedd01.fnal.gov.logs.tgz
List job events     Cached HTCondor job logs

Jobscript log (last 10,000 characters)

Filter:nf4> EOS at call=59 
[17:26:48.321] D [sigproc ] <OmnibusSigProc:anode4sigproc4> EOS at call=59 anode=4 
[17:26:48.321] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=29 
[17:26:48.321] D [  aux   ] <Resampler:resmp3> EOS at call=59 
[17:26:48.321] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=59 
[17:26:48.321] D [sigproc ] <OmnibusSigProc:anode3sigproc3> EOS at call=59 anode=3 
[17:26:48.321] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=29 
[17:26:48.321] D [  aux   ] <Resampler:resmp2> EOS at call=59 
[17:26:48.321] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=59 
[17:26:48.321] D [sigproc ] <OmnibusSigProc:anode2sigproc2> EOS at call=59 anode=2 
[17:26:48.321] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=29 
[17:26:48.321] D [  aux   ] <Resampler:resmp1> EOS at call=59 
[17:26:48.321] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=59 
[17:26:48.321] D [sigproc ] <OmnibusSigProc:anode1sigproc1> EOS at call=59 anode=1 
[17:26:48.321] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=29 
[17:26:48.321] D [  aux   ] <Resampler:resmp0> EOS at call=59 
[17:26:48.321] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=59 
[17:26:48.321] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=59 anode=0 
[17:26:48.321] D [  glue  ] <FrameFanin:nfsp> EOS at call=59 with 8 
[17:26:48.321] D [  glue  ] frame sink sees EOS
[17:26:48.321] D [ pgraph ] <Pgrapher:> graph execution complete 
[17:26:48.321] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 12.01 sec
[17:26:48.321] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 11.49 sec
[17:26:48.321] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 11.32 sec
[17:26:48.321] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 10.8 sec
[17:26:48.321] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.54 sec
[17:26:48.321] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.54 sec
[17:26:48.321] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.54 sec
[17:26:48.321] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.53 sec
[17:26:48.321] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.46 sec
[17:26:48.321] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.45 sec
[17:26:48.321] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.45 sec
[17:26:48.321] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.44 sec
[17:26:48.321] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[17:26:48.321] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[17:26:48.321] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[17:26:48.321] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[17:26:48.321] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[17:26:48.321] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[17:26:48.321] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[17:26:48.321] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[17:26:48.321] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:26:48.321] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[17:26:48.321] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[17:26:48.322] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[17:26:48.322] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[17:26:48.322] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:26:48.322] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:26:48.322] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:26:48.322] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[17:26:48.322] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:26:48.322] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:26:48.322] I [ timer  ] Timer: WireCell::Gen::Retagger : 0 sec
[17:26:48.322] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[17:26:48.322] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[17:26:48.322] I [ timer  ] Timer: Total node execution : 57.59999972395599 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 6144 traces tagged "gauss"
FrameSaver: q=1.63144e+06 n=498801 tag=gauss
wclsFrameSaver: saving 6144 traces tagged "wiener"
FrameSaver: q=1.64669e+06 n=487108 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 852 XUs and 638 XVs -> 30 XUVs
C:0 T:1 407 XUs and 687 XVs -> 15 XUVs
C:0 T:2 369 XUs and 578 XVs -> 31 XUVs
C:0 T:3 104 XUs and 130 XVs -> 1 XUVs
C:0 T:4 341 XUs and 522 XVs -> 23 XUVs
C:0 T:5 386 XUs and 476 XVs -> 27 XUVs
C:0 T:6 288 XUs and 400 XVs -> 13 XUVs
C:0 T:7 153 XUs and 132 XVs -> 5 XUVs
145 XUVs total
125 collection wire objects
145 potential space points
Neighbour search...
549 tests to find 288 neighbours
Iterating with no regularization...
Begin: 2.37158e+07
0 2.33533e+07
1 2.33533e+07
Now with regularization...
Begin: 2.31855e+07
0 2.31855e+07
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Dec-2025 17:26:58 CET  Closed output file "3430_41_c_pvdt_reco_stage1_20251218T162658_reco.root"
DataPrepModule::endJob: # events processed: 30
DataPrepModule::endJob:   # events skipped: 0

==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                        60.6587       74.6914       114.32        67.9504       13.6969        30     
----------------------------------------------------------------------------------------------------------------------------------
source:VDColdboxTDERawInput(read)               5.6411e-05    8.12233e-05   0.000177251   7.1772e-05    2.57022e-05      30     
produce:caldata:DataPrepModule                   0.188742      0.236277      0.502396      0.212079      0.0700436       30     
produce:wclsdatavd:WireCellToolkit                53.2093       59.773        74.9432       56.9852       6.43682        30     
produce:gaushit:GausHitFinder                    0.432959       1.22546       4.1306       0.737895       1.01377        30     
produce:reco3d:SpacePointSolver                   1.24149       3.67749       8.03008       3.13807       1.6858         30     
produce:hitpdune:DisambigFromSpacePoints        0.00869722     0.026318      0.0616209     0.0216106     0.0138487       30     
produce:pandora:StandardPandora                   1.99759       7.23031       25.7245       4.97631       5.59692        30     
produce:pandoraTrack:LArPandoraTrackCreation     0.0630745     0.152392      0.325509      0.130722      0.0680635       30     
produce:pandoraGnocalo:GnocchiCalorimetry       0.00831086     0.0148571     0.0262807     0.0140101    0.00427193       30     
[art]:TriggerResults:TriggerResultInserter      1.9155e-05    2.56279e-05   6.9982e-05    2.34345e-05   8.76485e-06      30     
end_path:out1:RootOutput                         3.921e-06    7.55253e-06   2.8062e-05     7.115e-06    4.44407e-06      30     
end_path:out1:RootOutput(write)                   2.09764       2.34093       3.27357       2.2471       0.239773        30     
==================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 5808.38 MB
  Peak resident set size usage (VmHWM): 3474.03 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.08 sec/event
ToolBasedRawDigitPrepService:dtor:    vdcb_adcChannelRawRmsFiller:   0.14 sec/event
ToolBasedRawDigitPrepService:dtor:                adcSampleFiller:   0.00 sec/event
Art has completed and will exit with status 0.
Output files:
\tReco: 3430_41_c_pvdt_reco_stage1_20251218T162658_reco.root
Forming reco metadata
Successfully opened file 3430_41_c_pvdt_reco_stage1_20251218T162658_reco.root
Ran successfully
{
  "name": "3430_41_c_pvdt_reco_stage1_20251218T162658_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": 1766075221.0,
    "core.end_time": 1766075221.0,
    "core.events": [
      4803,
      4807,
      4811,
      4815,
      4819,
      4823,
      4827,
      4831,
      4835,
      4839,
      4843,
      4847,
      4851,
      4855,
      4859,
      4863,
      4867,
      4871,
      4875,
      4879,
      4883,
      4887,
      4891,
      4895,
      4899,
      4903,
      4907,
      4911,
      4915,
      4919
    ],
    "core.event_count": 30,
    "core.first_event_number": 4803,
    "core.last_event_number": 4919,
    "core.data_stream": "cosmics",
    "core.file_type": "detector",
    "core.run_type": "vd-protodune-top",
    "core.runs": [
      3430
    ],
    "core.runs_subruns": [
      343000041
    ],
    "retention.status": "active",
    "retention.class": "physics"
  },
  "parents": [
    {
      "did": "vd-protodune-top:3430_41_c_pvdt.test"
    }
  ]
}
justIN time: 2025-12-18 23:23:53 UTC       justIN version: 01.05.03