Jobsub ID 41596.145@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
Proc:anode0sigproc0> EOS at call=93 anode=0
[07:28:36.216] D [ glue ] <FrameFanin:nfsp> EOS at call=93 with 8
[07:28:36.216] D [ glue ] frame sink sees EOS
[07:28:36.216] D [ pgraph ] <Pgrapher:> graph execution complete
[07:28:36.217] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.14 sec
[07:28:36.217] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.63 sec
[07:28:36.217] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.57 sec
[07:28:36.217] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.48 sec
[07:28:36.217] I [ timer ] Timer: WireCell::Aux::Resampler : 0.39 sec
[07:28:36.217] I [ timer ] Timer: WireCell::Aux::Resampler : 0.37 sec
[07:28:36.217] I [ timer ] Timer: WireCell::Aux::Resampler : 0.37 sec
[07:28:36.217] I [ timer ] Timer: WireCell::Aux::Resampler : 0.36 sec
[07:28:36.217] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[07:28:36.217] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[07:28:36.217] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[07:28:36.217] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[07:28:36.217] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[07:28:36.217] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[07:28:36.217] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[07:28:36.217] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[07:28:36.217] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[07:28:36.217] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[07:28:36.217] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[07:28:36.217] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[07:28:36.217] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[07:28:36.217] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[07:28:36.217] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[07:28:36.217] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[07:28:36.217] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[07:28:36.217] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[07:28:36.217] I [ timer ] Timer: Total node execution : 24.330000180751085 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 21357 traces tagged "gauss"
FrameSaver: q=3.78832e+06 n=523105 tag=gauss
wclsFrameSaver: saving 26015 traces tagged "wiener"
FrameSaver: q=4.0251e+06 n=513430 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 1561 XUs and 1960 XVs -> 50 XUVs
C:0 T:1 620 XUs and 611 XVs -> 31 XUVs
C:0 T:2 1365 XUs and 1341 XVs -> 30 XUVs
C:0 T:3 684 XUs and 696 XVs -> 11 XUVs
C:0 T:4 1308 XUs and 1262 XVs -> 37 XUVs
C:0 T:5 219 XUs and 222 XVs -> 10 XUVs
C:0 T:6 488 XUs and 500 XVs -> 18 XUVs
C:0 T:7 9577 XUs and 10454 XVs -> 911 XUVs
1098 XUVs total
622 collection wire objects
1098 potential space points
Neighbour search...
53550 tests to find 12002 neighbours
Iterating with no regularization...
Begin: 2.94633e+09
0 2.86405e+09
1 2.85652e+09
2 2.85641e+09
Now with regularization...
Begin: 2.79776e+09
0 2.79767e+09
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Sep-2025 07:29:04 UTC Closed output file "np02vd_raw_run039433_0324_df-s05-d2_dw_0_20250918T044048_reco_stage1_20250918T072904_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 34.5236 131.407 3475.22 54.6062 493.348 47
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 7.3811e-05 0.000122163 0.000254564 0.000102364 4.60674e-05 47
produce:tpcrawdecoder:PDVDTPCReader 6.60147 7.39341 10.1055 6.89193 1.13041 47
produce:triggerrawdecoder:PDVDTriggerReader4 0.389211 0.395512 0.409657 0.392976 0.00614163 47
produce:pdvddaphne:DAPHNEReaderPDVD 2.72304 3.1874 3.55684 3.14472 0.177898 47
produce:ophit:OpHitFinder 0.0359471 0.0436628 0.0525737 0.043742 0.00444819 47
produce:opflash:OpFlashFinderVerticalDrift 0.00103727 0.00936526 0.0147414 0.00924082 0.00280689 47
produce:wclsdatavd:WireCellToolkit 16.5245 28.1864 60.6641 24.2676 9.13939 47
produce:gaushit:GausHitFinder 0.210747 0.574254 1.9705 0.539274 0.269042 47
produce:nhitsfilter:NumberOfHitsFilter 7.5254e-05 0.000236018 0.00229206 0.000177237 0.000314188 47
produce:reco3d:SpacePointSolver 1.65816 4.6579 27.0327 3.58577 3.74127 47
produce:hitpdune:DisambigFromSpacePoints 0.0111072 0.0666631 0.405887 0.051823 0.0620126 47
produce:pandora:StandardPandora 2.53943 84.366 3392.03 9.39657 487.786 47
produce:pandoraTrack:LArPandoraTrackCreation 0.0649355 0.360079 6.94003 0.181789 0.979451 47
produce:pandoraGnocalo:GnocchiCalorimetry 0.00462296 0.0144009 0.0635804 0.0126845 0.00913585 47
[art]:TriggerResults:TriggerResultInserter 1.7496e-05 3.74791e-05 0.000136596 3.1478e-05 1.93226e-05 47
end_path:out1:RootOutput 3.556e-06 9.05087e-06 5.2709e-05 7.371e-06 7.44465e-06 47
end_path:out1:RootOutput(write) 1.41004 2.1285 3.01861 2.11238 0.388632 47
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5584.38 MB
Peak resident set size usage (VmHWM): 3395.98 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0324_df-s05-d2_dw_0_20250918T044048_reco_stage1_20250918T072904_keepup.root
\tHists: np02vd_raw_run039433_0324_df-s05-d2_dw_0_20250918T044048_reco_stage1_20250918T072904_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0324_df-s05-d2_dw_0_20250918T044048_reco_stage1_20250918T072904_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0324_df-s05-d2_dw_0_20250918T044048_reco_stage1_20250918T072904_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": 1758180545.0,
"core.end_time": 1758180545.0,
"core.events": [
92966,
92972,
92978,
92984,
92990,
92996,
93002,
93008,
93014,
93020,
93026,
93032,
93038,
93044,
93050,
93056,
93062,
93068,
93074,
93080,
93086,
93092,
93098,
93104,
93110,
93116,
93122,
93128,
93134,
93140,
93146,
93152,
93158,
93164,
93170,
93176,
93182,
93188,
93194,
93200,
93206,
93212,
93218,
93224,
93230,
93236,
93242
],
"core.event_count": 47,
"core.first_event_number": 92966,
"core.last_event_number": 93242,
"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_0324_df-s05-d2_dw_0_20250918T044048.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0324_df-s05-d2_dw_0_20250918T044048_reco_stage1_20250918T072904_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": 1758180545.0,
"core.end_time": 1758180545.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_0324_df-s05-d2_dw_0_20250918T044048.hdf5"
}
]
} 