Jobsub ID 46973.173@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
D [ glue ] frame sink sees EOS
[16:11:17.068] D [ pgraph ] <Pgrapher:> graph execution complete
[16:11:17.068] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 13.79 sec
[16:11:17.068] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.81 sec
[16:11:17.068] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.53 sec
[16:11:17.068] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.45 sec
[16:11:17.068] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.43 sec
[16:11:17.068] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.33 sec
[16:11:17.068] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.67 sec
[16:11:17.068] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.02 sec
[16:11:17.068] I [ timer ] Timer: WireCell::Aux::Resampler : 1.03 sec
[16:11:17.068] I [ timer ] Timer: WireCell::Aux::Resampler : 0.9 sec
[16:11:17.068] I [ timer ] Timer: WireCell::Aux::Resampler : 0.89 sec
[16:11:17.068] I [ timer ] Timer: WireCell::Aux::Resampler : 0.56 sec
[16:11:17.068] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.04 sec
[16:11:17.068] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[16:11:17.068] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[16:11:17.068] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[16:11:17.068] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:11:17.068] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:11:17.068] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:11:17.068] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:11:17.068] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:11:17.068] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[16:11:17.068] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:11:17.068] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[16:11:17.068] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[16:11:17.068] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[16:11:17.068] I [ timer ] Timer: Total node execution : 78.4900001436472 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 66219 traces tagged "gauss"
FrameSaver: q=1.18848e+07 n=1462100 tag=gauss
wclsFrameSaver: saving 82204 traces tagged "wiener"
FrameSaver: q=1.28463e+07 n=1401446 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 1473 XUs and 1423 XVs -> 62 XUVs
C:0 T:1 1076 XUs and 1201 XVs -> 78 XUVs
C:0 T:2 2374 XUs and 2800 XVs -> 93 XUVs
C:0 T:3 864 XUs and 1098 XVs -> 51 XUVs
C:0 T:4 126 XUs and 304 XVs -> 11 XUVs
C:0 T:5 2336 XUs and 2887 XVs -> 122 XUVs
C:0 T:6 492 XUs and 1031 XVs -> 12 XUVs
C:0 T:7 363 XUs and 492 XVs -> 30 XUVs
C:0 T:8 8212 XUs and 18571 XVs -> 2721 XUVs
C:0 T:9 14153 XUs and 18030 XVs -> 3692 XUVs
C:0 T:10 13782 XUs and 21534 XVs -> 3665 XUVs
C:0 T:11 32223 XUs and 58804 XVs -> 10969 XUVs
C:0 T:12 23247 XUs and 43568 XVs -> 8413 XUVs
C:0 T:13 12738 XUs and 24121 XVs -> 4247 XUVs
C:0 T:14 7925 XUs and 13473 XVs -> 2803 XUVs
C:0 T:15 1779 XUs and 1475 XVs -> 109 XUVs
37078 XUVs total
3173 collection wire objects
37078 potential space points
Neighbour search...
6615208 tests to find 2662086 neighbours
Iterating with no regularization...
Begin: 6.54186e+08
0 5.58764e+08
1 5.52462e+08
2 5.51138e+08
3 5.50647e+08
Now with regularization...
Begin: 5.36106e+08
0 5.35646e+08
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
16-Sep-2025 16:15:51 CEST Closed output file "np02vd_raw_run039275_0390_df-s04-d3_dw_0_20250902T032410_reco_stage1_20250916T141551_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 153.941 269.91 414.049 255.607 82.9572 18
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 6.9425e-05 0.00013715 0.000351484 0.000122196 6.12022e-05 18
produce:tpcrawdecoder:PDVDTPCReader 6.87899 7.51037 10.0304 7.35475 0.661017 18
produce:triggerrawdecoder:PDVDTriggerReader4 0.00622578 0.00678401 0.00809715 0.00672704 0.000446116 18
produce:pdvddaphne:DAPHNEReaderPDVD 3.39411 4.44112 5.13644 4.62382 0.483054 18
produce:ophit:OpHitFinder 0.0423743 0.066903 0.0865896 0.0664855 0.0128229 18
produce:opflash:OpFlashFinderVerticalDrift 0.00857585 0.0189774 0.0353339 0.0183549 0.0068638 18
produce:wclsdatavd:WireCellToolkit 67.0735 83.1761 96.7777 83.9098 7.78632 18
produce:gaushit:GausHitFinder 0.968899 1.97013 3.2601 1.91705 0.549138 18
produce:nhitsfilter:NumberOfHitsFilter 0.000315589 0.000945993 0.00206398 0.00097468 0.000433184 18
produce:reco3d:SpacePointSolver 13.3225 23.4594 34.7779 25.2441 6.22221 18
produce:hitpdune:DisambigFromSpacePoints 0.1839 0.446002 0.699288 0.463738 0.167109 18
produce:pandora:StandardPandora 43.8175 138.175 259.181 113.892 71.1902 18
produce:pandoraTrack:LArPandoraTrackCreation 0.9285 4.13081 10.0813 3.40399 2.42598 18
produce:pandoraGnocalo:GnocchiCalorimetry 0.0228771 0.0567198 0.0904365 0.0613921 0.017234 18
[art]:TriggerResults:TriggerResultInserter 3.1077e-05 9.04512e-05 0.000201646 8.7623e-05 3.72346e-05 18
end_path:out1:RootOutput 5.028e-06 1.99035e-05 6.3356e-05 1.6691e-05 1.20058e-05 18
end_path:out1:RootOutput(write) 4.70907 6.33028 7.13346 6.46051 0.606455 18
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5217.96 MB
Peak resident set size usage (VmHWM): 3269.28 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039275_0390_df-s04-d3_dw_0_20250902T032410_reco_stage1_20250916T141551_keepup.root
\tHists: np02vd_raw_run039275_0390_df-s04-d3_dw_0_20250902T032410_reco_stage1_20250916T141552_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039275_0390_df-s04-d3_dw_0_20250902T032410_reco_stage1_20250916T141551_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039275_0390_df-s04-d3_dw_0_20250902T032410_reco_stage1_20250916T141551_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": 1758032153.0,
"core.end_time": 1758032153.0,
"core.events": [
140413,
140433,
140453,
140473,
140493,
140513,
140533,
140553,
140573,
140593,
140613,
140633,
140653,
140673,
140693,
140713,
140733,
140753
],
"core.event_count": 18,
"core.first_event_number": 140413,
"core.last_event_number": 140753,
"core.data_stream": "physics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39275
],
"core.runs_subruns": [
3927500001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039275_0390_df-s04-d3_dw_0_20250902T032410.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039275_0390_df-s04-d3_dw_0_20250902T032410_reco_stage1_20250916T141552_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": 1758032153.0,
"core.end_time": 1758032153.0,
"core.data_stream": "physics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39275
],
"core.runs_subruns": [
3927500001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039275_0390_df-s04-d3_dw_0_20250902T032410.hdf5"
}
]
}