Jobsub ID 42699.13@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
9 anode=1
[01:46:20.533] D [ glue ] <ChannelSelector:chsel0> see EOS at call=39
[01:46:20.533] D [ aux ] <Resampler:resmp0> EOS at call=79
[01:46:20.534] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=79 anode=0
[01:46:20.534] D [ glue ] <FrameFanin:nfsp> EOS at call=79 with 8
[01:46:20.534] D [ glue ] frame sink sees EOS
[01:46:20.534] D [ pgraph ] <Pgrapher:> graph execution complete
[01:46:20.534] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.7 sec
[01:46:20.534] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.74 sec
[01:46:20.534] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.72 sec
[01:46:20.534] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.12 sec
[01:46:20.534] I [ timer ] Timer: WireCell::Aux::Resampler : 1.33 sec
[01:46:20.534] I [ timer ] Timer: WireCell::Aux::Resampler : 1.29 sec
[01:46:20.534] I [ timer ] Timer: WireCell::Aux::Resampler : 1.28 sec
[01:46:20.534] I [ timer ] Timer: WireCell::Aux::Resampler : 1.25 sec
[01:46:20.534] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[01:46:20.534] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[01:46:20.534] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[01:46:20.534] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[01:46:20.534] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[01:46:20.534] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:46:20.534] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[01:46:20.534] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:46:20.534] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:46:20.534] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[01:46:20.534] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:46:20.534] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[01:46:20.534] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:46:20.534] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[01:46:20.534] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:46:20.534] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[01:46:20.534] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[01:46:20.534] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[01:46:20.534] I [ timer ] Timer: Total node execution : 44.469999708235264 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 25892 traces tagged "gauss"
FrameSaver: q=2.91071e+06 n=498820 tag=gauss
wclsFrameSaver: saving 32295 traces tagged "wiener"
FrameSaver: q=3.06886e+06 n=476470 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 885 XUs and 828 XVs -> 35 XUVs
C:0 T:1 572 XUs and 617 XVs -> 18 XUVs
C:0 T:2 977 XUs and 1157 XVs -> 71 XUVs
C:0 T:3 1637 XUs and 1672 XVs -> 64 XUVs
C:0 T:4 489 XUs and 472 XVs -> 21 XUVs
C:0 T:5 1500 XUs and 1489 XVs -> 86 XUVs
C:0 T:6 3584 XUs and 3120 XVs -> 153 XUVs
C:0 T:7 820 XUs and 643 XVs -> 25 XUVs
473 XUVs total
399 collection wire objects
473 potential space points
Neighbour search...
3203 tests to find 1742 neighbours
Iterating with no regularization...
Begin: 7.22409e+07
0 7.09877e+07
1 7.09317e+07
Now with regularization...
Begin: 6.89304e+07
0 6.89286e+07
19-Sep-2025 01:46:42 BST Closed output file "np02vd_raw_run039499_0104_df-s04-d1_dw_0_20250918T211113_reco_stage1_20250919T004642_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 74.6238 121.696 234.093 107.372 38.361 40
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 8.7103e-05 0.000133103 0.000374662 0.000115011 5.07924e-05 40
produce:tpcrawdecoder:PDVDTPCReader 10.1599 29.0595 101.781 27.1167 15.3716 40
produce:triggerrawdecoder:PDVDTriggerReader4 0.314416 0.354916 0.654568 0.336738 0.0675237 40
produce:pdvddaphne:DAPHNEReaderPDVD 4.23934 6.81313 13.2866 6.56087 1.7475 40
produce:ophit:OpHitFinder 0.0333392 0.0544657 0.0636662 0.0549966 0.00615018 40
produce:opflash:OpFlashFinderVerticalDrift 0.00635305 0.0150624 0.0820933 0.0133856 0.0112178 40
produce:wclsdatavd:WireCellToolkit 28.8233 45.2843 86.6342 39.6083 13.3942 40
produce:gaushit:GausHitFinder 0.404618 0.808662 1.42408 0.801109 0.246749 40
produce:nhitsfilter:NumberOfHitsFilter 0.000138921 0.00021467 0.000534882 0.00020556 6.21891e-05 40
produce:reco3d:SpacePointSolver 2.73007 7.06475 14.2335 6.84564 2.6435 40
produce:hitpdune:DisambigFromSpacePoints 0.028816 0.0974312 0.280339 0.0783647 0.056546 40
produce:pandora:StandardPandora 6.68016 28.6632 104.853 19.7048 22.6371 40
produce:pandoraTrack:LArPandoraTrackCreation 0.103433 0.358556 0.932074 0.308343 0.180368 40
produce:pandoraGnocalo:GnocchiCalorimetry 0.00810107 0.0210111 0.0333651 0.0201123 0.0061615 40
[art]:TriggerResults:TriggerResultInserter 2.0509e-05 3.91863e-05 0.000132768 3.6533e-05 1.72123e-05 40
end_path:out1:RootOutput 5.44e-06 1.04343e-05 4.4834e-05 9.9835e-06 5.81292e-06 40
end_path:out1:RootOutput(write) 2.0731 3.07917 3.81882 3.13304 0.441738 40
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4599.37 MB
Peak resident set size usage (VmHWM): 2645.73 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0104_df-s04-d1_dw_0_20250918T211113_reco_stage1_20250919T004642_keepup.root
\tHists: np02vd_raw_run039499_0104_df-s04-d1_dw_0_20250918T211113_reco_stage1_20250919T004642_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0104_df-s04-d1_dw_0_20250918T211113_reco_stage1_20250919T004642_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0104_df-s04-d1_dw_0_20250918T211113_reco_stage1_20250919T004642_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": 1758242803.0,
"core.end_time": 1758242803.0,
"core.events": [
25326,
25332,
25338,
25344,
25350,
25356,
25362,
25368,
25374,
25380,
25386,
25392,
25398,
25404,
25410,
25416,
25422,
25428,
25434,
25440,
25446,
25452,
25458,
25464,
25470,
25476,
25482,
25488,
25494,
25500,
25506,
25512,
25518,
25524,
25530,
25536,
25542,
25548,
25554,
25560
],
"core.event_count": 40,
"core.first_event_number": 25326,
"core.last_event_number": 25560,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39499
],
"core.runs_subruns": [
3949900001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039499_0104_df-s04-d1_dw_0_20250918T211113.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0104_df-s04-d1_dw_0_20250918T211113_reco_stage1_20250919T004642_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": 1758242803.0,
"core.end_time": 1758242803.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39499
],
"core.runs_subruns": [
3949900001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039499_0104_df-s04-d1_dw_0_20250918T211113.hdf5"
}
]
}