Jobsub ID 40360.146@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
el0> see EOS at call=18
[10:39:26.939] D [ aux ] <Resampler:resmp0> EOS at call=37
[10:39:26.939] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=37 anode=0
[10:39:26.939] D [ glue ] <FrameFanin:nfsp> EOS at call=37 with 8
[10:39:26.939] D [ glue ] frame sink sees EOS
[10:39:26.939] D [ pgraph ] <Pgrapher:> graph execution complete
[10:39:26.939] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.64 sec
[10:39:26.939] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.16 sec
[10:39:26.939] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.95 sec
[10:39:26.939] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.49 sec
[10:39:26.939] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.46 sec
[10:39:26.939] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.98 sec
[10:39:26.939] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.83 sec
[10:39:26.939] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.78 sec
[10:39:26.939] I [ timer ] Timer: WireCell::Aux::Resampler : 0.88 sec
[10:39:26.939] I [ timer ] Timer: WireCell::Aux::Resampler : 0.72 sec
[10:39:26.939] I [ timer ] Timer: WireCell::Aux::Resampler : 0.65 sec
[10:39:26.939] I [ timer ] Timer: WireCell::Aux::Resampler : 0.64 sec
[10:39:26.939] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[10:39:26.939] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[10:39:26.939] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[10:39:26.939] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:39:26.939] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:39:26.939] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:39:26.939] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:39:26.939] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[10:39:26.939] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:39:26.939] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:39:26.939] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[10:39:26.939] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[10:39:26.939] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[10:39:26.939] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[10:39:26.939] I [ timer ] Timer: Total node execution : 58.20999994687736 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 42888 traces tagged "gauss"
FrameSaver: q=6.16412e+06 n=833445 tag=gauss
wclsFrameSaver: saving 50719 traces tagged "wiener"
FrameSaver: q=6.45179e+06 n=807789 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 441 XUs and 463 XVs -> 15 XUVs
C:0 T:1 357 XUs and 375 XVs -> 25 XUVs
C:0 T:2 407 XUs and 491 XVs -> 27 XUVs
C:0 T:3 60 XUs and 78 XVs -> 2 XUVs
C:0 T:4 492 XUs and 646 XVs -> 20 XUVs
C:0 T:5 1505 XUs and 1543 XVs -> 40 XUVs
C:0 T:6 543 XUs and 669 XVs -> 20 XUVs
C:0 T:7 747 XUs and 818 XVs -> 34 XUVs
C:0 T:8 938 XUs and 978 XVs -> 58 XUVs
C:0 T:9 583 XUs and 772 XVs -> 50 XUVs
C:0 T:10 431 XUs and 386 XVs -> 31 XUVs
C:0 T:11 711 XUs and 880 XVs -> 77 XUVs
C:0 T:12 1546 XUs and 1809 XVs -> 141 XUVs
C:0 T:13 1170 XUs and 1503 XVs -> 64 XUVs
C:0 T:14 1324 XUs and 1349 XVs -> 122 XUVs
C:0 T:15 3380 XUs and 3296 XVs -> 174 XUVs
900 XUVs total
795 collection wire objects
900 potential space points
Neighbour search...
4852 tests to find 2416 neighbours
Iterating with no regularization...
Begin: 1.92188e+08
0 1.87956e+08
1 1.87889e+08
Now with regularization...
Begin: 1.84449e+08
0 1.84449e+08
16-Sep-2025 10:40:15 CEST Closed output file "np02vd_raw_run039353_0779_df-s05-d3_dw_0_20250916T072321_reco_stage1_20250916T084015_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 110.638 153.44 235.95 143.207 38.0238 19
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 7.2761e-05 9.77904e-05 0.000193683 8.4921e-05 2.97297e-05 19
produce:tpcrawdecoder:PDVDTPCReader 6.8576 7.10464 7.38715 7.10187 0.167446 19
produce:triggerrawdecoder:PDVDTriggerReader4 0.00597534 0.0100058 0.0339014 0.00785002 0.00615724 19
produce:pdvddaphne:DAPHNEReaderPDVD 0.000289775 0.000340933 0.000835752 0.000311874 0.000118362 19
produce:ophit:OpHitFinder 0.000145042 0.000258087 0.00115103 0.000186473 0.00023402 19
produce:opflash:OpFlashFinderVerticalDrift 5.2001e-05 8.58628e-05 0.000437446 6.4741e-05 8.35675e-05 19
produce:wclsdatavd:WireCellToolkit 57.4717 69.4439 86.3415 65.7112 9.75292 19
produce:gaushit:GausHitFinder 0.744851 1.33764 2.07982 1.3432 0.382613 19
produce:nhitsfilter:NumberOfHitsFilter 0.000204683 0.000325459 0.000609289 0.000329515 9.72177e-05 19
produce:reco3d:SpacePointSolver 7.82148 14.1118 22.615 12.7519 4.00349 19
produce:hitpdune:DisambigFromSpacePoints 0.0942457 0.194905 0.338204 0.169833 0.0678723 19
produce:pandora:StandardPandora 21.4632 54.9034 127.724 48.3003 29.8354 19
produce:pandoraTrack:LArPandoraTrackCreation 0.434283 1.01823 1.8804 1.00211 0.374089 19
produce:pandoraGnocalo:GnocchiCalorimetry 0.0176303 0.0329964 0.0613984 0.0337461 0.0112404 19
[art]:TriggerResults:TriggerResultInserter 1.883e-05 3.35484e-05 7.2021e-05 3.086e-05 1.34558e-05 19
end_path:out1:RootOutput 4.36e-06 1.01423e-05 3.3921e-05 8.98e-06 6.29559e-06 19
end_path:out1:RootOutput(write) 3.80529 5.24781 6.42313 5.51993 0.870453 19
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4695.73 MB
Peak resident set size usage (VmHWM): 2743.01 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039353_0779_df-s05-d3_dw_0_20250916T072321_reco_stage1_20250916T084015_keepup.root
\tHists: np02vd_raw_run039353_0779_df-s05-d3_dw_0_20250916T072321_reco_stage1_20250916T084015_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039353_0779_df-s05-d3_dw_0_20250916T072321_reco_stage1_20250916T084015_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039353_0779_df-s05-d3_dw_0_20250916T072321_reco_stage1_20250916T084015_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": 1758012015.0,
"core.end_time": 1758012015.0,
"core.events": [
59911,
59915,
59919,
59923,
59927,
59931,
59935,
59939,
59943,
59947,
59951,
59955,
59959,
59963,
59967,
59971,
59975,
59979,
59983
],
"core.event_count": 19,
"core.first_event_number": 59911,
"core.last_event_number": 59983,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39353
],
"core.runs_subruns": [
3935300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039353_0779_df-s05-d3_dw_0_20250916T072321.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039353_0779_df-s05-d3_dw_0_20250916T072321_reco_stage1_20250916T084015_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": 1758012015.0,
"core.end_time": 1758012015.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39353
],
"core.runs_subruns": [
3935300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039353_0779_df-s05-d3_dw_0_20250916T072321.hdf5"
}
]
}