Jobsub ID 46972.172@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
at call=35
[15:32:38.141] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=35 anode=0
[15:32:38.141] D [ glue ] <FrameFanin:nfsp> EOS at call=35 with 8
[15:32:38.141] D [ glue ] frame sink sees EOS
[15:32:38.141] D [ pgraph ] <Pgrapher:> graph execution complete
[15:32:38.141] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.1 sec
[15:32:38.141] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.09 sec
[15:32:38.141] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.79 sec
[15:32:38.141] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.66 sec
[15:32:38.141] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.28 sec
[15:32:38.141] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.08 sec
[15:32:38.141] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.91 sec
[15:32:38.141] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.72 sec
[15:32:38.141] I [ timer ] Timer: WireCell::Aux::Resampler : 0.7 sec
[15:32:38.141] I [ timer ] Timer: WireCell::Aux::Resampler : 0.7 sec
[15:32:38.141] I [ timer ] Timer: WireCell::Aux::Resampler : 0.7 sec
[15:32:38.141] I [ timer ] Timer: WireCell::Aux::Resampler : 0.69 sec
[15:32:38.141] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[15:32:38.141] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[15:32:38.141] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[15:32:38.141] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[15:32:38.141] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0.01 sec
[15:32:38.141] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:32:38.141] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:32:38.141] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:32:38.141] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:32:38.141] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[15:32:38.141] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:32:38.141] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:32:38.141] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[15:32:38.141] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[15:32:38.141] I [ timer ] Timer: Total node execution : 67.47000007517636 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 52577 traces tagged "gauss"
FrameSaver: q=9.68747e+06 n=1197582 tag=gauss
wclsFrameSaver: saving 65724 traces tagged "wiener"
FrameSaver: q=1.0432e+07 n=1147839 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 202 XUs and 149 XVs -> 9 XUVs
C:0 T:1 390 XUs and 714 XVs -> 20 XUVs
C:0 T:2 517 XUs and 734 XVs -> 41 XUVs
C:0 T:3 432 XUs and 518 XVs -> 25 XUVs
C:0 T:4 142 XUs and 151 XVs -> 7 XUVs
C:0 T:5 3004 XUs and 2452 XVs -> 131 XUVs
C:0 T:6 306 XUs and 363 XVs -> 17 XUVs
C:0 T:7 1694 XUs and 2071 XVs -> 63 XUVs
C:0 T:8 20090 XUs and 36265 XVs -> 6017 XUVs
C:0 T:9 9077 XUs and 12974 XVs -> 1785 XUVs
C:0 T:10 12675 XUs and 29128 XVs -> 3871 XUVs
C:0 T:11 8120 XUs and 25005 XVs -> 2952 XUVs
C:0 T:12 9110 XUs and 12751 XVs -> 1474 XUVs
C:0 T:13 1976 XUs and 1944 XVs -> 178 XUVs
C:0 T:14 1732 XUs and 1950 XVs -> 198 XUVs
C:0 T:15 4735 XUs and 4485 XVs -> 269 XUVs
17057 XUVs total
2373 collection wire objects
17057 potential space points
Neighbour search...
2217963 tests to find 959082 neighbours
Iterating with no regularization...
Begin: 7.64552e+08
0 6.67233e+08
1 6.5865e+08
2 6.57967e+08
3 6.57723e+08
Now with regularization...
Begin: 6.45788e+08
0 6.45524e+08
16-Sep-2025 15:34:18 BST Closed output file "np02vd_raw_run039275_0373_df-s03-d3_dw_0_20250902T030653_reco_stage1_20250916T143418_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 282.152 367.564 523.551 379.806 59.0141 18
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 7.91e-05 0.000121363 0.000301481 0.000101742 5.0887e-05 18
produce:tpcrawdecoder:PDVDTPCReader 104.475 149.816 187.964 149.874 24.2769 18
produce:triggerrawdecoder:PDVDTriggerReader4 0.0597049 0.0651923 0.0770303 0.0605971 0.00659157 18
produce:pdvddaphne:DAPHNEReaderPDVD 12.6363 17.5315 28.8573 15.9881 3.64262 18
produce:ophit:OpHitFinder 0.0470785 0.0553063 0.0646143 0.054571 0.00459541 18
produce:opflash:OpFlashFinderVerticalDrift 0.00819028 0.0121647 0.0150966 0.0124836 0.00177476 18
produce:wclsdatavd:WireCellToolkit 63.221 71.7947 84.3896 71.8909 5.41751 18
produce:gaushit:GausHitFinder 0.83609 1.47302 1.98768 1.43054 0.304328 18
produce:nhitsfilter:NumberOfHitsFilter 0.000692363 0.00117072 0.00193731 0.00110175 0.000377392 18
produce:reco3d:SpacePointSolver 10.6082 20.0586 27.6619 19.3524 4.80083 18
produce:hitpdune:DisambigFromSpacePoints 0.152749 0.339811 0.52384 0.319894 0.0964359 18
produce:pandora:StandardPandora 24.1128 98.6401 274.004 77.0016 58.1393 18
produce:pandoraTrack:LArPandoraTrackCreation 0.922109 2.55606 9.18295 1.79568 1.98399 18
produce:pandoraGnocalo:GnocchiCalorimetry 0.0257195 0.0420616 0.0886638 0.0381731 0.0149033 18
[art]:TriggerResults:TriggerResultInserter 1.9878e-05 4.17997e-05 9.8677e-05 3.3664e-05 2.02822e-05 18
end_path:out1:RootOutput 4.198e-06 1.37722e-05 3.8904e-05 9.9695e-06 8.77681e-06 18
end_path:out1:RootOutput(write) 4.743 5.09806 5.49993 5.07166 0.192411 18
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5145.92 MB
Peak resident set size usage (VmHWM): 3236.8 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039275_0373_df-s03-d3_dw_0_20250902T030653_reco_stage1_20250916T143418_keepup.root
\tHists: np02vd_raw_run039275_0373_df-s03-d3_dw_0_20250902T030653_reco_stage1_20250916T143419_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039275_0373_df-s03-d3_dw_0_20250902T030653_reco_stage1_20250916T143418_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039275_0373_df-s03-d3_dw_0_20250902T030653_reco_stage1_20250916T143418_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": 1758033260.0,
"core.end_time": 1758033260.0,
"core.events": [
134289,
134309,
134329,
134349,
134369,
134389,
134409,
134429,
134449,
134469,
134489,
134509,
134529,
134549,
134569,
134589,
134609,
134629
],
"core.event_count": 18,
"core.first_event_number": 134289,
"core.last_event_number": 134629,
"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_0373_df-s03-d3_dw_0_20250902T030653.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039275_0373_df-s03-d3_dw_0_20250902T030653_reco_stage1_20250916T143419_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": 1758033260.0,
"core.end_time": 1758033260.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_0373_df-s03-d3_dw_0_20250902T030653.hdf5"
}
]
} 