Jobsub ID 41596.76@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
0> EOS at call=95 anode=0
[07:33:00.067] D [ glue ] <FrameFanin:nfsp> EOS at call=95 with 8
[07:33:00.067] D [ glue ] frame sink sees EOS
[07:33:00.067] D [ pgraph ] <Pgrapher:> graph execution complete
[07:33:00.067] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.32 sec
[07:33:00.067] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.29 sec
[07:33:00.067] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.67 sec
[07:33:00.067] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.39 sec
[07:33:00.067] I [ timer ] Timer: WireCell::Aux::Resampler : 0.17 sec
[07:33:00.067] I [ timer ] Timer: WireCell::Aux::Resampler : 0.16 sec
[07:33:00.067] I [ timer ] Timer: WireCell::Aux::Resampler : 0.16 sec
[07:33:00.067] I [ timer ] Timer: WireCell::Aux::Resampler : 0.15 sec
[07:33:00.067] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[07:33:00.067] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[07:33:00.067] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[07:33:00.067] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[07:33:00.067] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[07:33:00.067] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[07:33:00.067] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[07:33:00.067] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[07:33:00.067] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[07:33:00.067] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[07:33:00.067] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[07:33:00.067] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[07:33:00.067] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[07:33:00.067] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[07:33:00.067] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[07:33:00.067] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[07:33:00.067] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[07:33:00.067] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[07:33:00.067] I [ timer ] Timer: Total node execution : 27.3299995996058 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 27847 traces tagged "gauss"
FrameSaver: q=6.46597e+06 n=657098 tag=gauss
wclsFrameSaver: saving 35640 traces tagged "wiener"
FrameSaver: q=7.07937e+06 n=634377 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 786 XUs and 1384 XVs -> 56 XUVs
C:0 T:1 431 XUs and 510 XVs -> 21 XUVs
C:0 T:2 456 XUs and 629 XVs -> 20 XUVs
C:0 T:3 2006 XUs and 2036 XVs -> 102 XUVs
C:0 T:4 1420 XUs and 1224 XVs -> 87 XUVs
C:0 T:5 756 XUs and 777 XVs -> 56 XUVs
C:0 T:6 4004 XUs and 3863 XVs -> 281 XUVs
C:0 T:7 36822 XUs and 35481 XVs -> 3314 XUVs
3937 XUVs total
1543 collection wire objects
3937 potential space points
Neighbour search...
215149 tests to find 48454 neighbours
Iterating with no regularization...
Begin: 1.05266e+10
0 9.79874e+09
1 9.7265e+09
2 9.72393e+09
Now with regularization...
Begin: 9.62105e+09
0 9.62029e+09
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Sep-2025 07:33:48 BST Closed output file "np02vd_raw_run039433_0312_df-s05-d2_dw_0_20250918T041227_reco_stage1_20250918T063348_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 59.6091 98.4635 282.193 88.4584 35.6596 48
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 6.9685e-05 9.62582e-05 0.000395239 8.4378e-05 4.62001e-05 48
produce:tpcrawdecoder:PDVDTPCReader 20.9957 38.4521 68.9642 36.7391 10.5876 48
produce:triggerrawdecoder:PDVDTriggerReader4 0.310698 0.365287 0.521978 0.350138 0.0536462 48
produce:pdvddaphne:DAPHNEReaderPDVD 3.94234 8.54121 14.303 7.85649 2.29019 48
produce:ophit:OpHitFinder 0.0258217 0.0350783 0.0467915 0.0345575 0.00460446 48
produce:opflash:OpFlashFinderVerticalDrift 0.00402747 0.0082702 0.0123201 0.00828375 0.00208937 48
produce:wclsdatavd:WireCellToolkit 15.9623 23.716 35.9043 20.6905 6.14933 48
produce:gaushit:GausHitFinder 0.15732 0.487122 1.10999 0.466595 0.152219 48
produce:nhitsfilter:NumberOfHitsFilter 7.6435e-05 0.000120796 0.000341728 0.000113322 3.88272e-05 48
produce:reco3d:SpacePointSolver 1.07077 4.39847 19.5828 3.74273 2.84518 48
produce:hitpdune:DisambigFromSpacePoints 0.018258 0.0653295 0.437799 0.0518597 0.0617844 48
produce:pandora:StandardPandora 2.13053 20.1497 198.73 9.75207 31.3462 48
produce:pandoraTrack:LArPandoraTrackCreation 0.0537041 0.255931 1.75163 0.180563 0.264832 48
produce:pandoraGnocalo:GnocchiCalorimetry 0.00322936 0.0118951 0.0269429 0.0112101 0.0046183 48
[art]:TriggerResults:TriggerResultInserter 1.4712e-05 2.49353e-05 6.0321e-05 2.28695e-05 8.66061e-06 48
end_path:out1:RootOutput 3.886e-06 7.40998e-06 2.646e-05 7.125e-06 3.64023e-06 48
end_path:out1:RootOutput(write) 1.33557 1.95869 2.79599 1.93906 0.272661 48
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4580.13 MB
Peak resident set size usage (VmHWM): 2584.71 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0312_df-s05-d2_dw_0_20250918T041227_reco_stage1_20250918T063348_keepup.root
\tHists: np02vd_raw_run039433_0312_df-s05-d2_dw_0_20250918T041227_reco_stage1_20250918T063348_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0312_df-s05-d2_dw_0_20250918T041227_reco_stage1_20250918T063348_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0312_df-s05-d2_dw_0_20250918T041227_reco_stage1_20250918T063348_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": 1758177229.0,
"core.end_time": 1758177229.0,
"core.events": [
89546,
89552,
89558,
89564,
89570,
89576,
89582,
89588,
89594,
89600,
89606,
89612,
89618,
89624,
89630,
89636,
89642,
89648,
89654,
89660,
89666,
89672,
89678,
89684,
89690,
89696,
89702,
89708,
89714,
89720,
89726,
89732,
89738,
89744,
89750,
89756,
89762,
89768,
89774,
89780,
89786,
89792,
89798,
89804,
89810,
89816,
89822,
89828
],
"core.event_count": 48,
"core.first_event_number": 89546,
"core.last_event_number": 89828,
"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_0312_df-s05-d2_dw_0_20250918T041227.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0312_df-s05-d2_dw_0_20250918T041227_reco_stage1_20250918T063348_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": 1758177229.0,
"core.end_time": 1758177229.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_0312_df-s05-d2_dw_0_20250918T041227.hdf5"
}
]
} 