Jobsub ID 40695.5@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
368] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=37 anode=0
[02:20:22.368] D [ glue ] <FrameFanin:nfsp> EOS at call=37 with 8
[02:20:22.368] D [ glue ] frame sink sees EOS
[02:20:22.368] D [ pgraph ] <Pgrapher:> graph execution complete
[02:20:22.369] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.94 sec
[02:20:22.369] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.93 sec
[02:20:22.369] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.91 sec
[02:20:22.369] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.47 sec
[02:20:22.369] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.31 sec
[02:20:22.369] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.96 sec
[02:20:22.369] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.96 sec
[02:20:22.369] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.74 sec
[02:20:22.369] I [ timer ] Timer: WireCell::Aux::Resampler : 1 sec
[02:20:22.369] I [ timer ] Timer: WireCell::Aux::Resampler : 0.89 sec
[02:20:22.369] I [ timer ] Timer: WireCell::Aux::Resampler : 0.88 sec
[02:20:22.369] I [ timer ] Timer: WireCell::Aux::Resampler : 0.87 sec
[02:20:22.369] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[02:20:22.369] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[02:20:22.369] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[02:20:22.369] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[02:20:22.369] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[02:20:22.369] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[02:20:22.369] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[02:20:22.369] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[02:20:22.369] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[02:20:22.369] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[02:20:22.369] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[02:20:22.369] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[02:20:22.369] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[02:20:22.369] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[02:20:22.369] I [ timer ] Timer: Total node execution : 70.9100002516061 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 50546 traces tagged "gauss"
FrameSaver: q=7.66307e+06 n=1031794 tag=gauss
wclsFrameSaver: saving 60817 traces tagged "wiener"
FrameSaver: q=8.02921e+06 n=995428 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 711 XUs and 886 XVs -> 23 XUVs
C:0 T:1 1602 XUs and 1643 XVs -> 62 XUVs
C:0 T:2 710 XUs and 557 XVs -> 52 XUVs
C:0 T:3 328 XUs and 375 XVs -> 10 XUVs
C:0 T:4 1149 XUs and 1211 XVs -> 53 XUVs
C:0 T:5 329 XUs and 521 XVs -> 19 XUVs
C:0 T:6 765 XUs and 1323 XVs -> 37 XUVs
C:0 T:7 1081 XUs and 1582 XVs -> 46 XUVs
C:0 T:8 1044 XUs and 1400 XVs -> 63 XUVs
C:0 T:9 1547 XUs and 1897 XVs -> 95 XUVs
C:0 T:10 1669 XUs and 1306 XVs -> 67 XUVs
C:0 T:11 1646 XUs and 1664 XVs -> 97 XUVs
C:0 T:12 4038 XUs and 1975 XVs -> 214 XUVs
C:0 T:13 1310 XUs and 1392 XVs -> 85 XUVs
C:0 T:14 3664 XUs and 3136 XVs -> 193 XUVs
C:0 T:15 2277 XUs and 1668 XVs -> 155 XUVs
1271 XUVs total
1105 collection wire objects
1271 potential space points
Neighbour search...
9249 tests to find 5024 neighbours
Iterating with no regularization...
Begin: 7.10221e+08
0 6.96285e+08
1 6.96079e+08
Now with regularization...
Begin: 6.91717e+08
0 6.91702e+08
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
17-Sep-2025 02:21:47 CEST Closed output file "np02vd_raw_run039388_0258_df-s05-d3_dw_0_20250916T183706_reco_stage1_20250917T002147_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 105.184 181.373 295.087 163.14 50.315 19
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 8.7533e-05 0.000132633 0.000426968 0.00011191 7.32726e-05 19
produce:tpcrawdecoder:PDVDTPCReader 8.21604 9.24012 10.7457 8.96766 0.77234 19
produce:triggerrawdecoder:PDVDTriggerReader4 0.0490377 0.0580775 0.0981868 0.053564 0.0112723 19
produce:pdvddaphne:DAPHNEReaderPDVD 0.000289079 0.000481864 0.00135132 0.000423843 0.00026952 19
produce:ophit:OpHitFinder 0.000150629 0.000351514 0.00135115 0.000245362 0.00028255 19
produce:opflash:OpFlashFinderVerticalDrift 4.6521e-05 0.000119127 0.000492478 9.2721e-05 0.000101216 19
produce:wclsdatavd:WireCellToolkit 62.7189 79.0116 97.0121 78.7593 7.65643 19
produce:gaushit:GausHitFinder 0.861806 1.64018 2.55507 1.53991 0.448391 19
produce:nhitsfilter:NumberOfHitsFilter 0.000232333 0.000731173 0.00280279 0.000544037 0.00062397 19
produce:reco3d:SpacePointSolver 8.26615 16.7606 30.7038 15.036 6.31241 19
produce:hitpdune:DisambigFromSpacePoints 0.115074 0.279408 0.519465 0.258773 0.114124 19
produce:pandora:StandardPandora 18.0399 65.8523 160.127 58.3679 38.2283 19
produce:pandoraTrack:LArPandoraTrackCreation 0.464451 2.47461 6.39777 1.56569 1.73982 19
produce:pandoraGnocalo:GnocchiCalorimetry 0.0269506 0.049048 0.0860267 0.0412715 0.0173472 19
[art]:TriggerResults:TriggerResultInserter 3.5264e-05 7.65703e-05 0.000185412 6.6271e-05 3.23789e-05 19
end_path:out1:RootOutput 1.1337e-05 2.25457e-05 6.1363e-05 1.8598e-05 1.17185e-05 19
end_path:out1:RootOutput(write) 5.52996 5.91085 6.58019 5.87761 0.280011 19
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4836.27 MB
Peak resident set size usage (VmHWM): 2904.54 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039388_0258_df-s05-d3_dw_0_20250916T183706_reco_stage1_20250917T002147_keepup.root
\tHists: np02vd_raw_run039388_0258_df-s05-d3_dw_0_20250916T183706_reco_stage1_20250917T002147_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039388_0258_df-s05-d3_dw_0_20250916T183706_reco_stage1_20250917T002147_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039388_0258_df-s05-d3_dw_0_20250916T183706_reco_stage1_20250917T002147_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": 1758068508.0,
"core.end_time": 1758068508.0,
"core.events": [
19891,
19895,
19899,
19903,
19907,
19911,
19915,
19919,
19923,
19927,
19931,
19935,
19939,
19943,
19947,
19951,
19955,
19959,
19963
],
"core.event_count": 19,
"core.first_event_number": 19891,
"core.last_event_number": 19963,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39388
],
"core.runs_subruns": [
3938800001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039388_0258_df-s05-d3_dw_0_20250916T183706.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039388_0258_df-s05-d3_dw_0_20250916T183706_reco_stage1_20250917T002147_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": 1758068508.0,
"core.end_time": 1758068508.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39388
],
"core.runs_subruns": [
3938800001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039388_0258_df-s05-d3_dw_0_20250916T183706.hdf5"
}
]
} 