Jobsub ID 40375.112@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
[ aux ] <Resampler:resmp0> EOS at call=37
[12:49:56.331] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=37 anode=0
[12:49:56.331] D [ glue ] <FrameFanin:nfsp> EOS at call=37 with 8
[12:49:56.331] D [ glue ] frame sink sees EOS
[12:49:56.331] D [ pgraph ] <Pgrapher:> graph execution complete
[12:49:56.331] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.73 sec
[12:49:56.331] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.36 sec
[12:49:56.331] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.14 sec
[12:49:56.331] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.07 sec
[12:49:56.331] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.92 sec
[12:49:56.331] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.83 sec
[12:49:56.331] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.64 sec
[12:49:56.331] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.57 sec
[12:49:56.331] I [ timer ] Timer: WireCell::Aux::Resampler : 1.08 sec
[12:49:56.331] I [ timer ] Timer: WireCell::Aux::Resampler : 1.05 sec
[12:49:56.331] I [ timer ] Timer: WireCell::Aux::Resampler : 1 sec
[12:49:56.331] I [ timer ] Timer: WireCell::Aux::Resampler : 0.84 sec
[12:49:56.331] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[12:49:56.331] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[12:49:56.331] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[12:49:56.331] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[12:49:56.331] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[12:49:56.331] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:49:56.331] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:49:56.331] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:49:56.331] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:49:56.331] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[12:49:56.331] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:49:56.331] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[12:49:56.331] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[12:49:56.331] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[12:49:56.331] I [ timer ] Timer: Total node execution : 68.29999924264848 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 51576 traces tagged "gauss"
FrameSaver: q=8.07144e+06 n=1045657 tag=gauss
wclsFrameSaver: saving 62321 traces tagged "wiener"
FrameSaver: q=8.52001e+06 n=1007618 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 790 XUs and 852 XVs -> 41 XUVs
C:0 T:1 336 XUs and 561 XVs -> 14 XUVs
C:0 T:2 718 XUs and 805 XVs -> 29 XUVs
C:0 T:3 840 XUs and 1094 XVs -> 26 XUVs
C:0 T:4 1054 XUs and 1102 XVs -> 32 XUVs
C:0 T:5 1240 XUs and 1379 XVs -> 64 XUVs
C:0 T:6 542 XUs and 783 XVs -> 28 XUVs
C:0 T:7 1642 XUs and 2199 XVs -> 47 XUVs
C:0 T:8 3179 XUs and 3027 XVs -> 200 XUVs
C:0 T:9 4185 XUs and 3378 XVs -> 203 XUVs
C:0 T:10 1531 XUs and 1625 XVs -> 99 XUVs
C:0 T:11 1397 XUs and 1364 XVs -> 73 XUVs
C:0 T:12 1648 XUs and 1791 XVs -> 137 XUVs
C:0 T:13 1560 XUs and 1643 XVs -> 62 XUVs
C:0 T:14 4865 XUs and 4411 XVs -> 293 XUVs
C:0 T:15 5216 XUs and 4617 XVs -> 484 XUVs
1832 XUVs total
1344 collection wire objects
1832 potential space points
Neighbour search...
38340 tests to find 13758 neighbours
Iterating with no regularization...
Begin: 5.74369e+08
0 5.42996e+08
1 5.41652e+08
2 5.41579e+08
Now with regularization...
Begin: 5.31421e+08
0 5.31391e+08
16-Sep-2025 12:51:25 CEST Closed output file "np02vd_raw_run039353_0863_df-s05-d2_dw_0_20250916T091049_reco_stage1_20250916T105125_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 140.927 182.777 393.38 166.239 58.1027 19
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 8.8434e-05 0.00013321 0.000371474 0.000119411 5.99747e-05 19
produce:tpcrawdecoder:PDVDTPCReader 7.38605 8.64747 9.45936 8.89219 0.564927 19
produce:triggerrawdecoder:PDVDTriggerReader4 0.0501675 0.0576797 0.0702654 0.0556494 0.00583763 19
produce:pdvddaphne:DAPHNEReaderPDVD 0.000300546 0.000468376 0.00102951 0.000399146 0.0001674 19
produce:ophit:OpHitFinder 0.000203009 0.000451604 0.00148211 0.000298353 0.000334009 19
produce:opflash:OpFlashFinderVerticalDrift 5.9691e-05 0.000121027 0.000619181 9.2481e-05 0.000121039 19
produce:wclsdatavd:WireCellToolkit 70.4234 80.3917 103.244 77.2892 8.02128 19
produce:gaushit:GausHitFinder 1.19585 1.69151 2.82153 1.63622 0.390888 19
produce:nhitsfilter:NumberOfHitsFilter 0.000281457 0.000594616 0.00122203 0.00052673 0.000274541 19
produce:reco3d:SpacePointSolver 12.2277 16.0816 35.3526 13.7585 5.67978 19
produce:hitpdune:DisambigFromSpacePoints 0.178194 0.291264 0.874124 0.253505 0.146557 19
produce:pandora:StandardPandora 30.6132 67.1336 231.257 55.2795 44.7538 19
produce:pandoraTrack:LArPandoraTrackCreation 0.86323 2.3561 5.30932 1.86146 1.22826 19
produce:pandoraGnocalo:GnocchiCalorimetry 0.0338771 0.0464694 0.0782246 0.0377188 0.0122699 19
[art]:TriggerResults:TriggerResultInserter 4.3766e-05 8.17805e-05 0.000183408 7.3222e-05 3.18442e-05 19
end_path:out1:RootOutput 7.732e-06 2.10319e-05 8.7262e-05 1.6175e-05 1.66124e-05 19
end_path:out1:RootOutput(write) 5.29629 5.98014 7.21487 5.93271 0.381377 19
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5365.49 MB
Peak resident set size usage (VmHWM): 3434.06 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039353_0863_df-s05-d2_dw_0_20250916T091049_reco_stage1_20250916T105125_keepup.root
\tHists: np02vd_raw_run039353_0863_df-s05-d2_dw_0_20250916T091049_reco_stage1_20250916T105125_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039353_0863_df-s05-d2_dw_0_20250916T091049_reco_stage1_20250916T105125_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039353_0863_df-s05-d2_dw_0_20250916T091049_reco_stage1_20250916T105125_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": 1758019886.0,
"core.end_time": 1758019886.0,
"core.events": [
66530,
66534,
66538,
66542,
66546,
66550,
66554,
66558,
66562,
66566,
66570,
66574,
66578,
66582,
66586,
66590,
66594,
66598,
66602
],
"core.event_count": 19,
"core.first_event_number": 66530,
"core.last_event_number": 66602,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39353
],
"core.runs_subruns": [
3935300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039353_0863_df-s05-d2_dw_0_20250916T091049.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039353_0863_df-s05-d2_dw_0_20250916T091049_reco_stage1_20250916T105125_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": 1758019886.0,
"core.end_time": 1758019886.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39353
],
"core.runs_subruns": [
3935300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039353_0863_df-s05-d2_dw_0_20250916T091049.hdf5"
}
]
} 