1#!/usr/bin/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 22import ctypes as ct 23 24examples = """examples: 25 ./gethostlatency # trace all TCP accept()s 26 ./gethostlatency -p 181 # only trace PID 181 27""" 28parser = argparse.ArgumentParser( 29 description="Show latency for getaddrinfo/gethostbyname[2] calls", 30 formatter_class=argparse.RawDescriptionHelpFormatter, 31 epilog=examples) 32parser.add_argument("-p", "--pid", help="trace this PID only", type=int, 33 default=-1) 34parser.add_argument("--ebpf", action="store_true", 35 help=argparse.SUPPRESS) 36args = parser.parse_args() 37 38# load BPF program 39bpf_text = """ 40#include <uapi/linux/ptrace.h> 41#include <linux/sched.h> 42 43struct val_t { 44 u32 pid; 45 char comm[TASK_COMM_LEN]; 46 char host[80]; 47 u64 ts; 48}; 49 50struct data_t { 51 u32 pid; 52 u64 delta; 53 char comm[TASK_COMM_LEN]; 54 char host[80]; 55}; 56 57BPF_HASH(start, u32, struct val_t); 58BPF_PERF_OUTPUT(events); 59 60int do_entry(struct pt_regs *ctx) { 61 if (!PT_REGS_PARM1(ctx)) 62 return 0; 63 64 struct val_t val = {}; 65 u32 pid = bpf_get_current_pid_tgid(); 66 67 if (bpf_get_current_comm(&val.comm, sizeof(val.comm)) == 0) { 68 bpf_probe_read(&val.host, sizeof(val.host), 69 (void *)PT_REGS_PARM1(ctx)); 70 val.pid = bpf_get_current_pid_tgid(); 71 val.ts = bpf_ktime_get_ns(); 72 start.update(&pid, &val); 73 } 74 75 return 0; 76} 77 78int do_return(struct pt_regs *ctx) { 79 struct val_t *valp; 80 struct data_t data = {}; 81 u64 delta; 82 u32 pid = bpf_get_current_pid_tgid(); 83 84 u64 tsp = bpf_ktime_get_ns(); 85 86 valp = start.lookup(&pid); 87 if (valp == 0) 88 return 0; // missed start 89 90 bpf_probe_read(&data.comm, sizeof(data.comm), valp->comm); 91 bpf_probe_read(&data.host, sizeof(data.host), (void *)valp->host); 92 data.pid = valp->pid; 93 data.delta = tsp - valp->ts; 94 events.perf_submit(ctx, &data, sizeof(data)); 95 start.delete(&pid); 96 return 0; 97} 98""" 99if args.ebpf: 100 print(bpf_text) 101 exit() 102 103b = BPF(text=bpf_text) 104b.attach_uprobe(name="c", sym="getaddrinfo", fn_name="do_entry", pid=args.pid) 105b.attach_uprobe(name="c", sym="gethostbyname", fn_name="do_entry", 106 pid=args.pid) 107b.attach_uprobe(name="c", sym="gethostbyname2", fn_name="do_entry", 108 pid=args.pid) 109b.attach_uretprobe(name="c", sym="getaddrinfo", fn_name="do_return", 110 pid=args.pid) 111b.attach_uretprobe(name="c", sym="gethostbyname", fn_name="do_return", 112 pid=args.pid) 113b.attach_uretprobe(name="c", sym="gethostbyname2", fn_name="do_return", 114 pid=args.pid) 115 116TASK_COMM_LEN = 16 # linux/sched.h 117 118class Data(ct.Structure): 119 _fields_ = [ 120 ("pid", ct.c_ulonglong), 121 ("delta", ct.c_ulonglong), 122 ("comm", ct.c_char * TASK_COMM_LEN), 123 ("host", ct.c_char * 80) 124 ] 125 126# header 127print("%-9s %-6s %-16s %10s %s" % ("TIME", "PID", "COMM", "LATms", "HOST")) 128 129def print_event(cpu, data, size): 130 event = ct.cast(data, ct.POINTER(Data)).contents 131 print("%-9s %-6d %-16s %10.2f %s" % (strftime("%H:%M:%S"), event.pid, 132 event.comm.decode('utf-8', 'replace'), (float(event.delta) / 1000000), 133 event.host.decode('utf-8', 'replace'))) 134 135# loop with callback to print_event 136b["events"].open_perf_buffer(print_event) 137while 1: 138 b.perf_buffer_poll() 139