Jobsub ID 223125.185@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
6] D [  aux   ] <Resampler:resmp0> EOS at call=41 
[09:32:14.136] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=41 anode=0 
[09:32:14.136] D [  glue  ] <FrameFanin:nfsp> EOS at call=41 with 8 
[09:32:14.136] D [  glue  ] frame sink sees EOS
[09:32:14.136] D [ pgraph ] <Pgrapher:> graph execution complete 
[09:32:14.136] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 11.63 sec
[09:32:14.136] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 11.16 sec
[09:32:14.136] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 10.41 sec
[09:32:14.136] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 10.3 sec
[09:32:14.136] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.88 sec
[09:32:14.136] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.72 sec
[09:32:14.136] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.32 sec
[09:32:14.136] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8 sec
[09:32:14.136] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.38 sec
[09:32:14.136] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.38 sec
[09:32:14.136] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.23 sec
[09:32:14.136] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.21 sec
[09:32:14.136] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[09:32:14.136] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[09:32:14.136] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[09:32:14.136] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0.01 sec
[09:32:14.136] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.01 sec
[09:32:14.136] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0.01 sec
[09:32:14.136] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:32:14.136] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:32:14.136] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:32:14.136] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:32:14.136] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:32:14.136] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:32:14.136] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[09:32:14.136] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[09:32:14.136] I [ timer  ] Timer: Total node execution : 79.70000006258488 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 33063 traces tagged "gauss"
FrameSaver: q=5.8865e+06 n=656657 tag=gauss
wclsFrameSaver: saving 39886 traces tagged "wiener"
FrameSaver: q=6.22923e+06 n=630719 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 488 XUs and 1235 XVs -> 45 XUVs
C:0 T:1 738 XUs and 1193 XVs -> 54 XUVs
C:0 T:2 209 XUs and 404 XVs -> 9 XUVs
C:0 T:3 244 XUs and 612 XVs -> 36 XUVs
C:0 T:4 10 XUs and 8 XVs -> 0 XUVs
C:0 T:5 2735 XUs and 3109 XVs -> 227 XUVs
C:0 T:6 52 XUs and 57 XVs -> 0 XUVs
C:0 T:7 4382 XUs and 4122 XVs -> 341 XUVs
C:0 T:8 1602 XUs and 1706 XVs -> 153 XUVs
C:0 T:9 2151 XUs and 1496 XVs -> 179 XUVs
C:0 T:10 592 XUs and 520 XVs -> 35 XUVs
C:0 T:11 273 XUs and 228 XVs -> 14 XUVs
C:0 T:12 1462 XUs and 1406 XVs -> 91 XUVs
C:0 T:13 1247 XUs and 1114 XVs -> 62 XUVs
C:0 T:14 480 XUs and 420 XVs -> 36 XUVs
C:0 T:15 1059 XUs and 1102 XVs -> 46 XUVs
1328 XUVs total
1017 collection wire objects
1328 potential space points
Neighbour search...
24158 tests to find 7300 neighbours
Iterating with no regularization...
Begin: 1.64576e+09
0 1.60491e+09
1 1.60369e+09
Now with regularization...
Begin: 1.58407e+09
0 1.58403e+09
03-Oct-2025 09:33:00 BST  Closed output file "np02vd_raw_run039812_0304_df-s03-d1_dw_0_20251003T005622_reco_stage1_20251003T083300_keepup.root"
==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                        125.828       476.85        2303.96       259.079       563.623        21     
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read)                      7.1444e-05    0.000113029   0.000235169   0.000100672   4.39147e-05      21     
produce:tpcrawdecoder:PDVDTPCReader               12.117        14.3511       35.9978       13.1131       4.89315        21     
produce:triggerrawdecoder:PDVDTriggerReader4     0.279146      0.281755      0.300324      0.279875     0.00479081       21     
produce:pdvddaphne:DAPHNEReaderPDVD               3.95112       5.57382       6.81994       5.7163       0.586163        21     
produce:ophit:OpHitFinder                        0.0335924     0.0561692     0.0658569     0.0597094    0.00867983       21     
produce:opflash:OpFlashFinderVerticalDrift      0.00582452     0.0157384     0.0249839     0.0152945    0.00467128       21     
produce:wclsdatavd:WireCellToolkit                67.1591       124.027       191.221       128.757       32.2149        21     
produce:gaushit:GausHitFinder                     0.95537       2.47372       6.53634       1.88221       1.42081        21     
produce:nhitsfilter:NumberOfHitsFilter          0.000326454   0.000726797   0.00151444    0.000638469   0.000311726      21     
produce:reco3d:SpacePointSolver                   7.68698       26.0814       96.6935       16.7788       22.4024        21     
produce:hitpdune:DisambigFromSpacePoints         0.132212      0.890996       4.23692      0.403995       1.04451        21     
produce:pandora:StandardPandora                   24.2862       292.72        1960.75       72.0749       514.125        21     
produce:pandoraTrack:LArPandoraTrackCreation     0.704669       4.05148       18.0307       2.21264       4.41595        21     
produce:pandoraGnocalo:GnocchiCalorimetry        0.0191479     0.0525517     0.120004      0.0373948     0.0304741       21     
[art]:TriggerResults:TriggerResultInserter      2.3818e-05    3.58078e-05   6.8398e-05    3.4329e-05    9.14651e-06      21     
end_path:out1:RootOutput                         5.897e-06    8.3271e-06    2.1632e-05     7.698e-06    3.1599e-06       21     
end_path:out1:RootOutput(write)                   3.91921       6.21244       10.4834       6.32575       1.74496        21     
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
  Peak virtual memory usage (VmPeak)  : 7704.17 MB
  Peak resident set size usage (VmHWM): 5806.42 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039812_0304_df-s03-d1_dw_0_20251003T005622_reco_stage1_20251003T083300_keepup.root
\tHists: np02vd_raw_run039812_0304_df-s03-d1_dw_0_20251003T005622_reco_stage1_20251003T083301_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039812_0304_df-s03-d1_dw_0_20251003T005622_reco_stage1_20251003T083300_keepup.root
Ran successfully
{
  "name": "np02vd_raw_run039812_0304_df-s03-d1_dw_0_20251003T005622_reco_stage1_20251003T083300_keepup.root",
  "namespace": "vd-protodune-det-reco",
  "metadata": {
    "core.file_format": "artroot",
    "core.application.name": "reco",
    "core.application.family": "dunesw",
    "core.application.version": "v10_10_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": 1759480381.0,
    "core.end_time": 1759480381.0,
    "core.events": [
      51625,
      51633,
      51641,
      51649,
      51657,
      51665,
      51673,
      51681,
      51689,
      51697,
      51705,
      51713,
      51721,
      51729,
      51737,
      51745,
      51753,
      51761,
      51769,
      51777,
      51785
    ],
    "core.event_count": 21,
    "core.first_event_number": 51625,
    "core.last_event_number": 51785,
    "core.data_stream": "cosmics",
    "core.file_content_status": "good",
    "core.file_type": "detector",
    "core.run_type": "vd-protodune",
    "core.runs": [
      39812
    ],
    "core.runs_subruns": [
      3981200001
    ],
    "dune.daq_test": true,
    "retention.status": "active",
    "retention.class": "physics"
  },
  "parents": [
    {
      "did": "vd-protodune:np02vd_raw_run039812_0304_df-s03-d1_dw_0_20251003T005622.hdf5"
    }
  ]
}Forming hist metadata
formed
{
  "name": "np02vd_raw_run039812_0304_df-s03-d1_dw_0_20251003T005622_reco_stage1_20251003T083301_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_10_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": 1759480381.0,
    "core.end_time": 1759480381.0,
    "core.data_stream": "cosmics",
    "core.file_content_status": "good",
    "core.file_type": "detector",
    "core.run_type": "vd-protodune",
    "core.runs": [
      39812
    ],
    "core.runs_subruns": [
      3981200001
    ],
    "dune.daq_test": true,
    "retention.status": "active",
    "retention.class": "physics"
  },
  "parents": [
    {
      "did": "vd-protodune:np02vd_raw_run039812_0304_df-s03-d1_dw_0_20251003T005622.hdf5"
    }
  ]
}