Jobsub ID 236601.22@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
c ] <OmnibusSigProc:anode0sigproc0> EOS at call=45 anode=0 
[12:59:22.169] D [  glue  ] <FrameFanin:nfsp> EOS at call=45 with 8 
[12:59:22.169] D [  glue  ] frame sink sees EOS
[12:59:22.169] D [ pgraph ] <Pgrapher:> graph execution complete 
[12:59:22.169] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 10.83 sec
[12:59:22.169] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.88 sec
[12:59:22.169] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.26 sec
[12:59:22.169] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.77 sec
[12:59:22.169] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.68 sec
[12:59:22.169] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.12 sec
[12:59:22.169] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.81 sec
[12:59:22.169] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.39 sec
[12:59:22.169] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.34 sec
[12:59:22.169] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.33 sec
[12:59:22.169] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.21 sec
[12:59:22.169] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.2 sec
[12:59:22.169] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.03 sec
[12:59:22.169] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[12:59:22.169] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[12:59:22.169] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:59:22.169] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:59:22.169] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:59:22.169] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:59:22.169] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:59:22.169] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[12:59:22.170] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:59:22.170] I [ timer  ] Timer: WireCell::Gen::Retagger : 0 sec
[12:59:22.170] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[12:59:22.170] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[12:59:22.170] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[12:59:22.170] I [ timer  ] Timer: Total node execution : 71.87000073678792 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 53564 traces tagged "gauss"
FrameSaver: q=1.35814e+07 n=1152199 tag=gauss
wclsFrameSaver: saving 67619 traces tagged "wiener"
FrameSaver: q=1.49246e+07 n=1113577 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 19632 XUs and 20503 XVs -> 1276 XUVs
C:0 T:1 10650 XUs and 10401 XVs -> 1152 XUVs
C:0 T:2 3839 XUs and 3030 XVs -> 483 XUVs
C:0 T:3 590 XUs and 424 XVs -> 21 XUVs
C:0 T:4 2829 XUs and 2506 XVs -> 401 XUVs
C:0 T:5 1036 XUs and 971 XVs -> 244 XUVs
C:0 T:6 683 XUs and 788 XVs -> 14 XUVs
C:0 T:7 212 XUs and 319 XVs -> 7 XUVs
C:0 T:8 182 XUs and 280 XVs -> 14 XUVs
C:0 T:9 1562 XUs and 2121 XVs -> 136 XUVs
C:0 T:10 368 XUs and 596 XVs -> 22 XUVs
C:0 T:11 221 XUs and 385 XVs -> 18 XUVs
C:0 T:12 3434 XUs and 3738 XVs -> 212 XUVs
C:0 T:13 656 XUs and 400 XVs -> 32 XUVs
C:0 T:14 614 XUs and 839 XVs -> 24 XUVs
C:0 T:15 883 XUs and 826 XVs -> 60 XUVs
4116 XUVs total
1774 collection wire objects
4116 potential space points
Neighbour search...
162936 tests to find 60754 neighbours
Iterating with no regularization...
Begin: 8.37288e+09
0 7.8718e+09
1 7.83515e+09
2 7.83398e+09
Now with regularization...
Begin: 7.79453e+09
0 7.79421e+09
03-Nov-2025 13:00:18 CET  Closed output file "np02vd_raw_run040346_3302_df-s04-d2_dw_0_20251103T101900_reco_stage1_20251103T120018_keepup.root"
==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                        80.7299       173.398       1338.26       116.083       250.145        23     
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read)                      5.9791e-05    0.000120808   0.000398046   0.000103432   6.77781e-05      23     
produce:tpcrawdecoder:PDVDTPCReader               12.8761       13.8695       15.6948       13.4817      0.932237        23     
produce:triggerrawdecoder:PDVDTriggerReader4     0.458196      0.494223      0.537394      0.490859      0.0184137       23     
produce:pdvddaphne:DAPHNEReaderPDVD             0.000278643   0.000429492   0.000931242   0.000399586   0.00012482       23     
produce:ophit:OpHitFinder                        5.921e-05    0.000132611   0.00076998    0.000101751   0.000138287      23     
produce:opflash:OpFlashFinderVerticalDrift      4.0381e-05    8.50403e-05   0.000459406    6.33e-05     8.19326e-05      23     
produce:wclsdatavd:WireCellToolkit                45.5496       67.4542       118.619       62.3539       16.8627        23     
produce:gaushit:GausHitFinder                    0.465048       1.09434       2.5604        1.00457      0.434563        23     
produce:nhitsfilter:NumberOfHitsFilter          0.000143822   0.000304808   0.000648028   0.000289084   0.00012204       23     
produce:reco3d:SpacePointSolver                   4.3633        11.4485       47.3467       9.30889       8.10261        23     
produce:hitpdune:DisambigFromSpacePoints         0.0786434     0.182833      0.967232      0.141045      0.174318        23     
produce:pandora:StandardPandora                   7.80668       71.8622       1135.58       19.8981       227.465        23     
produce:pandoraTrack:LArPandoraTrackCreation     0.236488       1.11923       10.2706      0.726743       1.96482        23     
produce:pandoraGnocalo:GnocchiCalorimetry        0.0120586     0.0317011     0.0880033     0.0309665     0.0135226       23     
[art]:TriggerResults:TriggerResultInserter       1.234e-05    2.22764e-05   6.9571e-05     1.788e-05    1.38893e-05      23     
end_path:out1:RootOutput                         3.08e-06     7.85013e-06   2.6921e-05     7.51e-06     5.25717e-06      23     
end_path:out1:RootOutput(write)                   4.54686       5.80251       8.45084       5.56985       1.07677        23     
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
  Peak virtual memory usage (VmPeak)  : 7171.92 MB
  Peak resident set size usage (VmHWM): 4656.51 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run040346_3302_df-s04-d2_dw_0_20251103T101900_reco_stage1_20251103T120018_keepup.root
\tHists: np02vd_raw_run040346_3302_df-s04-d2_dw_0_20251103T101900_reco_stage1_20251103T120018_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run040346_3302_df-s04-d2_dw_0_20251103T101900_reco_stage1_20251103T120018_keepup.root
Ran successfully
{
  "name": "np02vd_raw_run040346_3302_df-s04-d2_dw_0_20251103T101900_reco_stage1_20251103T120018_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": 1762171219.0,
    "core.end_time": 1762171219.0,
    "core.events": [
      304850,
      304854,
      304858,
      304862,
      304866,
      304870,
      304874,
      304878,
      304882,
      304886,
      304890,
      304894,
      304898,
      304902,
      304906,
      304910,
      304914,
      304918,
      304922,
      304926,
      304930,
      304934,
      304938
    ],
    "core.event_count": 23,
    "core.first_event_number": 304850,
    "core.last_event_number": 304938,
    "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_3302_df-s04-d2_dw_0_20251103T101900.hdf5"
    }
  ]
}Forming hist metadata
formed
{
  "name": "np02vd_raw_run040346_3302_df-s04-d2_dw_0_20251103T101900_reco_stage1_20251103T120018_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": 1762171219.0,
    "core.end_time": 1762171219.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_3302_df-s04-d2_dw_0_20251103T101900.hdf5"
    }
  ]
}