Jobsub ID 47409.170@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
OS at call=18
[10:10:04.376] D [ aux ] <Resampler:resmp0> EOS at call=37
[10:10:04.376] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=37 anode=0
[10:10:04.376] D [ glue ] <FrameFanin:nfsp> EOS at call=37 with 8
[10:10:04.376] D [ glue ] frame sink sees EOS
[10:10:04.376] D [ pgraph ] <Pgrapher:> graph execution complete
[10:10:04.376] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.32 sec
[10:10:04.376] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.86 sec
[10:10:04.376] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.75 sec
[10:10:04.376] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.06 sec
[10:10:04.376] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.01 sec
[10:10:04.376] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.93 sec
[10:10:04.376] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.35 sec
[10:10:04.376] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.68 sec
[10:10:04.376] I [ timer ] Timer: WireCell::Aux::Resampler : 1.56 sec
[10:10:04.376] I [ timer ] Timer: WireCell::Aux::Resampler : 1.56 sec
[10:10:04.376] I [ timer ] Timer: WireCell::Aux::Resampler : 1.55 sec
[10:10:04.376] I [ timer ] Timer: WireCell::Aux::Resampler : 1.45 sec
[10:10:04.376] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[10:10:04.376] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[10:10:04.376] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[10:10:04.376] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[10:10:04.377] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:10:04.377] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:10:04.377] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:10:04.377] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:10:04.377] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[10:10:04.377] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:10:04.377] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[10:10:04.377] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[10:10:04.377] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[10:10:04.377] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[10:10:04.377] I [ timer ] Timer: Total node execution : 87.13000087626278 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 40606 traces tagged "gauss"
FrameSaver: q=5.34837e+06 n=768735 tag=gauss
wclsFrameSaver: saving 49490 traces tagged "wiener"
FrameSaver: q=5.65942e+06 n=729747 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 797 XUs and 1108 XVs -> 34 XUVs
C:0 T:1 593 XUs and 644 XVs -> 44 XUVs
C:0 T:2 1854 XUs and 1214 XVs -> 67 XUVs
C:0 T:3 1037 XUs and 1930 XVs -> 40 XUVs
C:0 T:4 1217 XUs and 1520 XVs -> 81 XUVs
C:0 T:5 280 XUs and 347 XVs -> 19 XUVs
C:0 T:6 1758 XUs and 1668 XVs -> 92 XUVs
C:0 T:7 300 XUs and 647 XVs -> 23 XUVs
C:0 T:8 1419 XUs and 2492 XVs -> 118 XUVs
C:0 T:9 746 XUs and 1130 XVs -> 73 XUVs
C:0 T:10 995 XUs and 970 XVs -> 64 XUVs
C:0 T:11 1175 XUs and 1428 XVs -> 62 XUVs
C:0 T:12 386 XUs and 469 XVs -> 41 XUVs
C:0 T:13 707 XUs and 941 XVs -> 65 XUVs
C:0 T:14 415 XUs and 697 XVs -> 60 XUVs
C:0 T:15 509 XUs and 882 XVs -> 83 XUVs
966 XUVs total
867 collection wire objects
966 potential space points
Neighbour search...
6204 tests to find 3132 neighbours
Iterating with no regularization...
Begin: 1.97525e+08
0 1.93129e+08
1 1.931e+08
Now with regularization...
Begin: 1.89428e+08
0 1.89426e+08
17-Sep-2025 10:11:04 UTC Closed output file "np02vd_raw_run039388_0573_df-s05-d1_dw_0_20250917T011615_reco_stage1_20250917T101104_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 161.496 237.773 321.698 234.244 48.5586 19
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 9.0031e-05 0.000137044 0.000292203 0.000113461 5.21825e-05 19
produce:tpcrawdecoder:PDVDTPCReader 19.4018 20.3565 22.5948 20.2499 0.83152 19
produce:triggerrawdecoder:PDVDTriggerReader4 0.390519 0.404761 0.47321 0.396944 0.0194801 19
produce:pdvddaphne:DAPHNEReaderPDVD 0.000332083 0.000439193 0.00121929 0.000400834 0.000188831 19
produce:ophit:OpHitFinder 0.000145882 0.000397783 0.00163644 0.000290313 0.00034526 19
produce:opflash:OpFlashFinderVerticalDrift 5.9171e-05 0.000113785 0.000639706 7.8131e-05 0.000125777 19
produce:wclsdatavd:WireCellToolkit 81.9672 99.3529 132.423 95.4586 12.699 19
produce:gaushit:GausHitFinder 1.15536 1.93864 2.54665 1.93055 0.396094 19
produce:nhitsfilter:NumberOfHitsFilter 0.000306243 0.000490443 0.000854219 0.000481955 0.000116231 19
produce:reco3d:SpacePointSolver 8.47082 19.7251 30.3099 18.7292 5.59518 19
produce:hitpdune:DisambigFromSpacePoints 0.133361 0.290807 0.453463 0.287081 0.081332 19
produce:pandora:StandardPandora 33.4284 86.4303 150.49 77.9373 37.168 19
produce:pandoraTrack:LArPandoraTrackCreation 0.691926 1.79554 3.16224 1.84272 0.611836 19
produce:pandoraGnocalo:GnocchiCalorimetry 0.0340638 0.053852 0.0739906 0.0529269 0.010205 19
[art]:TriggerResults:TriggerResultInserter 2.804e-05 6.38133e-05 0.000168492 5.2041e-05 3.0336e-05 19
end_path:out1:RootOutput 4.71e-06 1.41207e-05 4.3871e-05 1.118e-05 8.6959e-06 19
end_path:out1:RootOutput(write) 6.26447 7.37188 8.12183 7.44045 0.476438 19
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4803.01 MB
Peak resident set size usage (VmHWM): 2724.23 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039388_0573_df-s05-d1_dw_0_20250917T011615_reco_stage1_20250917T101104_keepup.root
\tHists: np02vd_raw_run039388_0573_df-s05-d1_dw_0_20250917T011615_reco_stage1_20250917T101104_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039388_0573_df-s05-d1_dw_0_20250917T011615_reco_stage1_20250917T101104_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039388_0573_df-s05-d1_dw_0_20250917T011615_reco_stage1_20250917T101104_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": 1758103865.0,
"core.end_time": 1758103865.0,
"core.events": [
44141,
44145,
44149,
44153,
44157,
44161,
44165,
44169,
44173,
44177,
44181,
44185,
44189,
44193,
44197,
44201,
44205,
44209,
44213
],
"core.event_count": 19,
"core.first_event_number": 44141,
"core.last_event_number": 44213,
"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_0573_df-s05-d1_dw_0_20250917T011615.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039388_0573_df-s05-d1_dw_0_20250917T011615_reco_stage1_20250917T101104_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": 1758103865.0,
"core.end_time": 1758103865.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_0573_df-s05-d1_dw_0_20250917T011615.hdf5"
}
]
} 