blob: fe4e52b102e64d2241e13804bddf8684d46a7f18 [file] [log] [blame]
Brendan Gregg797c3ec2016-10-19 18:55:10 -07001Demonstrations of tcplife, the Linux BPF/bcc version.
2
3
4tcplife summarizes TCP sessions that open and close while tracing. For example:
5
6# ./tcplife
7PID COMM LADDR LPORT RADDR RPORT TX_KB RX_KB MS
822597 recordProg 127.0.0.1 46644 127.0.0.1 28527 0 0 0.23
93277 redis-serv 127.0.0.1 28527 127.0.0.1 46644 0 0 0.28
1022598 curl 100.66.3.172 61620 52.205.89.26 80 0 1 91.79
1122604 curl 100.66.3.172 44400 52.204.43.121 80 0 1 121.38
1222624 recordProg 127.0.0.1 46648 127.0.0.1 28527 0 0 0.22
133277 redis-serv 127.0.0.1 28527 127.0.0.1 46648 0 0 0.27
1422647 recordProg 127.0.0.1 46650 127.0.0.1 28527 0 0 0.21
153277 redis-serv 127.0.0.1 28527 127.0.0.1 46650 0 0 0.26
16[...]
17
18This caught a program, "recordProg" making a few short-lived TCP connections
19to "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
21milliseconds.
22
23This tool is useful for workload characterisation and flow accounting:
24identifying what connections are happening, with the bytes transferred.
25
26
27Process names are truncated to 10 characters. By using the wide option, -w,
28the column width becomes 16 characters. The IP address columns are also wider
29to fit IPv6 addresses:
30
31# ./tcplife -w
32PID COMM IP LADDR LPORT RADDR RPORT TX_KB RX_KB MS
3326315 recordProgramSt 4 127.0.0.1 44188 127.0.0.1 28527 0 0 0.21
343277 redis-server 4 127.0.0.1 28527 127.0.0.1 44188 0 0 0.26
3526320 ssh 6 fe80::8a3:9dff:fed5:6b19 22440 fe80::8a3:9dff:fed5:6b19 22 1 1 457.52
3626321 sshd 6 fe80::8a3:9dff:fed5:6b19 22 fe80::8a3:9dff:fed5:6b19 22440 1 1 458.69
3726341 recordProgramSt 4 127.0.0.1 44192 127.0.0.1 28527 0 0 0.27
383277 redis-server 4 127.0.0.1 28527 127.0.0.1 44192 0 0 0.32
39
40
41In this example, I uploaded a 10 Mbyte file to the server, and then downloaded
42it again, using scp:
43
44# ./tcplife
45PID COMM LADDR LPORT RADDR RPORT TX_KB RX_KB MS
467715 recordProg 127.0.0.1 50894 127.0.0.1 28527 0 0 0.25
473277 redis-serv 127.0.0.1 28527 127.0.0.1 50894 0 0 0.30
487619 sshd 100.66.3.172 22 100.127.64.230 63033 5 10255 3066.79
497770 recordProg 127.0.0.1 50896 127.0.0.1 28527 0 0 0.20
503277 redis-serv 127.0.0.1 28527 127.0.0.1 50896 0 0 0.24
517793 recordProg 127.0.0.1 50898 127.0.0.1 28527 0 0 0.23
523277 redis-serv 127.0.0.1 28527 127.0.0.1 50898 0 0 0.27
537847 recordProg 127.0.0.1 50900 127.0.0.1 28527 0 0 0.24
543277 redis-serv 127.0.0.1 28527 127.0.0.1 50900 0 0 0.29
557870 recordProg 127.0.0.1 50902 127.0.0.1 28527 0 0 0.29
563277 redis-serv 127.0.0.1 28527 127.0.0.1 50902 0 0 0.30
577798 sshd 100.66.3.172 22 100.127.64.230 64925 10265 6 2176.15
58[...]
59
60You can see the 10 Mbytes received by sshd, and then later transmitted. Looks
61like receive was slower (3.07 seconds) than transmit (2.18 seconds).
62
63
64Timestamps can be added with -t:
65
66# ./tcplife -t
67TIME(s) PID COMM LADDR LPORT RADDR RPORT TX_KB RX_KB MS
680.000000 5973 recordProg 127.0.0.1 47986 127.0.0.1 28527 0 0 0.25
690.000059 3277 redis-serv 127.0.0.1 28527 127.0.0.1 47986 0 0 0.29
701.022454 5996 recordProg 127.0.0.1 47988 127.0.0.1 28527 0 0 0.23
711.022513 3277 redis-serv 127.0.0.1 28527 127.0.0.1 47988 0 0 0.27
722.044868 6019 recordProg 127.0.0.1 47990 127.0.0.1 28527 0 0 0.24
732.044924 3277 redis-serv 127.0.0.1 28527 127.0.0.1 47990 0 0 0.28
743.069136 6042 recordProg 127.0.0.1 47992 127.0.0.1 28527 0 0 0.22
753.069204 3277 redis-serv 127.0.0.1 28527 127.0.0.1 47992 0 0 0.28
76
77This shows that the recordProg process was connecting once per second.
78
79There's also a -T for HH:MM:SS formatted times.
80
81
82There's a comma separated values mode, -s. Here it is with both -t and -T
83timestamps:
84
85# ./tcplife -stT
86TIME,TIME(s),PID,COMM,IP,LADDR,LPORT,RADDR,RPORT,TX_KB,RX_KB,MS
8723:39:38,0.000000,7335,recordProgramSt,4,127.0.0.1,48098,127.0.0.1,28527,0,0,0.26
8823:39:38,0.000064,3277,redis-server,4,127.0.0.1,28527,127.0.0.1,48098,0,0,0.32
8923:39:39,1.025078,7358,recordProgramSt,4,127.0.0.1,48100,127.0.0.1,28527,0,0,0.25
9023:39:39,1.025141,3277,redis-server,4,127.0.0.1,28527,127.0.0.1,48100,0,0,0.30
9123:39:41,2.040949,7381,recordProgramSt,4,127.0.0.1,48102,127.0.0.1,28527,0,0,0.24
9223:39:41,2.041011,3277,redis-server,4,127.0.0.1,28527,127.0.0.1,48102,0,0,0.29
9323:39:42,3.067848,7404,recordProgramSt,4,127.0.0.1,48104,127.0.0.1,28527,0,0,0.30
9423: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
98There are options for filtering on local and remote ports. Here is filtering
99on local ports 22 and 80:
100
101# ./tcplife.py -L 22,80
102PID COMM LADDR LPORT RADDR RPORT TX_KB RX_KB MS
1038301 sshd 100.66.3.172 22 100.127.64.230 58671 3 3 1448.52
104[...]
105
106
107USAGE:
108
109# ./tcplife.py -h
110usage: tcplife.py [-h] [-T] [-t] [-w] [-s] [-p PID] [-L LOCALPORT]
111 [-D REMOTEPORT]
112
113Trace the lifespan of TCP sessions and summarize
114
115optional 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 Bettsfdf9b082017-10-10 21:13:28 +0100120 -s, --csv comma separated values output
Brendan Gregg797c3ec2016-10-19 18:55:10 -0700121 -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
127examples:
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