Jobsub ID 48054.52@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
45.663] D [ aux ] <Resampler:resmp0> EOS at call=93
[09:12:45.663] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=93 anode=0
[09:12:45.664] D [ glue ] <FrameFanin:nfsp> EOS at call=93 with 8
[09:12:45.664] D [ glue ] frame sink sees EOS
[09:12:45.664] D [ pgraph ] <Pgrapher:> graph execution complete
[09:12:45.664] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 18.01 sec
[09:12:45.664] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 17.72 sec
[09:12:45.664] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 15.07 sec
[09:12:45.664] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.21 sec
[09:12:45.664] I [ timer ] Timer: WireCell::Aux::Resampler : 1.8 sec
[09:12:45.664] I [ timer ] Timer: WireCell::Aux::Resampler : 1.79 sec
[09:12:45.664] I [ timer ] Timer: WireCell::Aux::Resampler : 1.76 sec
[09:12:45.664] I [ timer ] Timer: WireCell::Aux::Resampler : 1.57 sec
[09:12:45.664] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[09:12:45.664] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[09:12:45.664] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[09:12:45.664] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:12:45.664] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:12:45.664] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:12:45.664] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:12:45.664] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:12:45.664] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[09:12:45.664] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:12:45.664] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:12:45.664] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:12:45.664] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:12:45.664] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[09:12:45.664] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[09:12:45.664] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[09:12:45.664] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:12:45.664] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[09:12:45.664] I [ timer ] Timer: Total node execution : 71.95999923162162 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 17516 traces tagged "gauss"
FrameSaver: q=2.05658e+06 n=369943 tag=gauss
wclsFrameSaver: saving 21588 traces tagged "wiener"
FrameSaver: q=2.15957e+06 n=356367 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 1590 XUs and 1477 XVs -> 46 XUVs
C:0 T:1 1060 XUs and 1047 XVs -> 28 XUVs
C:0 T:2 816 XUs and 1194 XVs -> 23 XUVs
C:0 T:3 852 XUs and 1056 XVs -> 37 XUVs
C:0 T:4 164 XUs and 236 XVs -> 18 XUVs
C:0 T:5 1199 XUs and 1384 XVs -> 79 XUVs
C:0 T:6 91 XUs and 116 XVs -> 5 XUVs
C:0 T:7 559 XUs and 440 XVs -> 34 XUVs
270 XUVs total
223 collection wire objects
270 potential space points
Neighbour search...
2112 tests to find 1138 neighbours
Iterating with no regularization...
Begin: 3.29208e+07
0 3.15113e+07
1 3.15052e+07
Now with regularization...
Begin: 3.09765e+07
0 3.09762e+07
18-Sep-2025 09:13:14 BST Closed output file "np02vd_raw_run039433_0294_df-s05-d4_dw_0_20250918T032833_reco_stage1_20250918T081314_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 85.5808 306.819 6549.41 123.045 949.71 47
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 8.5878e-05 0.000116628 0.000265417 0.00010588 3.20244e-05 47
produce:tpcrawdecoder:PDVDTPCReader 11.6253 13.6805 26.917 12.7261 2.61564 47
produce:triggerrawdecoder:PDVDTriggerReader4 0.29984 0.307936 0.357952 0.303426 0.0106117 47
produce:pdvddaphne:DAPHNEReaderPDVD 5.57634 6.51206 7.36983 6.50916 0.425146 47
produce:ophit:OpHitFinder 0.0475353 0.0607865 0.0855311 0.0609093 0.00636471 47
produce:opflash:OpFlashFinderVerticalDrift 0.00609755 0.0165794 0.0342211 0.0168534 0.0057047 47
produce:wclsdatavd:WireCellToolkit 50.1445 68.3565 150.409 60.4219 19.6292 47
produce:gaushit:GausHitFinder 0.599661 1.16976 3.99742 1.04623 0.562595 47
produce:nhitsfilter:NumberOfHitsFilter 0.000112109 0.00022118 0.000714574 0.000190831 0.000109902 47
produce:reco3d:SpacePointSolver 2.34298 8.64193 52.2373 7.01393 7.67675 47
produce:hitpdune:DisambigFromSpacePoints 0.0336297 0.223857 2.66714 0.113799 0.41308 47
produce:pandora:StandardPandora 6.72751 203.253 6301.48 22.5993 927.427 47
produce:pandoraTrack:LArPandoraTrackCreation 0.163928 0.821343 9.04283 0.489618 1.32329 47
produce:pandoraGnocalo:GnocchiCalorimetry 0.00767837 0.0293566 0.121713 0.0259915 0.0168316 47
[art]:TriggerResults:TriggerResultInserter 2.0489e-05 3.61307e-05 8.1028e-05 3.4198e-05 1.08905e-05 47
end_path:out1:RootOutput 4.205e-06 8.12589e-06 2.5125e-05 7.997e-06 2.97933e-06 47
end_path:out1:RootOutput(write) 2.0545 3.71711 6.18842 3.57015 0.74609 47
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 6036.43 MB
Peak resident set size usage (VmHWM): 4137.34 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0294_df-s05-d4_dw_0_20250918T032833_reco_stage1_20250918T081314_keepup.root
\tHists: np02vd_raw_run039433_0294_df-s05-d4_dw_0_20250918T032833_reco_stage1_20250918T081315_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0294_df-s05-d4_dw_0_20250918T032833_reco_stage1_20250918T081314_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0294_df-s05-d4_dw_0_20250918T032833_reco_stage1_20250918T081314_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": 1758183196.0,
"core.end_time": 1758183196.0,
"core.events": [
84292,
84298,
84304,
84310,
84316,
84322,
84328,
84334,
84340,
84346,
84352,
84358,
84364,
84370,
84376,
84382,
84388,
84394,
84400,
84406,
84412,
84418,
84424,
84430,
84436,
84442,
84448,
84454,
84460,
84466,
84472,
84478,
84484,
84490,
84496,
84502,
84508,
84514,
84520,
84526,
84532,
84538,
84544,
84550,
84556,
84562,
84568
],
"core.event_count": 47,
"core.first_event_number": 84292,
"core.last_event_number": 84568,
"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_0294_df-s05-d4_dw_0_20250918T032833.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0294_df-s05-d4_dw_0_20250918T032833_reco_stage1_20250918T081315_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": 1758183196.0,
"core.end_time": 1758183196.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_0294_df-s05-d4_dw_0_20250918T032833.hdf5"
}
]
}