Jobsub ID 41739.57@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
<OmnibusSigProc:anode0sigproc0> EOS at call=95 anode=0
[11:36:31.427] D [ glue ] <FrameFanin:nfsp> EOS at call=95 with 8
[11:36:31.427] D [ glue ] frame sink sees EOS
[11:36:31.427] D [ pgraph ] <Pgrapher:> graph execution complete
[11:36:31.427] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.35 sec
[11:36:31.427] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 4.97 sec
[11:36:31.427] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 4.64 sec
[11:36:31.427] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 4.48 sec
[11:36:31.427] I [ timer ] Timer: WireCell::Aux::Resampler : 0.35 sec
[11:36:31.427] I [ timer ] Timer: WireCell::Aux::Resampler : 0.33 sec
[11:36:31.427] I [ timer ] Timer: WireCell::Aux::Resampler : 0.33 sec
[11:36:31.427] I [ timer ] Timer: WireCell::Aux::Resampler : 0.33 sec
[11:36:31.427] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[11:36:31.427] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[11:36:31.427] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0.01 sec
[11:36:31.427] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[11:36:31.427] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:36:31.427] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:36:31.427] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[11:36:31.427] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:36:31.427] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:36:31.427] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[11:36:31.427] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:36:31.427] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[11:36:31.427] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:36:31.427] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:36:31.427] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[11:36:31.427] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[11:36:31.427] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[11:36:31.427] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[11:36:31.427] I [ timer ] Timer: Total node execution : 21.80999961309135 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 19958 traces tagged "gauss"
FrameSaver: q=5.69132e+06 n=469374 tag=gauss
wclsFrameSaver: saving 26099 traces tagged "wiener"
FrameSaver: q=6.17605e+06 n=447236 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 692 XUs and 887 XVs -> 54 XUVs
C:0 T:1 2198 XUs and 3018 XVs -> 138 XUVs
C:0 T:2 2089 XUs and 4065 XVs -> 268 XUVs
C:0 T:3 169 XUs and 343 XVs -> 7 XUVs
C:0 T:4 18300 XUs and 30700 XVs -> 2049 XUVs
C:0 T:5 421 XUs and 449 XVs -> 24 XUVs
C:0 T:6 797 XUs and 939 XVs -> 51 XUVs
C:0 T:7 113 XUs and 229 XVs -> 6 XUVs
2597 XUVs total
1432 collection wire objects
2597 potential space points
Neighbour search...
112859 tests to find 25056 neighbours
Iterating with no regularization...
Begin: 2.71838e+10
0 2.63922e+10
1 2.6328e+10
2 2.63274e+10
Now with regularization...
Begin: 2.60805e+10
0 2.60799e+10
18-Sep-2025 11:36:58 CEST Closed output file "np02vd_raw_run039433_0382_df-s05-d0_dw_0_20250918T070259_reco_stage1_20250918T093658_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 61.3007 125.638 675.879 110.553 85.7432 48
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 5.0527e-05 6.56174e-05 0.000175708 6.3538e-05 1.76992e-05 48
produce:tpcrawdecoder:PDVDTPCReader 20.3736 36.2437 57.1434 36.2007 9.27594 48
produce:triggerrawdecoder:PDVDTriggerReader4 0.306996 0.382447 0.655676 0.3673 0.0705256 48
produce:pdvddaphne:DAPHNEReaderPDVD 6.3104 9.30985 14.4026 8.86708 1.95664 48
produce:ophit:OpHitFinder 0.0266599 0.0403899 0.0493362 0.040826 0.00503381 48
produce:opflash:OpFlashFinderVerticalDrift 0.00220538 0.00879345 0.0127756 0.00905335 0.00239919 48
produce:wclsdatavd:WireCellToolkit 19.5406 43.6823 65.5089 43.9494 10.9868 48
produce:gaushit:GausHitFinder 0.294526 0.577665 1.34476 0.56215 0.1884 48
produce:nhitsfilter:NumberOfHitsFilter 7.6958e-05 0.000134585 0.000392889 0.00012446 5.89437e-05 48
produce:reco3d:SpacePointSolver 1.37203 5.2409 25.9407 4.60882 3.78696 48
produce:hitpdune:DisambigFromSpacePoints 0.0190831 0.069307 0.358056 0.0540332 0.0628068 48
produce:pandora:StandardPandora 3.19836 27.6605 548.971 11.4446 78.0848 48
produce:pandoraTrack:LArPandoraTrackCreation 0.0944463 0.274803 1.32082 0.216887 0.216133 48
produce:pandoraGnocalo:GnocchiCalorimetry 0.00717152 0.0135681 0.0300174 0.0137427 0.00397068 48
[art]:TriggerResults:TriggerResultInserter 1.4368e-05 2.08095e-05 5.7601e-05 1.9638e-05 6.76475e-06 48
end_path:out1:RootOutput 3.868e-06 5.2601e-06 2.1201e-05 4.549e-06 3.09952e-06 48
end_path:out1:RootOutput(write) 1.84668 2.11597 2.74778 2.05526 0.216843 48
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5709.81 MB
Peak resident set size usage (VmHWM): 3825.11 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0382_df-s05-d0_dw_0_20250918T070259_reco_stage1_20250918T093658_keepup.root
\tHists: np02vd_raw_run039433_0382_df-s05-d0_dw_0_20250918T070259_reco_stage1_20250918T093658_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0382_df-s05-d0_dw_0_20250918T070259_reco_stage1_20250918T093658_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0382_df-s05-d0_dw_0_20250918T070259_reco_stage1_20250918T093658_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": 1758188218.0,
"core.end_time": 1758188219.0,
"core.events": [
109692,
109698,
109704,
109710,
109716,
109722,
109728,
109734,
109740,
109746,
109752,
109758,
109764,
109770,
109776,
109782,
109788,
109794,
109800,
109806,
109812,
109818,
109824,
109830,
109836,
109842,
109848,
109854,
109860,
109866,
109872,
109878,
109884,
109890,
109896,
109902,
109908,
109914,
109920,
109926,
109932,
109938,
109944,
109950,
109956,
109962,
109968,
109974
],
"core.event_count": 48,
"core.first_event_number": 109692,
"core.last_event_number": 109974,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39433
],
"core.runs_subruns": [
3943300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039433_0382_df-s05-d0_dw_0_20250918T070259.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0382_df-s05-d0_dw_0_20250918T070259_reco_stage1_20250918T093658_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": 1758188218.0,
"core.end_time": 1758188219.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39433
],
"core.runs_subruns": [
3943300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039433_0382_df-s05-d0_dw_0_20250918T070259.hdf5"
}
]
} 