From owner-freebsd-stable@freebsd.org Wed Nov 2 05:49:59 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 54CC1C2A52B for ; Wed, 2 Nov 2016 05:49:59 +0000 (UTC) (envelope-from kob6558@gmail.com) Received: from mail-vk0-x232.google.com (mail-vk0-x232.google.com [IPv6:2607:f8b0:400c:c05::232]) (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 399361FD4 for ; Wed, 2 Nov 2016 05:49:58 +0000 (UTC) (envelope-from kob6558@gmail.com) Received: by mail-vk0-x232.google.com with SMTP id x186so4485859vkd.1 for ; Tue, 01 Nov 2016 22:49:58 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:sender:in-reply-to:references:from:date:message-id :subject:to:cc; bh=fY470maeajdR6V+8I3hXg/4Nfv2tngMSpas7nSaGPEM=; b=lKh9OL4nlsDg5EKf5BT/7j2Oz0cNRY4t0d/wWcoCBfBXe7veGTlgCk2e1WNgKCBxs8 oyup/r+rcPP7NjT/QUeg3KTs9obp8pL5DGAg9SYEjcaQV1tYYb3usfgEPvv6rHyS7avO Iur4D1/qUfA47MuobFEXb/HDae7YgJ9bN7TMVgVkRKJWqGI3asBH7r8lxvjBgnvruEDw jW8gfGoUa+D9kUbtJpWUBDtbu9qXsyL6Tl/B330PVYbD/VpZ65K3cS1zmm67vRbSgdXZ eLT7hngaguz/heeu7rc7s2Oc0Bt+ZPj2UmTCftIEH1edtff0uDi506K9SIs2ASao3LXb a0ag== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20130820; h=x-gm-message-state:mime-version:sender:in-reply-to:references:from :date:message-id:subject:to:cc; bh=fY470maeajdR6V+8I3hXg/4Nfv2tngMSpas7nSaGPEM=; b=b6SNuSLqSiWLGaHVsmmWUFCh0RGRkW5Kv0RSuzvJw+I534dU51d0JJuqZMWt14BmHP lfCUaazBTC1j4Ijz6K9nP06Jc0ZNlkZ2nJE/QCYSwcco+9CRINUib1ciqxZkgHWL5mPc KYu3ccJoOAn3qLoOpQgim9RvnBzI+zLcbEGc4gTAVqFf6GOMjapZZ0KKwTPzMmoAKVRf UpL0FT202mAf6riZHQfe4LyjygV8Vq7/jKGk8eCsJRWlXhEacqaZ3DDV7kzDyLb3h1Yn mUSkPfduQHx3EOhSPZhfLjobNnmQK3Cc9gyJipylgJTeN1dnc7IRCG/Z8VEiii9jjjQD 2n+w== X-Gm-Message-State: ABUngvdMo7FN+fwvfY6nafTDBq+Rh4gdRrkgKjdmk9HRa2d1oUKMOfB2Nw6LSCnIb60greL2HyiPMYGnJiwx3g== X-Received: by 10.31.60.85 with SMTP id j82mr1356388vka.42.1478065797046; Tue, 01 Nov 2016 22:49:57 -0700 (PDT) MIME-Version: 1.0 Sender: kob6558@gmail.com Received: by 10.103.119.79 with HTTP; Tue, 1 Nov 2016 22:49:56 -0700 (PDT) In-Reply-To: References: <6167392c-c37a-6e39-aa22-ca45435d6088@gmail.com> <1c3f4599-8aef-471a-3a39-49d913f1a4e5@gmail.com> From: Kevin Oberman Date: Tue, 1 Nov 2016 22:49:56 -0700 X-Google-Sender-Auth: NNcovKsrJ8WoFdVCX1Wz93OUpEY Message-ID: Subject: Re: huge nanosleep variance on 11-stable To: Jason Harmening Cc: FreeBSD-STABLE Mailing List Content-Type: text/plain; charset=UTF-8 X-Content-Filtered-By: Mailman/MimeDel 2.1.23 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:49:59 -0000 On Tue, Nov 1, 2016 at 10:16 PM, Jason Harmening wrote: > > > On 11/01/16 20:45, Kevin Oberman wrote: > > On Tue, Nov 1, 2016 at 2:36 PM, Jason Harmening > > > wrote: > > > > Sorry, that should be ~*30ms* to get 30fps, though the variance is > still > > up to 500ms for me either way. > > > > On 11/01/16 14:29, Jason Harmening wrote: > > > repro code is at http://pastebin.com/B68N4AFY if anyone's > interested. > > > > > > 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 issue: > > >> certain applications (but not the system as a whole) respond very > > >> 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 > problem: > > >> huge variance in the amount of time spent in the nanosleep system > > 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 waits > 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 huge > > >> nanosleep variance; under heavy load every nanosleep will > complete 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 be > > >> 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 > much > > >> appreciated. > > >> > > >> Thanks, > > >> Jason > > > > > > 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. > > > > 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. > > > > 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. > > You are almost certainly correct. My system is circa 2011; i5-2520M, Sandy Bridge. While it might have the same issue, I'd be surprised. It's possible, but probably completely different from what you are seeing. Reports of the problem I was seeing definitely pre-date 11, but 11 made things much worse, so it could be a combination of things. And I can't see how ULE could have anything to do with this issue. Congratulations on some really good sleuthing to find this. -- Kevin Oberman, Part time kid herder and retired Network Engineer E-mail: rkoberman@gmail.com PGP Fingerprint: D03FB98AFA78E3B78C1694B318AB39EF1B055683