From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from mx0a-001b2d01.pphosted.com ([148.163.156.1]:41576 "EHLO mx0a-001b2d01.pphosted.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751208AbdBXRbX (ORCPT ); Fri, 24 Feb 2017 12:31:23 -0500 Received: from pps.filterd (m0098410.ppops.net [127.0.0.1]) by mx0a-001b2d01.pphosted.com (8.16.0.20/8.16.0.20) with SMTP id v1OHOs2a024784 for ; Fri, 24 Feb 2017 12:30:01 -0500 Received: from e23smtp06.au.ibm.com (e23smtp06.au.ibm.com [202.81.31.148]) by mx0a-001b2d01.pphosted.com with ESMTP id 28t0awq8nk-1 (version=TLSv1.2 cipher=AES256-SHA bits=256 verify=NOT) for ; Fri, 24 Feb 2017 12:30:00 -0500 Received: from localhost by e23smtp06.au.ibm.com with IBM ESMTP SMTP Gateway: Authorized Use Only! Violators will be prosecuted for from ; Sat, 25 Feb 2017 03:29:58 +1000 Subject: Re: [tpmdd-devel] [RFC PATCH] tpm: msleep() delays - replace with usleep_range() in i2c nuvoton driver From: Mimi Zohar To: Jarkko Sakkinen Cc: tpmdd-devel , Thomas@intel.com, Dan Morav , linux-fsdevel , linux-security-module , linux-ima-devel , Gleixner Date: Fri, 24 Feb 2017 12:29:02 -0500 In-Reply-To: <20170224170100.prwbcsffxdqjudc2@intel.com> References: <1487893578.3193.155.camel@linux.vnet.ibm.com> <20170224170100.prwbcsffxdqjudc2@intel.com> Content-Type: text/plain; charset="UTF-8" Mime-Version: 1.0 Content-Transfer-Encoding: 7bit Message-Id: <1487957342.3193.200.camel@linux.vnet.ibm.com> Sender: linux-fsdevel-owner@vger.kernel.org List-ID: On Fri, 2017-02-24 at 19:01 +0200, Jarkko Sakkinen wrote: > On Thu, Feb 23, 2017 at 06:46:18PM -0500, Mimi Zohar wrote: > > Commit 500462a9de65 "timers: Switch to a non-cascading wheel" replaced > > the 'classic' timer wheel, which aimed for near 'exact' expiry of the > > timers. Their analysis was that the vast majority of timeout timers > > are used as safeguards, not as real timers, and are cancelled or > > rearmed before expiration. The only exception noted to this were > > networking timers with a small expiry time. > > > > Not included in the analysis was the TPM polling timer, which resulted > > in a longer normal delay and, every so often, a very long delay. The > > non-cascading wheel delay is based on CONFIG_HZ. For a description of > > the different rings and their delays, refer to the comments in > > kernel/time/timer.c. > > > > Below are the delays given for rings 0 - 2, which explains the longer > > "normal" delays and the very, long delays as seen on systems with > > CONFIG_HZ 250. > > > > * HZ 1000 steps > > * Level Offset Granularity Range > > * 0 0 1 ms 0 ms - 63 ms > > * 1 64 8 ms 64 ms - 511 ms > > * 2 128 64 ms 512 ms - 4095 ms (512ms - ~4s) > > > > * HZ 250 > > * Level Offset Granularity Range > > * 0 0 4 ms 0 ms - 255 ms > > * 1 64 32 ms 256 ms - 2047 ms (256ms - ~2s) > > * 2 128 256 ms 2048 ms - 16383 ms (~2s - ~16s) > > > > Below is a comparison of extending the TPM with 1000 measurements, > > using msleep() vs. usleep_delay() when configured for 1000 hz vs. 250 > > hz, before and after commit 500462a9de65. > > > > linux-4.7 | msleep() usleep_range() > > 1000 hz: 0m44.628s | 1m34.497s 29.243s > > 250 hz: 1m28.510s | 4m49.269s 32.386s > > > > linux-4.7 | min-max (msleep) min-max (usleep_range) > > 1000 hz: 0:017 - 2:760s | 0:015 - 3:967s 0:014 - 0:418s > > 250 hz: 0:028 - 1:954s | 0:040 - 4:096s 0:016 - 0:816s > > > > This patch replaces the msleep() with usleep_range() calls in the > > i2c nuvoton driver with a consistent max range value. > > > > Signed-of-by: Mimi Zohar > > Reviewed-by: Nayna Jain > > So why doesn't it go to level 0 with msleep()? I quickly skimmed > through __mod_timer() and for me it looked like that level 0 would be > calculated (when it is eventually called starting from msleep()). > What did I miss? I've just added some printk's in kernel/time/timer.c. It looks like it is level 0. The delay seems to be caused by schedule() in schedule_timeout(). setup_timer_on_stack(&timer, process_timeout, (unsigned long)current); __mod_timer(&timer, expire, false, false); schedule(); <=== del_singleshot_timer_sync(&timer); /* Remove the timer from the object tracker */ destroy_timer_on_stack(&timer); printks output: 124.901002] calc_wheel_index: level 0 timer: c000003fab32b150 expires 4294923520 new expires 4294923520 now 4294923518 [ 124.901003] __mod_timer: exit timer c000003fab32b1a0 now 4294923518 < call to schedule() > [ 128.607463] schedule_timeout: before destroy timer: c000003fab32b150 expires 4294923520 now 4294924439 <=== notice that the "now" time is way beyond the expires time. Mimi