Jobsub ID 39336.125@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
] <Resampler:resmp0> EOS at call=35
[20:03:07.740] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=35 anode=0
[20:03:07.740] D [ glue ] <FrameFanin:nfsp> EOS at call=35 with 8
[20:03:07.740] D [ glue ] frame sink sees EOS
[20:03:07.740] D [ pgraph ] <Pgrapher:> graph execution complete
[20:03:07.741] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.54 sec
[20:03:07.741] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.29 sec
[20:03:07.741] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.84 sec
[20:03:07.741] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.47 sec
[20:03:07.741] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.41 sec
[20:03:07.741] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.1 sec
[20:03:07.741] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.94 sec
[20:03:07.741] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.45 sec
[20:03:07.741] I [ timer ] Timer: WireCell::Aux::Resampler : 1.2 sec
[20:03:07.741] I [ timer ] Timer: WireCell::Aux::Resampler : 1.12 sec
[20:03:07.741] I [ timer ] Timer: WireCell::Aux::Resampler : 1.1 sec
[20:03:07.741] I [ timer ] Timer: WireCell::Aux::Resampler : 0.65 sec
[20:03:07.741] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.03 sec
[20:03:07.741] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[20:03:07.741] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[20:03:07.741] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[20:03:07.741] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:03:07.741] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:03:07.741] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:03:07.741] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[20:03:07.741] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:03:07.741] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:03:07.741] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[20:03:07.741] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[20:03:07.741] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[20:03:07.741] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[20:03:07.741] I [ timer ] Timer: Total node execution : 85.17000001296401 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 63698 traces tagged "gauss"
FrameSaver: q=1.29914e+07 n=1519204 tag=gauss
wclsFrameSaver: saving 79385 traces tagged "wiener"
FrameSaver: q=1.39604e+07 n=1452514 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 492 XUs and 561 XVs -> 25 XUVs
C:0 T:1 1619 XUs and 2201 XVs -> 101 XUVs
C:0 T:2 889 XUs and 842 XVs -> 34 XUVs
C:0 T:3 1434 XUs and 1502 XVs -> 76 XUVs
C:0 T:4 1578 XUs and 1520 XVs -> 58 XUVs
C:0 T:5 1314 XUs and 1975 XVs -> 110 XUVs
C:0 T:6 603 XUs and 487 XVs -> 30 XUVs
C:0 T:7 366 XUs and 605 XVs -> 36 XUVs
C:0 T:8 23852 XUs and 63804 XVs -> 7268 XUVs
C:0 T:9 3733 XUs and 3586 XVs -> 575 XUVs
C:0 T:10 3803 XUs and 9209 XVs -> 572 XUVs
C:0 T:11 11763 XUs and 21160 XVs -> 4776 XUVs
C:0 T:12 10676 XUs and 15898 XVs -> 1773 XUVs
C:0 T:13 5986 XUs and 6023 XVs -> 392 XUVs
C:0 T:14 2227 XUs and 2656 XVs -> 164 XUVs
C:0 T:15 9917 XUs and 18444 XVs -> 1837 XUVs
17827 XUVs total
2732 collection wire objects
17827 potential space points
Neighbour search...
2380731 tests to find 982708 neighbours
Iterating with no regularization...
Begin: 1.58051e+09
0 1.45324e+09
1 1.44611e+09
2 1.44506e+09
Now with regularization...
Begin: 1.42773e+09
0 1.42715e+09
13-Sep-2025 20:05:49 CEST Closed output file "np02vd_raw_run039275_0150_df-s04-d3_dw_0_20250901T194025_reco_stage1_20250913T180549_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 143.036 230.275 355.93 236.713 52.2289 18
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 7.454e-05 0.000126833 0.000379432 0.000108695 7.23565e-05 18
produce:tpcrawdecoder:PDVDTPCReader 5.95526 7.09547 14.2932 6.74416 1.771 18
produce:triggerrawdecoder:PDVDTriggerReader4 0.00118515 0.00141618 0.002336 0.00135132 0.000254654 18
produce:pdvddaphne:DAPHNEReaderPDVD 3.90779 4.76532 6.18453 4.57085 0.638737 18
produce:ophit:OpHitFinder 0.0458383 0.0613942 0.0753167 0.0627667 0.00973284 18
produce:opflash:OpFlashFinderVerticalDrift 0.0099727 0.0154393 0.0211574 0.0152538 0.00365861 18
produce:wclsdatavd:WireCellToolkit 71.4304 82.2021 99.4379 81.7209 7.17993 18
produce:gaushit:GausHitFinder 1.06404 1.77203 2.60035 1.71076 0.441388 18
produce:nhitsfilter:NumberOfHitsFilter 0.000232981 0.000505256 0.00132862 0.000431597 0.000249802 18
produce:reco3d:SpacePointSolver 10.4568 22.4856 36.4315 22.8806 6.78031 18
produce:hitpdune:DisambigFromSpacePoints 0.131457 0.431131 0.774262 0.450432 0.176596 18
produce:pandora:StandardPandora 36.3306 103.582 209.182 107.417 42.7235 18
produce:pandoraTrack:LArPandoraTrackCreation 0.710809 1.58022 2.55954 1.47167 0.499009 18
produce:pandoraGnocalo:GnocchiCalorimetry 0.0192172 0.0425337 0.0708717 0.042448 0.0153207 18
[art]:TriggerResults:TriggerResultInserter 1.814e-05 3.21796e-05 7.2111e-05 3.1105e-05 1.18294e-05 18
end_path:out1:RootOutput 6.57e-06 1.00806e-05 3.2271e-05 8.145e-06 5.66926e-06 18
end_path:out1:RootOutput(write) 4.69565 6.19125 7.64932 6.03666 0.988947 18
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5367.62 MB
Peak resident set size usage (VmHWM): 3451.39 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039275_0150_df-s04-d3_dw_0_20250901T194025_reco_stage1_20250913T180549_keepup.root
\tHists: np02vd_raw_run039275_0150_df-s04-d3_dw_0_20250901T194025_reco_stage1_20250913T180549_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039275_0150_df-s04-d3_dw_0_20250901T194025_reco_stage1_20250913T180549_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039275_0150_df-s04-d3_dw_0_20250901T194025_reco_stage1_20250913T180549_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": 1757786750.0,
"core.end_time": 1757786750.0,
"core.events": [
54013,
54033,
54053,
54073,
54093,
54113,
54133,
54153,
54173,
54193,
54213,
54233,
54253,
54273,
54293,
54313,
54333,
54353
],
"core.event_count": 18,
"core.first_event_number": 54013,
"core.last_event_number": 54353,
"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_0150_df-s04-d3_dw_0_20250901T194025.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039275_0150_df-s04-d3_dw_0_20250901T194025_reco_stage1_20250913T180549_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": 1757786750.0,
"core.end_time": 1757786750.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_0150_df-s04-d3_dw_0_20250901T194025.hdf5"
}
]
} 