How to Summarize gdb Backtrace with pt-pmp (and Flamegraph)

Дата публикации: 10-02-2022 16:30:00

This is going to be more like a note to myself and my readers than a real blog post. But still I\'d like o document the trick that I am applying for years already, in its most convenient form. Assuming you have a backtrace (or full backtrace) created from a core file or by attaching gdb to a live (and maybe hanging) process with many threads, like MySQL or MariaDB server, what is the best way to summarize it quickly, to understand what most of the threads are doing/hanging at? Like this huge backtrace with hundreds of threads:openxs@ao756:~$ ls -l /tmp/backtrace1.txt-rw-rw-r-- 1 openxs openxs 2817054 лют 10 17:02 /tmp/backtrace1.txtopenxs@ao756:~$ grep LWP /tmp/backtrace1.txt | wc -l1915Here it is. You have to download pt-pmp from Percona Toolkit. Then source the pt-pmp script and rely on the aggregate_stacktrace function from it, quite advanced in summarizing stack traces:openxs@ao756:~$ which pt-pmp/usr/bin/pt-pmpopenxs@ao756:~$ . /usr/bin/pt-pmpopenxs@ao756:~$ cat /tmp/backtrace1.txt | aggregate_stacktrace > /tmp/pmp1.txt  openxs@ao756:~$ ls -l /tmp/pmp1.txt-rw-rw-r-- 1 openxs openxs 34174 лют 10 18:07 /tmp/pmp1.txtopenxs@ao756:~$ head -5 /tmp/pmp1.txt    598 poll(libc.so.6),vio_io_wait(viosocket.c:945),vio_socket_io_wait(viosocket.c:108),vio_read(viosocket.c:184),my_real_read(net_serv.cc:892),my_net_read_packet_reallen(net_serv.cc:1162),my_net_read_packet(net_serv.cc:1146),do_command(sql_parse.cc:1262),do_handle_one_connection(sql_connect.cc:1336),handle_one_connection(sql_connect.cc:1241),pfs_spawn_thread(pfs.cc:1862),start_thread(libpthread.so.0),clone(libc.so.6)     82 pthread_cond_wait,wait(os0event.cc:158),wait_low(os0event.cc:158),os_event_wait_low(os0event.cc:158),sync_array_wait_event(sync0arr.cc:471),rw_lock_s_lock_spin(sync0rw.cc:373),rw_lock_s_lock_func(sync0rw.ic:290),pfs_rw_lock_s_lock_func(sync0rw.ic:290),buf_page_get_gen(buf0buf.cc:4905),btr_cur_search_to_nth_level(btr0cur.cc:1243),btr_pcur_open_low(btr0pcur.ic:467),row_ins_scan_sec_index_for_duplicate(btr0pcur.ic:467),row_ins_sec_index_entry_low(btr0pcur.ic:467),row_ins_sec_index_entry(row0ins.cc:3251),row_ins_index_entry(row0ins.cc:3297),row_ins_index_entry_step(row0ins.cc:3297),row_ins(row0ins.cc:3297),row_ins_step(row0ins.cc:3297),row_insert_for_mysql(row0mysql.cc:1414),ha_innobase::write_row(ha_innodb.cc:8231),handler::ha_write_row(handler.cc:6089),write_record(sql_insert.cc:1941),mysql_insert(sql_insert.cc:1066),mysql_execute_command(sql_parse.cc:4170),mysql_parse(sql_parse.cc:7760),dispatch_command(sql_parse.cc:1832),do_command(sql_parse.cc:1386),do_handle_one_connection(sql_connect.cc:1336),handle_one_connection(sql_connect.cc:1241),pfs_spawn_thread(pfs.cc:1862),start_thread(libpthread.so.0),clone(libc.so.6)     55 pthread_cond_wait,wait(os0event.cc:158),wait_low(os0event.cc:158),os_event_wait_low(os0event.cc:158),lock_wait_suspend_thread(lock0wait.cc:347),row_mysql_handle_errors(row0mysql.cc:741),row_insert_for_mysql(row0mysql.cc:1428),ha_innobase::write_row(ha_innodb.cc:8231),handler::ha_write_row(handler.cc:6089),write_record(sql_insert.cc:1941),mysql_insert(sql_insert.cc:1066),mysql_execute_command(sql_parse.cc:4170),mysql_parse(sql_parse.cc:7760),dispatch_command(sql_parse.cc:1832),do_command(sql_parse.cc:1386),do_handle_one_connection(sql_connect.cc:1336),handle_one_connection(sql_connect.cc:1241),pfs_spawn_thread(pfs.cc:1862),start_thread(libpthread.so.0),clone(libc.so.6)     38 pthread_cond_wait,wait(os0event.cc:158),wait_low(os0event.cc:158),os_event_wait_low(os0event.cc:158),sync_array_wait_event(sync0arr.cc:471),rw_lock_x_lock_func(sync0rw.cc:733),pfs_rw_lock_x_lock_func(sync0rw.ic:544),buf_page_get_gen(buf0buf.cc:4918),btr_cur_search_to_nth_level(btr0cur.cc:1243),row_ins_sec_index_entry_low(row0ins.cc:2946),row_ins_sec_index_entry(row0ins.cc:3251),row_ins_index_entry(row0ins.cc:3297),row_ins_index_entry_step(row0ins.cc:3297),row_ins(row0ins.cc:3297),row_ins_step(row0ins.cc:3297),row_insert_for_mysql(row0mysql.cc:1414),ha_innobase::write_row(ha_innodb.cc:8231),handler::ha_write_row(handler.cc:6089),write_record(sql_insert.cc:1941),mysql_insert(sql_insert.cc:1066),mysql_execute_command(sql_parse.cc:4170),mysql_parse(sql_parse.cc:7760),dispatch_command(sql_parse.cc:1832),do_command(sql_parse.cc:1386),do_handle_one_connection(sql_connect.cc:1336),handle_one_connection(sql_connect.cc:1241),pfs_spawn_thread(pfs.cc:1862),start_thread(libpthread.so.0),clone(libc.so.6)     32 pthread_cond_wait,wait(os0event.cc:158),wait_low(os0event.cc:158),os_event_wait_low(os0event.cc:158),sync_array_wait_event(sync0arr.cc:471),rw_lock_x_lock_func(sync0rw.cc:733),pfs_rw_lock_x_lock_func(sync0rw.ic:544),buf_page_get_gen(buf0buf.cc:4918),btr_cur_search_to_nth_level(btr0cur.cc:1243),row_ins_sec_index_entry_low(row0ins.cc:3040),row_ins_sec_index_entry(row0ins.cc:3251),row_ins_index_entry(row0ins.cc:3297),row_ins_index_entry_step(row0ins.cc:3297),row_ins(row0ins.cc:3297),row_ins_step(row0ins.cc:3297),row_insert_for_mysql(row0mysql.cc:1414),ha_innobase::write_row(ha_innodb.cc:8231),handler::ha_write_row(handler.cc:6089),write_record(sql_insert.cc:1941),mysql_insert(sql_insert.cc:1066),mysql_execute_command(sql_parse.cc:4170),mysql_parse(sql_parse.cc:7760),dispatch_command(sql_parse.cc:1832),do_command(sql_parse.cc:1386),do_handle_one_connection(sql_connect.cc:1336),handle_one_connection(sql_connect.cc:1241),pfs_spawn_thread(pfs.cc:1862),start_thread(libpthread.so.0),clone(libc.so.6)If a summary like above is not clear enough, we can surely go one step further and create a proper flame graph based on the output above:openxs@ao756:~$ cat /tmp/pmp1.txt | awk \'{print $2, $1}\' | sed -e \'s/,/;/g\' | ~/git/FlameGraph/flamegraph.pl --countname=\"threads\" --reverse - >/tmp/pmp1.svg   Then with some creative zooming and search we can concentrate on waits:Frames with \"wait\" substring in the function name are highlightedThat\'s all. As simple as it looks. Quick overview of the backtrace before you start digging there.
How to Summarize gdb Backtrace with pt-pmp (and Flamegraph) appeared first on MariaDB.org

Основное содержимое страницы с новостью.

Схожие новости

#	Наименование новости	Тональность	Информативность	Дата публикации
1	Dynamic Tracing of pthread_mutex_lock in MariaDB – First Steps	0	6.5	20-09-2020
2	How to Add Probe Inside a Function and Access Local Variables with bpftrace	0	5.9	04-02-2022
3	Playing with recent bpftrace and MariaDB 10.5 on Fedora – Part II, Using the Existing Tools	0	7.98	24-01-2021
4	Playing with recent bpftrace and MariaDB 10.5 on Fedora – Part V, Proper Way To Summarize Time Spent per Stack	0	6.84	30-01-2021
5	On Upcoming FOSDEM 2021	0	7.67	05-02-2021
6	Playing with recent bpftrace and MariaDB 10.5 on Fedora – Part IV, Creating a New Tool for Tracing Time Spent in __lll_lock_wait	0	7	28-01-2021
7	Playing with recent bpftrace and MariaDB 10.5 on Fedora – Part III, Creating a New Tool for Tracing Mutexes	0	6.5	27-01-2021
8	bpftrace as a code/function coverage tool for MariaDB server	0	6.46	03-10-2021
9	Quick builds and rebuilds of MariaDB using Docker	0	8.01	12-03-2023
10	MySQL GTID tags and binlog events	0	5.43	02-12-2024

Классификация: Мнения. Схожих патентов: 0. Схожих новостей: 10. Тональность: 0. Информативность: 6.06. Источник: mariadb.org.