justIN           Dashboard       Workflows       Jobs       AWT       Sites       Storages       Docs       Login

Jobsub ID 269049.94@dunegpschedd01.fnal.gov

Jobsub ID269049.94@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 17:09:14
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:21
Input filesvd-protodune-top:3430_6_b_pvdt.test
JobscriptExit code0
Real time1h (4771s)
CPU time1h (4669s = 97%)
Max RSS bytes3800485888 (3624 MiB)
Outputting started2025-12-18 17:05:57
Output filesvd-protodune-det-reco:3430_6_b_pvdt_reco_stage1_20251218T170544_reco.root
Finished2025-12-18 17:09:14
Saved logsjustin-logs:269049.94-dunegpschedd01.fnal.gov.logs.tgz
List job events     Cached HTCondor job logs

Jobscript log (last 10,000 characters)

S at call=29 
[18:01:04.658] D [  aux   ] <Resampler:resmp3> EOS at call=59 
[18:01:04.658] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=59 
[18:01:04.658] D [sigproc ] <OmnibusSigProc:anode3sigproc3> EOS at call=59 anode=3 
[18:01:04.658] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=29 
[18:01:04.658] D [  aux   ] <Resampler:resmp2> EOS at call=59 
[18:01:04.658] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=59 
[18:01:04.658] D [sigproc ] <OmnibusSigProc:anode2sigproc2> EOS at call=59 anode=2 
[18:01:04.658] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=29 
[18:01:04.658] D [  aux   ] <Resampler:resmp1> EOS at call=59 
[18:01:04.658] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=59 
[18:01:04.658] D [sigproc ] <OmnibusSigProc:anode1sigproc1> EOS at call=59 anode=1 
[18:01:04.658] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=29 
[18:01:04.658] D [  aux   ] <Resampler:resmp0> EOS at call=59 
[18:01:04.658] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=59 
[18:01:04.658] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=59 anode=0 
[18:01:04.658] D [  glue  ] <FrameFanin:nfsp> EOS at call=59 with 8 
[18:01:04.658] D [  glue  ] frame sink sees EOS
[18:01:04.658] D [ pgraph ] <Pgrapher:> graph execution complete 
[18:01:04.659] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 25.64 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 22.77 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 21.79 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 18.74 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.67 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.54 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.53 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.51 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.54 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.46 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.45 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.43 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:01:04.659] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::Gen::Retagger : 0 sec
[18:01:04.659] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[18:01:04.659] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[18:01:04.659] I [ timer  ] Timer: Total node execution : 101.1100005581975 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 6144 traces tagged "gauss"
FrameSaver: q=1.23384e+07 n=3206801 tag=gauss
wclsFrameSaver: saving 6144 traces tagged "wiener"
FrameSaver: q=1.27031e+07 n=3103022 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 55610 XUs and 108707 XVs -> 21009 XUVs
C:0 T:1 55773 XUs and 114363 XVs -> 22983 XUVs
C:0 T:2 65662 XUs and 109595 XVs -> 23297 XUVs
C:0 T:3 82266 XUs and 173303 XVs -> 37114 XUVs
C:0 T:4 57573 XUs and 123708 XVs -> 24454 XUVs
C:0 T:5 31048 XUs and 63962 XVs -> 11417 XUVs
C:0 T:6 33520 XUs and 59257 XVs -> 12480 XUVs
C:0 T:7 53736 XUs and 101695 XVs -> 21343 XUVs
174097 XUVs total
10915 collection wire objects
174097 potential space points
Neighbour search...
30212635 tests to find 12831852 neighbours
Iterating with no regularization...
Begin: 6.42305e+08
0 4.56226e+08
1 4.38292e+08
2 4.35718e+08
3 4.34864e+08
4 4.34482e+08
Now with regularization...
Begin: 4.2187e+08
0 4.21498e+08
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Dec-2025 18:05:44 CET  Closed output file "3430_6_b_pvdt_reco_stage1_20251218T170544_reco.root"
DataPrepModule::endJob: # events processed: 30
DataPrepModule::endJob:   # events skipped: 0

==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                        65.6406       152.286       602.873       90.7547       130.096        30     
----------------------------------------------------------------------------------------------------------------------------------
source:VDColdboxTDERawInput(read)               5.2535e-05    9.7092e-05    0.000223634   8.33445e-05   4.29751e-05      30     
produce:caldata:DataPrepModule                   0.185629      0.254821      0.668775      0.214683      0.0979528       30     
produce:wclsdatavd:WireCellToolkit                57.4281       74.0597       108.515       68.0318       15.5788        30     
produce:gaushit:GausHitFinder                    0.522228       2.39311       5.40098       1.94968       1.7087         30     
produce:reco3d:SpacePointSolver                   1.94164       17.3999        81.85        5.46128       23.7681        30     
produce:hitpdune:DisambigFromSpacePoints         0.013109      0.342574       1.80392      0.0400977     0.572515        30     
produce:pandora:StandardPandora                   2.99606       53.9239       400.951       13.5657       89.569         30     
produce:pandoraTrack:LArPandoraTrackCreation     0.0919249     0.985417       4.12765      0.232453       1.42628        30     
produce:pandoraGnocalo:GnocchiCalorimetry        0.0102295     0.0344424     0.0999704     0.017767      0.0305976       30     
[art]:TriggerResults:TriggerResultInserter      2.0755e-05    2.83124e-05   5.2755e-05    2.59285e-05   7.48719e-06      30     
end_path:out1:RootOutput                         3.628e-06    5.68377e-06   2.1129e-05    5.4275e-06    3.03651e-06      30     
end_path:out1:RootOutput(write)                   2.12213       2.87307       4.45674       2.49362      0.768333        30     
==================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 6150.15 MB
  Peak resident set size usage (VmHWM): 3800.49 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.15 sec/event
ToolBasedRawDigitPrepService:dtor:                adcSampleFiller:   0.00 sec/event
Art has completed and will exit with status 0.
Output files:
\tReco: 3430_6_b_pvdt_reco_stage1_20251218T170544_reco.root
Forming reco metadata
Successfully opened file 3430_6_b_pvdt_reco_stage1_20251218T170544_reco.root
Ran successfully
{
  "name": "3430_6_b_pvdt_reco_stage1_20251218T170544_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": 1766077546.0,
    "core.end_time": 1766077546.0,
    "core.events": [
      602,
      606,
      610,
      614,
      618,
      622,
      626,
      630,
      634,
      638,
      642,
      646,
      650,
      654,
      658,
      662,
      666,
      670,
      674,
      678,
      682,
      686,
      690,
      694,
      698,
      702,
      706,
      710,
      714,
      718
    ],
    "core.event_count": 30,
    "core.first_event_number": 602,
    "core.last_event_number": 718,
    "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_b_pvdt.test"
    }
  ]
}
justIN time: 2025-12-18 23:23:52 UTC       justIN version: 01.05.03