Jobsub ID 41739.120@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
oc ] <OmnibusSigProc:anode0sigproc0> EOS at call=95 anode=0
[11:25:00.831] D [ glue ] <FrameFanin:nfsp> EOS at call=95 with 8
[11:25:00.831] D [ glue ] frame sink sees EOS
[11:25:00.831] D [ pgraph ] <Pgrapher:> graph execution complete
[11:25:00.831] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.88 sec
[11:25:00.831] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.48 sec
[11:25:00.831] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.44 sec
[11:25:00.831] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.62 sec
[11:25:00.831] I [ timer ] Timer: WireCell::Aux::Resampler : 0.57 sec
[11:25:00.831] I [ timer ] Timer: WireCell::Aux::Resampler : 0.55 sec
[11:25:00.831] I [ timer ] Timer: WireCell::Aux::Resampler : 0.53 sec
[11:25:00.831] I [ timer ] Timer: WireCell::Aux::Resampler : 0.42 sec
[11:25:00.831] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[11:25:00.831] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[11:25:00.831] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[11:25:00.831] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[11:25:00.831] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:25:00.831] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:25:00.831] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[11:25:00.831] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:25:00.831] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:25:00.831] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[11:25:00.831] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:25:00.831] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[11:25:00.831] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:25:00.831] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:25:00.832] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[11:25:00.832] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[11:25:00.832] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[11:25:00.832] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[11:25:00.832] I [ timer ] Timer: Total node execution : 40.5199990849942 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 16544 traces tagged "gauss"
FrameSaver: q=2.69358e+06 n=382949 tag=gauss
wclsFrameSaver: saving 21348 traces tagged "wiener"
FrameSaver: q=2.96526e+06 n=370598 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 1293 XUs and 1635 XVs -> 113 XUVs
C:0 T:1 1891 XUs and 2356 XVs -> 201 XUVs
C:0 T:2 844 XUs and 1694 XVs -> 23 XUVs
C:0 T:3 14258 XUs and 25315 XVs -> 1163 XUVs
C:0 T:4 72 XUs and 75 XVs -> 1 XUVs
C:0 T:5 67 XUs and 131 XVs -> 2 XUVs
C:0 T:6 179 XUs and 218 XVs -> 16 XUVs
C:0 T:7 660 XUs and 1002 XVs -> 32 XUVs
1551 XUVs total
896 collection wire objects
1551 potential space points
Neighbour search...
42497 tests to find 11472 neighbours
Iterating with no regularization...
Begin: 2.4262e+09
0 2.3257e+09
1 2.31256e+09
2 2.31245e+09
Now with regularization...
Begin: 2.30073e+09
0 2.30071e+09
18-Sep-2025 11:25:36 BST Closed output file "np02vd_raw_run039433_0393_df-s05-d5_dw_0_20250918T072842_reco_stage1_20250918T102536_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 97.8898 158.295 563.294 128.902 81.8455 48
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 8.5892e-05 0.000104367 0.000337657 9.72335e-05 3.70522e-05 48
produce:tpcrawdecoder:PDVDTPCReader 27.4481 39.8543 75.4248 38.7953 8.321 48
produce:triggerrawdecoder:PDVDTriggerReader4 0.380449 0.455337 0.922621 0.417949 0.0992243 48
produce:pdvddaphne:DAPHNEReaderPDVD 6.7409 10.0193 15.0886 9.73966 1.82712 48
produce:ophit:OpHitFinder 0.0492772 0.0635639 0.0896926 0.0633793 0.00746275 48
produce:opflash:OpFlashFinderVerticalDrift 0.00492868 0.0147769 0.0304257 0.0147289 0.0045067 48
produce:wclsdatavd:WireCellToolkit 36.7165 51.7147 112.706 44.5252 14.9893 48
produce:gaushit:GausHitFinder 0.402052 0.995681 1.96312 0.914542 0.363625 48
produce:nhitsfilter:NumberOfHitsFilter 8.7615e-05 0.000244141 0.000593049 0.000227815 0.00011061 48
produce:reco3d:SpacePointSolver 2.82571 7.87558 22.579 6.77269 4.22196 48
produce:hitpdune:DisambigFromSpacePoints 0.0334106 0.123518 0.509242 0.0933583 0.10419 48
produce:pandora:StandardPandora 5.08654 43.0933 405.577 22.5046 69.1347 48
produce:pandoraTrack:LArPandoraTrackCreation 0.161752 0.49871 1.76396 0.382056 0.360157 48
produce:pandoraGnocalo:GnocchiCalorimetry 0.0126572 0.0251958 0.0532706 0.0235715 0.00890887 48
[art]:TriggerResults:TriggerResultInserter 2.2142e-05 3.38477e-05 0.000119846 2.88245e-05 1.56051e-05 48
end_path:out1:RootOutput 4.208e-06 5.92631e-06 3.2752e-05 5.4405e-06 3.95451e-06 48
end_path:out1:RootOutput(write) 2.97718 3.52762 4.86889 3.33263 0.431821 48
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5443.56 MB
Peak resident set size usage (VmHWM): 3494.53 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0393_df-s05-d5_dw_0_20250918T072842_reco_stage1_20250918T102536_keepup.root
\tHists: np02vd_raw_run039433_0393_df-s05-d5_dw_0_20250918T072842_reco_stage1_20250918T102537_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0393_df-s05-d5_dw_0_20250918T072842_reco_stage1_20250918T102536_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0393_df-s05-d5_dw_0_20250918T072842_reco_stage1_20250918T102536_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": 1758191138.0,
"core.end_time": 1758191138.0,
"core.events": [
112655,
112661,
112667,
112673,
112679,
112685,
112691,
112697,
112703,
112709,
112715,
112721,
112727,
112733,
112739,
112745,
112751,
112757,
112763,
112769,
112775,
112781,
112787,
112793,
112799,
112805,
112811,
112817,
112823,
112829,
112835,
112841,
112847,
112853,
112859,
112865,
112871,
112877,
112883,
112889,
112895,
112901,
112907,
112913,
112919,
112925,
112931,
112937
],
"core.event_count": 48,
"core.first_event_number": 112655,
"core.last_event_number": 112937,
"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_0393_df-s05-d5_dw_0_20250918T072842.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0393_df-s05-d5_dw_0_20250918T072842_reco_stage1_20250918T102537_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": 1758191138.0,
"core.end_time": 1758191138.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_0393_df-s05-d5_dw_0_20250918T072842.hdf5"
}
]
} 