Date: Thu, 6 Oct 2016 09:28:06 +0200 From: Julien Charbon <jch@freebsd.org> To: Slawa Olhovchenkov <slw@zxy.spb.ru>, Julien Charbon <julien.charbon@gmail.com> Cc: Konstantin Belousov <kostikbel@gmail.com>, freebsd-stable@FreeBSD.org, hiren panchasara <hiren@strugglingcoder.info> Subject: Re: 11.0 stuck on high network load Message-ID: <a0425aad-a421-05bc-c1a8-c6fe06b83833@freebsd.org> In-Reply-To: <20160928115909.GC54003@zxy.spb.ru> References: <8ba75d6e-4f01-895e-0aed-53c6c6692cb9@freebsd.org> <20160920202633.GQ2840@zxy.spb.ru> <f644cd52-4377-aa90-123a-3a2887972bbc@freebsd.org> <20160921195155.GW2840@zxy.spb.ru> <e4e0188c-b22b-29af-ed15-b650c3ec4553@gmail.com> <20160923200143.GG2840@zxy.spb.ru> <20160925124626.GI2840@zxy.spb.ru> <dc2798ff-2ace-81f7-a563-18ffa1ace990@gmail.com> <20160926172159.GA54003@zxy.spb.ru> <62453d9c-b1e4-1129-70ff-654dacea37f9@gmail.com> <20160928115909.GC54003@zxy.spb.ru>
next in thread | previous in thread | raw e-mail | index | archive | help
This is an OpenPGP/MIME signed message (RFC 4880 and 3156) --iObGiuqRXRxfbNqO4ss2AeHoPF6e2gPOF Content-Type: multipart/mixed; boundary="tTtWsDhKmocbCF2RFmwOv4pFIUxwPTxnn"; protected-headers="v1" From: Julien Charbon <jch@freebsd.org> To: Slawa Olhovchenkov <slw@zxy.spb.ru>, Julien Charbon <julien.charbon@gmail.com> Cc: Konstantin Belousov <kostikbel@gmail.com>, freebsd-stable@FreeBSD.org, hiren panchasara <hiren@strugglingcoder.info> Message-ID: <a0425aad-a421-05bc-c1a8-c6fe06b83833@freebsd.org> Subject: Re: 11.0 stuck on high network load References: <8ba75d6e-4f01-895e-0aed-53c6c6692cb9@freebsd.org> <20160920202633.GQ2840@zxy.spb.ru> <f644cd52-4377-aa90-123a-3a2887972bbc@freebsd.org> <20160921195155.GW2840@zxy.spb.ru> <e4e0188c-b22b-29af-ed15-b650c3ec4553@gmail.com> <20160923200143.GG2840@zxy.spb.ru> <20160925124626.GI2840@zxy.spb.ru> <dc2798ff-2ace-81f7-a563-18ffa1ace990@gmail.com> <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: >> <SNIP> >> 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--
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?a0425aad-a421-05bc-c1a8-c6fe06b83833>