Brendan Gregg | 797c3ec | 2016-10-19 18:55:10 -0700 | [diff] [blame] | 1 | Demonstrations of tcplife, the Linux BPF/bcc version. |
| 2 | |
| 3 | |
| 4 | tcplife summarizes TCP sessions that open and close while tracing. For example: |
| 5 | |
| 6 | # ./tcplife |
| 7 | PID COMM LADDR LPORT RADDR RPORT TX_KB RX_KB MS |
| 8 | 22597 recordProg 127.0.0.1 46644 127.0.0.1 28527 0 0 0.23 |
| 9 | 3277 redis-serv 127.0.0.1 28527 127.0.0.1 46644 0 0 0.28 |
| 10 | 22598 curl 100.66.3.172 61620 52.205.89.26 80 0 1 91.79 |
| 11 | 22604 curl 100.66.3.172 44400 52.204.43.121 80 0 1 121.38 |
| 12 | 22624 recordProg 127.0.0.1 46648 127.0.0.1 28527 0 0 0.22 |
| 13 | 3277 redis-serv 127.0.0.1 28527 127.0.0.1 46648 0 0 0.27 |
| 14 | 22647 recordProg 127.0.0.1 46650 127.0.0.1 28527 0 0 0.21 |
| 15 | 3277 redis-serv 127.0.0.1 28527 127.0.0.1 46650 0 0 0.26 |
| 16 | [...] |
| 17 | |
| 18 | This caught a program, "recordProg" making a few short-lived TCP connections |
| 19 | to "redis-serv", lasting about 0.25 milliseconds each connection. A couple of |
| 20 | "curl" sessions were also traced, connecting to port 80, and lasting 91 and 121 |
| 21 | milliseconds. |
| 22 | |
| 23 | This tool is useful for workload characterisation and flow accounting: |
| 24 | identifying what connections are happening, with the bytes transferred. |
| 25 | |
| 26 | |
| 27 | Process names are truncated to 10 characters. By using the wide option, -w, |
| 28 | the column width becomes 16 characters. The IP address columns are also wider |
| 29 | to fit IPv6 addresses: |
| 30 | |
| 31 | # ./tcplife -w |
| 32 | PID COMM IP LADDR LPORT RADDR RPORT TX_KB RX_KB MS |
| 33 | 26315 recordProgramSt 4 127.0.0.1 44188 127.0.0.1 28527 0 0 0.21 |
| 34 | 3277 redis-server 4 127.0.0.1 28527 127.0.0.1 44188 0 0 0.26 |
| 35 | 26320 ssh 6 fe80::8a3:9dff:fed5:6b19 22440 fe80::8a3:9dff:fed5:6b19 22 1 1 457.52 |
| 36 | 26321 sshd 6 fe80::8a3:9dff:fed5:6b19 22 fe80::8a3:9dff:fed5:6b19 22440 1 1 458.69 |
| 37 | 26341 recordProgramSt 4 127.0.0.1 44192 127.0.0.1 28527 0 0 0.27 |
| 38 | 3277 redis-server 4 127.0.0.1 28527 127.0.0.1 44192 0 0 0.32 |
| 39 | |
| 40 | |
| 41 | In this example, I uploaded a 10 Mbyte file to the server, and then downloaded |
| 42 | it again, using scp: |
| 43 | |
| 44 | # ./tcplife |
| 45 | PID COMM LADDR LPORT RADDR RPORT TX_KB RX_KB MS |
| 46 | 7715 recordProg 127.0.0.1 50894 127.0.0.1 28527 0 0 0.25 |
| 47 | 3277 redis-serv 127.0.0.1 28527 127.0.0.1 50894 0 0 0.30 |
| 48 | 7619 sshd 100.66.3.172 22 100.127.64.230 63033 5 10255 3066.79 |
| 49 | 7770 recordProg 127.0.0.1 50896 127.0.0.1 28527 0 0 0.20 |
| 50 | 3277 redis-serv 127.0.0.1 28527 127.0.0.1 50896 0 0 0.24 |
| 51 | 7793 recordProg 127.0.0.1 50898 127.0.0.1 28527 0 0 0.23 |
| 52 | 3277 redis-serv 127.0.0.1 28527 127.0.0.1 50898 0 0 0.27 |
| 53 | 7847 recordProg 127.0.0.1 50900 127.0.0.1 28527 0 0 0.24 |
| 54 | 3277 redis-serv 127.0.0.1 28527 127.0.0.1 50900 0 0 0.29 |
| 55 | 7870 recordProg 127.0.0.1 50902 127.0.0.1 28527 0 0 0.29 |
| 56 | 3277 redis-serv 127.0.0.1 28527 127.0.0.1 50902 0 0 0.30 |
| 57 | 7798 sshd 100.66.3.172 22 100.127.64.230 64925 10265 6 2176.15 |
| 58 | [...] |
| 59 | |
| 60 | You can see the 10 Mbytes received by sshd, and then later transmitted. Looks |
| 61 | like receive was slower (3.07 seconds) than transmit (2.18 seconds). |
| 62 | |
| 63 | |
| 64 | Timestamps can be added with -t: |
| 65 | |
| 66 | # ./tcplife -t |
| 67 | TIME(s) PID COMM LADDR LPORT RADDR RPORT TX_KB RX_KB MS |
| 68 | 0.000000 5973 recordProg 127.0.0.1 47986 127.0.0.1 28527 0 0 0.25 |
| 69 | 0.000059 3277 redis-serv 127.0.0.1 28527 127.0.0.1 47986 0 0 0.29 |
| 70 | 1.022454 5996 recordProg 127.0.0.1 47988 127.0.0.1 28527 0 0 0.23 |
| 71 | 1.022513 3277 redis-serv 127.0.0.1 28527 127.0.0.1 47988 0 0 0.27 |
| 72 | 2.044868 6019 recordProg 127.0.0.1 47990 127.0.0.1 28527 0 0 0.24 |
| 73 | 2.044924 3277 redis-serv 127.0.0.1 28527 127.0.0.1 47990 0 0 0.28 |
| 74 | 3.069136 6042 recordProg 127.0.0.1 47992 127.0.0.1 28527 0 0 0.22 |
| 75 | 3.069204 3277 redis-serv 127.0.0.1 28527 127.0.0.1 47992 0 0 0.28 |
| 76 | |
| 77 | This shows that the recordProg process was connecting once per second. |
| 78 | |
| 79 | There's also a -T for HH:MM:SS formatted times. |
| 80 | |
| 81 | |
| 82 | There's a comma separated values mode, -s. Here it is with both -t and -T |
| 83 | timestamps: |
| 84 | |
| 85 | # ./tcplife -stT |
| 86 | TIME,TIME(s),PID,COMM,IP,LADDR,LPORT,RADDR,RPORT,TX_KB,RX_KB,MS |
| 87 | 23:39:38,0.000000,7335,recordProgramSt,4,127.0.0.1,48098,127.0.0.1,28527,0,0,0.26 |
| 88 | 23:39:38,0.000064,3277,redis-server,4,127.0.0.1,28527,127.0.0.1,48098,0,0,0.32 |
| 89 | 23:39:39,1.025078,7358,recordProgramSt,4,127.0.0.1,48100,127.0.0.1,28527,0,0,0.25 |
| 90 | 23:39:39,1.025141,3277,redis-server,4,127.0.0.1,28527,127.0.0.1,48100,0,0,0.30 |
| 91 | 23:39:41,2.040949,7381,recordProgramSt,4,127.0.0.1,48102,127.0.0.1,28527,0,0,0.24 |
| 92 | 23:39:41,2.041011,3277,redis-server,4,127.0.0.1,28527,127.0.0.1,48102,0,0,0.29 |
| 93 | 23:39:42,3.067848,7404,recordProgramSt,4,127.0.0.1,48104,127.0.0.1,28527,0,0,0.30 |
| 94 | 23:39:42,3.067914,3277,redis-server,4,127.0.0.1,28527,127.0.0.1,48104,0,0,0.35 |
| 95 | [...] |
| 96 | |
| 97 | |
| 98 | There are options for filtering on local and remote ports. Here is filtering |
| 99 | on local ports 22 and 80: |
| 100 | |
| 101 | # ./tcplife.py -L 22,80 |
| 102 | PID COMM LADDR LPORT RADDR RPORT TX_KB RX_KB MS |
| 103 | 8301 sshd 100.66.3.172 22 100.127.64.230 58671 3 3 1448.52 |
| 104 | [...] |
| 105 | |
| 106 | |
| 107 | USAGE: |
| 108 | |
| 109 | # ./tcplife.py -h |
| 110 | usage: tcplife.py [-h] [-T] [-t] [-w] [-s] [-p PID] [-L LOCALPORT] |
| 111 | [-D REMOTEPORT] |
| 112 | |
| 113 | Trace the lifespan of TCP sessions and summarize |
| 114 | |
| 115 | optional arguments: |
| 116 | -h, --help show this help message and exit |
| 117 | -T, --time include time column on output (HH:MM:SS) |
| 118 | -t, --timestamp include timestamp on output (seconds) |
| 119 | -w, --wide wide column output (fits IPv6 addresses) |
Edward Betts | fdf9b08 | 2017-10-10 21:13:28 +0100 | [diff] [blame] | 120 | -s, --csv comma separated values output |
Brendan Gregg | 797c3ec | 2016-10-19 18:55:10 -0700 | [diff] [blame] | 121 | -p PID, --pid PID trace this PID only |
| 122 | -L LOCALPORT, --localport LOCALPORT |
| 123 | comma-separated list of local ports to trace. |
| 124 | -D REMOTEPORT, --remoteport REMOTEPORT |
| 125 | comma-separated list of remote ports to trace. |
| 126 | |
| 127 | examples: |
| 128 | ./tcplife # trace all TCP connect()s |
| 129 | ./tcplife -t # include time column (HH:MM:SS) |
| 130 | ./tcplife -w # wider colums (fit IPv6) |
| 131 | ./tcplife -stT # csv output, with times & timestamps |
| 132 | ./tcplife -p 181 # only trace PID 181 |
| 133 | ./tcplife -L 80 # only trace local port 80 |
| 134 | ./tcplife -L 80,81 # only trace local ports 80 and 81 |
| 135 | ./tcplife -D 80 # only trace remote port 80 |