Jobsub ID 47203.173@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
nibusSigProc:anode0sigproc0> EOS at call=37 anode=0
[02:21:23.286] D [ glue ] <FrameFanin:nfsp> EOS at call=37 with 8
[02:21:23.286] D [ glue ] frame sink sees EOS
[02:21:23.287] D [ pgraph ] <Pgrapher:> graph execution complete
[02:21:23.287] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 16.8 sec
[02:21:23.287] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 15.24 sec
[02:21:23.287] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 15.13 sec
[02:21:23.287] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 15.12 sec
[02:21:23.287] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 15.05 sec
[02:21:23.287] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.98 sec
[02:21:23.287] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.48 sec
[02:21:23.287] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 13.18 sec
[02:21:23.287] I [ timer ] Timer: WireCell::Aux::Resampler : 1.93 sec
[02:21:23.287] I [ timer ] Timer: WireCell::Aux::Resampler : 1.92 sec
[02:21:23.287] I [ timer ] Timer: WireCell::Aux::Resampler : 1.84 sec
[02:21:23.287] I [ timer ] Timer: WireCell::Aux::Resampler : 1.83 sec
[02:21:23.287] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.04 sec
[02:21:23.287] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[02:21:23.287] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[02:21:23.287] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[02:21:23.287] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[02:21:23.287] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[02:21:23.287] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[02:21:23.287] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[02:21:23.287] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[02:21:23.287] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[02:21:23.287] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[02:21:23.287] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[02:21:23.287] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[02:21:23.287] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[02:21:23.287] I [ timer ] Timer: Total node execution : 127.61999856680632 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 49913 traces tagged "gauss"
FrameSaver: q=7.72205e+06 n=1014175 tag=gauss
wclsFrameSaver: saving 60973 traces tagged "wiener"
FrameSaver: q=8.12667e+06 n=975490 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 2537 XUs and 2257 XVs -> 170 XUVs
C:0 T:1 1746 XUs and 1497 XVs -> 80 XUVs
C:0 T:2 2538 XUs and 2265 XVs -> 170 XUVs
C:0 T:3 683 XUs and 631 XVs -> 27 XUVs
C:0 T:4 1146 XUs and 837 XVs -> 43 XUVs
C:0 T:5 1770 XUs and 1409 XVs -> 74 XUVs
C:0 T:6 693 XUs and 673 XVs -> 34 XUVs
C:0 T:7 782 XUs and 638 XVs -> 37 XUVs
C:0 T:8 1024 XUs and 1543 XVs -> 70 XUVs
C:0 T:9 1521 XUs and 1140 XVs -> 60 XUVs
C:0 T:10 2447 XUs and 3223 XVs -> 173 XUVs
C:0 T:11 1991 XUs and 1828 XVs -> 70 XUVs
C:0 T:12 276 XUs and 319 XVs -> 22 XUVs
C:0 T:13 2599 XUs and 2511 XVs -> 133 XUVs
C:0 T:14 831 XUs and 825 XVs -> 41 XUVs
C:0 T:15 1869 XUs and 2255 XVs -> 91 XUVs
1295 XUVs total
1134 collection wire objects
1295 potential space points
Neighbour search...
10659 tests to find 4604 neighbours
Iterating with no regularization...
Begin: 4.88319e+08
0 4.79065e+08
1 4.78909e+08
Now with regularization...
Begin: 4.73718e+08
0 4.73712e+08
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
17-Sep-2025 02:23:38 CEST Closed output file "np02vd_raw_run039388_0407_df-s05-d2_dw_0_20250916T214608_reco_stage1_20250917T002338_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 219.701 276.943 405.295 261.74 53.6234 19
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 8.379e-05 0.000146339 0.000567033 0.000119657 0.000102309 19
produce:tpcrawdecoder:PDVDTPCReader 8.75264 10.1146 11.4132 10.0921 0.842481 19
produce:triggerrawdecoder:PDVDTriggerReader4 0.00612944 0.0180596 0.0637853 0.0111578 0.0155954 19
produce:pdvddaphne:DAPHNEReaderPDVD 0.000384998 0.000616473 0.0010287 0.000582889 0.000164229 19
produce:ophit:OpHitFinder 0.000166563 0.000396864 0.00122436 0.000313096 0.000270046 19
produce:opflash:OpFlashFinderVerticalDrift 5.8288e-05 0.000114095 0.000463171 9.4803e-05 8.50036e-05 19
produce:wclsdatavd:WireCellToolkit 98.4226 133.112 173.36 128.797 20.2047 19
produce:gaushit:GausHitFinder 1.57376 2.58557 3.78826 2.52321 0.581568 19
produce:nhitsfilter:NumberOfHitsFilter 0.000408672 0.000639523 0.00103583 0.000651209 0.000139705 19
produce:reco3d:SpacePointSolver 12.7469 21.0717 28.8573 21.8191 4.67617 19
produce:hitpdune:DisambigFromSpacePoints 0.247194 0.432284 0.669787 0.444478 0.124499 19
produce:pandora:StandardPandora 50.3979 97.487 207.122 87.8338 36.7392 19
produce:pandoraTrack:LArPandoraTrackCreation 0.871986 3.34598 6.81377 3.16482 1.45419 19
produce:pandoraGnocalo:GnocchiCalorimetry 0.0302535 0.0605688 0.0904053 0.063133 0.0160512 19
[art]:TriggerResults:TriggerResultInserter 3.1142e-05 6.00101e-05 0.000157558 5.4175e-05 2.71316e-05 19
end_path:out1:RootOutput 4.812e-06 1.30379e-05 5.285e-05 1.0934e-05 1.0027e-05 19
end_path:out1:RootOutput(write) 6.15676 8.65083 9.85485 8.94716 1.10183 19
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4682.28 MB
Peak resident set size usage (VmHWM): 2763.03 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039388_0407_df-s05-d2_dw_0_20250916T214608_reco_stage1_20250917T002338_keepup.root
\tHists: np02vd_raw_run039388_0407_df-s05-d2_dw_0_20250916T214608_reco_stage1_20250917T002338_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039388_0407_df-s05-d2_dw_0_20250916T214608_reco_stage1_20250917T002338_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039388_0407_df-s05-d2_dw_0_20250916T214608_reco_stage1_20250917T002338_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": 1758068619.0,
"core.end_time": 1758068619.0,
"core.events": [
31354,
31358,
31362,
31366,
31370,
31374,
31378,
31382,
31386,
31390,
31394,
31398,
31402,
31406,
31410,
31414,
31418,
31422,
31426
],
"core.event_count": 19,
"core.first_event_number": 31354,
"core.last_event_number": 31426,
"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_0407_df-s05-d2_dw_0_20250916T214608.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039388_0407_df-s05-d2_dw_0_20250916T214608_reco_stage1_20250917T002338_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": 1758068619.0,
"core.end_time": 1758068619.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_0407_df-s05-d2_dw_0_20250916T214608.hdf5"
}
]
} 