5章、他観測ツールとの比較, インストール方法, それぞれのProbeに対しての解説, 内部動作についてみたいな感じ
何かやりたいときに参照することが多そう、手を動かした部分はあまりなかったので短め
目次
USDT Probe
読んでて試したくなったので、MySQLで試すかと思ったが8.0からProbeが消失していた、残念
なので、PostgreSQLの11で試すことにした
By default the probes are not compiled into PostgreSQL; the user needs to explicitly tell the configure script to make the probes available.
とのことだったがaptのリポジトリとして追加した先から落としてくるものは既にコンパイルオプションに入っていたので、そのままで問題なかった
❯ sudo /usr/share/bcc/tools/tplist -l /usr/lib/postgresql/11/bin/postgres /usr/lib/postgresql/11/bin/postgres postgresql:clog__checkpoint__start /usr/lib/postgresql/11/bin/postgres postgresql:clog__checkpoint__done /usr/lib/postgresql/11/bin/postgres postgresql:multixact__checkpoint__start /usr/lib/postgresql/11/bin/postgres postgresql:multixact__checkpoint__done /usr/lib/postgresql/11/bin/postgres postgresql:subtrans__checkpoint__start /usr/lib/postgresql/11/bin/postgres postgresql:subtrans__checkpoint__done /usr/lib/postgresql/11/bin/postgres postgresql:twophase__checkpoint__start /usr/lib/postgresql/11/bin/postgres postgresql:twophase__checkpoint__done /usr/lib/postgresql/11/bin/postgres postgresql:transaction__start /usr/lib/postgresql/11/bin/postgres postgresql:transaction__commit /usr/lib/postgresql/11/bin/postgres postgresql:transaction__abort /usr/lib/postgresql/11/bin/postgres postgresql:wal__buffer__write__dirty__start /usr/lib/postgresql/11/bin/postgres postgresql:wal__buffer__write__dirty__done /usr/lib/postgresql/11/bin/postgres postgresql:wal__switch /usr/lib/postgresql/11/bin/postgres postgresql:checkpoint__start /usr/lib/postgresql/11/bin/postgres postgresql:checkpoint__done /usr/lib/postgresql/11/bin/postgres postgresql:wal__insert /usr/lib/postgresql/11/bin/postgres postgresql:statement__status /usr/lib/postgresql/11/bin/postgres postgresql:buffer__flush__start /usr/lib/postgresql/11/bin/postgres postgresql:buffer__flush__done /usr/lib/postgresql/11/bin/postgres postgresql:buffer__read__start /usr/lib/postgresql/11/bin/postgres postgresql:buffer__read__done /usr/lib/postgresql/11/bin/postgres postgresql:buffer__write__dirty__start /usr/lib/postgresql/11/bin/postgres postgresql:buffer__write__dirty__done /usr/lib/postgresql/11/bin/postgres postgresql:buffer__sync__start /usr/lib/postgresql/11/bin/postgres postgresql:buffer__sync__done /usr/lib/postgresql/11/bin/postgres postgresql:buffer__sync__written /usr/lib/postgresql/11/bin/postgres postgresql:buffer__checkpoint__start /usr/lib/postgresql/11/bin/postgres postgresql:buffer__checkpoint__sync__start /usr/lib/postgresql/11/bin/postgres postgresql:buffer__checkpoint__done /usr/lib/postgresql/11/bin/postgres postgresql:lock__wait__start /usr/lib/postgresql/11/bin/postgres postgresql:lock__wait__done /usr/lib/postgresql/11/bin/postgres postgresql:deadlock__found /usr/lib/postgresql/11/bin/postgres postgresql:lwlock__wait__start /usr/lib/postgresql/11/bin/postgres postgresql:lwlock__wait__done /usr/lib/postgresql/11/bin/postgres postgresql:lwlock__acquire /usr/lib/postgresql/11/bin/postgres postgresql:lwlock__condacquire /usr/lib/postgresql/11/bin/postgres postgresql:lwlock__condacquire__fail /usr/lib/postgresql/11/bin/postgres postgresql:lwlock__acquire__or__wait /usr/lib/postgresql/11/bin/postgres postgresql:lwlock__acquire__or__wait__fail /usr/lib/postgresql/11/bin/postgres postgresql:lwlock__release /usr/lib/postgresql/11/bin/postgres postgresql:smgr__md__read__start /usr/lib/postgresql/11/bin/postgres postgresql:smgr__md__read__done /usr/lib/postgresql/11/bin/postgres postgresql:smgr__md__write__start /usr/lib/postgresql/11/bin/postgres postgresql:smgr__md__write__done /usr/lib/postgresql/11/bin/postgres postgresql:query__parse__start /usr/lib/postgresql/11/bin/postgres postgresql:query__parse__done /usr/lib/postgresql/11/bin/postgres postgresql:query__rewrite__start /usr/lib/postgresql/11/bin/postgres postgresql:query__rewrite__done /usr/lib/postgresql/11/bin/postgres postgresql:query__plan__start /usr/lib/postgresql/11/bin/postgres postgresql:query__plan__done /usr/lib/postgresql/11/bin/postgres postgresql:query__start /usr/lib/postgresql/11/bin/postgres postgresql:query__done /usr/lib/postgresql/11/bin/postgres postgresql:query__execute__start /usr/lib/postgresql/11/bin/postgres postgresql:query__execute__done /usr/lib/postgresql/11/bin/postgres postgresql:sort__start /usr/lib/postgresql/11/bin/postgres postgresql:sort__done
まだ良く書き方がわからないので、参考になりそうなサイト探していたらとてもわかりやすいサイトがあった
bccとUSDTを使ってMySQL/PostgreSQLのクエリログを取得する
クエリについて確認することは既にやっていたので、クエリのかかった時間を計測することにしてソースを一部いじってやってみた
from __future__ import print_function from bcc import BPF, USDT import sys pid = sys.argv[1] bpf_text = """ #include <uapi/linux/ptrace.h> int do_trace1(struct pt_regs *ctx) { char *query; bpf_usdt_readarg(1, ctx, &query); bpf_trace_printk("%s\\n", query); return 0; }; int do_trace2(struct pt_regs *ctx) { char *query; bpf_usdt_readarg(1, ctx, &query); bpf_trace_printk("%s\\n", query); return 0; }; """ contexts = [] u1 = USDT(pid=int(pid)) u1.enable_probe(probe="query__start", fn_name="do_trace1") contexts.append(u1) u2 = USDT(pid=int(pid)) u2.enable_probe(probe="query__done", fn_name="do_trace2") contexts.append(u2) b = BPF(text=bpf_text, usdt_contexts=contexts) print("%-18s %-16s %-6s %s" % ("TIME(s)", "COMM", "PID", "QUERY")) while True: try: (start_task, start_pid, start_cpu, start_flags, start_ts, start_msg) = b.trace_fields() (end_task, end_pid, end_cpu, end_flags, end_ts, end_msg) = b.trace_fields() except ValueError: print("value error") continue except KeyboardInterrupt: exit() print("%-18.9f %-16s %-6d %s" % (end_ts - start_ts, start_task.decode('utf-8'), start_pid, start_msg.decode('utf-8')))
後は普通に別ターミナルでクエリを投げて実行してみる
❯ sudo python3 psql_query_logger.py 16052 TIME(s) COMM PID QUERY 0.000189000 postgres 16052 SELECT * FROM user; 0.064199000 postgres 16052 SELECT * FROM pg_roles;
