Jobsub ID 45997.43@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
[ aux ] <Resampler:resmp0> EOS at call=35
[20:11:37.532] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=35 anode=0
[20:11:37.532] D [ glue ] <FrameFanin:nfsp> EOS at call=35 with 8
[20:11:37.532] D [ glue ] frame sink sees EOS
[20:11:37.532] D [ pgraph ] <Pgrapher:> graph execution complete
[20:11:37.532] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.73 sec
[20:11:37.532] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.54 sec
[20:11:37.533] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.76 sec
[20:11:37.533] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.7 sec
[20:11:37.533] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.42 sec
[20:11:37.533] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.41 sec
[20:11:37.533] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.26 sec
[20:11:37.533] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.99 sec
[20:11:37.533] I [ timer ] Timer: WireCell::Aux::Resampler : 0.79 sec
[20:11:37.533] I [ timer ] Timer: WireCell::Aux::Resampler : 0.79 sec
[20:11:37.533] I [ timer ] Timer: WireCell::Aux::Resampler : 0.78 sec
[20:11:37.533] I [ timer ] Timer: WireCell::Aux::Resampler : 0.77 sec
[20:11:37.533] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[20:11:37.533] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[20:11:37.533] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:11:37.533] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:11:37.533] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:11:37.533] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:11:37.533] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[20:11:37.533] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:11:37.533] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:11:37.533] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:11:37.533] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[20:11:37.533] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[20:11:37.533] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[20:11:37.533] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[20:11:37.533] I [ timer ] Timer: Total node execution : 65.96999946050346 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 54405 traces tagged "gauss"
FrameSaver: q=9.31637e+06 n=1167054 tag=gauss
wclsFrameSaver: saving 67413 traces tagged "wiener"
FrameSaver: q=1.00516e+07 n=1114778 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 1229 XUs and 865 XVs -> 75 XUVs
C:0 T:1 1284 XUs and 1807 XVs -> 56 XUVs
C:0 T:2 511 XUs and 428 XVs -> 24 XUVs
C:0 T:3 2129 XUs and 2446 XVs -> 113 XUVs
C:0 T:4 1645 XUs and 1811 XVs -> 46 XUVs
C:0 T:5 90 XUs and 89 XVs -> 6 XUVs
C:0 T:6 1530 XUs and 1545 XVs -> 54 XUVs
C:0 T:7 363 XUs and 325 XVs -> 23 XUVs
C:0 T:8 20582 XUs and 40283 XVs -> 5302 XUVs
C:0 T:9 5916 XUs and 6167 XVs -> 563 XUVs
C:0 T:10 2514 XUs and 1610 XVs -> 129 XUVs
C:0 T:11 1639 XUs and 1535 XVs -> 104 XUVs
C:0 T:12 915 XUs and 1243 XVs -> 50 XUVs
C:0 T:13 1749 XUs and 2893 XVs -> 108 XUVs
C:0 T:14 7750 XUs and 8846 XVs -> 611 XUVs
C:0 T:15 3882 XUs and 5142 XVs -> 397 XUVs
7661 XUVs total
1917 collection wire objects
7661 potential space points
Neighbour search...
708185 tests to find 319624 neighbours
Iterating with no regularization...
Begin: 6.18476e+08
0 5.50421e+08
1 5.47556e+08
2 5.46985e+08
3 5.46735e+08
Now with regularization...
Begin: 5.33718e+08
0 5.33522e+08
13-Sep-2025 20:12:57 CEST Closed output file "np02vd_raw_run039275_0121_df-s03-d1_dw_0_20250901T184328_reco_stage1_20250913T181257_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 209.445 299.249 507.806 289.148 72.9654 18
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 6.6024e-05 8.02428e-05 0.000195237 7.28165e-05 2.83795e-05 18
produce:tpcrawdecoder:PDVDTPCReader 62.299 98.0767 139.327 96.7904 19.1621 18
produce:triggerrawdecoder:PDVDTriggerReader4 0.034867 0.0367025 0.0454225 0.0352422 0.0032958 18
produce:pdvddaphne:DAPHNEReaderPDVD 9.50542 14.3851 17.5722 14.7545 2.44659 18
produce:ophit:OpHitFinder 0.0508283 0.0783218 0.121972 0.0788454 0.0149247 18
produce:opflash:OpFlashFinderVerticalDrift 0.00860035 0.0189812 0.0263447 0.0184566 0.00506183 18
produce:wclsdatavd:WireCellToolkit 64.3983 72.7186 84.5214 72.2352 5.16301 18
produce:gaushit:GausHitFinder 0.996806 1.48064 2.1235 1.42149 0.292348 18
produce:nhitsfilter:NumberOfHitsFilter 0.00027692 0.000517111 0.00109163 0.000427954 0.000228057 18
produce:reco3d:SpacePointSolver 9.96815 17.8113 25.2378 17.0836 4.54397 18
produce:hitpdune:DisambigFromSpacePoints 0.12695 0.273464 0.443931 0.252959 0.087043 18
produce:pandora:StandardPandora 30.3186 88.033 258.016 60.1775 59.6111 18
produce:pandoraTrack:LArPandoraTrackCreation 0.587054 1.40898 3.18192 1.35368 0.586683 18
produce:pandoraGnocalo:GnocchiCalorimetry 0.0238913 0.0344288 0.0441902 0.0352437 0.00505877 18
[art]:TriggerResults:TriggerResultInserter 1.4898e-05 2.12443e-05 4.5295e-05 1.8039e-05 7.73119e-06 18
end_path:out1:RootOutput 2.976e-06 4.55361e-06 1.7563e-05 3.737e-06 3.17819e-06 18
end_path:out1:RootOutput(write) 4.46145 4.83116 5.12102 4.82821 0.17457 18
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5118.13 MB
Peak resident set size usage (VmHWM): 3235.49 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039275_0121_df-s03-d1_dw_0_20250901T184328_reco_stage1_20250913T181257_keepup.root
\tHists: np02vd_raw_run039275_0121_df-s03-d1_dw_0_20250901T184328_reco_stage1_20250913T181257_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039275_0121_df-s03-d1_dw_0_20250901T184328_reco_stage1_20250913T181257_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039275_0121_df-s03-d1_dw_0_20250901T184328_reco_stage1_20250913T181257_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": 1757787178.0,
"core.end_time": 1757787178.0,
"core.events": [
43567,
43587,
43607,
43627,
43647,
43667,
43687,
43707,
43727,
43747,
43767,
43787,
43807,
43827,
43847,
43867,
43887,
43907
],
"core.event_count": 18,
"core.first_event_number": 43567,
"core.last_event_number": 43907,
"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_0121_df-s03-d1_dw_0_20250901T184328.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039275_0121_df-s03-d1_dw_0_20250901T184328_reco_stage1_20250913T181257_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": 1757787178.0,
"core.end_time": 1757787178.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_0121_df-s03-d1_dw_0_20250901T184328.hdf5"
}
]
}