Jobsub ID 41655.26@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
<FrameFanin:nfsp> EOS at call=91 with 8
[08:27:58.041] D [ glue ] frame sink sees EOS
[08:27:58.041] D [ pgraph ] <Pgrapher:> graph execution complete
[08:27:58.041] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.95 sec
[08:27:58.041] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.59 sec
[08:27:58.041] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.46 sec
[08:27:58.041] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.38 sec
[08:27:58.041] I [ timer ] Timer: WireCell::Aux::Resampler : 0.52 sec
[08:27:58.041] I [ timer ] Timer: WireCell::Aux::Resampler : 0.5 sec
[08:27:58.041] I [ timer ] Timer: WireCell::Aux::Resampler : 0.5 sec
[08:27:58.041] I [ timer ] Timer: WireCell::Aux::Resampler : 0.49 sec
[08:27:58.041] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.04 sec
[08:27:58.041] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[08:27:58.041] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[08:27:58.041] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[08:27:58.042] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[08:27:58.042] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:27:58.042] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:27:58.042] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[08:27:58.042] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:27:58.042] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:27:58.042] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:27:58.042] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[08:27:58.042] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[08:27:58.042] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:27:58.042] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[08:27:58.042] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[08:27:58.042] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[08:27:58.042] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[08:27:58.042] I [ timer ] Timer: Total node execution : 40.46000010333955 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 24689 traces tagged "gauss"
FrameSaver: q=3.90316e+06 n=600684 tag=gauss
wclsFrameSaver: saving 31622 traces tagged "wiener"
FrameSaver: q=4.11388e+06 n=572534 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 1029 XUs and 967 XVs -> 34 XUVs
C:0 T:1 608 XUs and 668 XVs -> 23 XUVs
C:0 T:2 3131 XUs and 3191 XVs -> 133 XUVs
C:0 T:3 150 XUs and 161 XVs -> 8 XUVs
C:0 T:4 476 XUs and 595 XVs -> 20 XUVs
C:0 T:5 801 XUs and 896 XVs -> 41 XUVs
C:0 T:6 13908 XUs and 15473 XVs -> 824 XUVs
C:0 T:7 23195 XUs and 27811 XVs -> 1429 XUVs
2512 XUVs total
1627 collection wire objects
2512 potential space points
Neighbour search...
34010 tests to find 9916 neighbours
Iterating with no regularization...
Begin: 9.89141e+08
0 9.2375e+08
1 9.21351e+08
2 9.2133e+08
Now with regularization...
Begin: 9.1036e+08
0 9.10354e+08
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Sep-2025 08:29:17 BST Closed output file "np02vd_raw_run039433_0334_df-s05-d1_dw_0_20250918T050448_reco_stage1_20250918T072917_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 53.0482 110.844 354.743 97.412 57.7092 46
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 6.5828e-05 9.87513e-05 0.000273389 9.51435e-05 2.83505e-05 46
produce:tpcrawdecoder:PDVDTPCReader 6.24412 7.16765 9.51954 6.99995 0.737938 46
produce:triggerrawdecoder:PDVDTriggerReader4 0.280063 0.285218 0.324712 0.281946 0.00800735 46
produce:pdvddaphne:DAPHNEReaderPDVD 5.08703 5.48812 6.58155 5.46443 0.300958 46
produce:ophit:OpHitFinder 0.0453785 0.0642272 0.0766449 0.066465 0.00615693 46
produce:opflash:OpFlashFinderVerticalDrift 0.00088802 0.0167815 0.034815 0.0160144 0.00681545 46
produce:wclsdatavd:WireCellToolkit 33.311 50.9834 88.6492 50.8917 14.9696 46
produce:gaushit:GausHitFinder 0.345894 0.944416 1.75019 0.951317 0.295552 46
produce:nhitsfilter:NumberOfHitsFilter 0.000154563 0.000332925 0.000640713 0.000320599 0.000102382 46
produce:reco3d:SpacePointSolver 1.1684 6.78197 20.1164 6.47614 3.25005 46
produce:hitpdune:DisambigFromSpacePoints 0.0200005 0.140664 0.616984 0.109113 0.104915 46
produce:pandora:StandardPandora 2.93499 35.3069 258.021 22.4726 48.3653 46
produce:pandoraTrack:LArPandoraTrackCreation 0.115178 0.889625 4.44283 0.728516 0.796828 46
produce:pandoraGnocalo:GnocchiCalorimetry 0.010234 0.0255833 0.0496564 0.0250577 0.00922736 46
[art]:TriggerResults:TriggerResultInserter 2.422e-05 4.02382e-05 8.1267e-05 3.72915e-05 1.31434e-05 46
end_path:out1:RootOutput 3.72e-06 8.129e-06 2.7883e-05 7.5195e-06 3.40906e-06 46
end_path:out1:RootOutput(write) 2.06072 2.71684 3.92921 2.66609 0.425149 46
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5015.44 MB
Peak resident set size usage (VmHWM): 3131.09 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0334_df-s05-d1_dw_0_20250918T050448_reco_stage1_20250918T072917_keepup.root
\tHists: np02vd_raw_run039433_0334_df-s05-d1_dw_0_20250918T050448_reco_stage1_20250918T072919_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0334_df-s05-d1_dw_0_20250918T050448_reco_stage1_20250918T072917_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0334_df-s05-d1_dw_0_20250918T050448_reco_stage1_20250918T072917_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": 1758180559.0,
"core.end_time": 1758180559.0,
"core.events": [
95773,
95779,
95785,
95791,
95797,
95803,
95809,
95815,
95821,
95827,
95833,
95839,
95845,
95851,
95857,
95863,
95869,
95875,
95881,
95887,
95893,
95899,
95905,
95911,
95917,
95923,
95929,
95935,
95941,
95947,
95953,
95959,
95965,
95971,
95977,
95983,
95989,
95995,
96001,
96007,
96013,
96019,
96025,
96031,
96037,
96043
],
"core.event_count": 46,
"core.first_event_number": 95773,
"core.last_event_number": 96043,
"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_0334_df-s05-d1_dw_0_20250918T050448.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0334_df-s05-d1_dw_0_20250918T050448_reco_stage1_20250918T072919_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": 1758180559.0,
"core.end_time": 1758180559.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_0334_df-s05-d1_dw_0_20250918T050448.hdf5"
}
]
}