Jobsub ID 48994.55@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
2:40:31.445] D [ glue ] <ChannelSelector:chsel0> see EOS at call=40
[22:40:31.445] D [ aux ] <Resampler:resmp0> EOS at call=81
[22:40:31.445] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=81 anode=0
[22:40:31.445] D [ glue ] <FrameFanin:nfsp> EOS at call=81 with 8
[22:40:31.445] D [ glue ] frame sink sees EOS
[22:40:31.445] D [ pgraph ] <Pgrapher:> graph execution complete
[22:40:31.445] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.39 sec
[22:40:31.445] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.34 sec
[22:40:31.445] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.18 sec
[22:40:31.445] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.9 sec
[22:40:31.445] I [ timer ] Timer: WireCell::Aux::Resampler : 0.31 sec
[22:40:31.445] I [ timer ] Timer: WireCell::Aux::Resampler : 0.29 sec
[22:40:31.445] I [ timer ] Timer: WireCell::Aux::Resampler : 0.28 sec
[22:40:31.445] I [ timer ] Timer: WireCell::Aux::Resampler : 0.26 sec
[22:40:31.445] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[22:40:31.445] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[22:40:31.445] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[22:40:31.445] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0.01 sec
[22:40:31.445] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:40:31.445] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:40:31.445] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:40:31.445] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:40:31.445] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:40:31.445] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:40:31.445] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:40:31.445] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[22:40:31.445] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:40:31.445] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:40:31.445] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:40:31.445] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[22:40:31.445] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[22:40:31.445] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[22:40:31.445] I [ timer ] Timer: Total node execution : 35.000000881031156 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 26621 traces tagged "gauss"
FrameSaver: q=3.82206e+06 n=564807 tag=gauss
wclsFrameSaver: saving 33617 traces tagged "wiener"
FrameSaver: q=4.16506e+06 n=547007 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 1431 XUs and 1671 XVs -> 96 XUVs
C:0 T:1 1934 XUs and 2298 XVs -> 51 XUVs
C:0 T:2 18600 XUs and 15958 XVs -> 1480 XUVs
C:0 T:3 1115 XUs and 1298 XVs -> 81 XUVs
C:0 T:4 322 XUs and 390 XVs -> 13 XUVs
C:0 T:5 2065 XUs and 2006 XVs -> 143 XUVs
C:0 T:6 1110 XUs and 952 XVs -> 53 XUVs
C:0 T:7 1569 XUs and 1147 XVs -> 172 XUVs
2089 XUVs total
940 collection wire objects
2089 potential space points
Neighbour search...
92095 tests to find 24206 neighbours
Iterating with no regularization...
Begin: 8.20986e+08
0 6.9879e+08
1 6.71227e+08
2 6.70487e+08
3 6.70421e+08
Now with regularization...
Begin: 6.57463e+08
0 6.5738e+08
18-Sep-2025 22:41:04 BST Closed output file "np02vd_raw_run039499_0024_df-s04-d2_dw_0_20250918T182948_reco_stage1_20250918T214104_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 89.5294 154.485 851.922 120.497 119.831 41
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 8.7645e-05 0.00015244 0.000354797 0.000133411 6.23816e-05 41
produce:tpcrawdecoder:PDVDTPCReader 16.1235 31.929 49.2001 31.4372 8.13523 41
produce:triggerrawdecoder:PDVDTriggerReader4 0.379748 0.430485 0.827297 0.403199 0.0751814 41
produce:pdvddaphne:DAPHNEReaderPDVD 4.95072 7.47969 11.1491 7.30104 1.58421 41
produce:ophit:OpHitFinder 0.0337637 0.0534563 0.0804935 0.0544486 0.0102163 41
produce:opflash:OpFlashFinderVerticalDrift 0.00488804 0.0130131 0.0287442 0.0124662 0.00459499 41
produce:wclsdatavd:WireCellToolkit 30.7685 42.8084 75.9636 40.4184 9.36774 41
produce:gaushit:GausHitFinder 0.420076 0.846636 1.83444 0.778267 0.29173 41
produce:nhitsfilter:NumberOfHitsFilter 0.000122129 0.000299639 0.00130174 0.000225864 0.000220268 41
produce:reco3d:SpacePointSolver 3.6126 7.82777 24.8336 7.14306 3.83042 41
produce:hitpdune:DisambigFromSpacePoints 0.0248711 0.136053 0.621098 0.108361 0.108202 41
produce:pandora:StandardPandora 8.2618 59.0853 717.613 32.9551 111.386 41
produce:pandoraTrack:LArPandoraTrackCreation 0.155017 0.546331 2.61293 0.485067 0.407608 41
produce:pandoraGnocalo:GnocchiCalorimetry 0.00845155 0.0227584 0.0426704 0.0221832 0.00761396 41
[art]:TriggerResults:TriggerResultInserter 2.5458e-05 5.70177e-05 0.000327886 4.2099e-05 4.83829e-05 41
end_path:out1:RootOutput 4.138e-06 1.17749e-05 4.8511e-05 1.059e-05 7.13622e-06 41
end_path:out1:RootOutput(write) 2.71936 3.27017 4.33112 3.29808 0.329926 41
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4745.36 MB
Peak resident set size usage (VmHWM): 2811.28 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0024_df-s04-d2_dw_0_20250918T182948_reco_stage1_20250918T214104_keepup.root
\tHists: np02vd_raw_run039499_0024_df-s04-d2_dw_0_20250918T182948_reco_stage1_20250918T214104_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0024_df-s04-d2_dw_0_20250918T182948_reco_stage1_20250918T214104_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0024_df-s04-d2_dw_0_20250918T182948_reco_stage1_20250918T214104_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": 1758231665.0,
"core.end_time": 1758231665.0,
"core.events": [
5839,
5845,
5851,
5857,
5863,
5869,
5875,
5881,
5887,
5893,
5899,
5905,
5911,
5917,
5923,
5929,
5935,
5941,
5947,
5953,
5959,
5965,
5971,
5977,
5983,
5989,
5995,
6001,
6007,
6013,
6019,
6025,
6031,
6037,
6043,
6049,
6055,
6061,
6067,
6073,
6079
],
"core.event_count": 41,
"core.first_event_number": 5839,
"core.last_event_number": 6079,
"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_0024_df-s04-d2_dw_0_20250918T182948.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0024_df-s04-d2_dw_0_20250918T182948_reco_stage1_20250918T214104_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": 1758231665.0,
"core.end_time": 1758231665.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_0024_df-s04-d2_dw_0_20250918T182948.hdf5"
}
]
} 