Jobsub ID 41739.118@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
[09:46:17.429] D [ glue ] <FrameFanin:nfsp> EOS at call=95 with 8
[09:46:17.429] D [ glue ] frame sink sees EOS
[09:46:17.429] D [ pgraph ] <Pgrapher:> graph execution complete
[09:46:17.429] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.11 sec
[09:46:17.429] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.79 sec
[09:46:17.429] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 4.66 sec
[09:46:17.429] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 4.49 sec
[09:46:17.430] I [ timer ] Timer: WireCell::Aux::Resampler : 0.48 sec
[09:46:17.430] I [ timer ] Timer: WireCell::Aux::Resampler : 0.41 sec
[09:46:17.430] I [ timer ] Timer: WireCell::Aux::Resampler : 0.38 sec
[09:46:17.430] I [ timer ] Timer: WireCell::Aux::Resampler : 0.23 sec
[09:46:17.430] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[09:46:17.430] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[09:46:17.430] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[09:46:17.430] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:46:17.430] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:46:17.430] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:46:17.430] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:46:17.430] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:46:17.430] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:46:17.430] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:46:17.430] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[09:46:17.430] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:46:17.430] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:46:17.430] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:46:17.430] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[09:46:17.430] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[09:46:17.430] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:46:17.430] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[09:46:17.430] I [ timer ] Timer: Total node execution : 24.579999221488833 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 15457 traces tagged "gauss"
FrameSaver: q=3.41912e+06 n=350526 tag=gauss
wclsFrameSaver: saving 19477 traces tagged "wiener"
FrameSaver: q=3.62592e+06 n=333601 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 202 XUs and 218 XVs -> 7 XUVs
C:0 T:1 223 XUs and 381 XVs -> 20 XUVs
C:0 T:2 316 XUs and 273 XVs -> 6 XUVs
C:0 T:3 137 XUs and 197 XVs -> 6 XUVs
C:0 T:4 1263 XUs and 768 XVs -> 49 XUVs
C:0 T:5 23395 XUs and 24830 XVs -> 1480 XUVs
C:0 T:6 322 XUs and 213 XVs -> 14 XUVs
C:0 T:7 409 XUs and 466 XVs -> 12 XUVs
1594 XUVs total
962 collection wire objects
1594 potential space points
Neighbour search...
38262 tests to find 8860 neighbours
Iterating with no regularization...
Begin: 7.52096e+09
0 7.47651e+09
1 7.47581e+09
Now with regularization...
Begin: 7.3605e+09
0 7.36044e+09
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Sep-2025 09:46:36 UTC Closed output file "np02vd_raw_run039433_0392_df-s05-d2_dw_0_20250918T072648_reco_stage1_20250918T094636_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 34.7815 111.786 1328.77 56.9488 228.495 48
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 7.99e-05 0.000124313 0.000339762 0.000110266 4.70748e-05 48
produce:tpcrawdecoder:PDVDTPCReader 6.35283 6.9825 10.056 6.67472 0.928009 48
produce:triggerrawdecoder:PDVDTriggerReader4 0.391838 0.397028 0.406862 0.396555 0.0032219 48
produce:pdvddaphne:DAPHNEReaderPDVD 2.85223 3.15794 3.50185 3.15325 0.167455 48
produce:ophit:OpHitFinder 0.0305358 0.0420676 0.0573868 0.0420229 0.0049568 48
produce:opflash:OpFlashFinderVerticalDrift 0.00457037 0.0105752 0.0318777 0.0099229 0.00442071 48
produce:wclsdatavd:WireCellToolkit 18.2367 30.7351 66.982 26.7514 9.62198 48
produce:gaushit:GausHitFinder 0.184904 0.566955 2.2282 0.538591 0.315414 48
produce:nhitsfilter:NumberOfHitsFilter 8.3706e-05 0.000430423 0.00256374 0.00036205 0.000371053 48
produce:reco3d:SpacePointSolver 1.19304 5.27791 31.0566 3.77868 4.66357 48
produce:hitpdune:DisambigFromSpacePoints 0.0111015 0.083617 0.627993 0.056876 0.101997 48
produce:pandora:StandardPandora 1.71001 61.9587 1224.92 9.59941 218.589 48
produce:pandoraTrack:LArPandoraTrackCreation 0.0552799 0.54311 10.6305 0.282243 1.49784 48
produce:pandoraGnocalo:GnocchiCalorimetry 0.00394498 0.0147562 0.0526303 0.01363 0.00776416 48
[art]:TriggerResults:TriggerResultInserter 1.6706e-05 4.31741e-05 0.000153782 3.5528e-05 2.45103e-05 48
end_path:out1:RootOutput 4.216e-06 1.12749e-05 6.8884e-05 8.3825e-06 1.04329e-05 48
end_path:out1:RootOutput(write) 1.3879 1.97562 2.92334 2.01157 0.314958 48
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5116.13 MB
Peak resident set size usage (VmHWM): 2916.1 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0392_df-s05-d2_dw_0_20250918T072648_reco_stage1_20250918T094636_keepup.root
\tHists: np02vd_raw_run039433_0392_df-s05-d2_dw_0_20250918T072648_reco_stage1_20250918T094636_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0392_df-s05-d2_dw_0_20250918T072648_reco_stage1_20250918T094636_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0392_df-s05-d2_dw_0_20250918T072648_reco_stage1_20250918T094636_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": 1758188797.0,
"core.end_time": 1758188797.0,
"core.events": [
112460,
112466,
112472,
112478,
112484,
112490,
112496,
112502,
112508,
112514,
112520,
112526,
112532,
112538,
112544,
112550,
112556,
112562,
112568,
112574,
112580,
112586,
112592,
112598,
112604,
112610,
112616,
112622,
112628,
112634,
112640,
112646,
112652,
112658,
112664,
112670,
112676,
112682,
112688,
112694,
112700,
112706,
112712,
112718,
112724,
112730,
112736,
112742
],
"core.event_count": 48,
"core.first_event_number": 112460,
"core.last_event_number": 112742,
"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_0392_df-s05-d2_dw_0_20250918T072648.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0392_df-s05-d2_dw_0_20250918T072648_reco_stage1_20250918T094636_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": 1758188797.0,
"core.end_time": 1758188797.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_0392_df-s05-d2_dw_0_20250918T072648.hdf5"
}
]
} 