Jobsub ID 48913.3@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
79 anode=1
[21:03:53.894] D [ glue ] <ChannelSelector:chsel0> see EOS at call=39
[21:03:53.894] D [ aux ] <Resampler:resmp0> EOS at call=79
[21:03:53.894] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=79 anode=0
[21:03:53.894] D [ glue ] <FrameFanin:nfsp> EOS at call=79 with 8
[21:03:53.894] D [ glue ] frame sink sees EOS
[21:03:53.894] D [ pgraph ] <Pgrapher:> graph execution complete
[21:03:53.894] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 15.21 sec
[21:03:53.894] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.16 sec
[21:03:53.894] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.97 sec
[21:03:53.894] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.43 sec
[21:03:53.894] I [ timer ] Timer: WireCell::Aux::Resampler : 0.26 sec
[21:03:53.894] I [ timer ] Timer: WireCell::Aux::Resampler : 0.22 sec
[21:03:53.894] I [ timer ] Timer: WireCell::Aux::Resampler : 0.2 sec
[21:03:53.895] I [ timer ] Timer: WireCell::Aux::Resampler : 0.19 sec
[21:03:53.895] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[21:03:53.895] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[21:03:53.895] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[21:03:53.895] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[21:03:53.895] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[21:03:53.895] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:03:53.895] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[21:03:53.895] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:03:53.895] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:03:53.895] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[21:03:53.895] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:03:53.895] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[21:03:53.895] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:03:53.895] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[21:03:53.895] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:03:53.895] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[21:03:53.895] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[21:03:53.895] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[21:03:53.895] I [ timer ] Timer: Total node execution : 39.669999493286014 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 28307 traces tagged "gauss"
FrameSaver: q=1.21517e+07 n=920850 tag=gauss
wclsFrameSaver: saving 35027 traces tagged "wiener"
FrameSaver: q=1.26308e+07 n=900286 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 912 XUs and 685 XVs -> 49 XUVs
C:0 T:1 272 XUs and 320 XVs -> 5 XUVs
C:0 T:2 1365 XUs and 713 XVs -> 28 XUVs
C:0 T:3 3512 XUs and 6856 XVs -> 299 XUVs
C:0 T:4 2124 XUs and 3325 XVs -> 66 XUVs
C:0 T:5 2157 XUs and 2136 XVs -> 87 XUVs
C:0 T:6 10375 XUs and 21839 XVs -> 800 XUVs
C:0 T:7 1192 XUs and 1030 XVs -> 40 XUVs
1374 XUVs total
882 collection wire objects
1374 potential space points
Neighbour search...
24512 tests to find 5574 neighbours
Iterating with no regularization...
Begin: 6.21055e+10
0 5.79924e+10
1 5.75377e+10
2 5.75362e+10
Now with regularization...
Begin: 5.68678e+10
0 5.6867e+10
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Sep-2025 21:05:13 CEST Closed output file "np02vd_raw_run039499_0000_df-s05-d4_dw_0_20250918T174250_reco_stage1_20250918T190513_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 56.3135 84.4086 148.904 77.8698 22.0976 40
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 5.9141e-05 8.35405e-05 0.000184345 7.8507e-05 1.91575e-05 40
produce:tpcrawdecoder:PDVDTPCReader 9.27905 9.95121 12.7418 9.65864 0.727509 40
produce:triggerrawdecoder:PDVDTriggerReader4 0.571786 0.577942 0.592727 0.576243 0.00529915 40
produce:pdvddaphne:DAPHNEReaderPDVD 2.4521 3.08853 3.80399 3.084 0.318796 40
produce:ophit:OpHitFinder 0.0303448 0.043611 0.0617826 0.0441301 0.00658374 40
produce:opflash:OpFlashFinderVerticalDrift 0.00693523 0.0130268 0.0369476 0.0117057 0.00521414 40
produce:wclsdatavd:WireCellToolkit 26.2232 37.9018 58.7587 35.4358 8.24877 40
produce:gaushit:GausHitFinder 0.353492 0.681187 1.1505 0.634785 0.198875 40
produce:nhitsfilter:NumberOfHitsFilter 6.3442e-05 0.000175229 0.000359141 0.000162675 7.26935e-05 40
produce:reco3d:SpacePointSolver 1.97232 5.96308 9.95857 5.40158 2.05529 40
produce:hitpdune:DisambigFromSpacePoints 0.0160478 0.0773761 0.196134 0.0637477 0.0377691 40
produce:pandora:StandardPandora 4.00107 23.2553 78.7906 17.5816 15.789 40
produce:pandoraTrack:LArPandoraTrackCreation 0.106354 0.313117 0.987001 0.292979 0.152294 40
produce:pandoraGnocalo:GnocchiCalorimetry 0.00877195 0.0156328 0.0376724 0.0146758 0.00504682 40
[art]:TriggerResults:TriggerResultInserter 1.288e-05 2.17398e-05 6.5272e-05 1.794e-05 1.02346e-05 40
end_path:out1:RootOutput 3.1e-06 4.5044e-06 1.562e-05 4.02e-06 1.88005e-06 40
end_path:out1:RootOutput(write) 2.05187 2.50681 4.28904 2.45806 0.406955 40
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4664.65 MB
Peak resident set size usage (VmHWM): 2742.08 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0000_df-s05-d4_dw_0_20250918T174250_reco_stage1_20250918T190513_keepup.root
\tHists: np02vd_raw_run039499_0000_df-s05-d4_dw_0_20250918T174250_reco_stage1_20250918T190513_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0000_df-s05-d4_dw_0_20250918T174250_reco_stage1_20250918T190513_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0000_df-s05-d4_dw_0_20250918T174250_reco_stage1_20250918T190513_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": 1758222313.0,
"core.end_time": 1758222313.0,
"core.events": [
4,
10,
16,
22,
28,
34,
40,
46,
52,
58,
64,
70,
76,
82,
88,
94,
100,
106,
112,
118,
124,
130,
136,
142,
148,
154,
160,
166,
172,
178,
184,
190,
196,
202,
208,
214,
220,
226,
232,
238
],
"core.event_count": 40,
"core.first_event_number": 4,
"core.last_event_number": 238,
"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_0000_df-s05-d4_dw_0_20250918T174250.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0000_df-s05-d4_dw_0_20250918T174250_reco_stage1_20250918T190513_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": 1758222313.0,
"core.end_time": 1758222313.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_0000_df-s05-d4_dw_0_20250918T174250.hdf5"
}
]
} 