Jobsub ID 41697.108@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
:anode0sigproc0> EOS at call=97 anode=0
[08:15:46.619] D [ glue ] <FrameFanin:nfsp> EOS at call=97 with 8
[08:15:46.619] D [ glue ] frame sink sees EOS
[08:15:46.619] D [ pgraph ] <Pgrapher:> graph execution complete
[08:15:46.619] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.39 sec
[08:15:46.619] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 13.31 sec
[08:15:46.619] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 13.02 sec
[08:15:46.619] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.28 sec
[08:15:46.619] I [ timer ] Timer: WireCell::Aux::Resampler : 0.32 sec
[08:15:46.619] I [ timer ] Timer: WireCell::Aux::Resampler : 0.32 sec
[08:15:46.619] I [ timer ] Timer: WireCell::Aux::Resampler : 0.31 sec
[08:15:46.619] I [ timer ] Timer: WireCell::Aux::Resampler : 0.3 sec
[08:15:46.619] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[08:15:46.619] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[08:15:46.619] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[08:15:46.619] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[08:15:46.619] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:15:46.619] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:15:46.619] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[08:15:46.619] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:15:46.619] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:15:46.619] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[08:15:46.619] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:15:46.619] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[08:15:46.620] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:15:46.620] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[08:15:46.620] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[08:15:46.620] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[08:15:46.620] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[08:15:46.620] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[08:15:46.620] I [ timer ] Timer: Total node execution : 54.29000095278025 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 26453 traces tagged "gauss"
FrameSaver: q=4.55141e+06 n=559572 tag=gauss
wclsFrameSaver: saving 32235 traces tagged "wiener"
FrameSaver: q=4.85503e+06 n=539507 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 322 XUs and 312 XVs -> 10 XUVs
C:0 T:1 2518 XUs and 2593 XVs -> 84 XUVs
C:0 T:2 1586 XUs and 1455 XVs -> 50 XUVs
C:0 T:3 442 XUs and 344 XVs -> 17 XUVs
C:0 T:4 1831 XUs and 847 XVs -> 48 XUVs
C:0 T:5 9200 XUs and 10488 XVs -> 884 XUVs
C:0 T:6 196 XUs and 269 XVs -> 8 XUVs
C:0 T:7 1241 XUs and 1647 XVs -> 91 XUVs
1192 XUVs total
689 collection wire objects
1192 potential space points
Neighbour search...
46096 tests to find 10656 neighbours
Iterating with no regularization...
Begin: 5.09246e+09
0 4.89067e+09
1 4.87221e+09
2 4.86996e+09
Now with regularization...
Begin: 4.68528e+09
0 4.68477e+09
18-Sep-2025 08:16:30 UTC Closed output file "np02vd_raw_run039433_0368_df-s05-d0_dw_0_20250918T062832_reco_stage1_20250918T081630_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 54.4057 76.8451 151.362 70.9269 19.6369 49
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 9.4523e-05 0.00016287 0.000515585 0.000140644 7.27268e-05 49
produce:tpcrawdecoder:PDVDTPCReader 7.31821 7.89397 9.71664 7.77068 0.525873 49
produce:triggerrawdecoder:PDVDTriggerReader4 0.392589 0.402061 0.420594 0.400962 0.00550191 49
produce:pdvddaphne:DAPHNEReaderPDVD 3.00593 3.63344 4.5275 3.64444 0.265194 49
produce:ophit:OpHitFinder 0.0374344 0.0549126 0.0812519 0.0555702 0.0081476 49
produce:opflash:OpFlashFinderVerticalDrift 0.00148668 0.0154343 0.030895 0.0153296 0.00510552 49
produce:wclsdatavd:WireCellToolkit 26.5379 38.6946 64.8917 33.8405 10.1852 49
produce:gaushit:GausHitFinder 0.425315 0.694177 1.10468 0.680727 0.169773 49
produce:nhitsfilter:NumberOfHitsFilter 0.000155535 0.000403033 0.00108583 0.000367761 0.000187262 49
produce:reco3d:SpacePointSolver 2.71579 5.53005 13.2559 4.97205 2.20836 49
produce:hitpdune:DisambigFromSpacePoints 0.0312607 0.0821456 0.259813 0.0649258 0.0488603 49
produce:pandora:StandardPandora 4.73071 16.7824 57.9961 15.8736 9.39403 49
produce:pandoraTrack:LArPandoraTrackCreation 0.0709137 0.314075 1.22405 0.256783 0.204957 49
produce:pandoraGnocalo:GnocchiCalorimetry 0.00980344 0.0206735 0.0487212 0.0192547 0.00865907 49
[art]:TriggerResults:TriggerResultInserter 2.4421e-05 5.47149e-05 0.000137644 4.8512e-05 2.26249e-05 49
end_path:out1:RootOutput 6.25e-06 1.61084e-05 5.3981e-05 1.414e-05 8.45179e-06 49
end_path:out1:RootOutput(write) 2.02191 2.67958 3.703 2.6068 0.302069 49
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5296.14 MB
Peak resident set size usage (VmHWM): 3221.19 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0368_df-s05-d0_dw_0_20250918T062832_reco_stage1_20250918T081630_keepup.root
\tHists: np02vd_raw_run039433_0368_df-s05-d0_dw_0_20250918T062832_reco_stage1_20250918T081630_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0368_df-s05-d0_dw_0_20250918T062832_reco_stage1_20250918T081630_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0368_df-s05-d0_dw_0_20250918T062832_reco_stage1_20250918T081630_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": 1758183391.0,
"core.end_time": 1758183391.0,
"core.events": [
105648,
105654,
105660,
105666,
105672,
105678,
105684,
105690,
105696,
105702,
105708,
105714,
105720,
105726,
105732,
105738,
105744,
105750,
105756,
105762,
105768,
105774,
105780,
105786,
105792,
105798,
105804,
105810,
105816,
105822,
105828,
105834,
105840,
105846,
105852,
105858,
105864,
105870,
105876,
105882,
105888,
105894,
105900,
105906,
105912,
105918,
105924,
105930,
105936
],
"core.event_count": 49,
"core.first_event_number": 105648,
"core.last_event_number": 105936,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39433
],
"core.runs_subruns": [
3943300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039433_0368_df-s05-d0_dw_0_20250918T062832.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0368_df-s05-d0_dw_0_20250918T062832_reco_stage1_20250918T081630_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": 1758183391.0,
"core.end_time": 1758183391.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39433
],
"core.runs_subruns": [
3943300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039433_0368_df-s05-d0_dw_0_20250918T062832.hdf5"
}
]
} 