Received: by 2002:a25:1506:0:0:0:0:0 with SMTP id 6csp2419416ybv; Mon, 24 Feb 2020 05:01:43 -0800 (PST) X-Google-Smtp-Source: APXvYqwOWJqoetC5K7wBvB2e/i2n+r0/eQfzRl4oXrhUsRDKzrKiPSEyNlb+Ud6WvyvR/Mehm23z X-Received: by 2002:a9d:6e98:: with SMTP id a24mr38677725otr.53.1582549303276; Mon, 24 Feb 2020 05:01:43 -0800 (PST) ARC-Seal: i=1; a=rsa-sha256; t=1582549303; cv=none; d=google.com; s=arc-20160816; b=QAmOutlxOMcp2NNQ4ic+7YqRlVfiGiG6xDj12ZvL84bnuJI0RGtzysQ8FFHtYTznc0 OCCnrhQgNrn0N8pDhjLK58NdxyJRbXLroxdceopcg5Ng94LQZQU4f4zSHd95TNTGSQt0 GMgrSLaM9ENwZzhHfthu3uE4RCe2hZjkOnX17nJYKxytzX4kVLUwmFOphY9844W/KUUH lWiMeTWX3dSjQszw47UeETO6qdtPyuyrV6Uoilb7L7+msldTLgfy/bQ6KBNFmU7mKhiJ WDh+R9Vzpmc0kfH8t/F72QaEevwD4VRgrlMRbX471Cv7Qyoe1AXlZv9ELJq5xzhcpb/M BZfA== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=arc-20160816; h=list-id:precedence:sender:content-transfer-encoding :content-language:in-reply-to:mime-version:user-agent:date :message-id:organization:from:references:cc:to:subject; bh=wa1/jDGLoDJEvIXCSCPNzCgMuuGCqPdn/Ro3Ei7sknw=; b=p4N90cUddAyesEXV/ds0neVl9YThezGMmhpsJHdPgeFJwdxATomHt55YE5ghfhLL8O pE299D298wkEWaMYOx+3ZVyPEPJ/sUlzV3OqlUmNDmMvPXPQwHPeGkHBLM+/tGOAaTOz 3GaPTrjpjLSyPH6d4Kvrq/Gud93V13jB0uPtRPOhg++/GmK3YsW5fwt/mh69s4HEXoVv NEAAJt+TB+sXKidT+eFlobGwDvnFlB630AbZ1KQA4wHAvI152TDftA4UPoezVA31zVHr 5UqV/z2tSbIJ5jNx7QlAijUHbdq+G8GxKR7EC60WxLSjcrAYmcKMeqggXESOjlyEtVbh Uuaw== ARC-Authentication-Results: i=1; mx.google.com; spf=pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org; dmarc=fail (p=NONE sp=NONE dis=NONE) header.from=intel.com Return-Path: Received: from vger.kernel.org (vger.kernel.org. [209.132.180.67]) by mx.google.com with ESMTP id b10si5570139otp.124.2020.02.24.05.01.28; Mon, 24 Feb 2020 05:01:43 -0800 (PST) Received-SPF: pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67; Authentication-Results: mx.google.com; spf=pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org; dmarc=fail (p=NONE sp=NONE dis=NONE) header.from=intel.com Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1727521AbgBXNAT (ORCPT + 99 others); Mon, 24 Feb 2020 08:00:19 -0500 Received: from mga18.intel.com ([134.134.136.126]:41866 "EHLO mga18.intel.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1727405AbgBXNAS (ORCPT ); Mon, 24 Feb 2020 08:00:18 -0500 X-Amp-Result: SKIPPED(no attachment in message) X-Amp-File-Uploaded: False Received: from orsmga005.jf.intel.com ([10.7.209.41]) by orsmga106.jf.intel.com with ESMTP/TLS/DHE-RSA-AES256-GCM-SHA384; 24 Feb 2020 05:00:17 -0800 X-ExtLoop1: 1 X-IronPort-AV: E=Sophos;i="5.70,480,1574150400"; d="scan'208";a="409867954" Received: from ahunter-desktop.fi.intel.com (HELO [10.237.72.167]) ([10.237.72.167]) by orsmga005.jf.intel.com with ESMTP; 24 Feb 2020 05:00:14 -0800 Subject: Re: LKFT: arm x15: mmc1: cache flush error -110 To: Ulf Hansson , Bitan Biswas Cc: Naresh Kamboju , Jens Axboe , Alexei Starovoitov , linux-block , lkft-triage@lists.linaro.org, open list , "linux-mmc@vger.kernel.org" , Arnd Bergmann , John Stultz , Thierry Reding , Jon Hunter References: From: Adrian Hunter Organization: Intel Finland Oy, Registered Address: PL 281, 00181 Helsinki, Business Identity Code: 0357606 - 4, Domiciled in Helsinki Message-ID: <728e1782-74d7-7238-2b34-0410523c2160@intel.com> Date: Mon, 24 Feb 2020 14:59:15 +0200 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:68.0) Gecko/20100101 Thunderbird/68.4.1 MIME-Version: 1.0 In-Reply-To: Content-Type: text/plain; charset=utf-8 Content-Language: en-US Content-Transfer-Encoding: 7bit Sender: linux-kernel-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On 24/02/20 1:16 pm, Ulf Hansson wrote: > + Adrian > > On Fri, 21 Feb 2020 at 20:44, Bitan Biswas wrote: >> >> On 2/21/20 1:48 AM, Ulf Hansson wrote: >>> External email: Use caution opening links or attachments >>> >>> >>> On Thu, 20 Feb 2020 at 18:54, Naresh Kamboju wrote: >>>> >>>> On Wed, 19 Feb 2020 at 21:54, Ulf Hansson wrote: >>>>> >>>>> On Thu, 13 Feb 2020 at 16:43, Naresh Kamboju wrote: >>>>>> >>>>> >>>>> Try to restore the value for the cache flush timeout, by updating the >>>>> define MMC_CACHE_FLUSH_TIMEOUT_MS to 10 * 60 * 1000". >>>> >>>> I have increased the timeout to 10 minutes but it did not help. >>>> Same error found. >>>> [ 608.679353] mmc1: Card stuck being busy! mmc_poll_for_busy >>>> [ 608.684964] mmc1: cache flush error -110 >>>> [ 608.689005] blk_update_request: I/O error, dev mmcblk1, sector >>>> 4302400 op 0x1:(WRITE) flags 0x20800 phys_seg 1 prio class 0 >>>> >>>> OTOH, What best i could do for my own experiment to revert all three patches and >>>> now the reported error gone and device mount successfully [1]. >>>> >>>> List of patches reverted, >>>> mmc: core: Specify timeouts for BKOPS and CACHE_FLUSH for eMMC >>>> mmc: block: Use generic_cmd6_time when modifying >>>> INAND_CMD38_ARG_EXT_CSD >>>> mmc: core: Default to generic_cmd6_time as timeout in __mmc_switch() >>>> >>>> [1] https://lkft.validation.linaro.org/scheduler/job/1238275#L4346 >>>> >>>> - Naresh >>> >>> Thanks for testing! >>> >>> This sounds a bit weird, I must say. Also, while looking into the >>> logs, it seems like you are comparing a v5.5 kernel with v5.6-rc2, but >>> maybe I didn't read the logs carefully enough. >>> >>> In any case, I am looking into creating a debug patch so we can >>> narrow down the problem a bit further. >>> >>> Kind regards >>> Uffe >>> >> >> Hi Ulf, >> >> I see that Jetson-TX2 / Jetson-Xavier suspend test is aborted and >> below error is seen due to the commit >> 24ed3bd01d6a844fd5e8a75f48d0a3d10ed71bf9 ("mmc: core: Specify timeouts >> for BKOPS and CACHE_FLUSH for eMMC"): >> >> ## >> [ 268.976197] Freezing user space processes ... (elapsed 0.001 seconds) >> done. >> [ 268.984414] OOM killer disabled. >> [ 268.987635] Freezing remaining freezable tasks ... (elapsed 0.000 >> seconds) done. >> [ 269.217471] PM: dpm_run_callback(): mmc_bus_suspend+0x0/0x58 returns -110 >> [ 269.224255] PM: Device mmc1:0001 failed to suspend: error -110 >> [ 269.230080] PM: Some devices failed to suspend, or early wake event >> detected > > Is there also a print in the log about "Card stuck being busy!"? > > In any case, it seems like the timeout error (-110) is happening way > too soon. The cache flush timeout is now 30s, but the timeout seems to > fire only a few hundred ms (at most) after the cache flush command has > been sent. > >> ## >> >> I find that from the commit the changes in mmc_flush_cache below is >> the cause. >> >> ## >> @@ -961,7 +963,8 @@ int mmc_flush_cache(struct mmc_card *card) >> (card->ext_csd.cache_size > 0) && >> (card->ext_csd.cache_ctrl & 1)) { >> err = mmc_switch(card, EXT_CSD_CMD_SET_NORMAL, >> - EXT_CSD_FLUSH_CACHE, 1, 0); >> + EXT_CSD_FLUSH_CACHE, 1, >> + MMC_CACHE_FLUSH_TIMEOUT_MS); >> >> ## >> >> Do you have suggestion to try for the suspend errors ? > > Just as a quick sanity test, please try the below patch, which > restores the old cache flush timeout to 10min. > > However, as I indicated above, this seems to be a problem that needs > to be fixed at in the host driver side. For the sdhci driver, there is > a bit of a tricky logic around how to deal with timeouts in > sdhci_send_command(). My best guess is that's where we should look > more closely (and I am doing that). Could be, but hard to narrow down without more debug. I would enable dynamic debug and mmc messages e.g. kernel config CONFIG_DYNAMIC_DEBUG=y kernel command line option dyndbg="file drivers/mmc/core/* +p;file drivers/mmc/host/* +p" But that might lead to a very large number of messages. > > From: Ulf Hansson > Date: Mon, 24 Feb 2020 11:43:33 +0100 > Subject: [PATCH] mmc: core: Restore busy timeout for eMMC cache flushing > > Signed-off-by: Ulf Hansson > --- > drivers/mmc/core/mmc_ops.c | 2 +- > 1 file changed, 1 insertion(+), 1 deletion(-) > > diff --git a/drivers/mmc/core/mmc_ops.c b/drivers/mmc/core/mmc_ops.c > index da425ee2d9bf..713e7dd6d028 100644 > --- a/drivers/mmc/core/mmc_ops.c > +++ b/drivers/mmc/core/mmc_ops.c > @@ -21,7 +21,7 @@ > > #define MMC_OPS_TIMEOUT_MS (10 * 60 * 1000) /* 10min*/ > #define MMC_BKOPS_TIMEOUT_MS (120 * 1000) /* 120s */ > -#define MMC_CACHE_FLUSH_TIMEOUT_MS (30 * 1000) /* 30s */ > +#define MMC_CACHE_FLUSH_TIMEOUT_MS (10 * 60 * 1000) /* 10min */ > > static const u8 tuning_blk_pattern_4bit[] = { > 0xff, 0x0f, 0xff, 0x00, 0xff, 0xcc, 0xc3, 0xcc, >