From mboxrd@z Thu Jan  1 00:00:00 1970
From: Marcelo Ricardo Leitner <marcelo.leitner@gmail.com>
Subject: Re: tcp hang when socket fills up ?
Date: Mon, 16 Apr 2018 17:43:34 -0300
Message-ID: <20180416204334.GA9219@localhost.localdomain>
References: <20180406090720.GA31845@nautica>
 <20180413163254.ucyvnkqpb4psluea@unicorn.suse.cz>
 <20180414010907.GA11526@nautica>
 <863dc88d-bc91-d3b6-70c6-5e279451f66d@gmail.com>
 <20180414015515.GA24798@nautica>
Mime-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Cc: Eric Dumazet <eric.dumazet@gmail.com>,
        Michal Kubecek <mkubecek@suse.cz>, netdev@vger.kernel.org,
        Florian Westphal <fw@strlen.de>
To: Dominique Martinet <asmadeus@codewreck.org>
Return-path: <netdev-owner@vger.kernel.org>
Received: from mail-qk0-f169.google.com ([209.85.220.169]:45701 "EHLO
        mail-qk0-f169.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org
        with ESMTP id S1752387AbeDPUnk (ORCPT
        <rfc822;netdev@vger.kernel.org>); Mon, 16 Apr 2018 16:43:40 -0400
Received: by mail-qk0-f169.google.com with SMTP id f9so10193496qkm.12
        for <netdev@vger.kernel.org>; Mon, 16 Apr 2018 13:43:40 -0700 (PDT)
Content-Disposition: inline
In-Reply-To: <20180414015515.GA24798@nautica>
Sender: netdev-owner@vger.kernel.org
List-ID: <netdev.vger.kernel.org>

On Sat, Apr 14, 2018 at 03:55:15AM +0200, Dominique Martinet wrote:
> 16:49:26.724457 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 25134, win 646, options [nop,nop,TS val 1617129467 ecr 1313937599], length 0
> 16:49:26.726081 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 26508, win 669, options [nop,nop,TS val 1617129471 ecr 1313937599], length 0
> 16:49:26.726391 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 27882, win 691, options [nop,nop,TS val 1617129471 ecr 1313937601], length 0
> 16:49:26.726962 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 29256, win 714, options [nop,nop,TS val 1617129472 ecr 1313937601], length 0
> 16:49:26.727614 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 30630, win 737, options [nop,nop,TS val 1617129473 ecr 1313937602], length 0
> 16:49:26.728084 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 32004, win 759, options [nop,nop,TS val 1617129473 ecr 1313937602], length 0

[A] (packet above)

> 16:49:26.728507 IP <server local ip>.13317 > <client public ip>.31872: Flags [.], seq 59484:60858, ack 4190, win 307, options [nop,nop,TS val 1313937635 ecr 1617129473], length 1374
> 16:49:26.728511 IP <server local ip>.13317 > <client public ip>.31872: Flags [.], seq 60858:62232, ack 4190, win 307, options [nop,nop,TS val 1313937635 ecr 1617129473], length 1374
> 16:49:26.729531 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 33378, win 782, options [nop,nop,TS val 1617129475 ecr 1313937607], length 0
> 16:49:26.730002 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 34752, win 805, options [nop,nop,TS val 1617129475 ecr 1313937607], length 0
> 16:49:26.730340 IP <server local ip>.13317 > <client public ip>.31872: Flags [.], seq 62232:63606, ack 4190, win 307, options [nop,nop,TS val 1313937636 ecr 1617129473], length 1374
> 16:49:26.730344 IP <server local ip>.13317 > <client public ip>.31872: Flags [.], seq 63606:64980, ack 4190, win 307, options [nop,nop,TS val 1313937636 ecr 1617129473], length 1374
> 16:49:26.731398 IP <server local ip>.13317 > <client public ip>.31872: Flags [.], seq 64980:66354, ack 4190, win 307, options [nop,nop,TS val 1313937638 ecr 1617129473], length 1374
> 16:49:26.731402 IP <server local ip>.13317 > <client public ip>.31872: Flags [.], seq 66354:67728, ack 4190, win 307, options [nop,nop,TS val 1313937638 ecr 1617129473], length 1374
> 16:49:26.731634 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 36126, win 827, options [nop,nop,TS val 1617129476 ecr 1313937607], length 0
> 16:49:26.732955 IP <server local ip>.13317 > <client public ip>.31872: Flags [.], seq 67728:69102, ack 4190, win 307, options [nop,nop,TS val 1313937639 ecr 1617129473], length 1374
> 16:49:26.732963 IP <server local ip>.13317 > <client public ip>.31872: Flags [.], seq 69102:70476, ack 4190, win 307, options [nop,nop,TS val 1313937639 ecr 1617129473], length 1374
> 16:49:26.733956 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 37500, win 850, options [nop,nop,TS val 1617129476 ecr 1313937607], length 0
> 16:49:26.734242 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 38874, win 872, options [nop,nop,TS val 1617129477 ecr 1313937608], length 0
> 16:49:26.734653 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 40248, win 895, options [nop,nop,TS val 1617129478 ecr 1313937608], length 0
> 16:49:26.735042 IP <server local ip>.13317 > <client public ip>.31872: Flags [.], seq 70476:71850, ack 4190, win 307, options [nop,nop,TS val 1313937641 ecr 1617129473], length 1374
> 16:49:26.735046 IP <server local ip>.13317 > <client public ip>.31872: Flags [.], seq 71850:73224, ack 4190, win 307, options [nop,nop,TS val 1313937641 ecr 1617129473], length 1374
> 16:49:26.735334 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 41622, win 918, options [nop,nop,TS val 1617129478 ecr 1313937609], length 0
> 16:49:26.736005 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 42996, win 940, options [nop,nop,TS val 1617129478 ecr 1313937609], length 0
> 16:49:26.736402 IP <server local ip>.13317 > <client public ip>.31872: Flags [.], seq 73224:74598, ack 4190, win 307, options [nop,nop,TS val 1313937643 ecr 1617129473], length 1374
> 16:49:26.736408 IP <server local ip>.13317 > <client public ip>.31872: Flags [.], seq 74598:75972, ack 4190, win 307, options [nop,nop,TS val 1313937643 ecr 1617129473], length 1374
> 16:49:26.738561 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 44370, win 963, options [nop,nop,TS val 1617129482 ecr 1313937616], length 0
> 16:49:26.739539 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 45744, win 986, options [nop,nop,TS val 1617129482 ecr 1313937616], length 0
> 16:49:26.739882 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 47118, win 1008, options [nop,nop,TS val 1617129484 ecr 1313937617], length 0
> 16:49:26.740255 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 48492, win 1031, options [nop,nop,TS val 1617129484 ecr 1313937617], length 0
> 16:49:26.746756 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 49866, win 1053, options [nop,nop,TS val 1617129493 ecr 1313937627], length 0
> 16:49:26.747923 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 51240, win 1076, options [nop,nop,TS val 1617129494 ecr 1313937627], length 0
> 16:49:26.749083 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 52614, win 1099, options [nop,nop,TS val 1617129495 ecr 1313937629], length 0
> 16:49:26.750171 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 53988, win 1121, options [nop,nop,TS val 1617129496 ecr 1313937629], length 0
> 16:49:26.750808 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 55362, win 1144, options [nop,nop,TS val 1617129497 ecr 1313937629], length 0
> 16:49:26.754648 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 56736, win 1167, options [nop,nop,TS val 1617129500 ecr 1313937629], length 0
> 16:49:26.755985 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 58110, win 1189, options [nop,nop,TS val 1617129501 ecr 1313937630], length 0
> 16:49:26.758513 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 59484, win 1212, options [nop,nop,TS val 1617129502 ecr 1313937630], length 0
> 16:49:26.759096 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 60858, win 1234, options [nop,nop,TS val 1617129503 ecr 1313937635], length 0
> 16:49:26.759421 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 62232, win 1257, options [nop,nop,TS val 1617129503 ecr 1313937635], length 0
> 16:49:26.759755 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 63606, win 1280, options [nop,nop,TS val 1617129504 ecr 1313937636], length 0
> 16:49:26.760653 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 64980, win 1302, options [nop,nop,TS val 1617129505 ecr 1313937636], length 0
> 16:49:26.761453 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 66354, win 1325, options [nop,nop,TS val 1617129506 ecr 1313937638], length 0
> 16:49:26.762199 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 67728, win 1348, options [nop,nop,TS val 1617129507 ecr 1313937638], length 0
> 16:49:26.763547 IP <client public ip>.31872 > <server local ip>.13317: Flags [P.], seq 4190:4226, ack 67728, win 1348, options [nop,nop,TS val 1617129507 ecr 1313937638], length 36
> 16:49:26.763553 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 70476, win 1393, options [nop,nop,TS val 1617129508 ecr 1313937639], length 0
> 16:49:26.764298 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 73224, win 1438, options [nop,nop,TS val 1617129509 ecr 1313937641], length 0
> 16:49:26.764676 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 75972, win 1444, options [nop,nop,TS val 1617129510 ecr 1313937643], length 0
> 16:49:26.807754 IP <server local ip>.13317 > <client public ip>.31872: Flags [.], seq 75972:77346, ack 4190, win 307, options [nop,nop,TS val 1313937714 ecr 1617129473], length 1374
> 16:49:26.876467 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 77346, win 1444, options [nop,nop,TS val 1617129620 ecr 1313937714], length 0
> 16:49:27.048760 IP <server local ip>.13317 > <client public ip>.31872: Flags [.], seq 32004:33378, ack 4190, win 307, options [nop,nop,TS val 1313937955 ecr 1617129473], length 1374

Probably bogus retrans for conntrack, but OUTPUT is not filtered.

> 16:49:27.051791 IP <client public ip>.31872 > <server local ip>.13317: Flags [P.], seq 4190:4226, ack 77346, win 1444, options [nop,nop,TS val 1617129762 ecr 1313937714], length 36
> 16:49:27.076444 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 77346, win 1444, options [nop,nop,TS val 1617129822 ecr 1313937714,nop,nop,sack 1 {32004:33378}], length 0

I guess the issue lies with the dup-sack here.

AFAIR Disabling timestamps also disables SACK, which would avoid the
issue as conntrack will not see these as they won't happen anymore.

Then it gets locked into a loopy behavior:

> 16:49:27.371182 IP <client public ip>.31872 > <server local ip>.13317: Flags [P.], seq 4190:4226, ack 77346, win 1444, options [nop,nop,TS val 1617130018 ecr 1313937714], length 36

> 16:49:27.519862 IP <server local ip>.13317 > <client public ip>.31872: Flags [.], seq 32004:33378, ack 4190, win 307, options [nop,nop,TS val 1313938426 ecr 1617129473], length 1374
> 16:49:27.547662 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 77346, win 1444, options [nop,nop,TS val 1617130293 ecr 1313937714,nop,nop,sack 1 {32004:33378}], length 0
> 16:49:27.883372 IP <client public ip>.31872 > <server local ip>.13317: Flags [P.], seq 4190:4226, ack 77346, win 1444, options [nop,nop,TS val 1617130530 ecr 1313937714], length 36

Cycle 1

> 16:49:28.511861 IP <server local ip>.13317 > <client public ip>.31872: Flags [.], seq 32004:33378, ack 4190, win 307, options [nop,nop,TS val 1313939418 ecr 1617129473], length 1374
> 16:49:28.538891 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 77346, win 1444, options [nop,nop,TS val 1617131285 ecr 1313937714,nop,nop,sack 1 {32004:33378}], length 0
> 16:49:28.907197 IP <client public ip>.31872 > <server local ip>.13317: Flags [P.], seq 4190:4226, ack 77346, win 1444, options [nop,nop,TS val 1617131554 ecr 1313937714], length 36

Cycle 2

> 16:49:30.431864 IP <server local ip>.13317 > <client public ip>.31872: Flags [.], seq 32004:33378, ack 4190, win 307, options [nop,nop,TS val 1313941338 ecr 1617129473], length 1374
> 16:49:30.459127 IP <client public ip>.31872 > <server local ip>.13317: Flags [.], ack 77346, win 1444, options [nop,nop,TS val 1617133204 ecr 1313937714,nop,nop,sack 1 {32004:33378}], length 0
> 16:49:30.955388 IP <client public ip>.31872 > <server local ip>.13317: Flags [P.], seq 4190:4226, ack 77346, win 1444, options [nop,nop,TS val 1617133602 ecr 1313937714], length 36

Cycle 3...

Based on server RTO.

But I can't tell why packet [A] and subsequent packets from client
never made to the server's socket.