Jobsub ID 41739.52@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
[09:48:21.838] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=93 anode=0
[09:48:21.838] D [ glue ] <FrameFanin:nfsp> EOS at call=93 with 8
[09:48:21.838] D [ glue ] frame sink sees EOS
[09:48:21.838] D [ pgraph ] <Pgrapher:> graph execution complete
[09:48:21.838] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.51 sec
[09:48:21.838] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.73 sec
[09:48:21.838] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.55 sec
[09:48:21.838] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.38 sec
[09:48:21.838] I [ timer ] Timer: WireCell::Aux::Resampler : 0.43 sec
[09:48:21.838] I [ timer ] Timer: WireCell::Aux::Resampler : 0.43 sec
[09:48:21.838] I [ timer ] Timer: WireCell::Aux::Resampler : 0.42 sec
[09:48:21.838] I [ timer ] Timer: WireCell::Aux::Resampler : 0.42 sec
[09:48:21.838] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[09:48:21.838] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[09:48:21.838] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[09:48:21.838] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:48:21.838] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:48:21.838] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:48:21.838] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:48:21.838] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:48:21.838] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:48:21.838] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:48:21.838] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[09:48:21.838] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:48:21.838] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:48:21.838] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[09:48:21.838] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[09:48:21.838] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[09:48:21.838] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:48:21.838] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[09:48:21.838] I [ timer ] Timer: Total node execution : 29.900000540539622 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 18240 traces tagged "gauss"
FrameSaver: q=5.4498e+06 n=496906 tag=gauss
wclsFrameSaver: saving 23259 traces tagged "wiener"
FrameSaver: q=5.72058e+06 n=480351 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 13331 XUs and 20347 XVs -> 1066 XUVs
C:0 T:1 347 XUs and 446 XVs -> 10 XUVs
C:0 T:2 4174 XUs and 3989 XVs -> 223 XUVs
C:0 T:3 176 XUs and 150 XVs -> 4 XUVs
C:0 T:4 110 XUs and 116 XVs -> 5 XUVs
C:0 T:5 1457 XUs and 1761 XVs -> 66 XUVs
C:0 T:6 1075 XUs and 1031 XVs -> 36 XUVs
C:0 T:7 318 XUs and 359 XVs -> 11 XUVs
1421 XUVs total
940 collection wire objects
1421 potential space points
Neighbour search...
31867 tests to find 7792 neighbours
Iterating with no regularization...
Begin: 1.32842e+10
0 1.24654e+10
1 1.24593e+10
Now with regularization...
Begin: 1.23389e+10
0 1.23388e+10
18-Sep-2025 09:48:46 BST Closed output file "np02vd_raw_run039433_0381_df-s05-d5_dw_0_20250918T065903_reco_stage1_20250918T084846_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 46.3879 70.3306 214.924 66.98 25.2597 47
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 7.1103e-05 0.000129052 0.000331882 0.000108844 5.42305e-05 47
produce:tpcrawdecoder:PDVDTPCReader 6.20306 6.7874 8.02568 6.62386 0.48767 47
produce:triggerrawdecoder:PDVDTriggerReader4 0.300284 0.308453 0.356126 0.305332 0.0112853 47
produce:pdvddaphne:DAPHNEReaderPDVD 2.49101 3.15799 3.55916 3.1818 0.199623 47
produce:ophit:OpHitFinder 0.0348725 0.0520009 0.0654376 0.0539784 0.00711858 47
produce:opflash:OpFlashFinderVerticalDrift 0.00319206 0.0111955 0.0211335 0.0112955 0.00374439 47
produce:wclsdatavd:WireCellToolkit 23.9599 34.1007 63.891 29.4318 8.77659 47
produce:gaushit:GausHitFinder 0.330369 0.64401 1.25464 0.650616 0.15998 47
produce:nhitsfilter:NumberOfHitsFilter 9.8124e-05 0.000193888 0.000399138 0.000182051 5.9913e-05 47
produce:reco3d:SpacePointSolver 1.51869 5.01812 10.778 4.87176 1.72746 47
produce:hitpdune:DisambigFromSpacePoints 0.0173791 0.0690827 0.254101 0.0596896 0.0413221 47
produce:pandora:StandardPandora 3.44572 17.2629 125.169 15.4592 17.5596 47
produce:pandoraTrack:LArPandoraTrackCreation 0.0841829 0.256478 0.810103 0.235585 0.134875 47
produce:pandoraGnocalo:GnocchiCalorimetry 0.00566992 0.0162016 0.0291408 0.0161689 0.0041813 47
[art]:TriggerResults:TriggerResultInserter 2.0989e-05 3.56798e-05 7.2736e-05 3.4324e-05 7.64175e-06 47
end_path:out1:RootOutput 4.809e-06 9.50674e-06 3.4164e-05 9.368e-06 3.98257e-06 47
end_path:out1:RootOutput(write) 2.00802 2.62381 3.52936 2.56201 0.34765 47
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4203.24 MB
Peak resident set size usage (VmHWM): 2243.99 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0381_df-s05-d5_dw_0_20250918T065903_reco_stage1_20250918T084846_keepup.root
\tHists: np02vd_raw_run039433_0381_df-s05-d5_dw_0_20250918T065903_reco_stage1_20250918T084847_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0381_df-s05-d5_dw_0_20250918T065903_reco_stage1_20250918T084846_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0381_df-s05-d5_dw_0_20250918T065903_reco_stage1_20250918T084846_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": 1758185327.0,
"core.end_time": 1758185327.0,
"core.events": [
109211,
109217,
109223,
109229,
109235,
109241,
109247,
109253,
109259,
109265,
109271,
109277,
109283,
109289,
109295,
109301,
109307,
109313,
109319,
109325,
109331,
109337,
109343,
109349,
109355,
109361,
109367,
109373,
109379,
109385,
109391,
109397,
109403,
109409,
109415,
109421,
109427,
109433,
109439,
109445,
109451,
109457,
109463,
109469,
109475,
109481,
109487
],
"core.event_count": 47,
"core.first_event_number": 109211,
"core.last_event_number": 109487,
"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_0381_df-s05-d5_dw_0_20250918T065903.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0381_df-s05-d5_dw_0_20250918T065903_reco_stage1_20250918T084847_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": 1758185327.0,
"core.end_time": 1758185327.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_0381_df-s05-d5_dw_0_20250918T065903.hdf5"
}
]
}