justIN           Dashboard       Workflows       Jobs       AWT       Sites       Storages       Docs       Login

Jobsub ID 269049.0@dunegpschedd01.fnal.gov

Jobsub ID269049.0@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 15:57:59
From worker nodeHostnamewn-s04-05-38-02.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:22:19
Input filesvd-protodune-top:3430_3_a_pvdt.test
JobscriptExit code0
Real time29m (1789s)
CPU time24m (1440s = 80%)
Max RSS bytes3268182016 (3116 MiB)
Outputting started2025-12-18 15:52:10
Output filesvd-protodune-det-reco:3430_3_a_pvdt_reco_stage1_20251218T155152_reco.root
Finished2025-12-18 15:57:59
Saved logsjustin-logs:269049.0-dunegpschedd01.fnal.gov.logs.tgz
List job events     Cached HTCondor job logs

Jobscript log (last 10,000 characters)

51:32.283] D [sigproc ] <OmnibusSigProc:anode4sigproc4> EOS at call=59 anode=4 
[16:51:32.283] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=29 
[16:51:32.283] D [  aux   ] <Resampler:resmp3> EOS at call=59 
[16:51:32.284] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=59 
[16:51:32.284] D [sigproc ] <OmnibusSigProc:anode3sigproc3> EOS at call=59 anode=3 
[16:51:32.284] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=29 
[16:51:32.284] D [  aux   ] <Resampler:resmp2> EOS at call=59 
[16:51:32.284] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=59 
[16:51:32.284] D [sigproc ] <OmnibusSigProc:anode2sigproc2> EOS at call=59 anode=2 
[16:51:32.284] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=29 
[16:51:32.284] D [  aux   ] <Resampler:resmp1> EOS at call=59 
[16:51:32.284] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=59 
[16:51:32.284] D [sigproc ] <OmnibusSigProc:anode1sigproc1> EOS at call=59 anode=1 
[16:51:32.284] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=29 
[16:51:32.284] D [  aux   ] <Resampler:resmp0> EOS at call=59 
[16:51:32.284] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=59 
[16:51:32.284] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=59 anode=0 
[16:51:32.284] D [  glue  ] <FrameFanin:nfsp> EOS at call=59 with 8 
[16:51:32.284] D [  glue  ] frame sink sees EOS
[16:51:32.284] D [ pgraph ] <Pgrapher:> graph execution complete 
[16:51:32.284] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 12.31 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.05 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 6.94 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 6.81 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.09 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.06 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.04 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 1.97 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.38 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.36 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.35 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.28 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:51:32.284] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0 sec
[16:51:32.284] I [ timer  ] Timer: WireCell::Gen::Retagger : 0 sec
[16:51:32.284] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[16:51:32.285] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[16:51:32.285] I [ timer  ] Timer: Total node execution : 42.64000046253204 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 6144 traces tagged "gauss"
FrameSaver: q=4.06976e+07 n=1389966 tag=gauss
wclsFrameSaver: saving 6144 traces tagged "wiener"
FrameSaver: q=4.0948e+07 n=1375201 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 2718 XUs and 5349 XVs -> 53 XUVs
C:0 T:1 3188 XUs and 6477 XVs -> 100 XUVs
C:0 T:2 1186 XUs and 1298 XVs -> 78 XUVs
C:0 T:3 1727 XUs and 2070 XVs -> 79 XUVs
C:0 T:4 3146 XUs and 3541 XVs -> 217 XUVs
C:0 T:5 357 XUs and 469 XVs -> 26 XUVs
C:0 T:6 493 XUs and 704 XVs -> 6 XUVs
C:0 T:7 180 XUs and 233 XVs -> 9 XUVs
568 XUVs total
451 collection wire objects
568 potential space points
Neighbour search...
4588 tests to find 1888 neighbours
Iterating with no regularization...
Begin: 2.44997e+11
0 2.44949e+11
Now with regularization...
Begin: 2.44935e+11
0 2.44935e+11
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Dec-2025 16:51:52 CET  Closed output file "3430_3_a_pvdt_reco_stage1_20251218T155152_reco.root"
DataPrepModule::endJob: # events processed: 30
DataPrepModule::endJob:   # events skipped: 0

==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                        32.7271       45.9253       69.9992       42.3278       10.6312        30     
----------------------------------------------------------------------------------------------------------------------------------
source:VDColdboxTDERawInput(read)               5.4873e-05    0.000102271   0.000348534   9.11615e-05   5.08326e-05      30     
produce:caldata:DataPrepModule                   0.124908      0.189936      0.545334       0.18207      0.0765506       30     
produce:wclsdatavd:WireCellToolkit                27.3234       35.1077       50.1509       34.1346       6.74411        30     
produce:gaushit:GausHitFinder                    0.341541       1.01429       3.37748      0.697161      0.775399        30     
produce:reco3d:SpacePointSolver                   1.31843       3.0787        5.37522       2.89342      0.988232        30     
produce:hitpdune:DisambigFromSpacePoints        0.00748118     0.0203849     0.0479162     0.0183457    0.00957334       30     
produce:pandora:StandardPandora                   1.64731       4.53294       11.3375        3.765        2.49902        30     
produce:pandoraTrack:LArPandoraTrackCreation     0.0464825     0.108053      0.269577      0.094346      0.0456419       30     
produce:pandoraGnocalo:GnocchiCalorimetry       0.00520551     0.0122069     0.0229843     0.0108178    0.00422728       30     
[art]:TriggerResults:TriggerResultInserter      2.0809e-05    3.56776e-05   0.000108483   3.07625e-05   1.68117e-05      30     
end_path:out1:RootOutput                         3.938e-06    8.7785e-06    3.9113e-05     8.731e-06    6.00646e-06      30     
end_path:out1:RootOutput(write)                   1.42585       1.8475        2.41756       1.74244      0.380364        30     
==================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 5586.29 MB
  Peak resident set size usage (VmHWM): 3268.18 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.06 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_3_a_pvdt_reco_stage1_20251218T155152_reco.root
Forming reco metadata
Successfully opened file 3430_3_a_pvdt_reco_stage1_20251218T155152_reco.root
Ran successfully
{
  "name": "3430_3_a_pvdt_reco_stage1_20251218T155152_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": 1766073113.0,
    "core.end_time": 1766073113.0,
    "core.events": [
      241,
      245,
      249,
      253,
      257,
      261,
      265,
      269,
      273,
      277,
      281,
      285,
      289,
      293,
      297,
      301,
      305,
      309,
      313,
      317,
      321,
      325,
      329,
      333,
      337,
      341,
      345,
      349,
      353,
      357
    ],
    "core.event_count": 30,
    "core.first_event_number": 241,
    "core.last_event_number": 357,
    "core.data_stream": "cosmics",
    "core.file_type": "detector",
    "core.run_type": "vd-protodune-top",
    "core.runs": [
      3430
    ],
    "core.runs_subruns": [
      343000003
    ],
    "retention.status": "active",
    "retention.class": "physics"
  },
  "parents": [
    {
      "did": "vd-protodune-top:3430_3_a_pvdt.test"
    }
  ]
}
justIN time: 2025-12-18 23:23:54 UTC       justIN version: 01.05.03