Jobsub ID 38128.85@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
r:resmp0> EOS at call=35
[13:59:49.816] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=35 anode=0
[13:59:49.816] D [ glue ] <FrameFanin:nfsp> EOS at call=35 with 8
[13:59:49.816] D [ glue ] frame sink sees EOS
[13:59:49.816] D [ pgraph ] <Pgrapher:> graph execution complete
[13:59:49.816] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.63 sec
[13:59:49.816] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.78 sec
[13:59:49.816] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.48 sec
[13:59:49.816] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.96 sec
[13:59:49.816] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.15 sec
[13:59:49.816] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.88 sec
[13:59:49.816] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.73 sec
[13:59:49.816] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.57 sec
[13:59:49.816] I [ timer ] Timer: WireCell::Aux::Resampler : 1.01 sec
[13:59:49.816] I [ timer ] Timer: WireCell::Aux::Resampler : 0.68 sec
[13:59:49.816] I [ timer ] Timer: WireCell::Aux::Resampler : 0.67 sec
[13:59:49.816] I [ timer ] Timer: WireCell::Aux::Resampler : 0.65 sec
[13:59:49.816] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[13:59:49.816] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[13:59:49.816] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[13:59:49.816] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:59:49.816] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:59:49.816] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:59:49.816] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:59:49.816] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:59:49.816] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[13:59:49.816] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:59:49.816] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:59:49.816] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[13:59:49.816] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[13:59:49.816] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[13:59:49.816] I [ timer ] Timer: Total node execution : 64.21999981813133 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 61710 traces tagged "gauss"
FrameSaver: q=1.55227e+07 n=1466498 tag=gauss
wclsFrameSaver: saving 77714 traces tagged "wiener"
FrameSaver: q=1.6232e+07 n=1405789 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 2853 XUs and 4105 XVs -> 132 XUVs
C:0 T:1 607 XUs and 600 XVs -> 35 XUVs
C:0 T:2 1620 XUs and 1132 XVs -> 67 XUVs
C:0 T:3 433 XUs and 454 XVs -> 21 XUVs
C:0 T:4 345 XUs and 566 XVs -> 37 XUVs
C:0 T:5 1417 XUs and 1595 XVs -> 33 XUVs
C:0 T:6 455 XUs and 360 XVs -> 40 XUVs
C:0 T:7 3249 XUs and 2922 XVs -> 454 XUVs
C:0 T:8 13334 XUs and 29512 XVs -> 3936 XUVs
C:0 T:9 7717 XUs and 13644 XVs -> 1409 XUVs
C:0 T:10 8232 XUs and 12254 XVs -> 1987 XUVs
C:0 T:11 4268 XUs and 5409 XVs -> 159 XUVs
C:0 T:12 11446 XUs and 29766 XVs -> 972 XUVs
C:0 T:13 3440 XUs and 3635 XVs -> 580 XUVs
C:0 T:14 724 XUs and 1236 XVs -> 58 XUVs
C:0 T:15 4440 XUs and 3031 XVs -> 222 XUVs
10142 XUVs total
2646 collection wire objects
10142 potential space points
Neighbour search...
1056224 tests to find 460738 neighbours
Iterating with no regularization...
Begin: 9.36351e+09
0 8.93478e+09
1 8.92579e+09
2 8.92528e+09
Now with regularization...
Begin: 8.8877e+09
0 8.88743e+09
11-Sep-2025 14:02:32 CEST Closed output file "np02vd_raw_run039255_1856_df-s05-d3_dw_0_20250831T074246_reco_stage1_20250911T120232_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 148.691 194.901 258.179 189.553 33.0591 18
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 5.597e-05 9.39286e-05 0.000238903 8.0751e-05 4.33514e-05 18
produce:tpcrawdecoder:PDVDTPCReader 5.69126 6.42109 9.49553 6.18209 0.797125 18
produce:triggerrawdecoder:PDVDTriggerReader4 0.00110501 0.00331125 0.0162012 0.00135637 0.00402514 18
produce:pdvddaphne:DAPHNEReaderPDVD 3.27581 4.09413 4.63979 4.21251 0.406097 18
produce:ophit:OpHitFinder 0.037415 0.0475557 0.0563038 0.046225 0.00658332 18
produce:opflash:OpFlashFinderVerticalDrift 0.00757013 0.0138266 0.0225868 0.0136719 0.00395783 18
produce:wclsdatavd:WireCellToolkit 57.4575 66.9429 75.8926 67.5295 4.5336 18
produce:gaushit:GausHitFinder 0.987282 1.58226 2.43352 1.58198 0.377451 18
produce:nhitsfilter:NumberOfHitsFilter 0.000248823 0.000382692 0.000646507 0.000364268 9.7149e-05 18
produce:reco3d:SpacePointSolver 13.5813 20.4211 29.4966 18.909 4.446 18
produce:hitpdune:DisambigFromSpacePoints 0.183729 0.337435 0.596699 0.294063 0.125278 18
produce:pandora:StandardPandora 47.6848 88.6675 140.542 86.7579 26.8729 18
produce:pandoraTrack:LArPandoraTrackCreation 0.843568 1.41454 2.2672 1.24524 0.415607 18
produce:pandoraGnocalo:GnocchiCalorimetry 0.0215943 0.0313033 0.0555116 0.0283342 0.00928935 18
[art]:TriggerResults:TriggerResultInserter 1.447e-05 2.39758e-05 5.428e-05 2.00205e-05 9.91001e-06 18
end_path:out1:RootOutput 6e-06 1.13391e-05 4.5881e-05 8.665e-06 8.72623e-06 18
end_path:out1:RootOutput(write) 4.23219 4.87804 5.84428 4.64373 0.564168 18
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5180.8 MB
Peak resident set size usage (VmHWM): 3238.22 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039255_1856_df-s05-d3_dw_0_20250831T074246_reco_stage1_20250911T120232_keepup.root
\tHists: np02vd_raw_run039255_1856_df-s05-d3_dw_0_20250831T074246_reco_stage1_20250911T120232_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039255_1856_df-s05-d3_dw_0_20250831T074246_reco_stage1_20250911T120232_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039255_1856_df-s05-d3_dw_0_20250831T074246_reco_stage1_20250911T120232_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": 1757592153.0,
"core.end_time": 1757592153.0,
"core.events": [
668170,
668190,
668210,
668230,
668250,
668270,
668290,
668310,
668330,
668350,
668370,
668390,
668410,
668430,
668450,
668470,
668490,
668510
],
"core.event_count": 18,
"core.first_event_number": 668170,
"core.last_event_number": 668510,
"core.data_stream": "physics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39255
],
"core.runs_subruns": [
3925500001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039255_1856_df-s05-d3_dw_0_20250831T074246.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039255_1856_df-s05-d3_dw_0_20250831T074246_reco_stage1_20250911T120232_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": 1757592153.0,
"core.end_time": 1757592153.0,
"core.data_stream": "physics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39255
],
"core.runs_subruns": [
3925500001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039255_1856_df-s05-d3_dw_0_20250831T074246.hdf5"
}
]
} 