Jobsub ID 242400.50@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=47 anode=0 
[17:32:23.248] D [  glue  ] <FrameFanin:nfsp> EOS at call=47 with 8 
[17:32:23.248] D [  glue  ] frame sink sees EOS
[17:32:23.248] D [ pgraph ] <Pgrapher:> graph execution complete 
[17:32:23.248] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.96 sec
[17:32:23.248] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.91 sec
[17:32:23.248] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.68 sec
[17:32:23.248] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.66 sec
[17:32:23.248] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.54 sec
[17:32:23.248] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.33 sec
[17:32:23.248] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.81 sec
[17:32:23.248] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.5 sec
[17:32:23.248] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.34 sec
[17:32:23.248] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.33 sec
[17:32:23.248] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.32 sec
[17:32:23.248] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.32 sec
[17:32:23.248] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[17:32:23.248] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[17:32:23.248] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[17:32:23.248] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[17:32:23.248] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.01 sec
[17:32:23.248] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:32:23.248] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:32:23.248] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:32:23.248] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[17:32:23.248] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:32:23.248] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:32:23.248] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[17:32:23.248] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[17:32:23.248] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[17:32:23.248] I [ timer  ] Timer: Total node execution : 76.77000034414232 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 37363 traces tagged "gauss"
FrameSaver: q=9.80304e+06 n=804110 tag=gauss
wclsFrameSaver: saving 45643 traces tagged "wiener"
FrameSaver: q=1.06605e+07 n=776101 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 683 XUs and 616 XVs -> 15 XUVs
C:0 T:1 843 XUs and 851 XVs -> 19 XUVs
C:0 T:2 345 XUs and 391 XVs -> 21 XUVs
C:0 T:3 11420 XUs and 14891 XVs -> 951 XUVs
C:0 T:4 270 XUs and 273 XVs -> 4 XUVs
C:0 T:5 192 XUs and 261 XVs -> 1 XUVs
C:0 T:6 1577 XUs and 2239 XVs -> 101 XUVs
C:0 T:7 600 XUs and 584 XVs -> 31 XUVs
C:0 T:8 372 XUs and 470 XVs -> 24 XUVs
C:0 T:9 1877 XUs and 2358 XVs -> 79 XUVs
C:0 T:10 54 XUs and 92 XVs -> 2 XUVs
C:0 T:11 484 XUs and 789 XVs -> 17 XUVs
C:0 T:12 484 XUs and 688 XVs -> 19 XUVs
C:0 T:13 614 XUs and 560 XVs -> 40 XUVs
C:0 T:14 489 XUs and 890 XVs -> 42 XUVs
C:0 T:15 575 XUs and 619 XVs -> 36 XUVs
1402 XUVs total
861 collection wire objects
1402 potential space points
Neighbour search...
33060 tests to find 7904 neighbours
Iterating with no regularization...
Begin: 1.19426e+10
0 1.16053e+10
1 1.15846e+10
2 1.1583e+10
Now with regularization...
Begin: 1.13066e+10
0 1.13064e+10
03-Nov-2025 17:33:06 UTC  Closed output file "np02vd_raw_run040346_3659_df-s04-d2_dw_0_20251103T153558_reco_stage1_20251103T173306_keepup.root"
==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                        179.465       216.018       290.134       203.532       31.7233        24     
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read)                      8.4218e-05    0.000107688   0.000247615   9.4688e-05    3.49958e-05      24     
produce:tpcrawdecoder:PDVDTPCReader               47.429        80.9437       160.947       72.3392       26.9005        24     
produce:triggerrawdecoder:PDVDTriggerReader4     0.590463      0.678885       1.01381      0.638693      0.103139        24     
produce:pdvddaphne:DAPHNEReaderPDVD             0.000409339   0.000532897   0.00116644    0.000497504   0.000150204      24     
produce:ophit:OpHitFinder                       7.0061e-05    0.000159648   0.000904889   0.000119975   0.000159618      24     
produce:opflash:OpFlashFinderVerticalDrift      6.8719e-05    0.000109567   0.000519906   8.7695e-05    8.72013e-05      24     
produce:wclsdatavd:WireCellToolkit                69.1635       83.7412       130.18        80.1983       13.1447        24     
produce:gaushit:GausHitFinder                     1.08407       1.51534       2.44819       1.45306      0.299807        24     
produce:nhitsfilter:NumberOfHitsFilter          0.000246313   0.000328148   0.000604705   0.000304968   7.33781e-05      24     
produce:reco3d:SpacePointSolver                   7.40178       11.7981       19.9107       11.3006       3.12096        24     
produce:hitpdune:DisambigFromSpacePoints         0.105211      0.182531      0.264832      0.172199      0.0433368       24     
produce:pandora:StandardPandora                   14.8025       30.1269       50.4782       28.519        8.9853         24     
produce:pandoraTrack:LArPandoraTrackCreation     0.484215       1.18097       1.95702       1.18237      0.352047        24     
produce:pandoraGnocalo:GnocchiCalorimetry        0.0284288     0.0415411     0.0602259     0.0415763    0.00773979       24     
[art]:TriggerResults:TriggerResultInserter      2.3063e-05    3.87653e-05    7.458e-05    3.3944e-05    1.29089e-05      24     
end_path:out1:RootOutput                         4.177e-06    8.10692e-06   3.3252e-05     4.714e-06    7.79748e-06      24     
end_path:out1:RootOutput(write)                   5.32678       5.74606       7.53843       5.57998      0.555884        24     
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
  Peak virtual memory usage (VmPeak)  : 5086.97 MB
  Peak resident set size usage (VmHWM): 2983.43 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run040346_3659_df-s04-d2_dw_0_20251103T153558_reco_stage1_20251103T173306_keepup.root
\tHists: np02vd_raw_run040346_3659_df-s04-d2_dw_0_20251103T153558_reco_stage1_20251103T173306_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run040346_3659_df-s04-d2_dw_0_20251103T153558_reco_stage1_20251103T173306_keepup.root
Ran successfully
{
  "name": "np02vd_raw_run040346_3659_df-s04-d2_dw_0_20251103T153558_reco_stage1_20251103T173306_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": 1762191187.0,
    "core.end_time": 1762191187.0,
    "core.events": [
      337810,
      337814,
      337818,
      337822,
      337826,
      337830,
      337834,
      337838,
      337842,
      337846,
      337850,
      337854,
      337858,
      337862,
      337866,
      337870,
      337874,
      337878,
      337882,
      337886,
      337890,
      337894,
      337898,
      337902
    ],
    "core.event_count": 24,
    "core.first_event_number": 337810,
    "core.last_event_number": 337902,
    "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_3659_df-s04-d2_dw_0_20251103T153558.hdf5"
    }
  ]
}Forming hist metadata
formed
{
  "name": "np02vd_raw_run040346_3659_df-s04-d2_dw_0_20251103T153558_reco_stage1_20251103T173306_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": 1762191187.0,
    "core.end_time": 1762191187.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_3659_df-s04-d2_dw_0_20251103T153558.hdf5"
    }
  ]
}