borjamunozf
commented
2 days ago I have a dummy python script to calculate elapsed time and map the IDs of the request. It shows the top 10.
import argparse
from pathlib import Path
import re
ELAPSED_PATTERN = r'\d+: \(\d+\) (\d+): elapsed time (\d+)'
def sum_elapsed_time(file: Path):
elapsed_time_by_id = {}
pattern = re.compile(ELAPSED_PATTERN)
with file.open('r') as f:
for line in f:
match = pattern.search(line)
if match:
unique_id = int(match.group(1))
elapsed_time = int(match.group(2))
if unique_id not in elapsed_time_by_id:
elapsed_time_by_id[unique_id] = elapsed_time
total_elapsed_time = sum(elapsed_time_by_id.values())
total_elapsed_time = total_elapsed_time / (1000 * 60)
return total_elapsed_time, elapsed_time_by_id
def main() -> None:
parser = argparse.ArgumentParser(description='Calculate elapsed time info - VScode debug')
parser.add_argument("logfile", nargs='?', help="Log file to parse")
args = parser.parse_args()
if not args.logfile:
print("No log file provided")
parser.print_usage()
return
logpath = Path(args.logfile).resolve()
total, ids_req = sum_elapsed_time(logpath)
print(f"Total elapsed time: {total} minutes")
print("Top requests IDs: <id> : <elapsed time> miliseconds")
print(sorted(ids_req.items(), key=lambda x: x[1], reverse=True)[:10])
main()However, something it's be wrong because the total elapsed time is way too high always, not the real one. Probably the conc requests and so on, but at least it's helpful to get the longest requests...?
For the gdb_multiarch txt:
Total elapsed time: 39.5403 minutes
Top requests IDs: <id> : <elapsed time> miliseconds
[(**1100**, **1009105**), (1007, 71709), (1072, 20475), (1070, 20474), (1071, 20474), (1068, 20473), (1069, 20473), (1008, 19430), (1016, 19415), (1017, 19415)]The 1100 takes ~16 minutes itself, which maps to this request (var-create cutFrames)
-> E (output): {"type":"event","event":"output","body":{"category":"console","output":"1: (100338) <-1100-var-create - * \"cutFrames\"\n"},"seq":3203}
1: (100338) <-1100-var-create - * "cutFrames"
--> E (output): {"type":"event","event":"output","body":{"category":"console","output":"1: (1109438) ->1100^done,name=\"var9\",numchild=\"0\",value=\"4\",type=\"size_t\",thread-id=\"1\",has_more=\"0\"\n"},"seq":3205}
1: (1109438) ->
^done,name="var9",numchild="0",value="4",type="size_t",thread-id="1",has_more="0"
--> E (output): {"type":"event","event":"output","body":{"category":"console","output":"1: (1109443) ->(gdb)\n"},"seq":3207}
1: (1109443) ->(gdb)
--> E (output): {"type":"event","event":"output","body":{"category":"console","output":"1: (1109443) 1100: elapsed time 1009105\n"},"seq":3209}
1: (1109443) 1100: elapsed time 1009105The 1007 request is file-exec-and-symbols, took ~1min 30secs
--> E (output): {"type":"event","event":"output","body":{"category":"console","output":"1: (578) <-1007-file-exec-and-symbols /mnt/disk1/asd/app/bin/DispApp\n"},"seq":86}
1: (578) <-1007-file-exec-and-symbols /mnt/disk1/asd/app/bin/DispApp
--> E (output): {"type":"event","event":"output","body":{"category":"console","output":"1: (72285) ->1007^done\n"},"seq":88}
1: (72285) ->1007^done
--> E (output): {"type":"event","event":"output","body":{"category":"console","output":"1: (72288) ->(gdb)\n"},"seq":90}
1: (72288) ->(gdb)
--> E (output): {"type":"event","event":"output","body":{"category":"console","output":"1: (72288) 1007: elapsed time 71709\n"},"seq":92}Could be this issue linked to #9988 ?
Environment
Bug Summary and Steps to Reproduce
Bug Summary:
Core dump debugging is quite slow with real world C++ scenarios. Last sample data we received from other devs throws a bad performance and overall experience.
Sample measurements:
From what we have seen, the symbol loading is not the main pain point, but the requests done afterwards the symbols have been loaded.
Tested in different OS versions, VScode and C++ ext. I don't think it's an issue or regression because this performance problems with debugging production C++ projects has been not new since a few years at least when I started working with vscode.
I also tested with different gdb versions with no effect regarding perf in Vscode core dump debugging:
Debugger Configurations
Debugger Logs
Other Extensions
No response
Additional Information
Log file (too huge for pasting) coredump_issue_debug_vscodelog_15.txt
gdb-multiarch 12.1 (20 minutes!)
gdb_multiarch_12.1_20minutes.txt
gdb15_fresh_wsl.txt