Jobsub ID 41739.53@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
ll=93
[11:23:05.391] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=93 anode=0
[11:23:05.391] D [ glue ] <FrameFanin:nfsp> EOS at call=93 with 8
[11:23:05.391] D [ glue ] frame sink sees EOS
[11:23:05.391] D [ pgraph ] <Pgrapher:> graph execution complete
[11:23:05.392] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 15.36 sec
[11:23:05.392] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.98 sec
[11:23:05.392] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.61 sec
[11:23:05.392] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.18 sec
[11:23:05.392] I [ timer ] Timer: WireCell::Aux::Resampler : 1.78 sec
[11:23:05.392] I [ timer ] Timer: WireCell::Aux::Resampler : 1.77 sec
[11:23:05.392] I [ timer ] Timer: WireCell::Aux::Resampler : 1.72 sec
[11:23:05.392] I [ timer ] Timer: WireCell::Aux::Resampler : 1.68 sec
[11:23:05.392] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[11:23:05.392] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[11:23:05.392] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[11:23:05.392] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[11:23:05.392] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[11:23:05.392] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0.01 sec
[11:23:05.392] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[11:23:05.392] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:23:05.392] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:23:05.392] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[11:23:05.392] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:23:05.392] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:23:05.392] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[11:23:05.392] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[11:23:05.392] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:23:05.392] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[11:23:05.392] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[11:23:05.392] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[11:23:05.392] I [ timer ] Timer: Total node execution : 66.1499990876764 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 14715 traces tagged "gauss"
FrameSaver: q=1.73825e+06 n=304839 tag=gauss
wclsFrameSaver: saving 18243 traces tagged "wiener"
FrameSaver: q=1.82316e+06 n=292219 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 235 XUs and 473 XVs -> 5 XUVs
C:0 T:1 228 XUs and 259 XVs -> 5 XUVs
C:0 T:2 416 XUs and 422 XVs -> 23 XUVs
C:0 T:3 154 XUs and 153 XVs -> 19 XUVs
C:0 T:4 425 XUs and 607 XVs -> 40 XUVs
C:0 T:5 833 XUs and 955 XVs -> 32 XUVs
C:0 T:6 1124 XUs and 1507 XVs -> 77 XUVs
C:0 T:7 712 XUs and 873 XVs -> 43 XUVs
244 XUVs total
210 collection wire objects
244 potential space points
Neighbour search...
1350 tests to find 788 neighbours
Iterating with no regularization...
Begin: 2.34953e+07
0 2.30283e+07
1 2.30277e+07
Now with regularization...
Begin: 2.2655e+07
0 2.2655e+07
18-Sep-2025 11:23:29 BST Closed output file "np02vd_raw_run039433_0381_df-s05-d3_dw_0_20250918T070041_reco_stage1_20250918T102329_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 118.565 190.039 797.009 161.701 113.894 47
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 9.161e-05 0.000206172 0.00208545 0.000151228 0.000283132 47
produce:tpcrawdecoder:PDVDTPCReader 27.322 44.7402 71.2862 40.0807 10.6836 47
produce:triggerrawdecoder:PDVDTriggerReader4 0.381304 0.445348 0.656688 0.443117 0.0646036 47
produce:pdvddaphne:DAPHNEReaderPDVD 9.15851 13.1988 19.1281 13.1225 2.12467 47
produce:ophit:OpHitFinder 0.0426544 0.0832728 0.14447 0.0806316 0.0174743 47
produce:opflash:OpFlashFinderVerticalDrift 0.00096801 0.0197656 0.0358384 0.019511 0.00703854 47
produce:wclsdatavd:WireCellToolkit 46.086 67.654 210.584 57.6029 26.3649 47
produce:gaushit:GausHitFinder 0.541222 1.2135 5.42827 1.12848 0.693656 47
produce:nhitsfilter:NumberOfHitsFilter 0.000196462 0.000325497 0.000877249 0.000304691 0.000112391 47
produce:reco3d:SpacePointSolver 3.10572 7.84555 26.6242 6.32165 4.29761 47
produce:hitpdune:DisambigFromSpacePoints 0.0259648 0.17257 0.754113 0.138368 0.140783 47
produce:pandora:StandardPandora 6.72708 49.7953 660.114 22.6053 100.299 47
produce:pandoraTrack:LArPandoraTrackCreation 0.137762 0.823809 2.80865 0.668246 0.560702 47
produce:pandoraGnocalo:GnocchiCalorimetry 0.00954468 0.0278772 0.0461836 0.0273309 0.00852524 47
[art]:TriggerResults:TriggerResultInserter 3.2801e-05 6.25056e-05 0.000144976 6.0052e-05 1.93402e-05 47
end_path:out1:RootOutput 4.541e-06 1.2493e-05 4.3589e-05 1.0904e-05 6.24692e-06 47
end_path:out1:RootOutput(write) 2.62032 3.97168 5.29728 3.98539 0.553675 47
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 7577.69 MB
Peak resident set size usage (VmHWM): 5668.63 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0381_df-s05-d3_dw_0_20250918T070041_reco_stage1_20250918T102329_keepup.root
\tHists: np02vd_raw_run039433_0381_df-s05-d3_dw_0_20250918T070041_reco_stage1_20250918T102331_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0381_df-s05-d3_dw_0_20250918T070041_reco_stage1_20250918T102329_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0381_df-s05-d3_dw_0_20250918T070041_reco_stage1_20250918T102329_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": 1758191012.0,
"core.end_time": 1758191012.0,
"core.events": [
109413,
109419,
109425,
109431,
109437,
109443,
109449,
109455,
109461,
109467,
109473,
109479,
109485,
109491,
109497,
109503,
109509,
109515,
109521,
109527,
109533,
109539,
109545,
109551,
109557,
109563,
109569,
109575,
109581,
109587,
109593,
109599,
109605,
109611,
109617,
109623,
109629,
109635,
109641,
109647,
109653,
109659,
109665,
109671,
109677,
109683,
109689
],
"core.event_count": 47,
"core.first_event_number": 109413,
"core.last_event_number": 109689,
"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_0381_df-s05-d3_dw_0_20250918T070041.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0381_df-s05-d3_dw_0_20250918T070041_reco_stage1_20250918T102331_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": 1758191012.0,
"core.end_time": 1758191012.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_0381_df-s05-d3_dw_0_20250918T070041.hdf5"
}
]
} 