From owner-freebsd-stable@freebsd.org Wed Nov 2 05:09:44 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 97E5AC2A85B for ; Wed, 2 Nov 2016 05:09:44 +0000 (UTC) (envelope-from jason.harmening@gmail.com) Received: from mail-pf0-x235.google.com (mail-pf0-x235.google.com [IPv6:2607:f8b0:400e:c00::235]) (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 30AE11203 for ; Wed, 2 Nov 2016 05:09:44 +0000 (UTC) (envelope-from jason.harmening@gmail.com) Received: by mail-pf0-x235.google.com with SMTP id n85so4688725pfi.1 for ; Tue, 01 Nov 2016 22:09:44 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=subject:to:references:cc:from:message-id:date:user-agent :mime-version:in-reply-to; bh=KcKIniNi53XtHAD26B+gWNwvLs/YkylhfwU+cVDbewc=; b=vSPUzlelkPMyLTK6bcvJXXKiMOY9n/11+z7PACdy01I0bTxxXudajWSJhCafIAiFni l31yfk7aa8dHl1LnUvImdsBW26g18ofDBHSEA9OrxVCh+8T8rUfy4PsYYDSRX46c28iQ 373i761Di5fyM5rcvUyebx56gesa5q6k+Xc6i9Nj4wSXlSd6Q/hbmWzA7LqmxDu67FG8 oN3/ciClgL8q5E8GB69khJFOcLxkLMsizHwF/z0DLA2aaeZ5r35IZVwCNwPRt+n7Je3c 9h7g6eCPjdlZOGyrETtblBdogMy4+AESdVrfx3BEF7M+4qkk88CciOzrql6ulKr3V15M qjgQ== 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=KcKIniNi53XtHAD26B+gWNwvLs/YkylhfwU+cVDbewc=; b=SQlU6P3RcRUglz/K9YhRV2hUvc0ivgcJM+j+Z10wwDU3pIG3BGGHRex5QY0EP+vqea tFzxjSyDje7a7yjFm5YF4K0qA9qcTgFAT74mp5JN6EivCbDr2VvMMxuFSAJAdpj+3E/z mqY1aAg97e3vvWH3GgvTG+dhS8AMsKJAsml+aFQMd11E11tsTA73YzwgOFkmZKQ1NSP8 th15HVrpmZ4kmR3bxyyqzdWzINBiQ89tGMnkKrve/4ywh92lq8Ayru5D01P7iTgn8Y+J 23N9c5Ac4uNxbtLwYsQaZAzfZVMHZR9Vj8CcEchZ7yxPPR5CjKzdbmvASOGlvBjcpC7r pX7w== X-Gm-Message-State: ABUngvfGvgMrYesVWR0hFWPIiGWgXOCSMyopDhM3K0cGSqATx8SCKdfYOAjyO6uepA2oYA== X-Received: by 10.98.144.83 with SMTP id a80mr3425853pfe.156.1478063383183; Tue, 01 Nov 2016 22:09:43 -0700 (PDT) Received: from corona.austin.rr.com (c-67-188-30-11.hsd1.ca.comcast.net. [67.188.30.11]) by smtp.googlemail.com with ESMTPSA id l7sm685709pfg.35.2016.11.01.22.09.41 (version=TLS1_2 cipher=ECDHE-RSA-AES128-GCM-SHA256 bits=128/128); Tue, 01 Nov 2016 22:09:42 -0700 (PDT) Subject: Re: huge nanosleep variance on 11-stable To: Kevin Oberman References: <6167392c-c37a-6e39-aa22-ca45435d6088@gmail.com> <1c3f4599-8aef-471a-3a39-49d913f1a4e5@gmail.com> Cc: FreeBSD-STABLE Mailing List From: Jason Harmening Message-ID: Date: Tue, 1 Nov 2016 22:16:39 -0700 User-Agent: Mozilla/5.0 (X11; FreeBSD amd64; rv:45.0) Gecko/20100101 Thunderbird/45.4.0 MIME-Version: 1.0 In-Reply-To: Content-Type: multipart/signed; micalg=pgp-sha512; protocol="application/pgp-signature"; boundary="17l0HvA18Gx7iIfq8LvJv7LJbKkkiT9Ah" 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: Wed, 02 Nov 2016 05:09:44 -0000 This is an OpenPGP/MIME signed message (RFC 4880 and 3156) --17l0HvA18Gx7iIfq8LvJv7LJbKkkiT9Ah Content-Type: multipart/mixed; boundary="8HTTFfHFskPSnrQDLV8uDFxOEbWF1knW6"; protected-headers="v1" From: Jason Harmening To: Kevin Oberman Cc: FreeBSD-STABLE Mailing List Message-ID: Subject: Re: huge nanosleep variance on 11-stable References: <6167392c-c37a-6e39-aa22-ca45435d6088@gmail.com> <1c3f4599-8aef-471a-3a39-49d913f1a4e5@gmail.com> In-Reply-To: --8HTTFfHFskPSnrQDLV8uDFxOEbWF1knW6 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable On 11/01/16 20:45, Kevin Oberman wrote: > On Tue, Nov 1, 2016 at 2:36 PM, Jason Harmening > > wrote: >=20 > Sorry, that should be ~*30ms* to get 30fps, though the variance is = still > up to 500ms for me either way. >=20 > On 11/01/16 14:29, Jason Harmening wrote: > > repro code is at http://pastebin.com/B68N4AFY if anyone's interes= ted. > > > > On 11/01/16 13:58, Jason Harmening wrote: > >> Hi everyone, > >> > >> I recently upgraded my main amd64 server from 10.3-stable > (r302011) to > >> 11.0-stable (r308099). It went smoothly except for one big issu= e: > >> certain applications (but not the system as a whole) respond ver= y > >> sluggishly, and video playback of any kind is extremely choppy. > >> > >> The system is under very light load, and I see no evidence of > abnormal > >> interrupt latency or interrupt load. More interestingly, if I > place the > >> system under full load (~0.0% idle) the problem *disappears* and= > >> playback/responsiveness are smooth and quick. > >> > >> Running ktrace on some of the affected apps points me at the pro= blem: > >> huge variance in the amount of time spent in the nanosleep syste= m > call. > >> A sleep of, say, 5ms might take anywhere from 5ms to ~500ms from= > entry > >> to return of the syscall. OTOH, anything CPU-bound or that wait= s on > >> condvars or I/O interrupts seems to work fine, so this doesn't > seem to > >> be an issue with overall system latency. > >> > >> I can repro this with a simple program that just does a 3ms > usleep in a > >> tight loop (i.e. roughly the amount of time a video player would= > sleep > >> between frames @ 30fps). At light load ktrace will show the hug= e > >> nanosleep variance; under heavy load every nanosleep will comple= te in > >> almost exactly 3ms. > >> > >> FWIW, I don't see this on -current, although right now all my > -current > >> images are VMs on different HW so that might not mean anything. = > I'm not > >> aware of any recent timer- or scheduler- specific changes, so I'= m > >> wondering if perhaps the recent IPI or taskqueue changes might b= e > >> somehow to blame. > >> > >> I'm not especially familiar w/ the relevant parts of the kernel,= > so any > >> guidance on where I should focus my debugging efforts would be m= uch > >> appreciated. > >> > >> Thanks, > >> Jason >=20 > =20 > This is likely off track, but this is a behavior I have noticed since > moving to 11, though it might have started in 10.3-STABLE before moving= > to head before 11 went to beta. I can't explain any way nanosleep could= > be involved, but I saw annoying lock-ups similar to yours. I also no > longer see them. >=20 > I eliminated the annoyance by change scheduler from ULE to 4BSD. That > was it, but I have not seen the issue since. I'd be very interested in > whether the scheduler is somehow impacting timing functions or it's s > different issue. I've felt that there was something off in ULE for some= > time, but it was not until these annoying hiccups convinced me to try > going back to 4BSD. >=20 > Tip o' the hat to Doug B. for his suggestions that ULE may have issues > that impacted interactivity. I figured it out: r282678 (which was never MFCed to 10-stable) added support for the MWAIT instruction on the idle path for Intel CPUs that claim to support it. While my CPU (2009-era Xeon 5500) advertises support for it in its feature mask and ACPI C-state entries, the cores don't seem to respond very quickly to interrupts while idling in MWAIT. Disabling mwait in acpi_cpu.c and falling back to the old "sti; hlt" mechanism for C1 completely fixes the responsiveness issues. So if your CPU is of a similar vintage, it may not be ULE's fault. --8HTTFfHFskPSnrQDLV8uDFxOEbWF1knW6-- --17l0HvA18Gx7iIfq8LvJv7LJbKkkiT9Ah Content-Type: application/pgp-signature; name="signature.asc" Content-Description: OpenPGP digital signature Content-Disposition: attachment; filename="signature.asc" -----BEGIN PGP SIGNATURE----- iQF8BAEBCgBmBQJYGXa6XxSAAAAAAC4AKGlzc3Vlci1mcHJAbm90YXRpb25zLm9w ZW5wZ3AuZmlmdGhob3JzZW1hbi5uZXRENkY3MTQyREU0MTU4MTgyRkZDNUU2ODVC QjlGOEJGOTkyODQxRDFCAAoJELufi/mShB0bwGwH/RVFzEp0ThkwNTW6nJc5j/0u QWOLclW56iZ3CJMMAdIG6Dk0P8V4fg9KxuSL276PFxxcGq1sNg3HeTh69cAUWK3N i3jjSa2JUgh4VAViKAEOTr1iWcNgqFpNl+05NP9ZWJY/v60n4AmMApNXH6KT8C5f WQnPymA3csxxUBtmHGZnDyUDrlpWNRfk2b6M2E9Zc975hJTpBxyxhI+IrmoyiB/4 2yQ0ha0SqzT2dN9f7XgFVvpuRJTGaaWWLhMYGib69U7EhVudkYNn33/dftI6eDYt ZRxLJgvfJr6Z3s3o9+xKv5ExGrMqOFF1DkCznm0klcCSkPiH1VVTfZCRkko8tI4= =xnUb -----END PGP SIGNATURE----- --17l0HvA18Gx7iIfq8LvJv7LJbKkkiT9Ah--