Jobsub ID 41739.116@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
3 anode=0
[12:15:30.338] D [ glue ] <FrameFanin:nfsp> EOS at call=93 with 8
[12:15:30.338] D [ glue ] frame sink sees EOS
[12:15:30.338] D [ pgraph ] <Pgrapher:> graph execution complete
[12:15:30.338] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.54 sec
[12:15:30.338] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.37 sec
[12:15:30.338] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5 sec
[12:15:30.338] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 4.83 sec
[12:15:30.338] I [ timer ] Timer: WireCell::Aux::Resampler : 0.29 sec
[12:15:30.338] I [ timer ] Timer: WireCell::Aux::Resampler : 0.27 sec
[12:15:30.338] I [ timer ] Timer: WireCell::Aux::Resampler : 0.26 sec
[12:15:30.338] I [ timer ] Timer: WireCell::Aux::Resampler : 0.26 sec
[12:15:30.338] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[12:15:30.338] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[12:15:30.338] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:15:30.338] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:15:30.338] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[12:15:30.338] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:15:30.338] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:15:30.338] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:15:30.338] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[12:15:30.338] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:15:30.338] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[12:15:30.338] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:15:30.338] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[12:15:30.338] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[12:15:30.338] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[12:15:30.338] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[12:15:30.338] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[12:15:30.338] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[12:15:30.338] I [ timer ] Timer: Total node execution : 22.829999754205346 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 16655 traces tagged "gauss"
FrameSaver: q=3.1649e+06 n=387152 tag=gauss
wclsFrameSaver: saving 21239 traces tagged "wiener"
FrameSaver: q=3.35983e+06 n=373119 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 3444 XUs and 4321 XVs -> 204 XUVs
C:0 T:1 7997 XUs and 10890 XVs -> 593 XUVs
C:0 T:2 460 XUs and 568 XVs -> 27 XUVs
C:0 T:3 686 XUs and 1182 XVs -> 98 XUVs
C:0 T:4 363 XUs and 537 XVs -> 60 XUVs
C:0 T:5 39 XUs and 43 XVs -> 2 XUVs
C:0 T:6 20 XUs and 28 XVs -> 1 XUVs
C:0 T:7 605 XUs and 691 XVs -> 15 XUVs
1000 XUVs total
670 collection wire objects
1000 potential space points
Neighbour search...
24804 tests to find 8472 neighbours
Iterating with no regularization...
Begin: 4.55804e+08
0 4.4176e+08
1 4.41099e+08
2 4.41087e+08
Now with regularization...
Begin: 4.33455e+08
0 4.33445e+08
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Sep-2025 12:15:45 CEST Closed output file "np02vd_raw_run039433_0391_df-s05-d3_dw_0_20250918T072523_reco_stage1_20250918T101545_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 43.9102 150.105 1700.55 59.2593 310.158 47
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 5.6581e-05 8.4755e-05 0.000228027 8.0882e-05 2.30397e-05 47
produce:tpcrawdecoder:PDVDTPCReader 9.86032 22.9321 391.867 10.346 56.3765 47
produce:triggerrawdecoder:PDVDTriggerReader4 0.572585 0.603978 1.20797 0.576445 0.10824 47
produce:pdvddaphne:DAPHNEReaderPDVD 2.60033 6.76528 129.357 3.16179 18.4068 47
produce:ophit:OpHitFinder 0.0258391 0.0408543 0.0675165 0.0390575 0.00921365 47
produce:opflash:OpFlashFinderVerticalDrift 0.00343249 0.00934213 0.0203868 0.00839634 0.0035089 47
produce:wclsdatavd:WireCellToolkit 20.5713 70.1148 1158.04 24.3315 187.331 47
produce:gaushit:GausHitFinder 0.278443 0.560858 1.84604 0.498269 0.254194 47
produce:nhitsfilter:NumberOfHitsFilter 6.4032e-05 0.000171856 0.000820954 0.000133644 0.000139436 47
produce:reco3d:SpacePointSolver 1.72265 7.35569 130.078 4.02908 18.5245 47
produce:hitpdune:DisambigFromSpacePoints 0.0149223 0.0711891 0.600384 0.0456004 0.0877519 47
produce:pandora:StandardPandora 2.68036 39.3476 951.549 10.9328 139.438 47
produce:pandoraTrack:LArPandoraTrackCreation 0.0537153 0.301517 3.4735 0.172562 0.48972 47
produce:pandoraGnocalo:GnocchiCalorimetry 0.00529863 0.0134885 0.0316987 0.0123276 0.00560737 47
[art]:TriggerResults:TriggerResultInserter 1.269e-05 2.07257e-05 6.9922e-05 1.7321e-05 1.04702e-05 47
end_path:out1:RootOutput 3.27e-06 4.68902e-06 2.9631e-05 4.02e-06 3.724e-06 47
end_path:out1:RootOutput(write) 1.5561 1.96995 2.88759 1.8485 0.31445 47
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4304.63 MB
Peak resident set size usage (VmHWM): 2389.82 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0391_df-s05-d3_dw_0_20250918T072523_reco_stage1_20250918T101545_keepup.root
\tHists: np02vd_raw_run039433_0391_df-s05-d3_dw_0_20250918T072523_reco_stage1_20250918T101545_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0391_df-s05-d3_dw_0_20250918T072523_reco_stage1_20250918T101545_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0391_df-s05-d3_dw_0_20250918T072523_reco_stage1_20250918T101545_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": 1758190546.0,
"core.end_time": 1758190546.0,
"core.events": [
112293,
112299,
112305,
112311,
112317,
112323,
112329,
112335,
112341,
112347,
112353,
112359,
112365,
112371,
112377,
112383,
112389,
112395,
112401,
112407,
112413,
112419,
112425,
112431,
112437,
112443,
112449,
112455,
112461,
112467,
112473,
112479,
112485,
112491,
112497,
112503,
112509,
112515,
112521,
112527,
112533,
112539,
112545,
112551,
112557,
112563,
112569
],
"core.event_count": 47,
"core.first_event_number": 112293,
"core.last_event_number": 112569,
"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_0391_df-s05-d3_dw_0_20250918T072523.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0391_df-s05-d3_dw_0_20250918T072523_reco_stage1_20250918T101545_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": 1758190546.0,
"core.end_time": 1758190546.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_0391_df-s05-d3_dw_0_20250918T072523.hdf5"
}
]
} 