Jobsub ID 49050.28@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
2:19:10.278] D [ glue ] <ChannelSelector:chsel0> see EOS at call=40
[22:19:10.278] D [ aux ] <Resampler:resmp0> EOS at call=81
[22:19:10.278] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=81 anode=0
[22:19:10.278] D [ glue ] <FrameFanin:nfsp> EOS at call=81 with 8
[22:19:10.278] D [ glue ] frame sink sees EOS
[22:19:10.278] D [ pgraph ] <Pgrapher:> graph execution complete
[22:19:10.278] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.76 sec
[22:19:10.278] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.97 sec
[22:19:10.278] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.86 sec
[22:19:10.278] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.8 sec
[22:19:10.278] I [ timer ] Timer: WireCell::Aux::Resampler : 0.4 sec
[22:19:10.278] I [ timer ] Timer: WireCell::Aux::Resampler : 0.39 sec
[22:19:10.278] I [ timer ] Timer: WireCell::Aux::Resampler : 0.39 sec
[22:19:10.278] I [ timer ] Timer: WireCell::Aux::Resampler : 0.37 sec
[22:19:10.278] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[22:19:10.278] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[22:19:10.278] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[22:19:10.278] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:19:10.278] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:19:10.278] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:19:10.278] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:19:10.278] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:19:10.278] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:19:10.278] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[22:19:10.278] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:19:10.278] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:19:10.278] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:19:10.278] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[22:19:10.278] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[22:19:10.278] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[22:19:10.278] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:19:10.278] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[22:19:10.278] I [ timer ] Timer: Total node execution : 33.97000032477081 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 19039 traces tagged "gauss"
FrameSaver: q=4.33422e+06 n=494177 tag=gauss
wclsFrameSaver: saving 23906 traces tagged "wiener"
FrameSaver: q=4.63052e+06 n=477919 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 558 XUs and 573 XVs -> 25 XUVs
C:0 T:1 122 XUs and 98 XVs -> 3 XUVs
C:0 T:2 15411 XUs and 17872 XVs -> 1280 XUVs
C:0 T:3 1660 XUs and 2296 XVs -> 182 XUVs
C:0 T:4 975 XUs and 749 XVs -> 27 XUVs
C:0 T:5 520 XUs and 754 XVs -> 44 XUVs
C:0 T:6 382 XUs and 231 XVs -> 25 XUVs
C:0 T:7 847 XUs and 1228 XVs -> 60 XUVs
1646 XUVs total
993 collection wire objects
1646 potential space points
Neighbour search...
43628 tests to find 10502 neighbours
Iterating with no regularization...
Begin: 1.85828e+10
0 1.84937e+10
1 1.84914e+10
Now with regularization...
Begin: 1.8068e+10
0 1.80679e+10
18-Sep-2025 22:19:27 BST Closed output file "np02vd_raw_run039499_0042_df-s05-d5_dw_0_20250918T190717_reco_stage1_20250918T211927_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 35.3095 66.2363 190.704 55.8323 28.5394 41
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 6.593e-05 9.67124e-05 0.000225942 8.5279e-05 2.88983e-05 41
produce:tpcrawdecoder:PDVDTPCReader 5.6213 6.52947 8.61784 6.13928 0.756149 41
produce:triggerrawdecoder:PDVDTriggerReader4 0.310223 0.316038 0.346378 0.31457 0.00607616 41
produce:pdvddaphne:DAPHNEReaderPDVD 2.29298 2.60028 2.88837 2.61041 0.145673 41
produce:ophit:OpHitFinder 0.0200068 0.0388648 0.0492021 0.0393404 0.00516829 41
produce:opflash:OpFlashFinderVerticalDrift 0.00309666 0.0104445 0.0166866 0.010694 0.00295104 41
produce:wclsdatavd:WireCellToolkit 18.4504 27.0731 41.5756 24.1692 6.74109 41
produce:gaushit:GausHitFinder 0.271793 0.534705 0.993266 0.5276 0.171541 41
produce:nhitsfilter:NumberOfHitsFilter 7.881e-05 0.00013544 0.000379404 0.000126111 5.09622e-05 41
produce:reco3d:SpacePointSolver 1.73158 5.11778 11.9651 4.31515 2.25901 41
produce:hitpdune:DisambigFromSpacePoints 0.0185865 0.0725855 0.27746 0.0616582 0.0498758 41
produce:pandora:StandardPandora 2.70084 21.3895 124.935 14.081 22.6634 41
produce:pandoraTrack:LArPandoraTrackCreation 0.09891 0.301685 1.12178 0.261834 0.192199 41
produce:pandoraGnocalo:GnocchiCalorimetry 0.005224 0.0143821 0.0376947 0.0142422 0.00579909 41
[art]:TriggerResults:TriggerResultInserter 1.4341e-05 3.24623e-05 9.0657e-05 2.8854e-05 1.35899e-05 41
end_path:out1:RootOutput 4.136e-06 8.86705e-06 2.8433e-05 7.672e-06 5.43324e-06 41
end_path:out1:RootOutput(write) 1.51988 2.21304 2.72654 2.28643 0.368984 41
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4988.39 MB
Peak resident set size usage (VmHWM): 3028.37 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0042_df-s05-d5_dw_0_20250918T190717_reco_stage1_20250918T211927_keepup.root
\tHists: np02vd_raw_run039499_0042_df-s05-d5_dw_0_20250918T190717_reco_stage1_20250918T211928_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0042_df-s05-d5_dw_0_20250918T190717_reco_stage1_20250918T211927_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0042_df-s05-d5_dw_0_20250918T190717_reco_stage1_20250918T211927_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": 1758230368.0,
"core.end_time": 1758230368.0,
"core.events": [
10247,
10253,
10259,
10265,
10271,
10277,
10283,
10289,
10295,
10301,
10307,
10313,
10319,
10325,
10331,
10337,
10343,
10349,
10355,
10361,
10367,
10373,
10379,
10385,
10391,
10397,
10403,
10409,
10415,
10421,
10427,
10433,
10439,
10445,
10451,
10457,
10463,
10469,
10475,
10481,
10487
],
"core.event_count": 41,
"core.first_event_number": 10247,
"core.last_event_number": 10487,
"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_0042_df-s05-d5_dw_0_20250918T190717.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0042_df-s05-d5_dw_0_20250918T190717_reco_stage1_20250918T211928_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": 1758230368.0,
"core.end_time": 1758230368.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_0042_df-s05-d5_dw_0_20250918T190717.hdf5"
}
]
}