Core dump debugging performance too slow #12772

Activity

1. borjamunozf commented on Sep 26, 2024

   

   BMF (borjamunozf)

   on Sep 26, 2024

   Last edited by borjamunozf

   Author

   More actions

   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 1009105
   

   The 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 ?
2. Colen Garoutte-Carson (Colengms)

   added

   debugger

   help wantedCan be fixed in the public (open source) repo.Can be fixed in the public (open source) repo.

   on Sep 26, 2024