Jobsub ID 41655.50@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
] D [ aux ] <Resampler:resmp0> EOS at call=95
[08:43:25.677] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=95 anode=0
[08:43:25.677] D [ glue ] <FrameFanin:nfsp> EOS at call=95 with 8
[08:43:25.677] D [ glue ] frame sink sees EOS
[08:43:25.677] D [ pgraph ] <Pgrapher:> graph execution complete
[08:43:25.677] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.66 sec
[08:43:25.677] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.15 sec
[08:43:25.677] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.96 sec
[08:43:25.677] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.18 sec
[08:43:25.677] I [ timer ] Timer: WireCell::Aux::Resampler : 1.85 sec
[08:43:25.677] I [ timer ] Timer: WireCell::Aux::Resampler : 1.84 sec
[08:43:25.677] I [ timer ] Timer: WireCell::Aux::Resampler : 1.83 sec
[08:43:25.677] I [ timer ] Timer: WireCell::Aux::Resampler : 1.82 sec
[08:43:25.677] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[08:43:25.677] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[08:43:25.677] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[08:43:25.677] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[08:43:25.677] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[08:43:25.677] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[08:43:25.677] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:43:25.677] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[08:43:25.677] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0 sec
[08:43:25.677] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:43:25.677] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:43:25.677] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[08:43:25.677] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[08:43:25.677] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:43:25.677] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[08:43:25.677] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[08:43:25.677] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[08:43:25.677] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[08:43:25.677] I [ timer ] Timer: Total node execution : 61.34999996051192 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 9284 traces tagged "gauss"
FrameSaver: q=1.01909e+06 n=178461 tag=gauss
wclsFrameSaver: saving 11864 traces tagged "wiener"
FrameSaver: q=1.07997e+06 n=166445 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 28 XUs and 28 XVs -> 0 XUVs
C:0 T:1 263 XUs and 97 XVs -> 6 XUVs
C:0 T:2 88 XUs and 126 XVs -> 8 XUVs
C:0 T:3 1102 XUs and 935 XVs -> 50 XUVs
C:0 T:4 1531 XUs and 966 XVs -> 65 XUVs
C:0 T:5 240 XUs and 414 XVs -> 25 XUVs
C:0 T:6 626 XUs and 501 XVs -> 16 XUVs
C:0 T:7 196 XUs and 147 XVs -> 12 XUVs
182 XUVs total
171 collection wire objects
182 potential space points
Neighbour search...
826 tests to find 382 neighbours
Iterating with no regularization...
Begin: 4.33795e+07
0 4.29009e+07
1 4.29009e+07
Now with regularization...
Begin: 4.26126e+07
0 4.26126e+07
18-Sep-2025 08:43:37 BST Closed output file "np02vd_raw_run039433_0338_df-s05-d3_dw_0_20250918T051545_reco_stage1_20250918T074337_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 72.923 115.587 294.742 107.843 36.785 48
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 8.0597e-05 0.000108533 0.000241655 9.68015e-05 2.93869e-05 48
produce:tpcrawdecoder:PDVDTPCReader 11.1049 13.0234 18.3372 12.5465 1.57071 48
produce:triggerrawdecoder:PDVDTriggerReader4 0.298901 0.308569 0.36115 0.302594 0.0143557 48
produce:pdvddaphne:DAPHNEReaderPDVD 5.86094 6.41395 7.17581 6.39759 0.357397 48
produce:ophit:OpHitFinder 0.0476763 0.061769 0.0786075 0.0625357 0.00625457 48
produce:opflash:OpFlashFinderVerticalDrift 0.00336618 0.0189232 0.0397185 0.0190496 0.00634622 48
produce:wclsdatavd:WireCellToolkit 38.8385 54.9841 101.643 47.7096 16.4232 48
produce:gaushit:GausHitFinder 0.379435 1.04329 2.05512 1.02296 0.295791 48
produce:nhitsfilter:NumberOfHitsFilter 9.4619e-05 0.000184714 0.000425111 0.000175703 5.3263e-05 48
produce:reco3d:SpacePointSolver 2.37657 6.40533 14.95 5.91523 2.50788 48
produce:hitpdune:DisambigFromSpacePoints 0.0304726 0.150864 0.834337 0.11366 0.127218 48
produce:pandora:StandardPandora 3.53288 28.946 176.678 22.4686 26.457 48
produce:pandoraTrack:LArPandoraTrackCreation 0.111501 0.527106 1.67647 0.498901 0.288817 48
produce:pandoraGnocalo:GnocchiCalorimetry 0.0125298 0.0243917 0.045123 0.0236594 0.00687959 48
[art]:TriggerResults:TriggerResultInserter 2.5279e-05 3.28871e-05 6.8206e-05 3.14365e-05 6.93034e-06 48
end_path:out1:RootOutput 4.983e-06 9.05592e-06 2.4268e-05 9.0915e-06 3.36409e-06 48
end_path:out1:RootOutput(write) 2.96368 3.65549 4.71692 3.53228 0.415054 48
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4401.99 MB
Peak resident set size usage (VmHWM): 2501.84 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0338_df-s05-d3_dw_0_20250918T051545_reco_stage1_20250918T074337_keepup.root
\tHists: np02vd_raw_run039433_0338_df-s05-d3_dw_0_20250918T051545_reco_stage1_20250918T074339_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0338_df-s05-d3_dw_0_20250918T051545_reco_stage1_20250918T074337_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0338_df-s05-d3_dw_0_20250918T051545_reco_stage1_20250918T074337_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": 1758181420.0,
"core.end_time": 1758181420.0,
"core.events": [
97053,
97059,
97065,
97071,
97077,
97083,
97089,
97095,
97101,
97107,
97113,
97119,
97125,
97131,
97137,
97143,
97149,
97155,
97161,
97167,
97173,
97179,
97185,
97191,
97197,
97203,
97209,
97215,
97221,
97227,
97233,
97239,
97245,
97251,
97257,
97263,
97269,
97275,
97281,
97287,
97293,
97299,
97305,
97311,
97317,
97323,
97329,
97335
],
"core.event_count": 48,
"core.first_event_number": 97053,
"core.last_event_number": 97335,
"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_0338_df-s05-d3_dw_0_20250918T051545.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0338_df-s05-d3_dw_0_20250918T051545_reco_stage1_20250918T074339_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": 1758181420.0,
"core.end_time": 1758181420.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_0338_df-s05-d3_dw_0_20250918T051545.hdf5"
}
]
}