justIN           Dashboard       Workflows       Jobs       AWT       Sites       Storages       Docs       Login

Jobsub ID 269049.123@dunegpschedd01.fnal.gov

Jobsub ID269049.123@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_ce02
Last heartbeat2025-12-18 19:07:01
From worker nodeHostnamewn5917300.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:46:08
Input filesvd-protodune-top:3430_11_b_pvdt.test
JobscriptExit code0
Real time3h (11551s)
CPU time2h (8220s = 71%)
Max RSS bytes4451786752 (4245 MiB)
Outputting started2025-12-18 18:58:40
Output filesvd-protodune-det-reco:3430_11_b_pvdt_reco_stage1_20251218T185828_reco.root
Finished2025-12-18 19:07:01
Saved logsjustin-logs:269049.123-dunegpschedd01.fnal.gov.logs.tgz
List job events     Cached HTCondor job logs

Jobscript log (last 10,000 characters)

c:anode4sigproc4> EOS at call=59 anode=4 
[18:58:05.026] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=29 
[18:58:05.026] D [  aux   ] <Resampler:resmp3> EOS at call=59 
[18:58:05.026] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=59 
[18:58:05.026] D [sigproc ] <OmnibusSigProc:anode3sigproc3> EOS at call=59 anode=3 
[18:58:05.026] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=29 
[18:58:05.026] D [  aux   ] <Resampler:resmp2> EOS at call=59 
[18:58:05.026] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=59 
[18:58:05.026] D [sigproc ] <OmnibusSigProc:anode2sigproc2> EOS at call=59 anode=2 
[18:58:05.026] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=29 
[18:58:05.026] D [  aux   ] <Resampler:resmp1> EOS at call=59 
[18:58:05.026] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=59 
[18:58:05.027] D [sigproc ] <OmnibusSigProc:anode1sigproc1> EOS at call=59 anode=1 
[18:58:05.027] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=29 
[18:58:05.027] D [  aux   ] <Resampler:resmp0> EOS at call=59 
[18:58:05.027] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=59 
[18:58:05.027] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=59 anode=0 
[18:58:05.027] D [  glue  ] <FrameFanin:nfsp> EOS at call=59 with 8 
[18:58:05.027] D [  glue  ] frame sink sees EOS
[18:58:05.027] D [ pgraph ] <Pgrapher:> graph execution complete 
[18:58:05.027] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 15.89 sec
[18:58:05.027] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 12.07 sec
[18:58:05.027] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 11.39 sec
[18:58:05.027] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 11.04 sec
[18:58:05.027] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.72 sec
[18:58:05.027] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.19 sec
[18:58:05.027] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.84 sec
[18:58:05.027] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.83 sec
[18:58:05.027] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.66 sec
[18:58:05.027] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.52 sec
[18:58:05.027] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.42 sec
[18:58:05.027] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.41 sec
[18:58:05.027] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0.01 sec
[18:58:05.027] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0.01 sec
[18:58:05.027] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[18:58:05.027] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[18:58:05.028] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[18:58:05.028] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[18:58:05.028] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[18:58:05.028] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[18:58:05.028] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:58:05.028] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[18:58:05.028] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[18:58:05.028] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[18:58:05.028] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[18:58:05.028] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:58:05.028] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:58:05.028] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:58:05.028] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:58:05.028] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:58:05.028] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:58:05.028] I [ timer  ] Timer: WireCell::Gen::Retagger : 0 sec
[18:58:05.028] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[18:58:05.028] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[18:58:05.028] I [ timer  ] Timer: Total node execution : 65.020000256598 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 6144 traces tagged "gauss"
FrameSaver: q=1.91944e+07 n=1029288 tag=gauss
wclsFrameSaver: saving 6144 traces tagged "wiener"
FrameSaver: q=1.9267e+07 n=1016530 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 2343 XUs and 4101 XVs -> 51 XUVs
C:0 T:1 1505 XUs and 1575 XVs -> 52 XUVs
C:0 T:2 680 XUs and 1101 XVs -> 44 XUVs
C:0 T:3 579 XUs and 410 XVs -> 27 XUVs
C:0 T:4 352 XUs and 312 XVs -> 11 XUVs
C:0 T:5 392 XUs and 531 XVs -> 27 XUVs
C:0 T:6 998 XUs and 639 XVs -> 17 XUVs
C:0 T:7 193 XUs and 104 XVs -> 3 XUVs
232 XUVs total
202 collection wire objects
232 potential space points
Neighbour search...
954 tests to find 508 neighbours
Iterating with no regularization...
Begin: 1.32426e+10
0 1.32423e+10
Now with regularization...
Begin: 1.324e+10
0 1.324e+10
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Dec-2025 18:58:28 GMT  Closed output file "3430_11_b_pvdt_reco_stage1_20251218T185828_reco.root"
DataPrepModule::endJob: # events processed: 30
DataPrepModule::endJob:   # events skipped: 0

==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                        81.8459       275.205       1422.22       101.18        297.093        30     
----------------------------------------------------------------------------------------------------------------------------------
source:VDColdboxTDERawInput(read)               6.6696e-05    0.000109965   0.000229734   9.4929e-05    3.56066e-05      30     
produce:caldata:DataPrepModule                   0.186107      0.314515      0.759122      0.306886      0.0879651       30     
produce:wclsdatavd:WireCellToolkit                66.8625       93.5156       140.717       77.1759       24.7748        30     
produce:gaushit:GausHitFinder                    0.777507       3.89678       9.67346       3.02301       3.07693        30     
produce:reco3d:SpacePointSolver                   3.07068       33.6297       119.815       6.66749       40.8943        30     
produce:hitpdune:DisambigFromSpacePoints         0.0158361     0.544399       2.18318      0.0491208     0.734051        30     
produce:pandora:StandardPandora                   3.56474       137.076       1143.68       11.8167       235.503        30     
produce:pandoraTrack:LArPandoraTrackCreation     0.105753       1.50059       6.88239      0.256991       1.94388        30     
produce:pandoraGnocalo:GnocchiCalorimetry        0.0157009     0.0697895     0.184322      0.030946      0.0646033       30     
[art]:TriggerResults:TriggerResultInserter      2.4276e-05    3.64565e-05   9.8627e-05    3.21555e-05   1.42305e-05      30     
end_path:out1:RootOutput                         3.927e-06    5.8161e-06    2.7563e-05     5.29e-06     4.0804e-06       30     
end_path:out1:RootOutput(write)                   2.75444       4.61429       7.37231       3.85358       1.37026        30     
==================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 6807.47 MB
  Peak resident set size usage (VmHWM): 4451.79 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_11_b_pvdt_reco_stage1_20251218T185828_reco.root
Forming reco metadata
Successfully opened file 3430_11_b_pvdt_reco_stage1_20251218T185828_reco.root
Ran successfully
{
  "name": "3430_11_b_pvdt_reco_stage1_20251218T185828_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": 1766084311.0,
    "core.end_time": 1766084311.0,
    "core.events": [
      1202,
      1206,
      1210,
      1214,
      1218,
      1222,
      1226,
      1230,
      1234,
      1238,
      1242,
      1246,
      1250,
      1254,
      1258,
      1262,
      1266,
      1270,
      1274,
      1278,
      1282,
      1286,
      1290,
      1294,
      1298,
      1302,
      1306,
      1310,
      1314,
      1318
    ],
    "core.event_count": 30,
    "core.first_event_number": 1202,
    "core.last_event_number": 1318,
    "core.data_stream": "cosmics",
    "core.file_type": "detector",
    "core.run_type": "vd-protodune-top",
    "core.runs": [
      3430
    ],
    "core.runs_subruns": [
      343000011
    ],
    "retention.status": "active",
    "retention.class": "physics"
  },
  "parents": [
    {
      "did": "vd-protodune-top:3430_11_b_pvdt.test"
    }
  ]
}
justIN time: 2025-12-19 08:50:39 UTC       justIN version: 01.05.03