Jobsub ID 41596.25@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
0> EOS at call=97
[09:44:07.446] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=97 anode=0
[09:44:07.446] D [ glue ] <FrameFanin:nfsp> EOS at call=97 with 8
[09:44:07.446] D [ glue ] frame sink sees EOS
[09:44:07.446] D [ pgraph ] <Pgrapher:> graph execution complete
[09:44:07.446] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.96 sec
[09:44:07.446] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.43 sec
[09:44:07.446] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.41 sec
[09:44:07.446] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.37 sec
[09:44:07.446] I [ timer ] Timer: WireCell::Aux::Resampler : 0.38 sec
[09:44:07.446] I [ timer ] Timer: WireCell::Aux::Resampler : 0.38 sec
[09:44:07.446] I [ timer ] Timer: WireCell::Aux::Resampler : 0.37 sec
[09:44:07.446] I [ timer ] Timer: WireCell::Aux::Resampler : 0.36 sec
[09:44:07.446] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[09:44:07.446] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[09:44:07.446] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:44:07.446] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0 sec
[09:44:07.446] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:44:07.446] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:44:07.446] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:44:07.446] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:44:07.446] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[09:44:07.446] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:44:07.446] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:44:07.446] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:44:07.446] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:44:07.446] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[09:44:07.446] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:44:07.446] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[09:44:07.446] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[09:44:07.446] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[09:44:07.446] I [ timer ] Timer: Total node execution : 24.679999608546495 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 16655 traces tagged "gauss"
FrameSaver: q=2.72278e+06 n=349004 tag=gauss
wclsFrameSaver: saving 20932 traces tagged "wiener"
FrameSaver: q=2.93649e+06 n=332637 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 197 XUs and 166 XVs -> 8 XUVs
C:0 T:1 1916 XUs and 1718 XVs -> 133 XUVs
C:0 T:2 7670 XUs and 5697 XVs -> 540 XUVs
C:0 T:3 4969 XUs and 4018 XVs -> 279 XUVs
C:0 T:4 728 XUs and 1008 XVs -> 28 XUVs
C:0 T:5 4 XUs and 5 XVs -> 0 XUVs
C:0 T:6 364 XUs and 425 XVs -> 12 XUVs
C:0 T:7 179 XUs and 262 XVs -> 16 XUVs
1016 XUVs total
644 collection wire objects
1016 potential space points
Neighbour search...
25978 tests to find 7410 neighbours
Iterating with no regularization...
Begin: 1.10597e+09
0 1.00232e+09
1 9.99342e+08
2 9.99254e+08
Now with regularization...
Begin: 9.80039e+08
0 9.79996e+08
18-Sep-2025 09:44:22 CEST Closed output file "np02vd_raw_run039433_0304_df-s05-d3_dw_0_20250918T035404_reco_stage1_20250918T074422_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 40.3955 198.443 6525.78 55.4173 913.867 49
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 6.121e-05 0.000115985 0.00028763 0.00010129 5.11368e-05 49
produce:tpcrawdecoder:PDVDTPCReader 4.79985 5.09323 6.03281 5.02297 0.262097 49
produce:triggerrawdecoder:PDVDTriggerReader4 0.264975 0.269837 0.285044 0.268824 0.00382245 49
produce:pdvddaphne:DAPHNEReaderPDVD 2.81063 3.11542 3.90244 3.0832 0.224071 49
produce:ophit:OpHitFinder 0.033016 0.0518412 0.100966 0.0487968 0.0107612 49
produce:opflash:OpFlashFinderVerticalDrift 0.00368472 0.0100231 0.027688 0.00977056 0.00395942 49
produce:wclsdatavd:WireCellToolkit 22.2232 32.9735 117.929 27.2475 14.2415 49
produce:gaushit:GausHitFinder 0.266934 0.705527 4.99543 0.589894 0.665225 49
produce:nhitsfilter:NumberOfHitsFilter 7.3941e-05 0.000151134 0.00036506 0.0001355 5.58877e-05 49
produce:reco3d:SpacePointSolver 1.43879 5.39591 40.8284 4.37764 5.54299 49
produce:hitpdune:DisambigFromSpacePoints 0.0227136 0.080021 0.774484 0.0543938 0.108694 49
produce:pandora:StandardPandora 3.4899 147.799 6415.78 11.4169 904.986 49
produce:pandoraTrack:LArPandoraTrackCreation 0.0749428 0.290791 3.13786 0.216829 0.424667 49
produce:pandoraGnocalo:GnocchiCalorimetry 0.00870672 0.0170894 0.109888 0.0145992 0.0138876 49
[art]:TriggerResults:TriggerResultInserter 1.475e-05 2.53831e-05 5.842e-05 2.321e-05 9.2897e-06 49
end_path:out1:RootOutput 6.43e-06 9.48757e-06 2.973e-05 8.52e-06 3.80291e-06 49
end_path:out1:RootOutput(write) 1.965 2.62704 3.85646 2.48015 0.399154 49
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 6493.13 MB
Peak resident set size usage (VmHWM): 4583.37 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0304_df-s05-d3_dw_0_20250918T035404_reco_stage1_20250918T074422_keepup.root
\tHists: np02vd_raw_run039433_0304_df-s05-d3_dw_0_20250918T035404_reco_stage1_20250918T074423_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0304_df-s05-d3_dw_0_20250918T035404_reco_stage1_20250918T074422_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0304_df-s05-d3_dw_0_20250918T035404_reco_stage1_20250918T074422_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": 1758181463.0,
"core.end_time": 1758181463.0,
"core.events": [
87279,
87285,
87291,
87297,
87303,
87309,
87315,
87321,
87327,
87333,
87339,
87345,
87351,
87357,
87363,
87369,
87375,
87381,
87387,
87393,
87399,
87405,
87411,
87417,
87423,
87429,
87435,
87441,
87447,
87453,
87459,
87465,
87471,
87477,
87483,
87489,
87495,
87501,
87507,
87513,
87519,
87525,
87531,
87537,
87543,
87549,
87555,
87561,
87567
],
"core.event_count": 49,
"core.first_event_number": 87279,
"core.last_event_number": 87567,
"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_0304_df-s05-d3_dw_0_20250918T035404.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0304_df-s05-d3_dw_0_20250918T035404_reco_stage1_20250918T074423_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": 1758181463.0,
"core.end_time": 1758181463.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_0304_df-s05-d3_dw_0_20250918T035404.hdf5"
}
]
}