Jobsub ID 49243.10@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
pler:resmp0> EOS at call=81
[04:36:57.467] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=81 anode=0
[04:36:57.467] D [ glue ] <FrameFanin:nfsp> EOS at call=81 with 8
[04:36:57.467] D [ glue ] frame sink sees EOS
[04:36:57.467] D [ pgraph ] <Pgrapher:> graph execution complete
[04:36:57.467] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.25 sec
[04:36:57.467] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.56 sec
[04:36:57.467] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.41 sec
[04:36:57.467] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.75 sec
[04:36:57.467] I [ timer ] Timer: WireCell::Aux::Resampler : 0.3 sec
[04:36:57.467] I [ timer ] Timer: WireCell::Aux::Resampler : 0.29 sec
[04:36:57.467] I [ timer ] Timer: WireCell::Aux::Resampler : 0.29 sec
[04:36:57.467] I [ timer ] Timer: WireCell::Aux::Resampler : 0.28 sec
[04:36:57.467] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[04:36:57.467] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[04:36:57.467] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[04:36:57.467] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[04:36:57.467] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[04:36:57.467] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[04:36:57.467] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[04:36:57.467] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[04:36:57.467] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[04:36:57.467] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[04:36:57.467] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[04:36:57.467] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[04:36:57.467] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[04:36:57.467] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[04:36:57.467] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[04:36:57.467] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[04:36:57.467] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[04:36:57.467] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[04:36:57.467] I [ timer ] Timer: Total node execution : 31.169999785721302 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 22613 traces tagged "gauss"
FrameSaver: q=3.91852e+06 n=527009 tag=gauss
wclsFrameSaver: saving 28992 traces tagged "wiener"
FrameSaver: q=4.22145e+06 n=504813 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 866 XUs and 704 XVs -> 67 XUVs
C:0 T:1 522 XUs and 670 XVs -> 38 XUVs
C:0 T:2 1550 XUs and 1354 XVs -> 75 XUVs
C:0 T:3 934 XUs and 1232 XVs -> 27 XUVs
C:0 T:4 2987 XUs and 2379 XVs -> 128 XUVs
C:0 T:5 6413 XUs and 5772 XVs -> 454 XUVs
C:0 T:6 307 XUs and 221 XVs -> 17 XUVs
C:0 T:7 11601 XUs and 11787 XVs -> 953 XUVs
1759 XUVs total
1102 collection wire objects
1759 potential space points
Neighbour search...
75859 tests to find 18876 neighbours
Iterating with no regularization...
Begin: 2.02033e+09
0 1.85795e+09
1 1.85101e+09
2 1.85093e+09
Now with regularization...
Begin: 1.8337e+09
0 1.83367e+09
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
19-Sep-2025 04:37:36 BST Closed output file "np02vd_raw_run039499_0158_df-s05-d3_dw_0_20250918T230006_reco_stage1_20250919T033736_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 50.6939 108.397 841.446 75.3624 125.85 41
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 7.3809e-05 0.000133705 0.00027208 0.000118602 4.11462e-05 41
produce:tpcrawdecoder:PDVDTPCReader 6.11169 6.95308 15.011 6.60249 1.346 41
produce:triggerrawdecoder:PDVDTriggerReader4 0.302068 0.309306 0.356072 0.306231 0.00902735 41
produce:pdvddaphne:DAPHNEReaderPDVD 2.84996 3.28453 3.57224 3.29823 0.159159 41
produce:ophit:OpHitFinder 0.0398926 0.0545905 0.0692137 0.0556133 0.00638238 41
produce:opflash:OpFlashFinderVerticalDrift 0.00629462 0.0133475 0.019712 0.0138045 0.00317476 41
produce:wclsdatavd:WireCellToolkit 28.9445 39.0278 77.2336 33.1538 12.8131 41
produce:gaushit:GausHitFinder 0.269188 0.7608 2.0687 0.715023 0.308865 41
produce:nhitsfilter:NumberOfHitsFilter 9.1591e-05 0.000190885 0.000601728 0.00017571 8.45743e-05 41
produce:reco3d:SpacePointSolver 2.19406 7.05756 28.8887 6.52341 4.59149 41
produce:hitpdune:DisambigFromSpacePoints 0.0306111 0.118505 0.858898 0.076573 0.131822 41
produce:pandora:StandardPandora 5.6768 47.2957 719.538 20.3183 112.402 41
produce:pandoraTrack:LArPandoraTrackCreation 0.110655 0.434463 3.62339 0.352222 0.538331 41
produce:pandoraGnocalo:GnocchiCalorimetry 0.00735261 0.0192089 0.0366656 0.0185946 0.00657313 41
[art]:TriggerResults:TriggerResultInserter 1.6231e-05 3.05966e-05 0.000132188 2.6801e-05 1.88915e-05 41
end_path:out1:RootOutput 4.869e-06 1.01346e-05 4.9923e-05 9.598e-06 6.52563e-06 41
end_path:out1:RootOutput(write) 2.55837 3.04954 4.45929 2.95625 0.396875 41
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4563.03 MB
Peak resident set size usage (VmHWM): 2596.89 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0158_df-s05-d3_dw_0_20250918T230006_reco_stage1_20250919T033736_keepup.root
\tHists: np02vd_raw_run039499_0158_df-s05-d3_dw_0_20250918T230006_reco_stage1_20250919T033736_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0158_df-s05-d3_dw_0_20250918T230006_reco_stage1_20250919T033736_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0158_df-s05-d3_dw_0_20250918T230006_reco_stage1_20250919T033736_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": 1758253057.0,
"core.end_time": 1758253057.0,
"core.events": [
38637,
38643,
38649,
38655,
38661,
38667,
38673,
38679,
38685,
38691,
38697,
38703,
38709,
38715,
38721,
38727,
38733,
38739,
38745,
38751,
38757,
38763,
38769,
38775,
38781,
38787,
38793,
38799,
38805,
38811,
38817,
38823,
38829,
38835,
38841,
38847,
38853,
38859,
38865,
38871,
38877
],
"core.event_count": 41,
"core.first_event_number": 38637,
"core.last_event_number": 38877,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39499
],
"core.runs_subruns": [
3949900001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039499_0158_df-s05-d3_dw_0_20250918T230006.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0158_df-s05-d3_dw_0_20250918T230006_reco_stage1_20250919T033736_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": 1758253057.0,
"core.end_time": 1758253057.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39499
],
"core.runs_subruns": [
3949900001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039499_0158_df-s05-d3_dw_0_20250918T230006.hdf5"
}
]
}