1#!/usr/bin/env python 2# 3# gethostlatency Show latency for getaddrinfo/gethostbyname[2] calls. 4# For Linux, uses BCC, eBPF. Embedded C. 5# 6# This can be useful for identifying DNS latency, by identifying which 7# remote host name lookups were slow, and by how much. 8# 9# This uses dynamic tracing of user-level functions and registers, and may 10# need modifications to match your software and processor architecture. 11# 12# Copyright 2016 Netflix, Inc. 13# Licensed under the Apache License, Version 2.0 (the "License") 14# 15# 28-Jan-2016 Brendan Gregg Created this. 16# 30-Mar-2016 Allan McAleavy updated for BPF_PERF_OUTPUT 17 18from __future__ import print_function 19from bcc import BPF 20from time import strftime 21import argparse 22 23examples = """examples: 24 ./gethostlatency # time getaddrinfo/gethostbyname[2] calls 25 ./gethostlatency -p 181 # only trace PID 181 26""" 27parser = argparse.ArgumentParser( 28 description="Show latency for getaddrinfo/gethostbyname[2] calls", 29 formatter_class=argparse.RawDescriptionHelpFormatter, 30 epilog=examples) 31parser.add_argument("-p", "--pid", help="trace this PID only", type=int, 32 default=-1) 33parser.add_argument("--ebpf", action="store_true", 34 help=argparse.SUPPRESS) 35args = parser.parse_args() 36 37# load BPF program 38bpf_text = """ 39#include <uapi/linux/ptrace.h> 40#include <linux/sched.h> 41 42struct val_t { 43 u32 pid; 44 char comm[TASK_COMM_LEN]; 45 char host[80]; 46 u64 ts; 47}; 48 49struct data_t { 50 u32 pid; 51 u64 delta; 52 char comm[TASK_COMM_LEN]; 53 char host[80]; 54}; 55 56BPF_HASH(start, u32, struct val_t); 57BPF_PERF_OUTPUT(events); 58 59int do_entry(struct pt_regs *ctx) { 60 if (!PT_REGS_PARM1(ctx)) 61 return 0; 62 63 struct val_t val = {}; 64 u64 pid_tgid = bpf_get_current_pid_tgid(); 65 u32 pid = pid_tgid >> 32; 66 u32 tid = (u32)pid_tgid; 67 68 if (bpf_get_current_comm(&val.comm, sizeof(val.comm)) == 0) { 69 bpf_probe_read_user(&val.host, sizeof(val.host), 70 (void *)PT_REGS_PARM1(ctx)); 71 val.pid = pid; 72 val.ts = bpf_ktime_get_ns(); 73 start.update(&tid, &val); 74 } 75 76 return 0; 77} 78 79int do_return(struct pt_regs *ctx) { 80 struct val_t *valp; 81 struct data_t data = {}; 82 u64 delta; 83 u64 pid_tgid = bpf_get_current_pid_tgid(); 84 u32 tid = (u32)pid_tgid; 85 86 u64 tsp = bpf_ktime_get_ns(); 87 88 valp = start.lookup(&tid); 89 if (valp == 0) 90 return 0; // missed start 91 92 bpf_probe_read_kernel(&data.comm, sizeof(data.comm), valp->comm); 93 bpf_probe_read_kernel(&data.host, sizeof(data.host), (void *)valp->host); 94 data.pid = valp->pid; 95 data.delta = tsp - valp->ts; 96 events.perf_submit(ctx, &data, sizeof(data)); 97 start.delete(&tid); 98 return 0; 99} 100""" 101if args.ebpf: 102 print(bpf_text) 103 exit() 104 105b = BPF(text=bpf_text) 106b.attach_uprobe(name="c", sym="getaddrinfo", fn_name="do_entry", pid=args.pid) 107b.attach_uprobe(name="c", sym="gethostbyname", fn_name="do_entry", 108 pid=args.pid) 109b.attach_uprobe(name="c", sym="gethostbyname2", fn_name="do_entry", 110 pid=args.pid) 111b.attach_uretprobe(name="c", sym="getaddrinfo", fn_name="do_return", 112 pid=args.pid) 113b.attach_uretprobe(name="c", sym="gethostbyname", fn_name="do_return", 114 pid=args.pid) 115b.attach_uretprobe(name="c", sym="gethostbyname2", fn_name="do_return", 116 pid=args.pid) 117 118# header 119print("%-9s %-7s %-16s %10s %s" % ("TIME", "PID", "COMM", "LATms", "HOST")) 120 121def print_event(cpu, data, size): 122 event = b["events"].event(data) 123 print("%-9s %-7d %-16s %10.2f %s" % (strftime("%H:%M:%S"), event.pid, 124 event.comm.decode('utf-8', 'replace'), (float(event.delta) / 1000000), 125 event.host.decode('utf-8', 'replace'))) 126 127# loop with callback to print_event 128b["events"].open_perf_buffer(print_event) 129while 1: 130 try: 131 b.perf_buffer_poll() 132 except KeyboardInterrupt: 133 exit() 134