Jobsub ID 41697.79@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
.870] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=93 anode=0
[10:50:35.870] D [ glue ] <FrameFanin:nfsp> EOS at call=93 with 8
[10:50:35.870] D [ glue ] frame sink sees EOS
[10:50:35.870] D [ pgraph ] <Pgrapher:> graph execution complete
[10:50:35.870] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.22 sec
[10:50:35.870] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.86 sec
[10:50:35.870] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.26 sec
[10:50:35.870] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.3 sec
[10:50:35.870] I [ timer ] Timer: WireCell::Aux::Resampler : 0.69 sec
[10:50:35.870] I [ timer ] Timer: WireCell::Aux::Resampler : 0.69 sec
[10:50:35.870] I [ timer ] Timer: WireCell::Aux::Resampler : 0.68 sec
[10:50:35.870] I [ timer ] Timer: WireCell::Aux::Resampler : 0.67 sec
[10:50:35.871] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.03 sec
[10:50:35.871] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[10:50:35.871] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[10:50:35.871] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[10:50:35.871] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:50:35.871] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:50:35.871] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[10:50:35.871] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:50:35.871] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:50:35.871] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:50:35.871] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[10:50:35.871] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:50:35.871] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[10:50:35.871] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:50:35.871] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[10:50:35.871] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[10:50:35.871] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[10:50:35.871] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[10:50:35.871] I [ timer ] Timer: Total node execution : 48.42000036127865 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 24939 traces tagged "gauss"
FrameSaver: q=4.05666e+06 n=570279 tag=gauss
wclsFrameSaver: saving 32255 traces tagged "wiener"
FrameSaver: q=4.29315e+06 n=541634 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 16317 XUs and 21092 XVs -> 1091 XUVs
C:0 T:1 340 XUs and 225 XVs -> 33 XUVs
C:0 T:2 3997 XUs and 4265 XVs -> 115 XUVs
C:0 T:3 659 XUs and 380 XVs -> 36 XUVs
C:0 T:4 1261 XUs and 1378 XVs -> 46 XUVs
C:0 T:5 3105 XUs and 2359 XVs -> 264 XUVs
C:0 T:6 3269 XUs and 2985 XVs -> 248 XUVs
C:0 T:7 306 XUs and 309 XVs -> 26 XUVs
1859 XUVs total
1205 collection wire objects
1859 potential space points
Neighbour search...
37321 tests to find 12740 neighbours
Iterating with no regularization...
Begin: 6.85336e+09
0 6.72482e+09
1 6.72164e+09
Now with regularization...
Begin: 6.6956e+09
0 6.69552e+09
18-Sep-2025 10:51:36 CEST Closed output file "np02vd_raw_run039433_0362_df-s05-d5_dw_0_20250918T061249_reco_stage1_20250918T085136_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 75.4184 144.246 1050.47 113.178 147.137 47
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 8.1791e-05 0.000107879 0.000259927 0.000100361 2.69534e-05 47
produce:tpcrawdecoder:PDVDTPCReader 5.33557 6.71966 10.8292 6.47256 1.22934 47
produce:triggerrawdecoder:PDVDTriggerReader4 0.175048 0.182661 0.262974 0.177514 0.0165553 47
produce:pdvddaphne:DAPHNEReaderPDVD 4.98597 5.62569 7.45943 5.55772 0.354528 47
produce:ophit:OpHitFinder 0.0516975 0.0613457 0.0704436 0.061908 0.00499284 47
produce:opflash:OpFlashFinderVerticalDrift 0.00521621 0.0178031 0.0294364 0.0179053 0.00610999 47
produce:wclsdatavd:WireCellToolkit 45.5623 63.8874 104.076 55.9033 17.9324 47
produce:gaushit:GausHitFinder 0.672969 1.03185 2.12238 0.984664 0.285748 47
produce:nhitsfilter:NumberOfHitsFilter 0.000130212 0.000207087 0.000490947 0.000182173 7.43372e-05 47
produce:reco3d:SpacePointSolver 2.78498 7.16486 24.9392 6.05448 3.83452 47
produce:hitpdune:DisambigFromSpacePoints 0.0413838 0.169127 0.773394 0.14136 0.136244 47
produce:pandora:StandardPandora 10.0923 54.9712 943.477 21.5774 140.98 47
produce:pandoraTrack:LArPandoraTrackCreation 0.177916 0.642328 2.69296 0.442667 0.49466 47
produce:pandoraGnocalo:GnocchiCalorimetry 0.0120301 0.0267834 0.0672734 0.0248412 0.0093052 47
[art]:TriggerResults:TriggerResultInserter 3.038e-05 3.83554e-05 7.7458e-05 3.6491e-05 7.43735e-06 47
end_path:out1:RootOutput 4.257e-06 8.62436e-06 3.0879e-05 9.222e-06 4.10787e-06 47
end_path:out1:RootOutput(write) 3.19291 3.72166 4.929 3.5381 0.459935 47
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5061.73 MB
Peak resident set size usage (VmHWM): 3169.35 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0362_df-s05-d5_dw_0_20250918T061249_reco_stage1_20250918T085136_keepup.root
\tHists: np02vd_raw_run039433_0362_df-s05-d5_dw_0_20250918T061249_reco_stage1_20250918T085136_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0362_df-s05-d5_dw_0_20250918T061249_reco_stage1_20250918T085136_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0362_df-s05-d5_dw_0_20250918T061249_reco_stage1_20250918T085136_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": 1758185497.0,
"core.end_time": 1758185497.0,
"core.events": [
103793,
103799,
103805,
103811,
103817,
103823,
103829,
103835,
103841,
103847,
103853,
103859,
103865,
103871,
103877,
103883,
103889,
103895,
103901,
103907,
103913,
103919,
103925,
103931,
103937,
103943,
103949,
103955,
103961,
103967,
103973,
103979,
103985,
103991,
103997,
104003,
104009,
104015,
104021,
104027,
104033,
104039,
104045,
104051,
104057,
104063,
104069
],
"core.event_count": 47,
"core.first_event_number": 103793,
"core.last_event_number": 104069,
"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_0362_df-s05-d5_dw_0_20250918T061249.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0362_df-s05-d5_dw_0_20250918T061249_reco_stage1_20250918T085136_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": 1758185497.0,
"core.end_time": 1758185497.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_0362_df-s05-d5_dw_0_20250918T061249.hdf5"
}
]
}