Jobsub ID 235526.28@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
OmnibusSigProc:anode0sigproc0> EOS at call=81 anode=0 
[00:31:48.563] D [  glue  ] <FrameFanin:nfsp> EOS at call=81 with 8 
[00:31:48.563] D [  glue  ] frame sink sees EOS
[00:31:48.563] D [ pgraph ] <Pgrapher:> graph execution complete 
[00:31:48.563] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 11.07 sec
[00:31:48.563] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 11.06 sec
[00:31:48.563] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 10.99 sec
[00:31:48.563] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 10.54 sec
[00:31:48.563] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.83 sec
[00:31:48.563] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.81 sec
[00:31:48.563] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.8 sec
[00:31:48.563] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.8 sec
[00:31:48.563] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[00:31:48.563] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[00:31:48.563] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[00:31:48.563] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[00:31:48.563] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[00:31:48.563] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[00:31:48.563] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[00:31:48.563] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[00:31:48.563] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[00:31:48.563] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[00:31:48.563] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[00:31:48.563] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[00:31:48.563] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[00:31:48.563] I [ timer  ] Timer: WireCell::Gen::Retagger : 0 sec
[00:31:48.563] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[00:31:48.563] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[00:31:48.563] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[00:31:48.563] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[00:31:48.563] I [ timer  ] Timer: Total node execution : 46.9299998562783 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 9812 traces tagged "gauss"
FrameSaver: q=1.68824e+06 n=190422 tag=gauss
wclsFrameSaver: saving 12512 traces tagged "wiener"
FrameSaver: q=1.78864e+06 n=177910 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 301 XUs and 430 XVs -> 17 XUVs
C:0 T:1 83 XUs and 116 XVs -> 3 XUVs
C:0 T:2 285 XUs and 585 XVs -> 12 XUVs
C:0 T:3 72 XUs and 124 XVs -> 2 XUVs
C:0 T:4 475 XUs and 541 XVs -> 17 XUVs
C:0 T:5 196 XUs and 285 XVs -> 6 XUVs
C:0 T:6 353 XUs and 225 XVs -> 10 XUVs
C:0 T:7 416 XUs and 502 XVs -> 11 XUVs
78 XUVs total
70 collection wire objects
78 potential space points
Neighbour search...
210 tests to find 120 neighbours
Iterating with no regularization...
Begin: 2.98826e+07
0 2.95827e+07
1 2.95824e+07
Now with regularization...
Begin: 2.89377e+07
0 2.89376e+07
31-Oct-2025 00:31:54 GMT  Closed output file "np02vd_raw_run040330_0029_df-s04-d0_dw_0_20251030T193112_reco_stage1_20251031T003154_keepup.root"
==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                        10.2184       274.228       718.278       336.978       198.883        60     
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read)                      9.5118e-05    0.000112146   0.000181866   0.000110389   1.58625e-05      60     
produce:tpcrawdecoder:PDVDTPCReader               8.83118       235.686       578.783       279.223       170.873        60     
produce:triggerrawdecoder:PDVDTriggerReader4     0.592158       1.57092       2.81649       1.50281      0.564855        60     
produce:pdvddaphne:DAPHNEReaderPDVD             0.00112206    0.00117146     0.0017057     0.0011627    7.19089e-05      60     
produce:ophit:OpHitFinder                       9.9766e-05    0.000130759   0.00101355    0.000107805   0.000116322      60     
produce:opflash:OpFlashFinderVerticalDrift      8.5039e-05    0.000106545   0.000595372   9.5339e-05    6.54128e-05      60     
produce:wclsdatavd:WireCellToolkit              0.000854278     24.6948       47.2619       34.8119       17.3634        60     
produce:gaushit:GausHitFinder                   8.3399e-05     0.289321      0.689833       0.36319      0.226171        60     
produce:nhitsfilter:NumberOfHitsFilter          1.8401e-05    9.56805e-05   0.000262284   0.000104038   5.66799e-05      60     
produce:reco3d:SpacePointSolver                 0.000137291     2.18677       6.77282       2.21184       1.8656         60     
produce:hitpdune:DisambigFromSpacePoints        0.000183151    0.0201983     0.0742457     0.0190328     0.0185841       60     
produce:pandora:StandardPandora                 0.000702383     8.4327        276.389       3.70032       35.0782        60     
produce:pandoraTrack:LArPandoraTrackCreation    0.000136255    0.0957892     0.358112      0.0813092     0.0920349       60     
produce:pandoraGnocalo:GnocchiCalorimetry       9.7812e-05    0.00666373     0.0163851    0.00686556    0.00522661       60     
[art]:TriggerResults:TriggerResultInserter      1.1478e-05    1.97511e-05   4.1595e-05    1.8615e-05    4.92259e-06      60     
end_path:out1:RootOutput                         2.811e-06    5.97452e-06   1.6483e-05    5.9935e-06    1.77732e-06      60     
end_path:out1:RootOutput(write)                  0.0105034      1.22371       2.08775       1.77651      0.861905        60     
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
  Peak virtual memory usage (VmPeak)  : 4081.07 MB
  Peak resident set size usage (VmHWM): 2045.7 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run040330_0029_df-s04-d0_dw_0_20251030T193112_reco_stage1_20251031T003154_keepup.root
\tHists: np02vd_raw_run040330_0029_df-s04-d0_dw_0_20251030T193112_reco_stage1_20251031T003157_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run040330_0029_df-s04-d0_dw_0_20251030T193112_reco_stage1_20251031T003154_keepup.root
Ran successfully
{
  "name": "np02vd_raw_run040330_0029_df-s04-d0_dw_0_20251030T193112_reco_stage1_20251031T003154_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": 1761870718.0,
    "core.end_time": 1761870718.0,
    "core.events": [
      1726,
      1727,
      1728,
      1729,
      1730,
      1731,
      1732,
      1733,
      1734,
      1735,
      1736,
      1737,
      1738,
      1739,
      1740,
      1741,
      1742,
      1743,
      1744,
      1745,
      1746,
      1747,
      1748,
      1749,
      1750,
      1751,
      1752,
      1753,
      1754,
      1755,
      1756,
      1757,
      1758,
      1759,
      1760,
      1761,
      1762,
      1763,
      1764,
      1765,
      1766,
      1767,
      1768,
      1769,
      1770,
      1771,
      1772,
      1773,
      1774,
      1775,
      1776,
      1777,
      1778,
      1779,
      1780,
      1781,
      1782,
      1783,
      1784,
      1785
    ],
    "core.event_count": 60,
    "core.first_event_number": 1726,
    "core.last_event_number": 1785,
    "core.data_stream": "cosmics",
    "core.file_content_status": "good",
    "core.file_type": "detector",
    "core.run_type": "vd-protodune",
    "core.runs": [
      40330
    ],
    "core.runs_subruns": [
      4033000001
    ],
    "dune.daq_test": true,
    "retention.status": "active",
    "retention.class": "physics"
  },
  "parents": [
    {
      "did": "vd-protodune:np02vd_raw_run040330_0029_df-s04-d0_dw_0_20251030T193112.hdf5"
    }
  ]
}Forming hist metadata
formed
{
  "name": "np02vd_raw_run040330_0029_df-s04-d0_dw_0_20251030T193112_reco_stage1_20251031T003157_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": 1761870718.0,
    "core.end_time": 1761870718.0,
    "core.data_stream": "cosmics",
    "core.file_content_status": "good",
    "core.file_type": "detector",
    "core.run_type": "vd-protodune",
    "core.runs": [
      40330
    ],
    "core.runs_subruns": [
      4033000001
    ],
    "dune.daq_test": true,
    "retention.status": "active",
    "retention.class": "physics"
  },
  "parents": [
    {
      "did": "vd-protodune:np02vd_raw_run040330_0029_df-s04-d0_dw_0_20251030T193112.hdf5"
    }
  ]
}