justIN           Dashboard       Workflows       Jobs       AWT       Sites       Storages       Docs       Login

Jobsub ID 269049.162@dunegpschedd01.fnal.gov

Jobsub ID269049.162@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_Manchester
EntryUBoone_T2_UK_Manchester_ce01
Last heartbeat2025-12-18 18:56:38
From worker nodeHostnamewn1205080.tier2.hep.manchester.ac.uk
cpuinfoAMD EPYC 7702P 64-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:47
Input filesvd-protodune-top:3430_6_d_pvdt.test
JobscriptExit code0
Real time3h (10977s)
CPU time1h (7036s = 64%)
Max RSS bytes4001071104 (3815 MiB)
Outputting started2025-12-18 18:50:45
Output filesvd-protodune-det-reco:3430_6_d_pvdt_reco_stage1_20251218T185032_reco.root
Finished2025-12-18 18:56:38
Saved logsjustin-logs:269049.162-dunegpschedd01.fnal.gov.logs.tgz
List job events     Cached HTCondor job logs

Jobscript log (last 10,000 characters)

59 anode=4 
[18:44:56.086] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=29 
[18:44:56.086] D [  aux   ] <Resampler:resmp3> EOS at call=59 
[18:44:56.086] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=59 
[18:44:56.086] D [sigproc ] <OmnibusSigProc:anode3sigproc3> EOS at call=59 anode=3 
[18:44:56.086] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=29 
[18:44:56.086] D [  aux   ] <Resampler:resmp2> EOS at call=59 
[18:44:56.087] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=59 
[18:44:56.087] D [sigproc ] <OmnibusSigProc:anode2sigproc2> EOS at call=59 anode=2 
[18:44:56.087] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=29 
[18:44:56.087] D [  aux   ] <Resampler:resmp1> EOS at call=59 
[18:44:56.087] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=59 
[18:44:56.087] D [sigproc ] <OmnibusSigProc:anode1sigproc1> EOS at call=59 anode=1 
[18:44:56.087] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=29 
[18:44:56.087] D [  aux   ] <Resampler:resmp0> EOS at call=59 
[18:44:56.087] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=59 
[18:44:56.087] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=59 anode=0 
[18:44:56.087] D [  glue  ] <FrameFanin:nfsp> EOS at call=59 with 8 
[18:44:56.087] D [  glue  ] frame sink sees EOS
[18:44:56.088] D [ pgraph ] <Pgrapher:> graph execution complete 
[18:44:56.088] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 29.15 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 29.02 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 19.62 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 17.76 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.56 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.56 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.51 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.51 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.62 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.61 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.61 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.61 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0.01 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:44:56.088] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::Gen::Retagger : 0 sec
[18:44:56.088] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[18:44:56.088] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[18:44:56.088] I [ timer  ] Timer: Total node execution : 112.18000105768442 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 6144 traces tagged "gauss"
FrameSaver: q=1.02095e+07 n=2846441 tag=gauss
wclsFrameSaver: saving 6144 traces tagged "wiener"
FrameSaver: q=1.04798e+07 n=2761550 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 35731 XUs and 62687 XVs -> 11314 XUVs
C:0 T:1 88668 XUs and 166772 XVs -> 34943 XUVs
C:0 T:2 85983 XUs and 168151 XVs -> 29707 XUVs
C:0 T:3 24520 XUs and 50543 XVs -> 10760 XUVs
C:0 T:4 25577 XUs and 46434 XVs -> 12153 XUVs
C:0 T:5 10852 XUs and 24207 XVs -> 5413 XUVs
C:0 T:6 29445 XUs and 55110 XVs -> 11515 XUVs
C:0 T:7 37024 XUs and 60714 XVs -> 11408 XUVs
127213 XUVs total
8738 collection wire objects
127213 potential space points
Neighbour search...
20924759 tests to find 8911758 neighbours
Iterating with no regularization...
Begin: 4.03617e+08
0 2.79597e+08
1 2.69197e+08
2 2.67132e+08
3 2.66404e+08
4 2.6605e+08
5 2.65846e+08
Now with regularization...
Begin: 2.57435e+08
0 2.57198e+08
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Dec-2025 18:50:32 GMT  Closed output file "3430_6_d_pvdt_reco_stage1_20251218T185032_reco.root"
DataPrepModule::endJob: # events processed: 30
DataPrepModule::endJob:   # events skipped: 0

==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                        71.6743       234.425       1213.06       101.453       284.501        30     
----------------------------------------------------------------------------------------------------------------------------------
source:VDColdboxTDERawInput(read)               6.6426e-05    0.000128769   0.000249139   0.000122436   3.73401e-05      30     
produce:caldata:DataPrepModule                   0.250424      0.307785      0.798152      0.293408      0.0916407       30     
produce:wclsdatavd:WireCellToolkit                62.1269       84.3069       134.717       77.1821       22.3974        30     
produce:gaushit:GausHitFinder                    0.387014       3.02898       8.89281       2.50057       2.45965        30     
produce:reco3d:SpacePointSolver                   1.69479       25.014        120.059       6.64073       35.5919        30     
produce:hitpdune:DisambigFromSpacePoints         0.0116696     0.401303       2.03151      0.0504129      0.65276        30     
produce:pandora:StandardPandora                   2.33557       116.202       934.148       11.6265       226.335        30     
produce:pandoraTrack:LArPandoraTrackCreation     0.0683725      1.05815       6.02965      0.251559       1.59391        30     
produce:pandoraGnocalo:GnocchiCalorimetry        0.0109683     0.0496198     0.192751      0.0271082     0.0468851       30     
[art]:TriggerResults:TriggerResultInserter      1.8275e-05    2.96199e-05   7.5462e-05     2.657e-05    1.20664e-05      30     
end_path:out1:RootOutput                         3.606e-06    5.76513e-06   3.0027e-05    4.9045e-06    4.56656e-06      30     
end_path:out1:RootOutput(write)                   2.41486       4.03056       7.08136       3.66379       1.05386        30     
==================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 6377.84 MB
  Peak resident set size usage (VmHWM): 3995.44 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.09 sec/event
ToolBasedRawDigitPrepService:dtor:    vdcb_adcChannelRawRmsFiller:   0.19 sec/event
ToolBasedRawDigitPrepService:dtor:                adcSampleFiller:   0.00 sec/event
Art has completed and will exit with status 0.
Output files:
\tReco: 3430_6_d_pvdt_reco_stage1_20251218T185032_reco.root
Forming reco metadata
Successfully opened file 3430_6_d_pvdt_reco_stage1_20251218T185032_reco.root
Ran successfully
{
  "name": "3430_6_d_pvdt_reco_stage1_20251218T185032_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": 1766083836.0,
    "core.end_time": 1766083836.0,
    "core.events": [
      604,
      608,
      612,
      616,
      620,
      624,
      628,
      632,
      636,
      640,
      644,
      648,
      652,
      656,
      660,
      664,
      668,
      672,
      676,
      680,
      684,
      688,
      692,
      696,
      700,
      704,
      708,
      712,
      716,
      720
    ],
    "core.event_count": 30,
    "core.first_event_number": 604,
    "core.last_event_number": 720,
    "core.data_stream": "cosmics",
    "core.file_type": "detector",
    "core.run_type": "vd-protodune-top",
    "core.runs": [
      3430
    ],
    "core.runs_subruns": [
      343000006
    ],
    "retention.status": "active",
    "retention.class": "physics"
  },
  "parents": [
    {
      "did": "vd-protodune-top:3430_6_d_pvdt.test"
    }
  ]
}
justIN time: 2025-12-19 08:50:39 UTC       justIN version: 01.05.03