Jobsub ID 236587.17@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
OmnibusSigProc:anode0sigproc0> EOS at call=45 anode=0 
[14:14:17.046] D [  glue  ] <FrameFanin:nfsp> EOS at call=45 with 8 
[14:14:17.046] D [  glue  ] frame sink sees EOS
[14:14:17.046] D [ pgraph ] <Pgrapher:> graph execution complete 
[14:14:17.046] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 13.12 sec
[14:14:17.046] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 12.75 sec
[14:14:17.046] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 12.17 sec
[14:14:17.046] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 12.05 sec
[14:14:17.046] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 11.99 sec
[14:14:17.046] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 11.28 sec
[14:14:17.046] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.53 sec
[14:14:17.046] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.35 sec
[14:14:17.046] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.51 sec
[14:14:17.046] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.51 sec
[14:14:17.046] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.49 sec
[14:14:17.046] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.31 sec
[14:14:17.046] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[14:14:17.046] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[14:14:17.046] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.01 sec
[14:14:17.046] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0.01 sec
[14:14:17.046] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:14:17.046] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:14:17.046] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:14:17.046] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:14:17.046] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:14:17.046] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[14:14:17.046] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:14:17.046] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:14:17.046] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[14:14:17.046] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[14:14:17.046] I [ timer  ] Timer: Total node execution : 94.10999976284802 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 60505 traces tagged "gauss"
FrameSaver: q=1.74043e+07 n=1367304 tag=gauss
wclsFrameSaver: saving 76565 traces tagged "wiener"
FrameSaver: q=1.88812e+07 n=1308504 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 732 XUs and 1446 XVs -> 50 XUVs
C:0 T:1 3167 XUs and 3599 XVs -> 210 XUVs
C:0 T:2 1947 XUs and 1740 XVs -> 79 XUVs
C:0 T:3 27071 XUs and 33774 XVs -> 2209 XUVs
C:0 T:4 2311 XUs and 2593 XVs -> 96 XUVs
C:0 T:5 2870 XUs and 3296 XVs -> 231 XUVs
C:0 T:6 744 XUs and 1113 XVs -> 58 XUVs
C:0 T:7 527 XUs and 723 XVs -> 15 XUVs
C:0 T:8 17011 XUs and 27031 XVs -> 5483 XUVs
C:0 T:9 3794 XUs and 2510 XVs -> 277 XUVs
C:0 T:10 275 XUs and 302 XVs -> 17 XUVs
C:0 T:11 1120 XUs and 1613 XVs -> 66 XUVs
C:0 T:12 1796 XUs and 2305 XVs -> 426 XUVs
C:0 T:13 413 XUs and 528 XVs -> 30 XUVs
C:0 T:14 372 XUs and 410 XVs -> 16 XUVs
C:0 T:15 644 XUs and 815 XVs -> 38 XUVs
9301 XUVs total
2486 collection wire objects
9301 potential space points
Neighbour search...
1085505 tests to find 432616 neighbours
Iterating with no regularization...
Begin: 1.86364e+10
0 1.83205e+10
1 1.83061e+10
Now with regularization...
Begin: 1.79614e+10
0 1.79603e+10
03-Nov-2025 14:15:49 CET  Closed output file "np02vd_raw_run040346_2628_df-s04-d1_dw_0_20251103T005345_reco_stage1_20251103T131549_keepup.root"
==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                        79.7215       445.319       7754.38       112.72        1558.56        23     
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read)                      5.6872e-05    9.32601e-05   0.000288307   8.1042e-05    4.44224e-05      23     
produce:tpcrawdecoder:PDVDTPCReader               4.92432       5.67255       6.99047       5.5891       0.566776        23     
produce:triggerrawdecoder:PDVDTriggerReader4     0.0102825     0.0179443     0.0790161     0.012394      0.014647        23     
produce:pdvddaphne:DAPHNEReaderPDVD             0.000241586   0.000358479   0.000840939   0.000338468   0.000110221      23     
produce:ophit:OpHitFinder                       5.2181e-05    0.000101823   0.000733637   6.6722e-05    0.000135359      23     
produce:opflash:OpFlashFinderVerticalDrift      4.1271e-05    7.73952e-05   0.000464161   5.7342e-05    8.32349e-05      23     
produce:wclsdatavd:WireCellToolkit                43.1759       65.9315       116.14        57.942        19.6964        23     
produce:gaushit:GausHitFinder                    0.725723       1.11052       1.88301       1.02337      0.356558        23     
produce:nhitsfilter:NumberOfHitsFilter          0.000149364   0.000252123   0.000623775   0.000231106   9.92196e-05      23     
produce:reco3d:SpacePointSolver                   6.68901       12.3785       54.4382       10.5465       9.33573        23     
produce:hitpdune:DisambigFromSpacePoints         0.0738131     0.242808       1.68599      0.150085      0.322409        23     
produce:pandora:StandardPandora                   9.97127       353.785       7560.96       23.8595       1536.64        23     
produce:pandoraTrack:LArPandoraTrackCreation      0.29616       1.10709       7.60671      0.769032       1.42356        23     
produce:pandoraGnocalo:GnocchiCalorimetry        0.0167616     0.0285239     0.0424847     0.0281053    0.00831496       23     
[art]:TriggerResults:TriggerResultInserter       1.575e-05    2.54417e-05   7.1891e-05     2.33e-05     1.21513e-05      23     
end_path:out1:RootOutput                         3.62e-06     6.31922e-06   3.0171e-05     4.61e-06     5.26272e-06      23     
end_path:out1:RootOutput(write)                   3.85378       5.00165       6.58427       4.92955       0.81092        23     
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
  Peak virtual memory usage (VmPeak)  : 6878.83 MB
  Peak resident set size usage (VmHWM): 4785.92 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run040346_2628_df-s04-d1_dw_0_20251103T005345_reco_stage1_20251103T131549_keepup.root
\tHists: np02vd_raw_run040346_2628_df-s04-d1_dw_0_20251103T005345_reco_stage1_20251103T131550_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run040346_2628_df-s04-d1_dw_0_20251103T005345_reco_stage1_20251103T131549_keepup.root
Ran successfully
{
  "name": "np02vd_raw_run040346_2628_df-s04-d1_dw_0_20251103T005345_reco_stage1_20251103T131549_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": 1762175750.0,
    "core.end_time": 1762175750.0,
    "core.events": [
      242733,
      242737,
      242741,
      242745,
      242749,
      242753,
      242757,
      242761,
      242765,
      242769,
      242773,
      242777,
      242781,
      242785,
      242789,
      242793,
      242797,
      242801,
      242805,
      242809,
      242813,
      242817,
      242821
    ],
    "core.event_count": 23,
    "core.first_event_number": 242733,
    "core.last_event_number": 242821,
    "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_2628_df-s04-d1_dw_0_20251103T005345.hdf5"
    }
  ]
}Forming hist metadata
formed
{
  "name": "np02vd_raw_run040346_2628_df-s04-d1_dw_0_20251103T005345_reco_stage1_20251103T131550_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": 1762175750.0,
    "core.end_time": 1762175750.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_2628_df-s04-d1_dw_0_20251103T005345.hdf5"
    }
  ]
}