From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-2.2 required=3.0 tests=DKIM_SIGNED,DKIM_VALID, HEADER_FROM_DIFFERENT_DOMAINS,MAILING_LIST_MULTI,SPF_HELO_NONE,SPF_PASS, URIBL_BLOCKED,USER_AGENT_SANE_1 autolearn=no autolearn_force=no version=3.4.0 Received: from mail.kernel.org (mail.kernel.org [198.145.29.99]) by smtp.lore.kernel.org (Postfix) with ESMTP id 1B110C47254 for ; Wed, 6 May 2020 02:35:35 +0000 (UTC) Received: from alsa0.perex.cz (alsa0.perex.cz [77.48.224.243]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by mail.kernel.org (Postfix) with ESMTPS id 9525320752 for ; Wed, 6 May 2020 02:35:34 +0000 (UTC) Authentication-Results: mail.kernel.org; dkim=pass (1024-bit key) header.d=alsa-project.org header.i=@alsa-project.org header.b="bPjeuRrZ" DMARC-Filter: OpenDMARC Filter v1.3.2 mail.kernel.org 9525320752 Authentication-Results: mail.kernel.org; dmarc=fail (p=none dis=none) header.from=linux.intel.com Authentication-Results: mail.kernel.org; spf=pass smtp.mailfrom=alsa-devel-bounces@alsa-project.org Received: from alsa1.perex.cz (alsa1.perex.cz [207.180.221.201]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by alsa0.perex.cz (Postfix) with ESMTPS id E4FCE177B; Wed, 6 May 2020 04:34:42 +0200 (CEST) DKIM-Filter: OpenDKIM Filter v2.11.0 alsa0.perex.cz E4FCE177B DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=alsa-project.org; s=default; t=1588732533; bh=+gOO1e9hHO2FP1HrANjKGPZwkNMLWpSS+vx1iL0x/hw=; h=Subject:To:References:From:Date:In-Reply-To:Cc:List-Id: List-Unsubscribe:List-Archive:List-Post:List-Help:List-Subscribe: From; b=bPjeuRrZLJyz6STaVPQhK7Z3bo4VLfpkCvY14VnXa4BXlrZTRrR/MYInPUwGYJK6r EwF/I3uJxmB0UCuOxtTAk8QGGSNbMeuUcH7QDUHvtjZXaaQmTqd8GsGnHm1r6X0417 XbPcl991xVDJ+cDFy9r4cNd1XpiiLPevOguosz+M= Received: from alsa1.perex.cz (localhost.localdomain [127.0.0.1]) by alsa1.perex.cz (Postfix) with ESMTP id 4FB04F80234; Wed, 6 May 2020 04:34:42 +0200 (CEST) Received: by alsa1.perex.cz (Postfix, from userid 50401) id 83C71F80259; Wed, 6 May 2020 04:34:38 +0200 (CEST) Received: from mga02.intel.com (mga02.intel.com [134.134.136.20]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by alsa1.perex.cz (Postfix) with ESMTPS id BF66FF80258 for ; Wed, 6 May 2020 04:34:32 +0200 (CEST) DKIM-Filter: OpenDKIM Filter v2.11.0 alsa1.perex.cz BF66FF80258 IronPort-SDR: 6kfMk5HotNtsIhJXEZ8cBrCYO6mFBaeCsQ+bz+aT6i7H4LJJRRQEaAZdV2fA9BMKSM8+1WNh2b 2tYMPM6diGTA== X-Amp-Result: SKIPPED(no attachment in message) X-Amp-File-Uploaded: False Received: from orsmga001.jf.intel.com ([10.7.209.18]) by orsmga101.jf.intel.com with ESMTP/TLS/ECDHE-RSA-AES256-GCM-SHA384; 05 May 2020 19:34:28 -0700 IronPort-SDR: zyDBtX2S7VPVpvrTqzdmbBJHTOdw/2LBbG6F2vT1/GmoNDTnEYfNNw4D+Q2se78qNDxVnJn81L +Sjg6JTn6qMQ== X-ExtLoop1: 1 X-IronPort-AV: E=Sophos;i="5.73,357,1583222400"; d="scan'208";a="338853107" Received: from nxiao-mobl.ccr.corp.intel.com (HELO [10.254.215.171]) ([10.254.215.171]) by orsmga001.jf.intel.com with ESMTP; 05 May 2020 19:34:24 -0700 Subject: Re: [PATCH] ASoC: Intel: sst: ipc command timeout To: "Lu, Brent" , "Rojewski, Cezary" , Pierre-Louis Bossart , "alsa-devel@alsa-project.org" References: <1586506705-3194-1-git-send-email-brent.lu@intel.com> <4f495cf1-4740-cf3b-196f-cc850c503b43@linux.intel.com> From: Keyon Jie Message-ID: <4623d6b9-8dc6-b301-c8ff-74dfb6baf2a3@linux.intel.com> Date: Wed, 6 May 2020 10:35:10 +0800 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:68.0) Gecko/20100101 Thunderbird/68.7.0 MIME-Version: 1.0 In-Reply-To: Content-Type: text/plain; charset=utf-8; format=flowed Content-Language: en-US Content-Transfer-Encoding: 7bit Cc: Kate Stewart , Richard Fontana , Greg Kroah-Hartman , Takashi Iwai , "linux-kernel@vger.kernel.org" , Liam Girdwood , "clang-built-linux@googlegroups.com" , Mark Brown , "amadeuszx.slawinski@linux.intel.com" , Thomas Gleixner , Allison Randal X-BeenThere: alsa-devel@alsa-project.org X-Mailman-Version: 2.1.15 Precedence: list List-Id: "Alsa-devel mailing list for ALSA developers - http://www.alsa-project.org" List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: alsa-devel-bounces@alsa-project.org Sender: "Alsa-devel" On 4/22/20 12:16 AM, Lu, Brent wrote: >> >> Regs width difference between BDW and BYT comes from specification. BDW >> has IPC registers which are 32 wide. This fact ain't exactly the reason to modify >> sst_shim32_read64. >> >> I'm sharing Amadeo's point of view. Your change should slow down execution a >> bit - but that might be just what handlers needed to make everything work again. >> Debug prints also slow down the execution what could have prevented you from >> spotting the real problem. >> Let's ignore the memcpy stuff for a moment - could you focus on elaborating >> the scenario where such issue occurs? Your initial commit message also skips >> important bits such as platform used when reproducing and so on, please add >> them. >> >> Thanks, >> Czarek > > This issue is reported to happen on BYT Chrome book (rambi) on Chrome-v4.4 > branch after changing toolchain from clang10 to clang11. > > The reproduce step is simple. Just run arecord multiple times (<10) then you will > see error message for hw_params ioctl failure. > > $ arecord -D hw:1,0 -f S16_LE -c 2 /dev/null > $ ctrl+c > > The error message suggests the stream commit (IPC_IA_ALLOC_STREAM, 0x20) IPC > command failed due to timeout but the msg id field of ipcd read after the timeout is > also 0x20. It seems to me that the command is success but the host driver does not > know it for some reason. > > 2020-03-15T23:02:06.614151+00:00 ERR kernel: [ 852.023766] baytrail-pcm-audio baytrail-pcm-audio: ipc: --message timeout-- ipcx 0x2220 isr 0xf0020 ipcd 0x2220 imrx 0x0 > 2020-03-15T23:02:06.614209+00:00 ERR kernel: [ 852.023796] baytrail-pcm-audio baytrail-pcm-audio: ipc: error stream commit failed > 2020-03-15T23:02:06.614218+00:00 ERR kernel: [ 852.023813] Baytrail Audio: PCM: failed stream commit -110 > 2020-03-15T23:02:06.614225+00:00 ERR kernel: [ 852.023832] baytrail-pcm-audio baytrail-pcm-audio: ASoC: baytrail-pcm-audio hw params failed: -110 > > I add some messages to make the log easier to read. You can check the gerrit link if you > are interested: > https://chromium-review.googlesource.com/c/chromiumos/third_party/kernel/+/2131507 > > In the test patch I read the SST_IPCD register in sst_byt_irq_thread() twice and found > the value could be different. The IPC_IA_FREE_STREAM(0x21) seems to be the last IPC > command sent in the pcm_release of previous arecord command. > > [ 125.009724] sound pcmC1D0c: snd_pcm_release: > [ 125.009732] baytrail-pcm-audio baytrail-pcm-audio: ipc_tx_message: header 0x8000000000000221 wait 1 > [ 125.009760] baytrail-pcm-audio baytrail-pcm-audio: byt_tx_msg: header 0x8000000000000226 > [ 125.009803] baytrail-pcm-audio baytrail-pcm-audio: sst_byt_irq_thread: header 0x297 > [ 125.009823] baytrail-pcm-audio baytrail-pcm-audio: byt_tx_msg: header 0x8000000000000221 > [ 125.009872] baytrail-pcm-audio baytrail-pcm-audio: sst_byt_irq_thread: header 0x297 > [ 125.010442] baytrail-pcm-audio baytrail-pcm-audio: sst_byt_irq_thread: header 0x80000000000c2226 > [ 125.010456] baytrail-pcm-audio baytrail-pcm-audio: sst_ipc_reply_find_msg: not match, msg header 0x8000000000000221 > [ 125.010511] baytrail-pcm-audio baytrail-pcm-audio: sst_byt_irq_thread: header 0x8000000000000221 > [ 125.011355] baytrail-pcm-audio baytrail-pcm-audio: tx_wait_done: ipc success, header 0x8000000000000221 > [ 125.380506] sound pcmC1D0c: snd_pcm_capture_open: > [ 125.380544] sound pcmC1D0c: snd_pcm_capture_ioctl1: INFO > [ 125.380554] sound pcmC1D0c: snd_pcm_capture_ioctl1: PVERSION > [ 125.380561] sound pcmC1D0c: snd_pcm_capture_ioctl1: TTSTAMP > [ 125.380581] sound pcmC1D0c: snd_pcm_mmap: > [ 125.380622] sound pcmC1D0c: snd_pcm_mmap: > [ 125.380648] sound pcmC1D0c: snd_pcm_capture_ioctl1: INFO > [ 125.380717] sound pcmC1D0c: snd_pcm_capture_ioctl1: HW_REFINE > [ 125.380737] sound pcmC1D0c: snd_pcm_capture_ioctl1: HW_REFINE > [ 125.380766] sound pcmC1D0c: snd_pcm_capture_ioctl1: HW_REFINE > [ 125.380779] sound pcmC1D0c: snd_pcm_capture_ioctl1: HW_REFINE > [ 125.380789] sound pcmC1D0c: snd_pcm_capture_ioctl1: HW_REFINE > [ 125.380799] sound pcmC1D0c: snd_pcm_capture_ioctl1: HW_REFINE > [ 125.380808] sound pcmC1D0c: snd_pcm_capture_ioctl1: HW_REFINE > [ 125.380815] sound pcmC1D0c: snd_pcm_capture_ioctl1: HW_PARAMS > [ 125.380839] baytrail-pcm-audio baytrail-pcm-audio: ipc_tx_message: header 0x8000000000642220 wait 1 > [ 125.380854] baytrail-pcm-audio baytrail-pcm-audio: byt_tx_msg: header 0x8000000000642220 > => write IPC_IA_ALLOC_STREAM message (0x20) to SST_IPCX > [ 125.380931] baytrail-pcm-audio baytrail-pcm-audio: sst_byt_irq_thread: header 0x8000000000000221 > => read message reply from SST_IPCD and an IPC_IA_FREE_STREAM(0x21) is returned > [ 125.380942] baytrail-pcm-audio baytrail-pcm-audio: sst_byt_irq_thread: ipcd 0x8000000000602220 > => read SST_IPCD again, this time the message id is what we are expected (0x20) Looks there is race between the previous stream stop and the current stream start here. Can you help try changing the sst_byt_stream_start/stop() from 'nowait' mode to 'wait' mode, and see if the issue can be reproduced with it? Thanks, ~Keyon > [ 125.380948] baytrail-pcm-audio baytrail-pcm-audio: sst_ipc_reply_find_msg: not match, msg header 0x8000000000642220 > [ 125.681171] baytrail-pcm-audio baytrail-pcm-audio: tx_wait_done: ipc timeout, header 0x8000000000642220 > [ 125.681204] baytrail-pcm-audio baytrail-pcm-audio: ipc: --message timeout-- ipcx 0x2220 isr 0x50020 ipcd 0x2220 imrx 0x0 > [ 125.681212] baytrail-pcm-audio baytrail-pcm-audio: ipc: error stream commit failed > [ 125.681217] Baytrail Audio: PCM: failed stream commit -110 > [ 125.681223] baytrail-pcm-audio baytrail-pcm-audio: ASoC: baytrail-pcm-audio hw params failed: -110 > > Regards, > Brent >