From owner-freebsd-bugs@freebsd.org Thu Aug 29 10:18:15 2019 Return-Path: Delivered-To: freebsd-bugs@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 D4219D18E2 for ; Thu, 29 Aug 2019 10:18:15 +0000 (UTC) (envelope-from brde@optusnet.com.au) Received: from mailman.nyi.freebsd.org (mailman.nyi.freebsd.org [IPv6:2610:1c1:1:606c::50:13]) by mx1.freebsd.org (Postfix) with ESMTP id 46Jz8R1PGZz4TTP for ; Thu, 29 Aug 2019 10:18:15 +0000 (UTC) (envelope-from brde@optusnet.com.au) Received: by mailman.nyi.freebsd.org (Postfix) id 2DB2CD18E1; Thu, 29 Aug 2019 10:18:15 +0000 (UTC) Delivered-To: bugs@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 2D6C9D18E0 for ; Thu, 29 Aug 2019 10:18:15 +0000 (UTC) (envelope-from brde@optusnet.com.au) Received: from mail105.syd.optusnet.com.au (mail105.syd.optusnet.com.au [211.29.132.249]) by mx1.freebsd.org (Postfix) with ESMTP id 46Jz8P1sgdz4TTM; Thu, 29 Aug 2019 10:18:09 +0000 (UTC) (envelope-from brde@optusnet.com.au) Received: from [192.168.0.102] (c110-21-101-228.carlnfd1.nsw.optusnet.com.au [110.21.101.228]) by mail105.syd.optusnet.com.au (Postfix) with ESMTPS id 0E886361397; Thu, 29 Aug 2019 20:18:06 +1000 (AEST) Date: Thu, 29 Aug 2019 20:18:04 +1000 (EST) From: Bruce Evans X-X-Sender: bde@besplex.bde.org To: Alexander Motin cc: bugs@FreeBSD.org, nicolas.masse@stormshield.eu Subject: Re: [Bug 240121] Serial console can eat a lot of CPU with low baudrate In-Reply-To: Message-ID: <20190829185320.Y2032@besplex.bde.org> References: MIME-Version: 1.0 Content-Type: TEXT/PLAIN; charset=US-ASCII; format=flowed X-Optus-CM-Score: 0 X-Optus-CM-Analysis: v=2.2 cv=FNpr/6gs c=1 sm=1 tr=0 a=PalzARQSbocsUSjMRkwAPg==:117 a=PalzARQSbocsUSjMRkwAPg==:17 a=jpOVt7BSZ2e4Z31A5e1TngXxSK0=:19 a=kj9zAlcOel0A:10 a=6I5d2MoRAAAA:8 a=rEYp1om3bJNTb4q7tmMA:9 a=CjuIK1q_8ugA:10 a=IjZwj45LgO3ly-622nXo:22 X-Rspamd-Queue-Id: 46Jz8P1sgdz4TTM X-Spamd-Bar: --- Authentication-Results: mx1.freebsd.org; dkim=none; dmarc=none; spf=pass (mx1.freebsd.org: domain of brde@optusnet.com.au designates 211.29.132.249 as permitted sender) smtp.mailfrom=brde@optusnet.com.au X-Spamd-Result: default: False [-3.26 / 15.00]; ARC_NA(0.00)[]; NEURAL_HAM_MEDIUM(-1.00)[-1.000,0]; RCVD_IN_DNSWL_LOW(-0.10)[249.132.29.211.list.dnswl.org : 127.0.5.1]; FROM_HAS_DN(0.00)[]; RCPT_COUNT_THREE(0.00)[3]; R_SPF_ALLOW(-0.20)[+ip4:211.29.132.0/23:c]; FREEMAIL_FROM(0.00)[optusnet.com.au]; MIME_GOOD(-0.10)[text/plain]; DMARC_NA(0.00)[optusnet.com.au]; NEURAL_HAM_LONG(-1.00)[-1.000,0]; TO_DN_SOME(0.00)[]; IP_SCORE_FREEMAIL(0.00)[]; TO_MATCH_ENVRCPT_SOME(0.00)[]; NEURAL_HAM_SHORT(-0.96)[-0.958,0]; IP_SCORE(0.00)[ip: (-5.04), ipnet: 211.28.0.0/14(-3.23), asn: 4804(-2.36), country: AU(0.01)]; RCVD_NO_TLS_LAST(0.10)[]; FROM_EQ_ENVFROM(0.00)[]; R_DKIM_NA(0.00)[]; FREEMAIL_ENVFROM(0.00)[optusnet.com.au]; ASN(0.00)[asn:4804, ipnet:211.28.0.0/14, country:AU]; MIME_TRACE(0.00)[0:+]; RCVD_COUNT_TWO(0.00)[2] X-BeenThere: freebsd-bugs@freebsd.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: Bug reports List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 29 Aug 2019 10:18:15 -0000 On Mon, 26 Aug 2019 a bug that doesn't want replies@freebsd.org wrote: > https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=240121 > > That effect is unexpected to me. I would expect opposite -- reduction of wait > time, since code reduces number of buffer flushes and utilizes hardware FIFO. > I may need to reproduce it to understand the issue. uart already made dubious use of the fifo for serial consoles. sio is more careful, and reinitializes essentially the whole hardware device for every character, as needed to work when the device is in an inderterminate of unwanted active state. For this, it is best to not use the fifo at all. I see the following problems in the uart serial console code: - can wait forever if hardware flow control is active (requires a 16650+ in if the uart is an xx50+). But hardware flow control never worked even for sio (except in my uncomitted version of sio), and is hard-coded turned off for uart in the driver, and may also be locked off in the lock state device, and is also hard-coded-fixated off in some versions of uart. - the previous version of uart has a 1 second timeout for the shift register (spelled LSR_TEMT) being empty. I don't know if this bit really works for showning that the whole tx is empty. The 1 second timeout is clearly wrong, and might be the reason for this PR -- it is too short, so gave wrong behaviour but less overhead. E.g., at the PR speed of only 2400 bps, it takes about 1/240 second per character, so if the fifo size is > 240 then data might be lost. More likely, the fifo size is 128 an there was no data loss and less waiting for the fifo in the previous version. I test sio down to 2 bps so would see large data loss with a 1 byte fifo (holding register) with a 1 second timeout. My version of sio avoids such problems by using infinite timeouts not only for itself, but for things like spinlocks while console output is in progress. Testing at 2 bps is a good way to find timing problems. - now for tx fifo size 1, you removed the 1 second timeout, but only wait for the holding register to become empty. I don't like that. Oops, my version of sio still has a 1 second timeout. but waits for the shift register to become empty too. It waits before and after txing each char as needed for switching the mode on each char. - now for tx fifo size > 1, the timeout is done differently. That looks more like the cause of the slowness. After finding the device busy, the device state was checked after about 4 usec. Now the granularity of the check is supposed to be 1/10 of a character time = 1/2400 = 416 usec at 2400 bps. - after filling the fifo or holding register, uart still doesn't wait. The code is too complicated for me. > > What UART hardware are you using? Does it have FIFO? Bruce