Jobsub ID 48913.4@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
call=79
[20:58:22.266] D [sigproc ] <OmnibusSigProc:anode1sigproc1> EOS at call=79 anode=1
[20:58:22.266] D [ glue ] <ChannelSelector:chsel0> see EOS at call=39
[20:58:22.266] D [ aux ] <Resampler:resmp0> EOS at call=79
[20:58:22.266] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=79 anode=0
[20:58:22.266] D [ glue ] <FrameFanin:nfsp> EOS at call=79 with 8
[20:58:22.266] D [ glue ] frame sink sees EOS
[20:58:22.266] D [ pgraph ] <Pgrapher:> graph execution complete
[20:58:22.266] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 18.61 sec
[20:58:22.266] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 13.04 sec
[20:58:22.266] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.82 sec
[20:58:22.266] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.89 sec
[20:58:22.266] I [ timer ] Timer: WireCell::Aux::Resampler : 0.32 sec
[20:58:22.266] I [ timer ] Timer: WireCell::Aux::Resampler : 0.3 sec
[20:58:22.266] I [ timer ] Timer: WireCell::Aux::Resampler : 0.21 sec
[20:58:22.266] I [ timer ] Timer: WireCell::Aux::Resampler : 0.21 sec
[20:58:22.266] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[20:58:22.266] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[20:58:22.266] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[20:58:22.266] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:58:22.266] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:58:22.266] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[20:58:22.266] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:58:22.266] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:58:22.266] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[20:58:22.266] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:58:22.266] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[20:58:22.266] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:58:22.266] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:58:22.266] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[20:58:22.266] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[20:58:22.266] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[20:58:22.266] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[20:58:22.266] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[20:58:22.266] I [ timer ] Timer: Total node execution : 53.42000060155988 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 29278 traces tagged "gauss"
FrameSaver: q=1.2119e+07 n=944148 tag=gauss
wclsFrameSaver: saving 36407 traces tagged "wiener"
FrameSaver: q=1.26262e+07 n=922422 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 922 XUs and 691 XVs -> 51 XUVs
C:0 T:1 282 XUs and 378 XVs -> 12 XUVs
C:0 T:2 1403 XUs and 751 XVs -> 39 XUVs
C:0 T:3 2968 XUs and 6712 XVs -> 269 XUVs
C:0 T:4 2187 XUs and 3562 XVs -> 70 XUVs
C:0 T:5 2158 XUs and 2104 XVs -> 86 XUVs
C:0 T:6 11314 XUs and 23279 XVs -> 985 XUVs
C:0 T:7 1238 XUs and 973 XVs -> 35 XUVs
1547 XUVs total
956 collection wire objects
1547 potential space points
Neighbour search...
34737 tests to find 7734 neighbours
Iterating with no regularization...
Begin: 6.25981e+10
0 5.68308e+10
1 5.66044e+10
2 5.65956e+10
Now with regularization...
Begin: 5.58526e+10
0 5.58476e+10
18-Sep-2025 20:59:30 CEST Closed output file "np02vd_raw_run039499_0000_df-s05-d5_dw_0_20250918T174250_reco_stage1_20250918T185930_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 51.9747 75.3538 147.484 71.7104 21.3568 40
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 6.0452e-05 8.78928e-05 0.000157745 8.16125e-05 1.99957e-05 40
produce:tpcrawdecoder:PDVDTPCReader 9.37608 10.2707 11.6198 10.1009 0.545528 40
produce:triggerrawdecoder:PDVDTriggerReader4 0.573057 0.580707 0.598487 0.578737 0.00542682 40
produce:pdvddaphne:DAPHNEReaderPDVD 2.28004 3.13147 3.94005 3.28334 0.441275 40
produce:ophit:OpHitFinder 0.0302555 0.0434909 0.0621781 0.0444376 0.0071145 40
produce:opflash:OpFlashFinderVerticalDrift 0.00657312 0.0137345 0.0222935 0.0139534 0.00410885 40
produce:wclsdatavd:WireCellToolkit 21.4093 35.4028 71.1464 32.0761 10.2439 40
produce:gaushit:GausHitFinder 0.296674 0.610065 1.11906 0.611997 0.179449 40
produce:nhitsfilter:NumberOfHitsFilter 5.5792e-05 0.000222807 0.000828697 0.000201491 0.000146304 40
produce:reco3d:SpacePointSolver 1.46053 5.39409 10.8358 5.15126 2.03329 40
produce:hitpdune:DisambigFromSpacePoints 0.0156704 0.067415 0.174852 0.0583905 0.0367535 40
produce:pandora:StandardPandora 3.03527 17.2924 55.3975 14.2389 11.2631 40
produce:pandoraTrack:LArPandoraTrackCreation 0.0769923 0.287805 0.858814 0.246976 0.153465 40
produce:pandoraGnocalo:GnocchiCalorimetry 0.0069486 0.0146754 0.0262319 0.0132847 0.00450338 40
[art]:TriggerResults:TriggerResultInserter 1.209e-05 2.25121e-05 5.4182e-05 1.86255e-05 1.09411e-05 40
end_path:out1:RootOutput 3.05e-06 4.66425e-06 1.5061e-05 4.54e-06 1.81585e-06 40
end_path:out1:RootOutput(write) 1.86758 2.22098 4.32548 2.0439 0.497245 40
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4386.79 MB
Peak resident set size usage (VmHWM): 2458.73 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0000_df-s05-d5_dw_0_20250918T174250_reco_stage1_20250918T185930_keepup.root
\tHists: np02vd_raw_run039499_0000_df-s05-d5_dw_0_20250918T174250_reco_stage1_20250918T185930_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0000_df-s05-d5_dw_0_20250918T174250_reco_stage1_20250918T185930_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0000_df-s05-d5_dw_0_20250918T174250_reco_stage1_20250918T185930_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": 1758221971.0,
"core.end_time": 1758221971.0,
"core.events": [
5,
11,
17,
23,
29,
35,
41,
47,
53,
59,
65,
71,
77,
83,
89,
95,
101,
107,
113,
119,
125,
131,
137,
143,
149,
155,
161,
167,
173,
179,
185,
191,
197,
203,
209,
215,
221,
227,
233,
239
],
"core.event_count": 40,
"core.first_event_number": 5,
"core.last_event_number": 239,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39499
],
"core.runs_subruns": [
3949900001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039499_0000_df-s05-d5_dw_0_20250918T174250.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0000_df-s05-d5_dw_0_20250918T174250_reco_stage1_20250918T185930_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": 1758221971.0,
"core.end_time": 1758221971.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39499
],
"core.runs_subruns": [
3949900001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039499_0000_df-s05-d5_dw_0_20250918T174250.hdf5"
}
]
} 