Jobsub ID 236578.75@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
frame sink sees EOS
[11:36:43.417] D [ pgraph ] <Pgrapher:> graph execution complete 
[11:36:43.417] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.61 sec
[11:36:43.417] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.49 sec
[11:36:43.417] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.3 sec
[11:36:43.417] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.5 sec
[11:36:43.417] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.04 sec
[11:36:43.417] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.04 sec
[11:36:43.417] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.74 sec
[11:36:43.417] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.73 sec
[11:36:43.417] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.3 sec
[11:36:43.417] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.29 sec
[11:36:43.417] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.29 sec
[11:36:43.418] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.28 sec
[11:36:43.418] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.03 sec
[11:36:43.418] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[11:36:43.418] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[11:36:43.418] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[11:36:43.418] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.01 sec
[11:36:43.418] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:36:43.418] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:36:43.418] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:36:43.418] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:36:43.418] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[11:36:43.418] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:36:43.418] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[11:36:43.418] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[11:36:43.418] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[11:36:43.418] I [ timer  ] Timer: Total node execution : 69.69999932684004 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 50543 traces tagged "gauss"
FrameSaver: q=1.60909e+07 n=1146247 tag=gauss
wclsFrameSaver: saving 62725 traces tagged "wiener"
FrameSaver: q=1.72911e+07 n=1105348 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 1097 XUs and 1119 XVs -> 61 XUVs
C:0 T:1 448 XUs and 306 XVs -> 14 XUVs
C:0 T:2 705 XUs and 626 XVs -> 26 XUVs
C:0 T:3 14059 XUs and 17232 XVs -> 1217 XUVs
C:0 T:4 353 XUs and 710 XVs -> 29 XUVs
C:0 T:5 502 XUs and 747 XVs -> 14 XUVs
C:0 T:6 1258 XUs and 1490 XVs -> 81 XUVs
C:0 T:7 1905 XUs and 2286 XVs -> 81 XUVs
C:0 T:8 984 XUs and 1109 XVs -> 121 XUVs
C:0 T:9 1538 XUs and 1581 XVs -> 70 XUVs
C:0 T:10 971 XUs and 832 XVs -> 32 XUVs
C:0 T:11 575 XUs and 855 XVs -> 30 XUVs
C:0 T:12 1113 XUs and 1178 XVs -> 68 XUVs
C:0 T:13 4432 XUs and 3476 XVs -> 263 XUVs
C:0 T:14 612 XUs and 789 XVs -> 48 XUVs
C:0 T:15 544 XUs and 549 XVs -> 27 XUVs
2182 XUVs total
1197 collection wire objects
2182 potential space points
Neighbour search...
50230 tests to find 13194 neighbours
Iterating with no regularization...
Begin: 5.3325e+09
0 4.84002e+09
1 4.80174e+09
2 4.79969e+09
Now with regularization...
Begin: 4.70295e+09
0 4.70228e+09
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
03-Nov-2025 11:37:53 GMT  Closed output file "np02vd_raw_run040346_3204_df-s04-d0_dw_0_20251103T085138_reco_stage1_20251103T113753_keepup.root"
==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                        180.244       248.329       461.252       239.219       59.0905        23     
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read)                       5.896e-05    0.00011491    0.000270288   0.00010085    4.40999e-05      23     
produce:tpcrawdecoder:PDVDTPCReader               60.6227       103.62        167.355       97.5948       28.8389        23     
produce:triggerrawdecoder:PDVDTriggerReader4     0.719832      0.952296       1.42774      0.933721      0.172289        23     
produce:pdvddaphne:DAPHNEReaderPDVD             0.000366949   0.000448255   0.000983828   0.000412785   0.000126564      23     
produce:ophit:OpHitFinder                        9.031e-05    0.000186591   0.000808829   0.000134793   0.000155791      23     
produce:opflash:OpFlashFinderVerticalDrift      5.7658e-05    0.000114958   0.000553861   8.2205e-05    0.000100175      23     
produce:wclsdatavd:WireCellToolkit                56.6143       75.4428       109.907       68.808        16.428         23     
produce:gaushit:GausHitFinder                     1.01819       1.62284       2.35725       1.70519      0.326948        23     
produce:nhitsfilter:NumberOfHitsFilter          0.000227708   0.000378768   0.000968138   0.000353083   0.000157846      23     
produce:reco3d:SpacePointSolver                   7.51983        14.42        31.391        14.2513       4.74503        23     
produce:hitpdune:DisambigFromSpacePoints          0.10447      0.275657      0.885906      0.258297      0.144789        23     
produce:pandora:StandardPandora                   12.3644       44.5833       246.135       35.3862       45.4797        23     
produce:pandoraTrack:LArPandoraTrackCreation     0.484088       1.31202       5.28662       1.10708      0.913023        23     
produce:pandoraGnocalo:GnocchiCalorimetry        0.0275183     0.0455925     0.0668538     0.0444525     0.0105523       23     
[art]:TriggerResults:TriggerResultInserter      2.4185e-05    4.21329e-05   0.00015436    3.3153e-05     2.731e-05       23     
end_path:out1:RootOutput                         4.618e-06    1.13787e-05   4.1969e-05     9.328e-06    7.20038e-06      23     
end_path:out1:RootOutput(write)                   5.29541       6.00024       7.54286       5.7416       0.575491        23     
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
  Peak virtual memory usage (VmPeak)  : 5582.88 MB
  Peak resident set size usage (VmHWM): 3528.93 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run040346_3204_df-s04-d0_dw_0_20251103T085138_reco_stage1_20251103T113753_keepup.root
\tHists: np02vd_raw_run040346_3204_df-s04-d0_dw_0_20251103T085138_reco_stage1_20251103T113753_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run040346_3204_df-s04-d0_dw_0_20251103T085138_reco_stage1_20251103T113753_keepup.root
Ran successfully
{
  "name": "np02vd_raw_run040346_3204_df-s04-d0_dw_0_20251103T085138_reco_stage1_20251103T113753_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": 1762169874.0,
    "core.end_time": 1762169874.0,
    "core.events": [
      295740,
      295744,
      295748,
      295752,
      295756,
      295760,
      295764,
      295768,
      295772,
      295776,
      295780,
      295784,
      295788,
      295792,
      295796,
      295800,
      295804,
      295808,
      295812,
      295816,
      295820,
      295824,
      295828
    ],
    "core.event_count": 23,
    "core.first_event_number": 295740,
    "core.last_event_number": 295828,
    "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_3204_df-s04-d0_dw_0_20251103T085138.hdf5"
    }
  ]
}Forming hist metadata
formed
{
  "name": "np02vd_raw_run040346_3204_df-s04-d0_dw_0_20251103T085138_reco_stage1_20251103T113753_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": 1762169874.0,
    "core.end_time": 1762169874.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_3204_df-s04-d0_dw_0_20251103T085138.hdf5"
    }
  ]
}