Jobsub ID 44835.142@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
ibusSigProc:anode0sigproc0> EOS at call=35 anode=0
[14:02:13.057] D [ glue ] <FrameFanin:nfsp> EOS at call=35 with 8
[14:02:13.057] D [ glue ] frame sink sees EOS
[14:02:13.057] D [ pgraph ] <Pgrapher:> graph execution complete
[14:02:13.057] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.35 sec
[14:02:13.057] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.24 sec
[14:02:13.057] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.25 sec
[14:02:13.057] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.37 sec
[14:02:13.057] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.37 sec
[14:02:13.057] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.25 sec
[14:02:13.057] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.76 sec
[14:02:13.057] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.63 sec
[14:02:13.057] I [ timer ] Timer: WireCell::Aux::Resampler : 0.65 sec
[14:02:13.057] I [ timer ] Timer: WireCell::Aux::Resampler : 0.64 sec
[14:02:13.057] I [ timer ] Timer: WireCell::Aux::Resampler : 0.6 sec
[14:02:13.057] I [ timer ] Timer: WireCell::Aux::Resampler : 0.6 sec
[14:02:13.057] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[14:02:13.057] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[14:02:13.057] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[14:02:13.057] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0.01 sec
[14:02:13.057] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:02:13.057] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:02:13.057] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:02:13.057] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:02:13.057] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[14:02:13.057] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:02:13.057] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:02:13.057] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[14:02:13.057] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[14:02:13.057] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[14:02:13.057] I [ timer ] Timer: Total node execution : 56.760000275447965 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 60305 traces tagged "gauss"
FrameSaver: q=1.10899e+07 n=1345686 tag=gauss
wclsFrameSaver: saving 74865 traces tagged "wiener"
FrameSaver: q=1.17611e+07 n=1288877 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 179 XUs and 205 XVs -> 3 XUVs
C:0 T:1 333 XUs and 466 XVs -> 15 XUVs
C:0 T:2 607 XUs and 517 XVs -> 21 XUVs
C:0 T:3 740 XUs and 551 XVs -> 15 XUVs
C:0 T:4 1465 XUs and 2730 XVs -> 163 XUVs
C:0 T:5 503 XUs and 706 XVs -> 14 XUVs
C:0 T:6 383 XUs and 648 XVs -> 35 XUVs
C:0 T:7 2039 XUs and 2470 XVs -> 102 XUVs
C:0 T:8 17974 XUs and 41861 XVs -> 5970 XUVs
C:0 T:9 7778 XUs and 9204 XVs -> 1538 XUVs
C:0 T:10 4593 XUs and 6341 XVs -> 898 XUVs
C:0 T:11 2009 XUs and 2806 XVs -> 317 XUVs
C:0 T:12 14559 XUs and 16988 XVs -> 1234 XUVs
C:0 T:13 2719 XUs and 2587 XVs -> 146 XUVs
C:0 T:14 1701 XUs and 1666 XVs -> 123 XUVs
C:0 T:15 11141 XUs and 10390 XVs -> 1992 XUVs
12586 XUVs total
2475 collection wire objects
12586 potential space points
Neighbour search...
1570828 tests to find 666572 neighbours
Iterating with no regularization...
Begin: 1.08897e+09
0 1.00338e+09
1 9.9847e+08
2 9.9775e+08
Now with regularization...
Begin: 9.83931e+08
0 9.8356e+08
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
11-Sep-2025 14:04:12 CEST Closed output file "np02vd_raw_run039273_0091_df-s02-d0_dw_0_20250831T105325_reco_stage1_20250911T120412_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 90.9332 168.691 256.516 174.498 50.1008 18
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 4.3251e-05 6.34929e-05 9.9281e-05 5.21855e-05 1.92334e-05 18
produce:tpcrawdecoder:PDVDTPCReader 5.3498 6.15819 7.28787 6.15168 0.529126 18
produce:triggerrawdecoder:PDVDTriggerReader4 0.000832688 0.00223997 0.0100031 0.00114823 0.00232204 18
produce:pdvddaphne:DAPHNEReaderPDVD 2.55586 3.26651 3.86169 3.345 0.397114 18
produce:ophit:OpHitFinder 0.0303319 0.0397767 0.0523595 0.038197 0.00707445 18
produce:opflash:OpFlashFinderVerticalDrift 0.00694029 0.00982215 0.0169297 0.00875777 0.00290408 18
produce:wclsdatavd:WireCellToolkit 46.9353 55.0357 62.72 57.2729 4.65709 18
produce:gaushit:GausHitFinder 0.688659 1.19717 1.50601 1.25581 0.251187 18
produce:nhitsfilter:NumberOfHitsFilter 0.000186582 0.000284465 0.000424745 0.000293708 6.56226e-05 18
produce:reco3d:SpacePointSolver 8.65416 17.4676 26.0277 18.5486 5.1954 18
produce:hitpdune:DisambigFromSpacePoints 0.0916943 0.261086 0.406032 0.293943 0.098552 18
produce:pandora:StandardPandora 17.8995 79.8298 154.438 80.528 41.2326 18
produce:pandoraTrack:LArPandoraTrackCreation 0.509213 1.15545 1.94358 1.14599 0.395475 18
produce:pandoraGnocalo:GnocchiCalorimetry 0.0188174 0.0287375 0.0384187 0.0288714 0.0057426 18
[art]:TriggerResults:TriggerResultInserter 1.656e-05 2.29123e-05 4.205e-05 2.0885e-05 6.6011e-06 18
end_path:out1:RootOutput 6.04e-06 9.17128e-06 2.3451e-05 7.46e-06 5.11933e-06 18
end_path:out1:RootOutput(write) 3.79434 4.20786 4.51808 4.26283 0.235269 18
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5269.53 MB
Peak resident set size usage (VmHWM): 3285.91 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039273_0091_df-s02-d0_dw_0_20250831T105325_reco_stage1_20250911T120412_keepup.root
\tHists: np02vd_raw_run039273_0091_df-s02-d0_dw_0_20250831T105325_reco_stage1_20250911T120412_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039273_0091_df-s02-d0_dw_0_20250831T105325_reco_stage1_20250911T120412_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039273_0091_df-s02-d0_dw_0_20250831T105325_reco_stage1_20250911T120412_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": 1757592252.0,
"core.end_time": 1757592252.0,
"core.events": [
32762,
32782,
32802,
32822,
32842,
32862,
32882,
32902,
32922,
32942,
32962,
32982,
33002,
33022,
33042,
33062,
33082,
33102
],
"core.event_count": 18,
"core.first_event_number": 32762,
"core.last_event_number": 33102,
"core.data_stream": "physics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39273
],
"core.runs_subruns": [
3927300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039273_0091_df-s02-d0_dw_0_20250831T105325.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039273_0091_df-s02-d0_dw_0_20250831T105325_reco_stage1_20250911T120412_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": 1757592252.0,
"core.end_time": 1757592252.0,
"core.data_stream": "physics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39273
],
"core.runs_subruns": [
3927300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039273_0091_df-s02-d0_dw_0_20250831T105325.hdf5"
}
]
} 