From owner-freebsd-stable@freebsd.org Thu Oct 6 11:15:09 2016 Return-Path: Delivered-To: freebsd-stable@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id 344C4BD3BDF for ; Thu, 6 Oct 2016 11:15:09 +0000 (UTC) (envelope-from julien.charbon@gmail.com) Received: from mail-wm0-f41.google.com (mail-wm0-f41.google.com [74.125.82.41]) (using TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)) (Client CN "smtp.gmail.com", Issuer "Google Internet Authority G2" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id BBAEB9A7 for ; Thu, 6 Oct 2016 11:15:08 +0000 (UTC) (envelope-from julien.charbon@gmail.com) Received: by mail-wm0-f41.google.com with SMTP id b201so39066235wmb.0 for ; Thu, 06 Oct 2016 04:15:08 -0700 (PDT) X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20130820; h=x-gm-message-state:subject:to:references:cc:from:message-id:date :user-agent:mime-version:in-reply-to; bh=B4psAbe6B2YpFe7OK1WqRH9ROrwX4xMy9ZHeLKYwfRc=; b=YGaxOQ45Sfetdtm0mw9NxS+/E9fWi6AQO/GGL7Ykd+1i9kCsRgZfxcqF63txFOvFBp zsuzBXi/XA3ptflza7z0BBxK2ymbPnqgZam8k2HIBnZoYlGZSDqJiir9BZJC/9fj4p5R 0gwIY2kq+LzqpeYUtQ5iDjN7zp+tgOC/Cd5AOdJM+yL+LL6d78pMT8cNpHyEZRFirmea iN9ZqhXs1rft/q9Y9DrEJda7maRS/5cMRxdGCkL+P/hS0y0dX1qLds50EHd6EJFoe6l2 M2HZg5D9cWt2bouuC0jFvd1KMXO1Ur5UiYn9jrpBxRXQUzFG8WoJ14W/hd0WfRAh3w1J +TDw== X-Gm-Message-State: AA6/9Rl6eBjznZqltW5/6QDVKW7abtXH8QUEU1tmMlhif7eeaaHkpWJflDpnMp81YJ+bmA== X-Received: by 10.28.206.65 with SMTP id e62mr11656117wmg.85.1475738898161; Thu, 06 Oct 2016 00:28:18 -0700 (PDT) Received: from [10.100.64.23] ([217.30.88.7]) by smtp.gmail.com with ESMTPSA id x124sm33719945wmf.22.2016.10.06.00.28.15 (version=TLS1_2 cipher=ECDHE-RSA-AES128-GCM-SHA256 bits=128/128); Thu, 06 Oct 2016 00:28:17 -0700 (PDT) Subject: Re: 11.0 stuck on high network load To: Slawa Olhovchenkov , Julien Charbon References: <8ba75d6e-4f01-895e-0aed-53c6c6692cb9@freebsd.org> <20160920202633.GQ2840@zxy.spb.ru> <20160921195155.GW2840@zxy.spb.ru> <20160923200143.GG2840@zxy.spb.ru> <20160925124626.GI2840@zxy.spb.ru> <20160926172159.GA54003@zxy.spb.ru> <62453d9c-b1e4-1129-70ff-654dacea37f9@gmail.com> <20160928115909.GC54003@zxy.spb.ru> Cc: Konstantin Belousov , freebsd-stable@FreeBSD.org, hiren panchasara From: Julien Charbon Message-ID: Date: Thu, 6 Oct 2016 09:28:06 +0200 User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.11; rv:45.0) Gecko/20100101 Thunderbird/45.3.0 MIME-Version: 1.0 In-Reply-To: <20160928115909.GC54003@zxy.spb.ru> Content-Type: multipart/signed; micalg=pgp-sha512; protocol="application/pgp-signature"; boundary="iObGiuqRXRxfbNqO4ss2AeHoPF6e2gPOF" X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.23 Precedence: list List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 06 Oct 2016 11:15:09 -0000 This is an OpenPGP/MIME signed message (RFC 4880 and 3156) --iObGiuqRXRxfbNqO4ss2AeHoPF6e2gPOF Content-Type: multipart/mixed; boundary="tTtWsDhKmocbCF2RFmwOv4pFIUxwPTxnn"; protected-headers="v1" From: Julien Charbon To: Slawa Olhovchenkov , Julien Charbon Cc: Konstantin Belousov , freebsd-stable@FreeBSD.org, hiren panchasara Message-ID: Subject: Re: 11.0 stuck on high network load References: <8ba75d6e-4f01-895e-0aed-53c6c6692cb9@freebsd.org> <20160920202633.GQ2840@zxy.spb.ru> <20160921195155.GW2840@zxy.spb.ru> <20160923200143.GG2840@zxy.spb.ru> <20160925124626.GI2840@zxy.spb.ru> <20160926172159.GA54003@zxy.spb.ru> <62453d9c-b1e4-1129-70ff-654dacea37f9@gmail.com> <20160928115909.GC54003@zxy.spb.ru> In-Reply-To: <20160928115909.GC54003@zxy.spb.ru> --tTtWsDhKmocbCF2RFmwOv4pFIUxwPTxnn Content-Type: text/plain; charset=windows-1252 Content-Transfer-Encoding: quoted-printable Hi, On 9/28/16 1:59 PM, Slawa Olhovchenkov wrote: > On Wed, Sep 28, 2016 at 12:06:47PM +0200, Julien Charbon wrote: >> >> I am still trying to reproduce your issue, without success so far. Thanks for Slawa effort and multiple debug report we start seeing the bottom of this issue and it seems to be a generic one. The most useful report being: panic: tcp_detach: INP_TIMEWAIT && INP_DROPPED && tp !=3D NULL cpuid =3D 4 KDB: stack backtrace: db_trace_self_wrapper() at 0xffffffff8032467b =3D db_trace_self_wrapper+0x2b/frame 0xfffffe1f9e1f8730 vpanic() at 0xffffffff804b5672 =3D vpanic+0x182/frame 0xfffffe1f9e1f87b0 kassert_panic() at 0xffffffff804b54e6 =3D kassert_panic+0x126/frame 0xfffffe1f9e1f8820 tcp_usr_detach() at 0xffffffff806564dc =3D tcp_usr_detach+0x1bc/frame 0xfffffe1f9e1f8850 sofree() at 0xffffffff8053de66 =3D sofree+0x1a6/frame 0xfffffe1f9e1f8880 tcp_close() at 0xffffffff8064dd8e =3D tcp_close+0x11e/frame 0xfffffe1f9e1= f88b0 tcp_timer_2msl() at 0xffffffff80653c28 =3D tcp_timer_2msl+0x278/frame 0xfffffe1f9e1f88e0 softclock_call_cc() at 0xffffffff804cbacc =3D softclock_call_cc+0x19c/frame 0xfffffe1f9e1f89c0 softclock() at 0xffffffff804cbec7 =3D softclock+0x47/frame 0xfffffe1f9e1f= 89e0 intr_event_execute_handlers() at 0xffffffff8047aa86 =3D intr_event_execute_handlers+0x96/frame 0xfffffe1f9e1f8a20 ithread_loop() at 0xffffffff8047b106 =3D ithread_loop+0xa6/frame 0xfffffe1f9e1f8a70 fork_exit() at 0xffffffff804781b4 =3D fork_exit+0x84/frame 0xfffffe1f9e1f= 8ab0 fork_trampoline() at 0xffffffff80713fce =3D fork_trampoline+0xe/frame 0xfffffe1f9e1f8ab0 The scenario: 1. thread1: tcp_timer_2msl() expires and tcp_close() is called to clean this TCP connection. 2. thread1: In tcp_close() the inp is marked with INP_DROPPED flag, the process continues and calls INP_WUNLOCK() here: https://github.com/freebsd/freebsd/blob/releng/11.0/sys/netinet/tcp_subr.= c#L1568 3. thread2: Now because INP_WLOCK is released, the inp can transition to INP_TIMEWAIT state and nothing is preventing it. 4. thread2: During the INP_TIMEWAIT state transition, the inp is marked with INP_TIMEWAIT flag. 5. thread1: Back in business and tcp_close() call continues with sofree() -> tcp_usr_detach() -> tcp_detach(). Then as inp is marked with INP_DROPPED|INP_TIMEWAIT flags, in_pcbfree() is called. w/ INVARIANTS you have an assertion here, w/o INVARIANTS process continues. 6. Later: tcp_twclose() cleans up this INP_TIMEWAIT inp and calls in_pcbfree() again to achieve a fancy inp double-free. This issue is a tricky one and seems here since quite a while. It has been witness at least once in 10.1 and by two different people in 11.0. Astute questions: o Why INP_DROPPED flag is not tested in tcp_input() in the first place? When you are marked as INP_DROPPED, you are almost dead, you should not be allowed to transition to a different state! Good point, and tcp_input() relies on the fact that INP_DROPPED inps are no more in TCP hash table. But tcp_input() in some cases do relock INP (see relocked: label) and if it does check a lot of things after having relocked the inp it does not check for a recently added INP_DROPPED flag. o Why tcp_detach() does an unconditional in_pcbfree() for inps in TIMEWAIT state? This because inps in TIMEWAIT state have only one exit: Being freed. And it is the duty of tcp_detach() to free all inps with INP_DROPPED|INP_TIMEWAIT. o Why this issue is so rare? Good question, I can see how to have a specific TCP traffic to make it more frequent but no definitive answer yet. Fix proposal: This issue description is still a bit fresh but I would enforce that an inp with INP_DROPPED flag should not be allowed to change state. Thing learned: When re-locking an inp, it might have changed a lot, and you might not like what it became. Thanks again to Slawa, for his numerous debug reports and always questioning my explanations. His last question directly led to this finding. He is testing a quick workaround patch to check if there is mor= e. I will create a review with a fix proposal, and don't hesitate if you have other comments on this issue. -- Julien --tTtWsDhKmocbCF2RFmwOv4pFIUxwPTxnn-- --iObGiuqRXRxfbNqO4ss2AeHoPF6e2gPOF Content-Type: application/pgp-signature; name="signature.asc" Content-Description: OpenPGP digital signature Content-Disposition: attachment; filename="signature.asc" -----BEGIN PGP SIGNATURE----- Comment: GPGTools - https://gpgtools.org iQEcBAEBCgAGBQJX9f0LAAoJEKVlQ5Je6dhxmBEIAIptso+B273HmCgH/Ylv4GWr 6mBGNNtyUnMrHCejJms+wMMvnaNKZvhuPumTbHvNMt8S3jdwpQTYSVzzB4UjGyMT gJEjihrZIffz/4NN9KfvgrOJRDh2+PsGrDT5Y8ojbEzMuvDbFP1XagLlXR0K/Rcb H/4pO0DyD8aDD0Et7bGPFelZ9buxEpk98pcVblzrBzVgItu2G3MJe6IuuBjVv68d xvTlZvkLqMAQsAj3uyYpGt/VxwM/2gTdVeaGlstdbBUqQERkxCBZpCztogU/StTD 1RS1uLW/py+KyrqjANhD8wmaXm01oNObAsZtqOwm/cbl3ybS/VqP0j7CSsIKURE= =+IZc -----END PGP SIGNATURE----- --iObGiuqRXRxfbNqO4ss2AeHoPF6e2gPOF--