Jobsub ID 221938.4@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
D [ pgraph ] <Pgrapher:> graph execution complete 
[01:12:56.934] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 15.85 sec
[01:12:56.934] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 15.29 sec
[01:12:56.934] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 15.18 sec
[01:12:56.934] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 14.53 sec
[01:12:56.934] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 11.72 sec
[01:12:56.934] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 11.32 sec
[01:12:56.934] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 11.17 sec
[01:12:56.934] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 10.72 sec
[01:12:56.934] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.32 sec
[01:12:56.934] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.32 sec
[01:12:56.934] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.31 sec
[01:12:56.934] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.3 sec
[01:12:56.934] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[01:12:56.934] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[01:12:56.934] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[01:12:56.934] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[01:12:56.934] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[01:12:56.934] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.01 sec
[01:12:56.934] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:12:56.934] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:12:56.934] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:12:56.934] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[01:12:56.934] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:12:56.934] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[01:12:56.934] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[01:12:56.934] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[01:12:56.934] I [ timer  ] Timer: Total node execution : 107.11000068485737 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 49840 traces tagged "gauss"
FrameSaver: q=1.06834e+07 n=1080811 tag=gauss
wclsFrameSaver: saving 61010 traces tagged "wiener"
FrameSaver: q=1.13329e+07 n=1037191 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 477 XUs and 466 XVs -> 33 XUVs
C:0 T:1 306 XUs and 373 XVs -> 16 XUVs
C:0 T:2 4169 XUs and 2024 XVs -> 103 XUVs
C:0 T:3 11455 XUs and 15801 XVs -> 1098 XUVs
C:0 T:4 27 XUs and 31 XVs -> 0 XUVs
C:0 T:5 24 XUs and 31 XVs -> 1 XUVs
C:0 T:6 5113 XUs and 5758 XVs -> 359 XUVs
C:0 T:7 829 XUs and 1108 XVs -> 54 XUVs
C:0 T:8 1442 XUs and 1648 XVs -> 100 XUVs
C:0 T:9 1123 XUs and 1580 XVs -> 84 XUVs
C:0 T:10 2618 XUs and 3934 XVs -> 197 XUVs
C:0 T:11 4356 XUs and 3822 XVs -> 195 XUVs
C:0 T:12 1226 XUs and 1224 XVs -> 79 XUVs
C:0 T:13 2335 XUs and 2104 XVs -> 108 XUVs
C:0 T:14 2345 XUs and 2100 XVs -> 139 XUVs
C:0 T:15 3907 XUs and 3918 XVs -> 197 XUVs
2763 XUVs total
2002 collection wire objects
2763 potential space points
Neighbour search...
47375 tests to find 12600 neighbours
Iterating with no regularization...
Begin: 1.40046e+10
0 1.38281e+10
1 1.38235e+10
Now with regularization...
Begin: 1.35115e+10
0 1.35111e+10
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
03-Oct-2025 01:14:12 CEST  Closed output file "np02vd_raw_run039777_0434_df-s04-d3_dw_0_20251002T045023_reco_stage1_20251002T231412_keepup.root"
==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                        150.239       334.085       1112.05       204.817       248.618        21     
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read)                      6.7034e-05    0.000120275   0.000265957   9.9282e-05    5.03774e-05      21     
produce:tpcrawdecoder:PDVDTPCReader               14.6909       18.1304       22.4585       17.7026       1.75171        21     
produce:triggerrawdecoder:PDVDTriggerReader4     0.177894      0.186619      0.211113       0.18464     0.00808073       21     
produce:pdvddaphne:DAPHNEReaderPDVD               2.66435       3.38948       4.32449       3.39915      0.400052        21     
produce:ophit:OpHitFinder                         0.02893      0.0410347     0.0602091     0.0396111    0.00755892       21     
produce:opflash:OpFlashFinderVerticalDrift      0.00610194     0.0105143     0.0187394     0.0100666    0.00279499       21     
produce:wclsdatavd:WireCellToolkit                82.1471       111.854       177.87        106.42        25.1662        21     
produce:gaushit:GausHitFinder                    0.794132       1.53817       2.66247       1.28996      0.598125        21     
produce:nhitsfilter:NumberOfHitsFilter          0.000466194   0.000734712   0.00134924    0.000636882   0.000246563      21     
produce:reco3d:SpacePointSolver                   10.0599       24.2224       64.3558       16.3935       15.8015        21     
produce:hitpdune:DisambigFromSpacePoints         0.121137      0.423854       1.19358      0.253897      0.341637        21     
produce:pandora:StandardPandora                   23.6603       166.742       856.787       52.2787       209.275        21     
produce:pandoraTrack:LArPandoraTrackCreation     0.949103       2.89937       6.75197       2.18579       1.73088        21     
produce:pandoraGnocalo:GnocchiCalorimetry        0.0205592     0.035785      0.0664302     0.0343131     0.0126856       21     
[art]:TriggerResults:TriggerResultInserter      4.7128e-05    6.30057e-05   9.1244e-05    5.9206e-05    1.28206e-05      21     
end_path:out1:RootOutput                        1.3802e-05    1.78327e-05   3.0806e-05    1.6325e-05    4.71476e-06      21     
end_path:out1:RootOutput(write)                   3.7662        4.50239       5.93391       4.31333      0.595725        21     
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
  Peak virtual memory usage (VmPeak)  : 7777.69 MB
  Peak resident set size usage (VmHWM): 5886.66 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039777_0434_df-s04-d3_dw_0_20251002T045023_reco_stage1_20251002T231412_keepup.root
\tHists: np02vd_raw_run039777_0434_df-s04-d3_dw_0_20251002T045023_reco_stage1_20251002T231412_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039777_0434_df-s04-d3_dw_0_20251002T045023_reco_stage1_20251002T231412_keepup.root
Ran successfully
{
  "name": "np02vd_raw_run039777_0434_df-s04-d3_dw_0_20251002T045023_reco_stage1_20251002T231412_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": 1759446853.0,
    "core.end_time": 1759446853.0,
    "core.events": [
      75151,
      75159,
      75167,
      75175,
      75183,
      75191,
      75199,
      75207,
      75215,
      75223,
      75231,
      75239,
      75247,
      75255,
      75263,
      75271,
      75279,
      75287,
      75295,
      75303,
      75311
    ],
    "core.event_count": 21,
    "core.first_event_number": 75151,
    "core.last_event_number": 75311,
    "core.data_stream": "cosmics",
    "core.file_content_status": "good",
    "core.file_type": "detector",
    "core.run_type": "vd-protodune",
    "core.runs": [
      39777
    ],
    "core.runs_subruns": [
      3977700001
    ],
    "dune.daq_test": true,
    "retention.status": "active",
    "retention.class": "physics"
  },
  "parents": [
    {
      "did": "vd-protodune:np02vd_raw_run039777_0434_df-s04-d3_dw_0_20251002T045023.hdf5"
    }
  ]
}Forming hist metadata
formed
{
  "name": "np02vd_raw_run039777_0434_df-s04-d3_dw_0_20251002T045023_reco_stage1_20251002T231412_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": 1759446853.0,
    "core.end_time": 1759446853.0,
    "core.data_stream": "cosmics",
    "core.file_content_status": "good",
    "core.file_type": "detector",
    "core.run_type": "vd-protodune",
    "core.runs": [
      39777
    ],
    "core.runs_subruns": [
      3977700001
    ],
    "dune.daq_test": true,
    "retention.status": "active",
    "retention.class": "physics"
  },
  "parents": [
    {
      "did": "vd-protodune:np02vd_raw_run039777_0434_df-s04-d3_dw_0_20251002T045023.hdf5"
    }
  ]
}