Jobsub ID 38925.57@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
proc0> EOS at call=35 anode=0
[19:06:57.743] D [ glue ] <FrameFanin:nfsp> EOS at call=35 with 8
[19:06:57.743] D [ glue ] frame sink sees EOS
[19:06:57.743] D [ pgraph ] <Pgrapher:> graph execution complete
[19:06:57.743] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.7 sec
[19:06:57.743] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.63 sec
[19:06:57.743] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.38 sec
[19:06:57.743] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.35 sec
[19:06:57.743] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.32 sec
[19:06:57.743] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.14 sec
[19:06:57.743] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.91 sec
[19:06:57.743] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.31 sec
[19:06:57.743] I [ timer ] Timer: WireCell::Aux::Resampler : 0.87 sec
[19:06:57.743] I [ timer ] Timer: WireCell::Aux::Resampler : 0.86 sec
[19:06:57.743] I [ timer ] Timer: WireCell::Aux::Resampler : 0.86 sec
[19:06:57.744] I [ timer ] Timer: WireCell::Aux::Resampler : 0.84 sec
[19:06:57.744] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[19:06:57.744] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[19:06:57.744] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[19:06:57.744] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[19:06:57.744] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[19:06:57.744] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[19:06:57.744] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[19:06:57.744] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[19:06:57.744] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[19:06:57.744] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[19:06:57.744] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[19:06:57.744] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[19:06:57.744] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[19:06:57.744] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[19:06:57.744] I [ timer ] Timer: Total node execution : 71.20000025443733 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 56600 traces tagged "gauss"
FrameSaver: q=9.9953e+06 n=1240479 tag=gauss
wclsFrameSaver: saving 70368 traces tagged "wiener"
FrameSaver: q=1.06745e+07 n=1188350 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 398 XUs and 466 XVs -> 28 XUVs
C:0 T:1 436 XUs and 641 XVs -> 25 XUVs
C:0 T:2 951 XUs and 1039 XVs -> 42 XUVs
C:0 T:3 3186 XUs and 2417 XVs -> 160 XUVs
C:0 T:4 1768 XUs and 886 XVs -> 100 XUVs
C:0 T:5 476 XUs and 518 XVs -> 14 XUVs
C:0 T:6 1457 XUs and 1204 XVs -> 59 XUVs
C:0 T:7 5095 XUs and 6809 XVs -> 466 XUVs
C:0 T:8 13205 XUs and 30021 XVs -> 5586 XUVs
C:0 T:9 14484 XUs and 30909 XVs -> 5311 XUVs
C:0 T:10 10712 XUs and 14646 XVs -> 3837 XUVs
C:0 T:11 2154 XUs and 1865 XVs -> 84 XUVs
C:0 T:12 3097 XUs and 2985 XVs -> 201 XUVs
C:0 T:13 2176 XUs and 2080 XVs -> 145 XUVs
C:0 T:14 1630 XUs and 1660 XVs -> 92 XUVs
C:0 T:15 2619 XUs and 2349 XVs -> 148 XUVs
16298 XUVs total
2120 collection wire objects
16298 potential space points
Neighbour search...
3076982 tests to find 1206886 neighbours
Iterating with no regularization...
Begin: 9.04621e+08
0 8.47774e+08
1 8.45383e+08
2 8.45013e+08
Now with regularization...
Begin: 8.35344e+08
0 8.35077e+08
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
12-Sep-2025 19:08:38 CEST Closed output file "np02vd_raw_run039273_1292_df-s03-d0_dw_0_20250901T032429_reco_stage1_20250912T170838_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 260.67 342.657 475.881 330.656 61.0635 18
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 5.7127e-05 8.79961e-05 0.00024029 7.49105e-05 4.41246e-05 18
produce:tpcrawdecoder:PDVDTPCReader 87.6275 130.394 186.212 129.143 28.599 18
produce:triggerrawdecoder:PDVDTriggerReader4 0.0345723 0.0472659 0.0952318 0.0460584 0.0154236 18
produce:pdvddaphne:DAPHNEReaderPDVD 12.0519 16.4283 23.6688 15.4699 3.25459 18
produce:ophit:OpHitFinder 0.0453009 0.0662244 0.0783788 0.0679945 0.0078396 18
produce:opflash:OpFlashFinderVerticalDrift 0.0116126 0.0249454 0.0342211 0.0249284 0.00593302 18
produce:wclsdatavd:WireCellToolkit 66.087 74.6437 85.1705 72.9475 5.48896 18
produce:gaushit:GausHitFinder 1.18968 1.6708 2.41437 1.63868 0.343373 18
produce:nhitsfilter:NumberOfHitsFilter 0.000415639 0.00091516 0.00150702 0.000962084 0.000342056 18
produce:reco3d:SpacePointSolver 14.4717 22.8961 34.5671 21.3203 5.98172 18
produce:hitpdune:DisambigFromSpacePoints 0.216296 0.373989 0.613104 0.316309 0.11153 18
produce:pandora:StandardPandora 40.9339 88.9907 199.149 70.8963 43.218 18
produce:pandoraTrack:LArPandoraTrackCreation 0.801711 1.84799 4.03569 1.46178 0.891056 18
produce:pandoraGnocalo:GnocchiCalorimetry 0.0263632 0.040133 0.0561538 0.0366215 0.00899838 18
[art]:TriggerResults:TriggerResultInserter 1.5599e-05 2.11426e-05 5.6867e-05 1.9372e-05 8.93599e-06 18
end_path:out1:RootOutput 4.028e-06 6.01011e-06 2.5568e-05 4.9845e-06 4.75852e-06 18
end_path:out1:RootOutput(write) 4.50563 5.1786 5.56055 5.22144 0.262366 18
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5145.26 MB
Peak resident set size usage (VmHWM): 3262.68 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039273_1292_df-s03-d0_dw_0_20250901T032429_reco_stage1_20250912T170838_keepup.root
\tHists: np02vd_raw_run039273_1292_df-s03-d0_dw_0_20250901T032429_reco_stage1_20250912T170838_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039273_1292_df-s03-d0_dw_0_20250901T032429_reco_stage1_20250912T170838_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039273_1292_df-s03-d0_dw_0_20250901T032429_reco_stage1_20250912T170838_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": 1757696918.0,
"core.end_time": 1757696918.0,
"core.events": [
465126,
465146,
465166,
465186,
465206,
465226,
465246,
465266,
465286,
465306,
465326,
465346,
465366,
465386,
465406,
465426,
465446,
465466
],
"core.event_count": 18,
"core.first_event_number": 465126,
"core.last_event_number": 465466,
"core.data_stream": "physics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39273
],
"core.runs_subruns": [
3927300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039273_1292_df-s03-d0_dw_0_20250901T032429.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039273_1292_df-s03-d0_dw_0_20250901T032429_reco_stage1_20250912T170838_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": 1757696918.0,
"core.end_time": 1757696918.0,
"core.data_stream": "physics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39273
],
"core.runs_subruns": [
3927300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039273_1292_df-s03-d0_dw_0_20250901T032429.hdf5"
}
]
} 