Jobsub ID 47409.61@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
rameFanin:nfsp> EOS at call=37 with 8
[10:40:12.935] D [ glue ] frame sink sees EOS
[10:40:12.935] D [ pgraph ] <Pgrapher:> graph execution complete
[10:40:12.935] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.04 sec
[10:40:12.935] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.03 sec
[10:40:12.935] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.71 sec
[10:40:12.935] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.43 sec
[10:40:12.935] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.06 sec
[10:40:12.935] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.93 sec
[10:40:12.935] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.8 sec
[10:40:12.935] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.38 sec
[10:40:12.935] I [ timer ] Timer: WireCell::Aux::Resampler : 0.73 sec
[10:40:12.935] I [ timer ] Timer: WireCell::Aux::Resampler : 0.7 sec
[10:40:12.935] I [ timer ] Timer: WireCell::Aux::Resampler : 0.68 sec
[10:40:12.935] I [ timer ] Timer: WireCell::Aux::Resampler : 0.65 sec
[10:40:12.935] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.03 sec
[10:40:12.935] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[10:40:12.935] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[10:40:12.935] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[10:40:12.935] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[10:40:12.935] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:40:12.935] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:40:12.935] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:40:12.935] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[10:40:12.935] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:40:12.935] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:40:12.935] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[10:40:12.935] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[10:40:12.935] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[10:40:12.935] I [ timer ] Timer: Total node execution : 61.209999626502395 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 59074 traces tagged "gauss"
FrameSaver: q=9.91634e+06 n=1271948 tag=gauss
wclsFrameSaver: saving 71494 traces tagged "wiener"
FrameSaver: q=1.03613e+07 n=1223270 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 662 XUs and 680 XVs -> 56 XUVs
C:0 T:1 528 XUs and 594 XVs -> 21 XUVs
C:0 T:2 912 XUs and 1035 XVs -> 52 XUVs
C:0 T:3 1517 XUs and 1620 XVs -> 51 XUVs
C:0 T:4 1623 XUs and 1916 XVs -> 125 XUVs
C:0 T:5 934 XUs and 819 XVs -> 50 XUVs
C:0 T:6 713 XUs and 904 XVs -> 21 XUVs
C:0 T:7 1471 XUs and 1475 XVs -> 60 XUVs
C:0 T:8 3173 XUs and 3463 XVs -> 185 XUVs
C:0 T:9 1440 XUs and 1823 XVs -> 94 XUVs
C:0 T:10 666 XUs and 853 XVs -> 49 XUVs
C:0 T:11 3583 XUs and 3399 XVs -> 158 XUVs
C:0 T:12 2646 XUs and 3018 XVs -> 131 XUVs
C:0 T:13 2946 XUs and 3070 XVs -> 145 XUVs
C:0 T:14 4896 XUs and 5184 XVs -> 330 XUVs
C:0 T:15 1244 XUs and 632 XVs -> 65 XUVs
1593 XUVs total
1361 collection wire objects
1593 potential space points
Neighbour search...
12463 tests to find 5938 neighbours
Iterating with no regularization...
Begin: 5.57015e+08
0 5.45133e+08
1 5.44662e+08
Now with regularization...
Begin: 5.38385e+08
0 5.38374e+08
TestBeamParticleCreationAlgorithm::SetupTestBeamVertex - Test beam particle has no initial vertex
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
17-Sep-2025 10:41:32 UTC Closed output file "np02vd_raw_run039388_0515_df-s05-d1_dw_0_20250917T000253_reco_stage1_20250917T104132_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 253.066 359.964 508.889 337.408 72.0976 19
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 6.4793e-05 9.00325e-05 0.000191675 7.4081e-05 3.19638e-05 19
produce:tpcrawdecoder:PDVDTPCReader 161.157 231.98 367.757 202.288 66.9835 19
produce:triggerrawdecoder:PDVDTriggerReader4 0.336955 0.529531 1.19986 0.45659 0.209757 19
produce:pdvddaphne:DAPHNEReaderPDVD 0.000225209 0.000380346 0.000991689 0.000335008 0.000159884 19
produce:ophit:OpHitFinder 0.000122945 0.000290311 0.00116716 0.000217665 0.000232296 19
produce:opflash:OpFlashFinderVerticalDrift 4.5326e-05 9.50808e-05 0.000513528 6.7138e-05 0.0001009 19
produce:wclsdatavd:WireCellToolkit 53.0823 58.9198 69.6626 57.9889 4.51447 19
produce:gaushit:GausHitFinder 0.669417 1.12316 1.76272 1.09719 0.271704 19
produce:nhitsfilter:NumberOfHitsFilter 0.000232362 0.000359537 0.00056711 0.000347481 9.6268e-05 19
produce:reco3d:SpacePointSolver 7.65842 13.786 23.7275 13.7128 4.19681 19
produce:hitpdune:DisambigFromSpacePoints 0.0927546 0.175859 0.397462 0.167136 0.0685378 19
produce:pandora:StandardPandora 14.3537 46.8893 136.105 39.1163 30.1522 19
produce:pandoraTrack:LArPandoraTrackCreation 0.414681 0.91723 2.34838 0.914283 0.408852 19
produce:pandoraGnocalo:GnocchiCalorimetry 0.0162737 0.0271026 0.0437184 0.0270606 0.00653047 19
[art]:TriggerResults:TriggerResultInserter 2.2973e-05 3.23e-05 8.3129e-05 2.9266e-05 1.3078e-05 19
end_path:out1:RootOutput 4.589e-06 8.84253e-06 2.8294e-05 8.075e-06 4.86403e-06 19
end_path:out1:RootOutput(write) 4.25672 5.58057 20.0766 4.64207 3.47921 19
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4736.5 MB
Peak resident set size usage (VmHWM): 2770.53 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039388_0515_df-s05-d1_dw_0_20250917T000253_reco_stage1_20250917T104132_keepup.root
\tHists: np02vd_raw_run039388_0515_df-s05-d1_dw_0_20250917T000253_reco_stage1_20250917T104134_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039388_0515_df-s05-d1_dw_0_20250917T000253_reco_stage1_20250917T104132_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039388_0515_df-s05-d1_dw_0_20250917T000253_reco_stage1_20250917T104132_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": 1758105694.0,
"core.end_time": 1758105694.0,
"core.events": [
39701,
39705,
39709,
39713,
39717,
39721,
39725,
39729,
39733,
39737,
39741,
39745,
39749,
39753,
39757,
39761,
39765,
39769,
39773
],
"core.event_count": 19,
"core.first_event_number": 39701,
"core.last_event_number": 39773,
"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_0515_df-s05-d1_dw_0_20250917T000253.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039388_0515_df-s05-d1_dw_0_20250917T000253_reco_stage1_20250917T104134_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": 1758105694.0,
"core.end_time": 1758105694.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_0515_df-s05-d1_dw_0_20250917T000253.hdf5"
}
]
} 