Jobsub ID 242845.182@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
Proc:anode0sigproc0> EOS at call=43 anode=0
[11:17:58.830] D [ glue ] <FrameFanin:nfsp> EOS at call=43 with 8
[11:17:58.830] D [ glue ] frame sink sees EOS
[11:17:58.830] D [ pgraph ] <Pgrapher:> graph execution complete
[11:17:58.830] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.25 sec
[11:17:58.830] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.72 sec
[11:17:58.830] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.36 sec
[11:17:58.830] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.81 sec
[11:17:58.830] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.53 sec
[11:17:58.830] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.14 sec
[11:17:58.830] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.09 sec
[11:17:58.831] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.42 sec
[11:17:58.831] I [ timer ] Timer: WireCell::Aux::Resampler : 0.27 sec
[11:17:58.831] I [ timer ] Timer: WireCell::Aux::Resampler : 0.27 sec
[11:17:58.831] I [ timer ] Timer: WireCell::Aux::Resampler : 0.19 sec
[11:17:58.831] I [ timer ] Timer: WireCell::Aux::Resampler : 0.18 sec
[11:17:58.831] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[11:17:58.831] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[11:17:58.831] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[11:17:58.831] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:17:58.831] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:17:58.831] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:17:58.831] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[11:17:58.831] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:17:58.831] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:17:58.831] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[11:17:58.831] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:17:58.831] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[11:17:58.831] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[11:17:58.831] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[11:17:58.831] I [ timer ] Timer: Total node execution : 57.28000067360699 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 48543 traces tagged "gauss"
FrameSaver: q=2.63956e+07 n=1201780 tag=gauss
wclsFrameSaver: saving 60894 traces tagged "wiener"
FrameSaver: q=2.80171e+07 n=1159108 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 754 XUs and 1281 XVs -> 30 XUVs
C:0 T:1 25878 XUs and 43744 XVs -> 2572 XUVs
C:0 T:2 1143 XUs and 1171 XVs -> 50 XUVs
C:0 T:3 806 XUs and 1155 XVs -> 73 XUVs
C:0 T:4 7520 XUs and 14846 XVs -> 551 XUVs
C:0 T:5 252 XUs and 259 XVs -> 17 XUVs
C:0 T:6 3406 XUs and 5151 XVs -> 267 XUVs
C:0 T:7 570 XUs and 879 XVs -> 23 XUVs
C:0 T:8 738 XUs and 1297 XVs -> 113 XUVs
C:0 T:9 414 XUs and 1252 XVs -> 22 XUVs
C:0 T:10 573 XUs and 1249 XVs -> 46 XUVs
C:0 T:11 1204 XUs and 1453 XVs -> 86 XUVs
C:0 T:12 412 XUs and 413 XVs -> 43 XUVs
C:0 T:13 181 XUs and 396 XVs -> 20 XUVs
C:0 T:14 419 XUs and 530 XVs -> 20 XUVs
C:0 T:15 1169 XUs and 1296 XVs -> 112 XUVs
4045 XUVs total
2251 collection wire objects
4045 potential space points
Neighbour search...
180745 tests to find 41108 neighbours
Iterating with no regularization...
Begin: 3.65342e+12
0 3.65186e+12
Now with regularization...
Begin: 3.65092e+12
0 3.65084e+12
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
04-Nov-2025 11:19:40 CET Closed output file "np02vd_raw_run040348_0957_df-s04-d3_dw_0_20251104T082333_reco_stage1_20251104T101940_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 71.9004 120.151 189.416 119.79 30.4732 22
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 5.6681e-05 8.65022e-05 0.000180902 8.2461e-05 2.54443e-05 22
produce:tpcrawdecoder:PDVDTPCReader 5.01777 6.02203 8.17103 5.78982 0.790315 22
produce:triggerrawdecoder:PDVDTriggerReader4 0.011372 0.0203283 0.0587375 0.017704 0.0108996 22
produce:pdvddaphne:DAPHNEReaderPDVD 0.000251072 0.000364976 0.000833889 0.000345368 0.000111373 22
produce:ophit:OpHitFinder 6.893e-05 0.000119481 0.000620966 9.1721e-05 0.000110524 22
produce:opflash:OpFlashFinderVerticalDrift 5.2981e-05 8.19109e-05 0.000359534 6.69505e-05 6.20254e-05 22
produce:wclsdatavd:WireCellToolkit 41.5676 64.327 124.723 61.1109 18.3972 22
produce:gaushit:GausHitFinder 0.65872 1.06215 1.75115 1.0287 0.255495 22
produce:nhitsfilter:NumberOfHitsFilter 0.000182792 0.000264797 0.000409764 0.000254923 5.77695e-05 22
produce:reco3d:SpacePointSolver 5.8933 10.8191 17.5957 10.5765 2.90166 22
produce:hitpdune:DisambigFromSpacePoints 0.0943895 0.204587 0.3002 0.226364 0.0683008 22
produce:pandora:StandardPandora 8.64302 32.0268 80.7092 27.8876 18.7624 22
produce:pandoraTrack:LArPandoraTrackCreation 0.36961 0.856478 1.33444 0.887885 0.244091 22
produce:pandoraGnocalo:GnocchiCalorimetry 0.0162064 0.0315772 0.051543 0.0314257 0.00889918 22
[art]:TriggerResults:TriggerResultInserter 1.788e-05 2.6444e-05 7.091e-05 2.4596e-05 1.05366e-05 22
end_path:out1:RootOutput 3.68e-06 8.17286e-06 2.577e-05 7.71e-06 4.19724e-06 22
end_path:out1:RootOutput(write) 3.6231 4.73972 8.00787 4.67319 0.887191 22
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5689.59 MB
Peak resident set size usage (VmHWM): 3739.72 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run040348_0957_df-s04-d3_dw_0_20251104T082333_reco_stage1_20251104T101940_keepup.root
\tHists: np02vd_raw_run040348_0957_df-s04-d3_dw_0_20251104T082333_reco_stage1_20251104T101940_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run040348_0957_df-s04-d3_dw_0_20251104T082333_reco_stage1_20251104T101940_keepup.root
Ran successfully
{
"name": "np02vd_raw_run040348_0957_df-s04-d3_dw_0_20251104T082333_reco_stage1_20251104T101940_keepup.root",
"namespace": "vd-protodune-det-reco",
"metadata": {
"core.file_format": "artroot",
"core.application.name": "reco",
"core.application.family": "dunesw",
"core.application.version": "v10_11_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": 1762251580.0,
"core.end_time": 1762251580.0,
"core.events": [
88399,
88403,
88407,
88411,
88415,
88419,
88423,
88427,
88431,
88435,
88439,
88443,
88447,
88451,
88455,
88459,
88463,
88467,
88471,
88475,
88479,
88483
],
"core.event_count": 22,
"core.first_event_number": 88399,
"core.last_event_number": 88483,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
40348
],
"core.runs_subruns": [
4034800001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run040348_0957_df-s04-d3_dw_0_20251104T082333.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run040348_0957_df-s04-d3_dw_0_20251104T082333_reco_stage1_20251104T101940_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_11_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": 1762251580.0,
"core.end_time": 1762251580.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
40348
],
"core.runs_subruns": [
4034800001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run040348_0957_df-s04-d3_dw_0_20251104T082333.hdf5"
}
]
} 