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=-0.8 required=3.0 tests=DKIM_SIGNED,DKIM_VALID, HEADER_FROM_DIFFERENT_DOMAINS,MAILING_LIST_MULTI,SPF_HELO_NONE,SPF_PASS, URIBL_BLOCKED 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 9F76EC43331 for ; Tue, 12 Nov 2019 16:26:12 +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 2880421D7F for ; Tue, 12 Nov 2019 16:26:12 +0000 (UTC) Authentication-Results: mail.kernel.org; dkim=pass (1024-bit key) header.d=alsa-project.org header.i=@alsa-project.org header.b="fcMO1Qnu" DMARC-Filter: OpenDMARC Filter v1.3.2 mail.kernel.org 2880421D7F Authentication-Results: mail.kernel.org; dmarc=none (p=none dis=none) header.from=suse.de 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 F27B5820; Tue, 12 Nov 2019 17:25:19 +0100 (CET) DKIM-Filter: OpenDKIM Filter v2.11.0 alsa0.perex.cz F27B5820 DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=alsa-project.org; s=default; t=1573575970; bh=2NVw6DOUWeku0GelH73tW8K+F+lUvwTBkIt+JLYMmyo=; h=Date:From:To:In-Reply-To:References:Cc:Subject:List-Id: List-Unsubscribe:List-Archive:List-Post:List-Help:List-Subscribe: From; b=fcMO1QnueFi3sGiO6eDSfiXyxrwGicYY6wUPAkFjjhyRPfAl/IDE6LwXwpSeNZelr rep7yio5mSVkh223tkGIOTkGeeedVT2q7itTdEDRvnl4KHjCscccpBcHcE3Ahw5vuv r0zTKgUUgG8cXGMzbDQK9fhV9sgMKRuuZG/4CDQY= Received: from alsa1.perex.cz (localhost.localdomain [127.0.0.1]) by alsa1.perex.cz (Postfix) with ESMTP id 89F29F8044C; Tue, 12 Nov 2019 17:25:19 +0100 (CET) Received: by alsa1.perex.cz (Postfix, from userid 50401) id 62A71F80483; Tue, 12 Nov 2019 17:25:17 +0100 (CET) Received: from mx1.suse.de (mx2.suse.de [195.135.220.15]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by alsa1.perex.cz (Postfix) with ESMTPS id C14D0F802E0 for ; Tue, 12 Nov 2019 17:25:14 +0100 (CET) DKIM-Filter: OpenDKIM Filter v2.11.0 alsa1.perex.cz C14D0F802E0 X-Virus-Scanned: by amavisd-new at test-mx.suse.de Received: from relay2.suse.de (unknown [195.135.220.254]) by mx1.suse.de (Postfix) with ESMTP id 4BA0CAC24; Tue, 12 Nov 2019 16:25:13 +0000 (UTC) Date: Tue, 12 Nov 2019 17:25:13 +0100 Message-ID: From: Takashi Iwai To: Henry Lin In-Reply-To: References: <20191112065108.7766-1-henryl@nvidia.com> User-Agent: Wanderlust/2.15.9 (Almost Unreal) SEMI/1.14.6 (Maruoka) FLIM/1.14.9 (=?UTF-8?B?R29qxY0=?=) APEL/10.8 Emacs/25.3 (x86_64-suse-linux-gnu) MULE/6.0 (HANACHIRUSATO) MIME-Version: 1.0 (generated by SEMI 1.14.6 - "Maruoka") Cc: "alsa-devel@alsa-project.org" , Greg Kroah-Hartman , "linux-kernel@vger.kernel.org" , Richard Fontana , Thomas Gleixner , Allison Randal Subject: Re: [alsa-devel] [PATCH] usb-audio: not submit urb for stopped endpoint 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: , Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: 7bit Errors-To: alsa-devel-bounces@alsa-project.org Sender: "Alsa-devel" On Tue, 12 Nov 2019 17:13:37 +0100, Henry Lin wrote: > > >On Tue, 12 Nov 2019 07:51:06 +0100, > >Henry Lin wrote: > >> > >> While output urb's snd_complete_urb() is executing, calling > >> prepare_outbound_urb() may cause endpoint stopped before > >> prepare_outbound_urb() returns and result in next urb submitted > >> to stopped endpoint. usb-audio driver cannot re-use it afterwards as > >> the urb is still hold by usb stack. > >> > >> This change checks EP_FLAG_RUNNING flag after prepare_outbound_urb() again > >> to let snd_complete_urb() know the endpoint already stopped and does not > >> submit next urb. > > >OK, this part looks good and understandable. > > > >> We observed two scenario have this issue: > >> 1. While executing snd_complete_urb() to complete an output urb, calling > >> prepare_outbound_urb() let deactive_urbs() get called to unlink all > >> active urbs. > >> > >> [ 268.097066] [] deactivate_urbs+0xd4/0x108 > >> [ 268.102633] [] snd_usb_endpoint_stop+0x30/0x58 > >> [ 268.108636] [] snd_usb_substream_playback_trigger+0xa4/0xf4 > >> [ 268.115765] [] snd_pcm_do_stop+0x4c/0x58 > >> [ 268.121245] [] snd_pcm_action_single+0x40/0x88 > >> [ 268.127245] [] snd_pcm_action+0x30/0xf0 > >> [ 268.132632] [] snd_pcm_stop+0x24/0x2c > >> [ 268.137851] [] xrun+0x60/0x6c > >> [ 268.142374] [] snd_pcm_update_state+0xa8/0x10c > >> [ 268.148374] [] snd_pcm_update_hw_ptr0+0x328/0x344 > >> [ 268.154635] [] snd_pcm_period_elapsed+0x98/0xb0 > >> [ 268.160723] [] prepare_playback_urb+0x46c/0x488 > >> [ 268.166810] [] prepare_outbound_urb+0x60/0x1d4 > >> [ 268.172805] [] snd_complete_urb+0x244/0x264 > >> [ 268.178548] [] __usb_hcd_giveback_urb+0x94/0x104 > >> [ 268.184721] [] usb_hcd_giveback_urb+0x3c/0x114 > >> [ 268.190724] [] handle_tx_event+0x1304/0x1434 > >> [ 268.196552] [] xhci_handle_event+0x5dc/0x788 > >> [ 268.202378] [] xhci_irq+0x178/0x280 > >> > >> 2. Userspace application stops playback from sound subsystem with below > >> call stack: > >> > >> [ 28.506477] CPU: 5 PID: 1274 Comm: AudioOut_25 Not tainted 4.4.38-tegra #31 > >> [ 28.513430] Hardware name: quill (DT) > >> [ 28.517085] Call trace: > >> [ 28.519531] [] dump_backtrace+0x0/0xf8 > >> [ 28.524837] [] show_stack+0x14/0x1c > >> [ 28.529885] [] dump_stack+0xac/0xe0 > >> [ 28.534931] [] deactivate_urbs+0x148/0x180 > >> [ 28.540578] [] snd_usb_endpoint_stop+0x30/0x58 > >> [ 28.546571] [] snd_usb_substream_playback_trigger+0xa4/0xf4 > >> [ 28.553699] [] snd_pcm_do_stop+0x4c/0x58 > >> [ 28.559179] [] snd_pcm_action_single+0x40/0x88 > >> [ 28.565178] [] snd_pcm_action+0x30/0xf0 > >> [ 28.570568] [] snd_pcm_drop+0xac/0x140 > >> [ 28.575873] [] snd_pcm_release_substream+0x28/0xb0 > >> [ 28.582212] [] snd_pcm_release+0x3c/0x98 > >> [ 28.587686] [] __fput+0xe0/0x1ac > >> [ 28.592469] [] ____fput+0xc/0x14 > >> [ 28.597253] [] task_work_run+0xa0/0xc0 > >> [ 28.602558] [] do_notify_resume+0x48/0x60 > >> [ 28.608123] [] work_pending+0x1c/0x20 > >> > >> In the call path, snd_pcm_stream spinlock has been acquired in > >> snd_pcm_drop(). If an output urb is completed between the spinlock > >> acquired and deactivate_urbs() clears EP_FLAG_RUNNING for the endpoint, > >> its executing of snd_complete_urb() will be blocked for acquiring > >> snd_pcm_stream spinlock in snd_pcm_period_elapsed() until the lock is > >> released in snd_pcm_drop(). When snd_complete_urb() continues, all jobs > >> for deactivate_urbs() are finished. > > >... but this part is unclear to me. Do you mean that we have a > >deadlock in these two concurrent calls without your patch? > Above describes two different cases that endpoint is stopped before prepare_outbound_urb() returns in details. Listed two call stacks belong to different cases. Without this patch, both two cases will result in below error messages afterwards: > > [ 213.153103] usb 1-2: timeout: still 1 active urbs on EP #1 > [ 213.164121] usb 1-2: cannot submit urb 0, error -16: unknown error Ah, I see. Then you don't have to write up the full stack trace like the above. It's confusing as if it were some kernel Oops or WARNING. BTW, with your patch, is the error in the first line ("timeout: still 1 active urbs on EP #1") also fixed? thanks, Takashi _______________________________________________ Alsa-devel mailing list Alsa-devel@alsa-project.org https://mailman.alsa-project.org/mailman/listinfo/alsa-devel