Jobsub ID 242252.5@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
035] D [  glue  ] frame sink sees EOS
[14:00:21.035] D [ pgraph ] <Pgrapher:> graph execution complete 
[14:00:21.035] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.4 sec
[14:00:21.035] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 6.33 sec
[14:00:21.035] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 6.01 sec
[14:00:21.035] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 5.92 sec
[14:00:21.035] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 5.62 sec
[14:00:21.035] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 5.57 sec
[14:00:21.035] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 5.19 sec
[14:00:21.035] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 4.94 sec
[14:00:21.035] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.21 sec
[14:00:21.035] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.18 sec
[14:00:21.035] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.16 sec
[14:00:21.035] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.15 sec
[14:00:21.035] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[14:00:21.035] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[14:00:21.035] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.01 sec
[14:00:21.035] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:00:21.035] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:00:21.035] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:00:21.035] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:00:21.035] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:00:21.035] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[14:00:21.035] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:00:21.035] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:00:21.035] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[14:00:21.035] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[14:00:21.035] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[14:00:21.035] I [ timer  ] Timer: Total node execution : 47.710000498220325 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 48543 traces tagged "gauss"
FrameSaver: q=1.38196e+07 n=1092883 tag=gauss
wclsFrameSaver: saving 60121 traces tagged "wiener"
FrameSaver: q=1.47526e+07 n=1054099 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 914 XUs and 1160 XVs -> 28 XUVs
C:0 T:1 412 XUs and 530 XVs -> 19 XUVs
C:0 T:2 1573 XUs and 2146 XVs -> 111 XUVs
C:0 T:3 348 XUs and 387 XVs -> 22 XUVs
C:0 T:4 1075 XUs and 844 XVs -> 36 XUVs
C:0 T:5 807 XUs and 906 XVs -> 22 XUVs
C:0 T:6 1478 XUs and 1201 XVs -> 74 XUVs
C:0 T:7 7077 XUs and 7421 XVs -> 340 XUVs
C:0 T:8 4134 XUs and 4481 XVs -> 450 XUVs
C:0 T:9 668 XUs and 850 XVs -> 57 XUVs
C:0 T:10 199 XUs and 368 XVs -> 25 XUVs
C:0 T:11 334 XUs and 610 XVs -> 44 XUVs
C:0 T:12 1236 XUs and 1073 XVs -> 56 XUVs
C:0 T:13 1323 XUs and 1162 XVs -> 83 XUVs
C:0 T:14 1080 XUs and 1408 XVs -> 65 XUVs
C:0 T:15 1262 XUs and 1485 XVs -> 96 XUVs
1528 XUVs total
1103 collection wire objects
1528 potential space points
Neighbour search...
27530 tests to find 11258 neighbours
Iterating with no regularization...
Begin: 7.8503e+09
0 7.54409e+09
1 7.54177e+09
Now with regularization...
Begin: 7.45602e+09
0 7.45574e+09
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
03-Nov-2025 14:00:52 CET  Closed output file "np02vd_raw_run040346_3101_df-s04-d2_dw_0_20251103T072626_reco_stage1_20251103T130052_keepup.root"
==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                        86.1232       609.752       8362.1        115.79        1691.17        23     
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read)                      6.3305e-05    0.000112485   0.000228233   0.000104947   3.38049e-05      23     
produce:tpcrawdecoder:PDVDTPCReader               5.63278       6.43564       7.71948       6.31936      0.575845        23     
produce:triggerrawdecoder:PDVDTriggerReader4     0.0852415     0.0999351     0.132649      0.098414      0.0117254       23     
produce:pdvddaphne:DAPHNEReaderPDVD             0.000307701   0.00041661     0.0009533    0.000385638   0.000129034      23     
produce:ophit:OpHitFinder                       7.8918e-05    0.000148923   0.000746039   0.000109154   0.000134249      23     
produce:opflash:OpFlashFinderVerticalDrift      5.1026e-05    9.56244e-05   0.000415213   6.8983e-05    7.50492e-05      23     
produce:wclsdatavd:WireCellToolkit                47.7781       104.783       469.315       63.9244       108.534        23     
produce:gaushit:GausHitFinder                    0.738514       2.23524       9.09786       1.26848       2.50941        23     
produce:nhitsfilter:NumberOfHitsFilter          0.000150065    0.0004833    0.00228581    0.000295182   0.000454599      23     
produce:reco3d:SpacePointSolver                   8.54547       22.7583       123.175       11.7873       29.7429        23     
produce:hitpdune:DisambigFromSpacePoints         0.0881136     0.381363       1.79105      0.215812      0.452332        23     
produce:pandora:StandardPandora                   11.5486       466.051       7857.97       27.3151       1595.49        23     
produce:pandoraTrack:LArPandoraTrackCreation     0.478008       1.90925       9.00995       1.11839       2.04688        23     
produce:pandoraGnocalo:GnocchiCalorimetry        0.0195842     0.0414567     0.104078      0.0384483     0.0182153       23     
[art]:TriggerResults:TriggerResultInserter      3.0836e-05    5.74897e-05   0.00011325     5.366e-05    2.01099e-05      23     
end_path:out1:RootOutput                         5.979e-06    1.43371e-05   4.2154e-05     1.34e-05     7.55624e-06      23     
end_path:out1:RootOutput(write)                   3.67002       4.96273       7.17376       5.01249      0.871532        23     
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
  Peak virtual memory usage (VmPeak)  : 10996.6 MB
  Peak resident set size usage (VmHWM): 8903.53 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run040346_3101_df-s04-d2_dw_0_20251103T072626_reco_stage1_20251103T130052_keepup.root
\tHists: np02vd_raw_run040346_3101_df-s04-d2_dw_0_20251103T072626_reco_stage1_20251103T130052_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run040346_3101_df-s04-d2_dw_0_20251103T072626_reco_stage1_20251103T130052_keepup.root
Ran successfully
{
  "name": "np02vd_raw_run040346_3101_df-s04-d2_dw_0_20251103T072626_reco_stage1_20251103T130052_keepup.root",
  "namespace": "vd-protodune-det-reco",
  "metadata": {
    "core.file_format": "artroot",
    "core.application.name": "reco",
    "core.application.family": "dunesw",
    "core.application.version": "v10_11_00d00",
    "core.data_tier": "full-reconstructed",
    "dune.config_file": "standard_reco_stage1_protodunevd_keepup_all.fcl",
    "dune.campaign": "vd-protodune-reco-keepup-v0",
    "core.start_time": 1762174854.0,
    "core.end_time": 1762174854.0,
    "core.events": [
      286338,
      286342,
      286346,
      286350,
      286354,
      286358,
      286362,
      286366,
      286370,
      286374,
      286378,
      286382,
      286386,
      286390,
      286394,
      286398,
      286402,
      286406,
      286410,
      286414,
      286418,
      286422,
      286426
    ],
    "core.event_count": 23,
    "core.first_event_number": 286338,
    "core.last_event_number": 286426,
    "core.data_stream": "cosmics",
    "core.file_content_status": "good",
    "core.file_type": "detector",
    "core.run_type": "vd-protodune",
    "core.runs": [
      40346
    ],
    "core.runs_subruns": [
      4034600001
    ],
    "dune.daq_test": false,
    "retention.status": "active",
    "retention.class": "physics"
  },
  "parents": [
    {
      "did": "vd-protodune:np02vd_raw_run040346_3101_df-s04-d2_dw_0_20251103T072626.hdf5"
    }
  ]
}Forming hist metadata
formed
{
  "name": "np02vd_raw_run040346_3101_df-s04-d2_dw_0_20251103T072626_reco_stage1_20251103T130052_keepup_hists.root",
  "namespace": "vd-protodune-det-reco",
  "metadata": {
    "core.file_format": "root",
    "core.application.name": "reco",
    "core.application.family": "dunesw",
    "core.application.version": "v10_11_00d00",
    "core.data_tier": "root-tuple-virtual",
    "dune.config_file": "standard_reco_stage1_protodunevd_keepup_all.fcl",
    "dune.campaign": "vd-protodune-reco-keepup-v0",
    "core.start_time": 1762174854.0,
    "core.end_time": 1762174854.0,
    "core.data_stream": "cosmics",
    "core.file_content_status": "good",
    "core.file_type": "detector",
    "core.run_type": "vd-protodune",
    "core.runs": [
      40346
    ],
    "core.runs_subruns": [
      4034600001
    ],
    "dune.daq_test": false,
    "retention.status": "active",
    "retention.class": "physics"
  },
  "parents": [
    {
      "did": "vd-protodune:np02vd_raw_run040346_3101_df-s04-d2_dw_0_20251103T072626.hdf5"
    }
  ]
}