Jobsub ID 236601.86@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
5 
[11:59:40.853] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=45 anode=0 
[11:59:40.853] D [  glue  ] <FrameFanin:nfsp> EOS at call=45 with 8 
[11:59:40.853] D [  glue  ] frame sink sees EOS
[11:59:40.853] D [ pgraph ] <Pgrapher:> graph execution complete 
[11:59:40.853] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 10.71 sec
[11:59:40.853] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.66 sec
[11:59:40.853] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.51 sec
[11:59:40.853] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.47 sec
[11:59:40.853] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.46 sec
[11:59:40.853] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.75 sec
[11:59:40.853] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.34 sec
[11:59:40.853] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 6.51 sec
[11:59:40.853] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.33 sec
[11:59:40.853] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.3 sec
[11:59:40.853] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.3 sec
[11:59:40.853] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.3 sec
[11:59:40.853] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[11:59:40.853] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[11:59:40.853] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[11:59:40.853] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[11:59:40.853] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[11:59:40.853] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:59:40.853] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:59:40.853] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:59:40.853] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:59:40.853] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[11:59:40.853] I [ timer  ] Timer: WireCell::Gen::Retagger : 0 sec
[11:59:40.853] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[11:59:40.853] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[11:59:40.853] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[11:59:40.853] I [ timer  ] Timer: Total node execution : 67.71000084839761 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 44156 traces tagged "gauss"
FrameSaver: q=1.13731e+07 n=945885 tag=gauss
wclsFrameSaver: saving 54581 traces tagged "wiener"
FrameSaver: q=1.21495e+07 n=907841 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 205 XUs and 197 XVs -> 3 XUVs
C:0 T:1 503 XUs and 223 XVs -> 6 XUVs
C:0 T:2 110 XUs and 117 XVs -> 3 XUVs
C:0 T:3 1032 XUs and 934 XVs -> 67 XUVs
C:0 T:4 2037 XUs and 1691 XVs -> 87 XUVs
C:0 T:5 10839 XUs and 13203 XVs -> 646 XUVs
C:0 T:6 1204 XUs and 1232 XVs -> 39 XUVs
C:0 T:7 2247 XUs and 1806 XVs -> 80 XUVs
C:0 T:8 524 XUs and 744 XVs -> 54 XUVs
C:0 T:9 451 XUs and 739 XVs -> 24 XUVs
C:0 T:10 341 XUs and 511 XVs -> 20 XUVs
C:0 T:11 560 XUs and 1049 XVs -> 43 XUVs
C:0 T:12 324 XUs and 570 XVs -> 29 XUVs
C:0 T:13 804 XUs and 1014 XVs -> 54 XUVs
C:0 T:14 1103 XUs and 1343 XVs -> 77 XUVs
C:0 T:15 694 XUs and 651 XVs -> 30 XUVs
1262 XUVs total
961 collection wire objects
1262 potential space points
Neighbour search...
27360 tests to find 7758 neighbours
Iterating with no regularization...
Begin: 2.5534e+10
0 2.53348e+10
1 2.53305e+10
Now with regularization...
Begin: 2.53032e+10
0 2.53032e+10
03-Nov-2025 12:00:23 UTC  Closed output file "np02vd_raw_run040346_3318_df-s04-d0_dw_0_20251103T103157_reco_stage1_20251103T120023_keepup.root"
==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                        95.7446       160.758       327.004       140.088       62.9956        23     
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read)                      6.2152e-05    0.000113347   0.000296169   0.000102853   4.50316e-05      23     
produce:tpcrawdecoder:PDVDTPCReader               14.7875       16.2053       19.4071       16.0086       1.00544        23     
produce:triggerrawdecoder:PDVDTriggerReader4      0.67892      0.698261      0.739742      0.693003      0.0131079       23     
produce:pdvddaphne:DAPHNEReaderPDVD             0.000373311   0.000531078   0.000924139   0.000537776   0.000108916      23     
produce:ophit:OpHitFinder                       7.7092e-05    0.000148528   0.000682161   0.000125014   0.000115056      23     
produce:opflash:OpFlashFinderVerticalDrift      5.3522e-05    0.000145835   0.00132637    7.8063e-05    0.000262141      23     
produce:wclsdatavd:WireCellToolkit                51.8059       79.3908       123.956       74.269        20.6825        23     
produce:gaushit:GausHitFinder                    0.796435       1.31992       2.03514       1.26952      0.339469        23     
produce:nhitsfilter:NumberOfHitsFilter          0.000210107   0.00042421    0.00128912    0.000353211   0.000221814      23     
produce:reco3d:SpacePointSolver                   5.52017       12.3099       21.1769       11.6618       4.10943        23     
produce:hitpdune:DisambigFromSpacePoints         0.100314      0.233817       0.46305      0.188861      0.108838        23     
produce:pandora:StandardPandora                   10.8425       44.2981       187.295       26.0322       43.3586        23     
produce:pandoraTrack:LArPandoraTrackCreation     0.337164       1.17866       2.60562       1.0902       0.568667        23     
produce:pandoraGnocalo:GnocchiCalorimetry        0.0173433     0.0375925     0.0590906     0.0357349     0.0102383       23     
[art]:TriggerResults:TriggerResultInserter      2.0931e-05    4.19847e-05   0.000104533   3.6681e-05    1.81098e-05      23     
end_path:out1:RootOutput                         4.351e-06    8.91109e-06   3.8841e-05     5.91e-06     7.99667e-06      23     
end_path:out1:RootOutput(write)                   3.82964       5.02094        6.181        4.87089      0.692341        23     
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
  Peak virtual memory usage (VmPeak)  : 6095.18 MB
  Peak resident set size usage (VmHWM): 3662.53 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run040346_3318_df-s04-d0_dw_0_20251103T103157_reco_stage1_20251103T120023_keepup.root
\tHists: np02vd_raw_run040346_3318_df-s04-d0_dw_0_20251103T103157_reco_stage1_20251103T120024_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run040346_3318_df-s04-d0_dw_0_20251103T103157_reco_stage1_20251103T120023_keepup.root
Ran successfully
{
  "name": "np02vd_raw_run040346_3318_df-s04-d0_dw_0_20251103T103157_reco_stage1_20251103T120023_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": 1762171224.0,
    "core.end_time": 1762171224.0,
    "core.events": [
      306260,
      306264,
      306268,
      306272,
      306276,
      306280,
      306284,
      306288,
      306292,
      306296,
      306300,
      306304,
      306308,
      306312,
      306316,
      306320,
      306324,
      306328,
      306332,
      306336,
      306340,
      306344,
      306348
    ],
    "core.event_count": 23,
    "core.first_event_number": 306260,
    "core.last_event_number": 306348,
    "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_3318_df-s04-d0_dw_0_20251103T103157.hdf5"
    }
  ]
}Forming hist metadata
formed
{
  "name": "np02vd_raw_run040346_3318_df-s04-d0_dw_0_20251103T103157_reco_stage1_20251103T120024_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": 1762171224.0,
    "core.end_time": 1762171224.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_3318_df-s04-d0_dw_0_20251103T103157.hdf5"
    }
  ]
}