From owner-freebsd-net@freebsd.org Sat Dec 28 13:33:47 2019 Return-Path: Delivered-To: freebsd-net@mailman.nyi.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mailman.nyi.freebsd.org (Postfix) with ESMTP id A21CE1E8989 for ; Sat, 28 Dec 2019 13:33:47 +0000 (UTC) (envelope-from pkelsey@gmail.com) Received: from mail-qv1-xf34.google.com (mail-qv1-xf34.google.com [IPv6:2607:f8b0:4864:20::f34]) (using TLSv1.3 with cipher TLS_AES_128_GCM_SHA256 (128/128 bits) server-signature RSA-PSS (4096 bits) client-signature RSA-PSS (2048 bits) client-digest SHA256) (Client CN "smtp.gmail.com", Issuer "GTS CA 1O1" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id 47lPmB6hFgz4Mxb; Sat, 28 Dec 2019 13:33:46 +0000 (UTC) (envelope-from pkelsey@gmail.com) Received: by mail-qv1-xf34.google.com with SMTP id z3so10944010qvn.0; Sat, 28 Dec 2019 05:33:46 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=sender:content-transfer-encoding:from:mime-version:subject:date :message-id:references:cc:in-reply-to:to; bh=NidRJV9IXsSFZs4nJk6K5yjcu+2j45Yx1wQp1b6/X1c=; b=AB9cYyPsvzf1K8JRCZr7dif07t5BpmjqoSoZghHme1du2poSbBWorLfCZJWdMhD/3v P+tAVErBzvSoi0hujmskXOdLhgl50Jx2XJ+3qQUQb4pq3Q5MDbXwMztrbCgeQS38u+yf ATXFXzuHOPjUtHS9CV2yQP8u3r/cNb/Z1qfbqKFumEyYirRCqRoKfzMhE/I7I93VQNMX f5UGKgu6X/XP6zKA2pxR0Z1ybWPRhkV34pKF+P9ynarxv5kU1hSynDvjtfHg/ZhPPHnk MbHBHn4fkKpuTqggnoBmq7BUdMz9Jberji3/307oWnkXbC2OmVdQ+FeErlxGUHoA8imf 3QvA== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:sender:content-transfer-encoding:from :mime-version:subject:date:message-id:references:cc:in-reply-to:to; bh=NidRJV9IXsSFZs4nJk6K5yjcu+2j45Yx1wQp1b6/X1c=; b=gXjPLlf2Y/uJkekZd4Q45RlZCpPaOCwtIUfg4ITnkyUCV/Xj8deu9nuQr+Ro/D5UA8 fP7D7l3gx902BZdyM0dSkYdPOqMatVGsQ3lmd/HvO7i8vob4BMm8zELtvkPHRMoce/DB ETqM+dzZaaHYXkJFIM0fbbFOj9U4I+rQeTohfR1KZNX4kKJ5uBG7q6i1JSAKEcH+QY9n MB+0rKkkv6F5WVcs7nZa+2AwZEOwM5N5yY2MkjtOl84UnsvHPSWE2dTOlqhBADpJCiMd /Sf0q11+nJsydp86yY0V5h64aFytRx84szrl2ejeAJcvHKnpeMoHtfnKdblYQgd+Li+O mkiQ== X-Gm-Message-State: APjAAAVIf1q3EKlDc6j2q23obMFDKN1eLAeib+Im58aNn1kOGrTp6DSw jo+yLuSiBE1WqSmhkFIJRi9w24AM X-Google-Smtp-Source: APXvYqyWMMG7eBmDuMF1GVnSKDnZfhVT4O6pTXgEISU1zQlBf+yk6HY3HVwTJzIU8pRzNE4tO3hm5Q== X-Received: by 2002:ad4:514e:: with SMTP id g14mr44437300qvq.196.1577540020200; Sat, 28 Dec 2019 05:33:40 -0800 (PST) Received: from ?IPv6:2600:380:9064:d8e0:c0bb:78a8:179b:5aef? ([2600:380:9064:d8e0:c0bb:78a8:179b:5aef]) by smtp.gmail.com with ESMTPSA id v5sm11784788qtc.64.2019.12.28.05.33.39 (version=TLS1_3 cipher=TLS_AES_128_GCM_SHA256 bits=128/128); Sat, 28 Dec 2019 05:33:39 -0800 (PST) Sender: Patrick Kelsey From: Patrick Kelsey Mime-Version: 1.0 (1.0) Subject: Re: vmx: strange issue, related to to tso? Date: Sat, 28 Dec 2019 08:33:37 -0500 Message-Id: References: Cc: Patrick Kelsey , Andriy Gapon , freebsd-net In-Reply-To: To: Vincenzo Maffione X-Mailer: iPhone Mail (17C54) X-Rspamd-Queue-Id: 47lPmB6hFgz4Mxb X-Spamd-Bar: - Authentication-Results: mx1.freebsd.org; dkim=pass header.d=gmail.com header.s=20161025 header.b=AB9cYyPs; dmarc=none; spf=pass (mx1.freebsd.org: domain of pkelsey@gmail.com designates 2607:f8b0:4864:20::f34 as permitted sender) smtp.mailfrom=pkelsey@gmail.com X-Spamd-Result: default: False [-1.51 / 15.00]; ARC_NA(0.00)[]; RCVD_VIA_SMTP_AUTH(0.00)[]; R_DKIM_ALLOW(-0.20)[gmail.com:s=20161025]; RCVD_TLS_ALL(0.00)[]; FROM_HAS_DN(0.00)[]; RCPT_COUNT_THREE(0.00)[4]; R_SPF_ALLOW(-0.20)[+ip6:2607:f8b0:4000::/36]; TO_MATCH_ENVRCPT_ALL(0.00)[]; MIME_GOOD(-0.10)[multipart/alternative,text/plain]; MIME_TRACE(0.00)[0:+,1:+,2:~]; DMARC_NA(0.00)[freebsd.org]; MV_CASE(0.50)[]; NEURAL_HAM_LONG(-1.00)[-0.999,0]; RCVD_COUNT_THREE(0.00)[3]; IP_SCORE(-0.82)[ipnet: 2607:f8b0::/32(-2.15), asn: 15169(-1.88), country: US(-0.05)]; TO_DN_ALL(0.00)[]; DKIM_TRACE(0.00)[gmail.com:+]; NEURAL_HAM_MEDIUM(-1.00)[-0.996,0]; FORGED_SENDER(0.30)[pkelsey@freebsd.org,pkelsey@gmail.com]; SUBJECT_ENDS_QUESTION(1.00)[]; FREEMAIL_ENVFROM(0.00)[gmail.com]; ASN(0.00)[asn:15169, ipnet:2607:f8b0::/32, country:US]; FROM_NEQ_ENVFROM(0.00)[pkelsey@freebsd.org,pkelsey@gmail.com]; MID_RHS_MATCH_FROM(0.00)[] Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-Content-Filtered-By: Mailman/MimeDel 2.1.29 X-BeenThere: freebsd-net@freebsd.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: Networking and TCP/IP with FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sat, 28 Dec 2019 13:33:47 -0000 https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=3D236999 appears to be con= verging to the same issue. If you want to create a review for the proposed p= atch that would be great. It would be good to have corroborating test results for the proposed patch, s= omething I will probably not be able to try to obtain for at least a couple o= f days. -Patrick > On Dec 28, 2019, at 3:17 AM, Vincenzo Maffione wro= te: >=20 > =EF=BB=BF > I think you are correct. Good catch! > We should file a bug and/or create a review on the Phabricator (If you are= busy I could do that). >=20 > Thanks, > Vincenzo >=20 >> Il giorno sab 28 dic 2019 alle ore 05:44 Patrick Kelsey ha scritto: >>=20 >>> On Fri, Dec 27, 2019 at 5:01 PM Andriy Gapon wrote: >>> On 27/12/2019 15:34, Vincenzo Maffione wrote: >>> > It may be useful to check what happens if you replace the vmx0 interfa= ce with an >>> > em0. >>> > In this way you would know if the issue is vmx-specific or not. >>>=20 >>> I'll put this on my to-do, can't test right now. >>>=20 >>> But one thing I noticed when comparing the TCP control block of the conn= ection >>> before and after the "TSO dance" is that TF_TSO gets cleared after any o= utgoing >>> traffic while TSO is disabled on the interface. And the flag does not c= ome back >>> after TSO is reenabled. Any new connections get the flag, of course. >>>=20 >>> So, I indeed suspect that there is a problem with vmx TSO. >>> As another data point, an older system from before vmx->iflib conversion= does >>> not exhibit the problem. >>>=20 >>> > Il giorno gio 26 dic 2019 alle ore 20:04 Andriy Gapon >> > > ha scritto: >>> >=20 >>> >=20 >>> > Maybe someone would have any pointers for me with the following pr= oblem. >>> > This happens with CURRENT as of the beginning of September. >>> > I connect via ssh to a VM running on VMware, it has a single vmx0 i= nterface. >>> > The problem is that when I print a moderately large amount of text= to the >>> > terminal (e.g., tail -100 /var/log/messages) I literally see it pr= inted in >>> > chunks with noticeable pauses between chunks. It takes several se= conds for all >>> > lines to get shown. This happens every time I do it. >>> > There is an interesting twist. If I disable TSO with ifconfig vmx= 0 -tso and >>> > print the same output in the same ssh session, then the output is s= mooth and >>> > fast as I would expect it. The lines scroll by almost instantly. >>> > If then I re-enable TSO and again produce the same output in the s= ame ssh, then >>> > it is still fast. >>> >=20 >>> > It appears that the TCP connection gets tuned to some very sub-opt= imal >>> > parameters when TSO is enabled. When I disable TSO, the parameter= s get re-tuned >>> > to better values and the values stick when I re-enable TSO. >>> > This is just a conjecture, of course. >>> >=20 >>> > I have some tcpdump captures, but I do not see anything that would= really stand >>> > out. One difference is that in the slow case only "full sized" pa= ckets are sent >>> > while in the fast case there are shorter packets with push flag. >>> >=20 >>> > Some packets for the slow case: >>> > 00:00:00.453202 IP 10.180.106.180.22 > 10.180.1.29.25490: Flags [= .], seq >>> > 37:1485, ack 36, win 128, options [nop,nop,TS val 1403195134 ecr 4= 966311], >>> > length 1448 >>> > 00:00:00.096859 IP 10.180.1.29.25490 > 10.180.106.180.22: Flags [= .], ack 1485, >>> > win 1026, options [nop,nop,TS val 4966864 ecr 1403195134], length 0= >>> > 00:00:00.442963 IP 10.180.106.180.22 > 10.180.1.29.25490: Flags [= .], seq >>> > 1485:2933, ack 36, win 128, options [nop,nop,TS val 1403195664 ecr= 4966864], >>> > length 1448 >>> > 00:00:00.092677 IP 10.180.1.29.25490 > 10.180.106.180.22: Flags [= .], ack 2933, >>> > win 1026, options [nop,nop,TS val 4967400 ecr 1403195664], length 0= >>> > 00:00:00.437336 IP 10.180.106.180.22 > 10.180.1.29.25490: Flags [= .], seq >>> > 2933:4381, ack 36, win 128, options [nop,nop,TS val 1403196194 ecr= 4967400], >>> > length 1448 >>> > 00:00:00.097190 IP 10.180.1.29.25490 > 10.180.106.180.22: Flags [= .], ack 4381, >>> > win 1026, options [nop,nop,TS val 4967934 ecr 1403196194], length 0= >>> >=20 >>> > Some packets after the TSO dance: >>> > 00:00:00.000450 IP 10.180.106.180.22 > 10.180.1.29.25369: Flags [= .], seq >>> > 4077:5525, ack 36, win 128, options [nop,nop,TS val 2124310129 ecr= 21706510], >>> > length 1448 >>> > 00:00:00.000016 IP 10.180.106.180.22 > 10.180.1.29.25369: Flags [= P.], seq >>> > 5525:6097, ack 36, win 128, options [nop,nop,TS val 2124310129 ecr= 21706510], >>> > length 572 >>> > 00:00:00.000009 IP 10.180.1.29.25369 > 10.180.106.180.22: Flags [= .], ack 5525, >>> > win 1003, options [nop,nop,TS val 21706510 ecr 2124310129], length= 0 >>> > 00:00:00.000303 IP 10.180.106.180.22 > 10.180.1.29.25369: Flags [= .], seq >>> > 6097:7545, ack 36, win 128, options [nop,nop,TS val 2124310129 ecr= 21706510], >>> > length 1448 >>> > 00:00:00.000019 IP 10.180.106.180.22 > 10.180.1.29.25369: Flags [= P.], seq >>> > 7545:8117, ack 36, win 128, options [nop,nop,TS val 2124310129 ecr= 21706510], >>> > length 572 >>> > 00:00:00.000013 IP 10.180.1.29.25369 > 10.180.106.180.22: Flags [= .], ack 7545, >>> > win 1003, options [nop,nop,TS val 21706510 ecr 2124310129], length= 0 >>> > 00:00:00.000162 IP 10.180.106.180.22 > 10.180.1.29.25369: Flags [= .], seq >>> > 8117:9565, ack 36, win 128, options [nop,nop,TS val 2124310129 ecr= 21706510], >>> > length 1448 >>> > 00:00:00.000012 IP 10.180.106.180.22 > 10.180.1.29.25369: Flags [= P.], seq >>> > 9565:10137, ack 36, win 128, options [nop,nop,TS val 2124310129 ec= r 21706510], >>> > length 572 >>> > 00:00:00.000007 IP 10.180.1.29.25369 > 10.180.106.180.22: Flags [= .], ack 9565, >>> > win 1003, options [nop,nop,TS val 21706510 ecr 2124310129], length= 0 >>> >=20 >>> > What else can I examine to debug the problem further? >>> > Thank you! >>> > --=20 >>> > Andriy Gapon >>> > _______________________________________________ >>> > freebsd-net@freebsd.org mailing l= ist >>> > https://lists.freebsd.org/mailman/listinfo/freebsd-net >>> > To unsubscribe, send any mail to "freebsd-net-unsubscribe@freebsd.= org >>> > " >>> >=20 >>>=20 >>=20 >> I am not able to test this at the moment, nor likely in the very near fut= ure, but I did have a few minutes to do some code reading and now believe th= at the following is part of the problem, if not the entire problem. Using r= 353803 as a reference, I believe line 1323 in sys/dev/vmware/vmxnet3/if_vmx.= c (in vmxnet3_isc_txd_encap()) should be: >>=20 >> sop->hlen =3D hdrlen + ipi->ipi_tcp_hlen; >>=20 >> instead of the current: >>=20 >> sop->hlen =3D hdrlen; >>=20 >> This can be seen by going back to r333813 and examining the CSUM_TSO case= of vmxnet3_txq_offload_ctx(). The final increment of *start in that case i= s what was literally lost in translation when converting the driver to iflib= . >>=20 >> -Patrick