Brendan Gregg | 239e863 | 2016-07-25 15:02:32 -0700 | [diff] [blame] | 1 | #!/usr/bin/python |
| 2 | # |
| 3 | # sync_timing.py Trace time between syncs. |
| 4 | # For Linux, uses BCC, eBPF. Embedded C. |
| 5 | # |
| 6 | # Written as a basic example of tracing time between events. |
| 7 | # |
| 8 | # Copyright 2016 Netflix, Inc. |
| 9 | # Licensed under the Apache License, Version 2.0 (the "License") |
| 10 | |
| 11 | from __future__ import print_function |
| 12 | from bcc import BPF |
| 13 | |
| 14 | # load BPF program |
| 15 | b = BPF(text=""" |
| 16 | #include <uapi/linux/ptrace.h> |
Brendan Gregg | 239e863 | 2016-07-25 15:02:32 -0700 | [diff] [blame] | 17 | |
| 18 | BPF_HASH(last); |
| 19 | |
Samuel Nair | e7a5bdc | 2017-08-22 23:09:55 +0800 | [diff] [blame] | 20 | int do_trace(struct pt_regs *ctx) { |
Brendan Gregg | 239e863 | 2016-07-25 15:02:32 -0700 | [diff] [blame] | 21 | u64 ts, *tsp, delta, key = 0; |
| 22 | |
| 23 | // attempt to read stored timestamp |
| 24 | tsp = last.lookup(&key); |
| 25 | if (tsp != 0) { |
| 26 | delta = bpf_ktime_get_ns() - *tsp; |
| 27 | if (delta < 1000000000) { |
| 28 | // output if time is less than 1 second |
| 29 | bpf_trace_printk("%d\\n", delta / 1000000); |
| 30 | } |
| 31 | last.delete(&key); |
| 32 | } |
| 33 | |
| 34 | // update stored timestamp |
| 35 | ts = bpf_ktime_get_ns(); |
| 36 | last.update(&key, &ts); |
Samuel Nair | e7a5bdc | 2017-08-22 23:09:55 +0800 | [diff] [blame] | 37 | return 0; |
Brendan Gregg | 239e863 | 2016-07-25 15:02:32 -0700 | [diff] [blame] | 38 | } |
| 39 | """) |
| 40 | |
Yonghong Song | 83b49ad | 2018-04-24 10:15:24 -0700 | [diff] [blame] | 41 | b.attach_kprobe(event=b.get_syscall_fnname("sync"), fn_name="do_trace") |
Brendan Gregg | 239e863 | 2016-07-25 15:02:32 -0700 | [diff] [blame] | 42 | print("Tracing for quick sync's... Ctrl-C to end") |
| 43 | |
| 44 | # format output |
| 45 | start = 0 |
| 46 | while 1: |
| 47 | (task, pid, cpu, flags, ts, ms) = b.trace_fields() |
| 48 | if start == 0: |
| 49 | start = ts |
| 50 | ts = ts - start |
| 51 | print("At time %.2f s: multiple syncs detected, last %s ms ago" % (ts, ms)) |