mirror of
https://github.com/brendangregg/perf-tools.git
synced 2025-11-30 23:16:03 +07:00
94 lines
3.4 KiB
Plaintext
94 lines
3.4 KiB
Plaintext
Demonstrations of tcpretrans, the Linux ftrace version.
|
|
|
|
|
|
Tracing TCP retransmits on a busy server:
|
|
|
|
# ./tcpretrans
|
|
TIME PID LADDR:LPORT -- RADDR:RPORT STATE
|
|
05:16:44 3375 10.150.18.225:53874 R> 10.105.152.3:6001 ESTABLISHED
|
|
05:16:44 3375 10.150.18.225:53874 R> 10.105.152.3:6001 ESTABLISHED
|
|
05:16:54 4028 10.150.18.225:6002 R> 10.150.30.249:1710 ESTABLISHED
|
|
05:16:54 4028 10.150.18.225:6002 R> 10.150.30.249:1710 ESTABLISHED
|
|
05:16:54 4028 10.150.18.225:6002 R> 10.150.30.249:1710 ESTABLISHED
|
|
05:16:54 4028 10.150.18.225:6002 R> 10.150.30.249:1710 ESTABLISHED
|
|
05:16:54 4028 10.150.18.225:6002 R> 10.150.30.249:1710 ESTABLISHED
|
|
05:16:54 4028 10.150.18.225:6002 R> 10.150.30.249:1710 ESTABLISHED
|
|
05:16:54 4028 10.150.18.225:6002 R> 10.150.30.249:1710 ESTABLISHED
|
|
05:16:55 0 10.150.18.225:47115 R> 10.71.171.158:6001 ESTABLISHED
|
|
05:16:58 0 10.150.18.225:44388 R> 10.103.130.120:6001 ESTABLISHED
|
|
05:16:58 0 10.150.18.225:44388 R> 10.103.130.120:6001 ESTABLISHED
|
|
05:16:58 0 10.150.18.225:44388 R> 10.103.130.120:6001 ESTABLISHED
|
|
05:16:59 0 10.150.18.225:56086 R> 10.150.32.107:6001 ESTABLISHED
|
|
05:16:59 0 10.150.18.225:56086 R> 10.150.32.107:6001 ESTABLISHED
|
|
^C
|
|
Ending tracing...
|
|
|
|
This shows TCP retransmits by dynamically tracing the kernel function that does
|
|
the retransmit. This is a low overhead approach.
|
|
|
|
The PID may or may not make sense: it's showing the PID that was on-CPU,
|
|
however, retransmits are often timer-based, where it's the kernel that is
|
|
on-CPU.
|
|
|
|
The STATE column shows the TCP state for the socket performing the retransmit.
|
|
The "--" column is the packet type. "R>" for retransmit.
|
|
|
|
|
|
Kernel stack traces can be included with -s, which may show the type of
|
|
retransmit:
|
|
|
|
# ./tcpretrans -s
|
|
TIME PID LADDR:LPORT -- RADDR:RPORT STATE
|
|
06:21:10 19516 10.144.107.151:22 R> 10.13.106.251:32167 ESTABLISHED
|
|
=> tcp_fastretrans_alert
|
|
=> tcp_ack
|
|
=> tcp_rcv_established
|
|
=> tcp_v4_do_rcv
|
|
=> tcp_v4_rcv
|
|
=> ip_local_deliver_finish
|
|
=> ip_local_deliver
|
|
=> ip_rcv_finish
|
|
=> ip_rcv
|
|
=> __netif_receive_skb
|
|
=> netif_receive_skb
|
|
=> handle_incoming_queue
|
|
=> xennet_poll
|
|
=> net_rx_action
|
|
=> __do_softirq
|
|
=> call_softirq
|
|
=> do_softirq
|
|
=> irq_exit
|
|
=> xen_evtchn_do_upcall
|
|
=> xen_do_hypervisor_callback
|
|
|
|
This looks like a fast retransmit (inclusion of tcp_fastretrans_alert(), and
|
|
being based on receiving an ACK, rather than a timer).
|
|
|
|
|
|
The -l option will include TCP tail loss probe events (TLP; see
|
|
http://lwn.net/Articles/542642/). Eg:
|
|
|
|
# ./tcpretrans -l
|
|
TIME PID LADDR:LPORT -- RADDR:RPORT STATE
|
|
21:56:06 0 10.100.155.200:22 R> 10.10.237.72:18554 LAST_ACK
|
|
21:56:08 0 10.100.155.200:22 R> 10.10.237.72:18554 LAST_ACK
|
|
21:56:10 16452 10.100.155.200:22 R> 10.10.237.72:18554 LAST_ACK
|
|
21:56:10 0 10.100.155.200:22 L> 10.10.237.72:46408 LAST_ACK
|
|
21:56:10 0 10.100.155.200:22 R> 10.10.237.72:46408 LAST_ACK
|
|
21:56:12 0 10.100.155.200:22 R> 10.10.237.72:46408 LAST_ACK
|
|
21:56:13 0 10.100.155.200:22 R> 10.10.237.72:46408 LAST_ACK
|
|
^C
|
|
Ending tracing...
|
|
|
|
Look for "L>" in the type column ("--") for TLP events.
|
|
|
|
|
|
Use -h to print the USAGE message:
|
|
|
|
# ./tcpretrans -h
|
|
USAGE: tcpretrans [-hs]
|
|
-h # help message
|
|
-s # print stack traces
|
|
eg,
|
|
tcpretrans # trace TCP retransmits
|