Jobsub ID 41395.19@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
<FrameFanin:nfsp> EOS at call=93 with 8
[02:09:11.824] D [ glue ] frame sink sees EOS
[02:09:11.824] D [ pgraph ] <Pgrapher:> graph execution complete
[02:09:11.824] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.74 sec
[02:09:11.824] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.6 sec
[02:09:11.824] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.54 sec
[02:09:11.824] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.34 sec
[02:09:11.824] I [ timer ] Timer: WireCell::Aux::Resampler : 0.31 sec
[02:09:11.824] I [ timer ] Timer: WireCell::Aux::Resampler : 0.3 sec
[02:09:11.824] I [ timer ] Timer: WireCell::Aux::Resampler : 0.29 sec
[02:09:11.824] I [ timer ] Timer: WireCell::Aux::Resampler : 0.29 sec
[02:09:11.824] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[02:09:11.824] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0.01 sec
[02:09:11.824] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[02:09:11.824] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[02:09:11.824] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[02:09:11.824] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[02:09:11.824] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[02:09:11.824] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[02:09:11.824] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[02:09:11.824] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[02:09:11.824] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[02:09:11.824] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[02:09:11.824] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[02:09:11.824] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[02:09:11.824] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[02:09:11.824] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[02:09:11.824] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[02:09:11.824] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[02:09:11.824] I [ timer ] Timer: Total node execution : 24.42999978736043 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 17535 traces tagged "gauss"
FrameSaver: q=5.7279e+06 n=417436 tag=gauss
wclsFrameSaver: saving 22617 traces tagged "wiener"
FrameSaver: q=6.08105e+06 n=402887 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 346 XUs and 417 XVs -> 28 XUVs
C:0 T:1 1034 XUs and 760 XVs -> 60 XUVs
C:0 T:2 75 XUs and 93 XVs -> 3 XUVs
C:0 T:3 952 XUs and 836 XVs -> 39 XUVs
C:0 T:4 461 XUs and 684 XVs -> 37 XUVs
C:0 T:5 1397 XUs and 1116 XVs -> 61 XUVs
C:0 T:6 19358 XUs and 20766 XVs -> 1824 XUVs
C:0 T:7 726 XUs and 765 XVs -> 48 XUVs
2100 XUVs total
874 collection wire objects
2100 potential space points
Neighbour search...
107968 tests to find 24194 neighbours
Iterating with no regularization...
Begin: 3.04163e+10
0 2.87631e+10
1 2.86655e+10
2 2.86628e+10
Now with regularization...
Begin: 2.82002e+10
0 2.81992e+10
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Sep-2025 02:09:31 UTC Closed output file "np02vd_raw_run039433_0198_df-s05-d5_dw_0_20250917T233636_reco_stage1_20250918T020931_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 75.9952 106.985 176.506 105.829 22.7436 47
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 5.4414e-05 7.4668e-05 0.000204972 7.1717e-05 2.20194e-05 47
produce:tpcrawdecoder:PDVDTPCReader 12.1005 45.3925 71.1483 44.1942 11.4584 47
produce:triggerrawdecoder:PDVDTriggerReader4 0.330025 0.393035 0.814282 0.36056 0.0811061 47
produce:pdvddaphne:DAPHNEReaderPDVD 4.94387 10.1359 32.4766 9.53453 4.12811 47
produce:ophit:OpHitFinder 0.0255405 0.0386319 0.0489195 0.0387153 0.00389965 47
produce:opflash:OpFlashFinderVerticalDrift 0.000722624 0.0083521 0.0139841 0.0086824 0.00273033 47
produce:wclsdatavd:WireCellToolkit 20.2634 29.9859 51.3879 27.4094 7.04379 47
produce:gaushit:GausHitFinder 0.219861 0.456309 0.892966 0.417694 0.133702 47
produce:nhitsfilter:NumberOfHitsFilter 5.9053e-05 0.000106121 0.000269155 9.8739e-05 4.21446e-05 47
produce:reco3d:SpacePointSolver 1.42696 4.64957 16.6668 4.05896 2.713 47
produce:hitpdune:DisambigFromSpacePoints 0.0188302 0.053452 0.235252 0.0438313 0.0356004 47
produce:pandora:StandardPandora 2.55211 13.5433 71.966 9.76077 12.592 47
produce:pandoraTrack:LArPandoraTrackCreation 0.0631133 0.222955 1.11517 0.171 0.1788 47
produce:pandoraGnocalo:GnocchiCalorimetry 0.00642613 0.012526 0.0210834 0.0124792 0.00367002 47
[art]:TriggerResults:TriggerResultInserter 1.1362e-05 1.65442e-05 4.716e-05 1.579e-05 6.28629e-06 47
end_path:out1:RootOutput 3.216e-06 3.99166e-06 1.7534e-05 3.687e-06 2.01415e-06 47
end_path:out1:RootOutput(write) 1.65423 2.07232 3.94943 1.96905 0.386665 47
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4832.68 MB
Peak resident set size usage (VmHWM): 2857.22 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0198_df-s05-d5_dw_0_20250917T233636_reco_stage1_20250918T020931_keepup.root
\tHists: np02vd_raw_run039433_0198_df-s05-d5_dw_0_20250917T233636_reco_stage1_20250918T020934_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0198_df-s05-d5_dw_0_20250917T233636_reco_stage1_20250918T020931_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0198_df-s05-d5_dw_0_20250917T233636_reco_stage1_20250918T020931_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": 1758161374.0,
"core.end_time": 1758161374.0,
"core.events": [
56831,
56837,
56843,
56849,
56855,
56861,
56867,
56873,
56879,
56885,
56891,
56897,
56903,
56909,
56915,
56921,
56927,
56933,
56939,
56945,
56951,
56957,
56963,
56969,
56975,
56981,
56987,
56993,
56999,
57005,
57011,
57017,
57023,
57029,
57035,
57041,
57047,
57053,
57059,
57065,
57071,
57077,
57083,
57089,
57095,
57101,
57107
],
"core.event_count": 47,
"core.first_event_number": 56831,
"core.last_event_number": 57107,
"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_0198_df-s05-d5_dw_0_20250917T233636.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0198_df-s05-d5_dw_0_20250917T233636_reco_stage1_20250918T020934_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": 1758161374.0,
"core.end_time": 1758161374.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_0198_df-s05-d5_dw_0_20250917T233636.hdf5"
}
]
} 