Bug 1203742
Summary: | TCP bug creates additional RTO in very specific condition | ||||||||
---|---|---|---|---|---|---|---|---|---|
Product: | Red Hat Enterprise Linux 6 | Reporter: | Matias Bonaventura <matiasb> | ||||||
Component: | kernel | Assignee: | Thadeu Lima de Souza Cascardo <cascardo> | ||||||
kernel sub component: | tcp | QA Contact: | xmu | ||||||
Status: | CLOSED INSUFFICIENT_DATA | Docs Contact: | |||||||
Severity: | high | ||||||||
Priority: | medium | CC: | cascardo, hsowa, jaroslaw.polok, kzhang, matiasb, michele, mleitner, network-qe, rkhan, thomas.oulevey | ||||||
Version: | 6.6 | Flags: | matiasb:
needinfo-
|
||||||
Target Milestone: | rc | ||||||||
Target Release: | --- | ||||||||
Hardware: | x86_64 | ||||||||
OS: | Linux | ||||||||
Whiteboard: | |||||||||
Fixed In Version: | Doc Type: | Bug Fix | |||||||
Doc Text: | Story Points: | --- | |||||||
Clone Of: | Environment: | ||||||||
Last Closed: | 2015-11-06 14:42:43 UTC | Type: | Bug | ||||||
Regression: | --- | Mount Type: | --- | ||||||
Documentation: | --- | CRM: | |||||||
Verified Versions: | Category: | --- | |||||||
oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |||||||
Cloudforms Team: | --- | Target Upstream Version: | |||||||
Embargoed: | |||||||||
Bug Depends On: | |||||||||
Bug Blocks: | 1172231 | ||||||||
Attachments: |
|
Description
Matias Bonaventura
2015-03-19 15:02:29 UTC
Would it possible to mark this bug as public (viewable by public)? I would need technicians to be able to see the description and the progress of the bug report. Also I need to add references to it in some documents. Thanks a lot! Hi, is there anyone trying to follow this bug? any updated? Also, would it possible to mark this bug as public (viewable by public)? Apparently I have no permissions for this. Thanks Hi Matias, sorry the delay. Yes, it's possible to open it. I just did it. But I'm afraid, as you've noticed, that we weren't able to evaluate your report so far. It looks like you are using RHEL 6.2. RHEL 6.3 received some TCP fixes, can you try it and see if it fixes the problem for you? Cascardo. Hi, Matias. Can you confirm you are in fact using RHEL6.6 and not RHEL6.2? By the way, are there any socket options that your application uses either client or server side? Have you considered changing the rto_min of the route in order to workaround the minimal of 200ms? You can do that by issuing ip route replace address/mask dev ethX rto_min 50ms, for example. If it's a local network, you may need to add the option table local. Cascardo. Hi all, The tcpdump attached was using RHEL 6.5 (kernel 2.6.32-431.3.3.el6.x86_64) so if the changes to TCP where introduced in 6.3 they should have been in. We are now using RHEL 6.6 (kernel 2.6.32-504.3.3.el6.x86_64). I could repeat tests with the new kernel, but it will take me some time to find availability in the network to perform the tests. We didn't thought of changing the rto_min of the routes using "ip route", but it sounds like a good option. But before doing that change we would need to test it first (setting a rto to low can be dangerous) so hopefully next week we might give it a try. The server application does use one socket option: it uses the NODELAY socket option to disable Nagle's algorithm. Hopefully this helps. Let me know if you need more info. Regards, Matias I tried to reproduce this issue, forcing packets to be dropped. Specifically, this happens when a hole is lost, and the last packet is lost as well. Notice the SACK in the pcap file. I tried to reproduce this exact scenario, but still, the server sent the last packet right after receiving the ack for the first retransmission. I went through the code trying to come up with some specific scenario that could apply to this case, but couldn't find anything obvious. One possibility was previous packet losses, but I forced that as well, and still that didn't work out. Other possibilities are the sender dropping the packets itself, but that didn't seem likely giving the other data. I am not sure that could cause the second RTO, but it could be worth testing. Some data that could be helpful is MIB before the issue and after the issue. Maybe it could show some points that we hit that I am not considering, or that I disregarded as not the case. The best possible data I can think of would be ftrace for tcp functions. That, however, may be challenging, depending on how long it takes to reproduce the issue, the presence of any other TCP flows in the system, etc. In case you think you can do it, here are the instructions: # mount -t debugfs none /sys/kernel/debug/ # cd /sys/kernel/debug/tracing/ # echo '*tcp*' > set_ftrace_filter # echo function > current_tracer # echo 1 > tracing_on # cat trace_pipe > /var/tmp/tcp_tracer.log If possible, do it with only that single TCP flow. That means using a serial console is preferable than using SSH. Thanks. Cascardo Created attachment 1031267 [details]
ftrace for tcp
Here is the trace I did for the case I created.
The relevant parts here are:
server-2714 [000] 71742.919845: tcp_sacktag_write_queue <-tcp_ack
Where we receive the SACK, but do not retransmit immediately.
<idle>-0 [000] 71743.120434: tcp_enter_frto <-tcp_retransmit_timer
<idle>-0 [000] 71743.120434: tcp_retransmit_skb <-tcp_retransmit_timer
Where the RTO happens, about 200ms later, notice that we enter FRTO.
server-2714 [000] 71743.122755: tcp_enter_frto_loss <-tcp_ack
server-2714 [000] 71743.122755: tcp_fastretrans_alert <-tcp_ack
server-2714 [000] 71743.122756: tcp_xmit_retransmit_queue <-tcp_fastretrans_alert
Where we get the following ACK, and retransmit the last piece, no second RTO.
Cascardo.
Hi Cascardo, thank you very much for looking at the issue. I will try to prepare the ftraces and send them to you, but it will take while to prepare them. Regarding: "Specifically, this happens when a hole is lost, and the last packet is lost as well." My only comment to narrow your tests is that in my tcpdumps it always happened when exactly 3 packets (including the last one) where lost. If 4 or more packets were lost the problem was not there. If 2 or 1 packet were lost the problem was not there. Cheers! Hi, Matias. Were you able to prepare the ftraces? Thanks. Cascardo. Hi all, The lab is currently in production so it is really hard to prepare the setup for the ftraces. On the other hand, I am not working any more at CERN, so I personally don't have access to the lab or the testing environment. I have the information of the tests we did on the past, but I will not be able to continue performing new tests. Sorry for that. Regards, Matias So, I managed to reproduce this with the following packetdrill: 0 socket(..., SOCK_STREAM, IPPROTO_TCP) = 3 0 setsockopt(3, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0 0 bind(3, ..., ...) = 0 0 listen(3, 1) = 0 0 < S 0:0(0) win 32792 <mss 1460,nop,nop,sackOK,nop,wscale 7> 0 > S. 0:0(0) ack 1 <mss 1460,nop,nop,sackOK,nop,wscale 7> +0.020 < . 1:1(0) ack 1 win 257 +0 accept(3, ..., ...) = 4 +0.5 < . 1:65(64) ack 1 win 257 +0 > . 1:1(0) ack 65 +0 write(4, ..., 10016) = 10016 +0 > . 1:2921(2920) ack 65 +0 > . 2921:5841(2920) ack 65 +0 > . 5841:8761(2920) ack 65 +0 > P. 8761:10017(1256) ack 65 +0.020 < . 65:65(0) ack 2921 win 257 +0 < . 65:65(0) ack 2921 win 257 <sack 4381:5841,nop,nop> +0.22 > . 2921:4381(1460) ack 65 +0 < . 65:65(0) ack 8761 win 257 +0.44 > P. 8761:10017(1256) ack 65 However, I reproduced that on CentOS 7.1. When trying to reproduce on RHEL7.1, the last delta is around 230ms, not 440ms. And when running on RHEL6.6, it's 0ms. I am going to create ftraces so I can look more into this. Cascardo. Since we can't reproduce the issue and we don't have a contact anymore with the bug reporter in order to help us test any fixes or collect any other debug data, we will close this since the data is insufficient. If there is any new data, please reopen the bug. Thanks. Cascardo. |