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=-10.7 required=3.0 tests=BAYES_00,DKIM_SIGNED, DKIM_VALID,DKIM_VALID_AU,HEADER_FROM_DIFFERENT_DOMAINS,MAILING_LIST_MULTI, MENTIONS_GIT_HOSTING,SPF_HELO_NONE,SPF_PASS,URIBL_BLOCKED autolearn=ham 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 46FE3C433DB for ; Fri, 25 Dec 2020 01:01:11 +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 785EC22795 for ; Fri, 25 Dec 2020 01:01:09 +0000 (UTC) DMARC-Filter: OpenDMARC Filter v1.3.2 mail.kernel.org 785EC22795 Authentication-Results: mail.kernel.org; dmarc=none (p=none dis=none) header.from=sakamocchi.jp 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 ED52A17E7; Fri, 25 Dec 2020 02:00:16 +0100 (CET) DKIM-Filter: OpenDKIM Filter v2.11.0 alsa0.perex.cz ED52A17E7 DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=alsa-project.org; s=default; t=1608858067; bh=9ok1QqrMTlKhme16WjIhReUtyMscPuYMuK8jZsOIpHE=; h=Date:From:To:Subject:References:In-Reply-To:Cc:List-Id: List-Unsubscribe:List-Archive:List-Post:List-Help:List-Subscribe: From; b=jbMt8H97+x9PI7RkiVLXCtv1sh+bax1EELTUGT0QaIt3FWLFVF4966nYJhpl8ZdEp pfXv2shvr/QHUFzmWq5hqe8wub3E3GhCKA6TuXqtwrWQqGg3GOH79s73kF/yxqk+Ud ItZi+h8KMvw9gxI5gHg6Ppys8EofhiyymPTxBoC4= Received: from alsa1.perex.cz (localhost.localdomain [127.0.0.1]) by alsa1.perex.cz (Postfix) with ESMTP id 41C89F8021D; Fri, 25 Dec 2020 02:00:16 +0100 (CET) Received: by alsa1.perex.cz (Postfix, from userid 50401) id E0205F80224; Fri, 25 Dec 2020 02:00:13 +0100 (CET) Received: from wout2-smtp.messagingengine.com (wout2-smtp.messagingengine.com [64.147.123.25]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by alsa1.perex.cz (Postfix) with ESMTPS id D2960F800BC for ; Fri, 25 Dec 2020 02:00:02 +0100 (CET) DKIM-Filter: OpenDKIM Filter v2.11.0 alsa1.perex.cz D2960F800BC Authentication-Results: alsa1.perex.cz; dkim=pass (2048-bit key) header.d=sakamocchi.jp header.i=@sakamocchi.jp header.b="bAILL6w/"; dkim=pass (2048-bit key) header.d=messagingengine.com header.i=@messagingengine.com header.b="qw/MUtQk" Received: from compute4.internal (compute4.nyi.internal [10.202.2.44]) by mailout.west.internal (Postfix) with ESMTP id C3C1850C; Thu, 24 Dec 2020 19:59:58 -0500 (EST) Received: from mailfrontend1 ([10.202.2.162]) by compute4.internal (MEProxy); Thu, 24 Dec 2020 19:59:59 -0500 DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=sakamocchi.jp; h=date:from:to:cc:subject:message-id:references:mime-version :content-type:in-reply-to; s=fm3; bh=RkwuP0pyzfxjQmEOQiOYmHmA3aO 1RuDV1FqJqVamqyo=; b=bAILL6w/iR6XLBtUkxbcIuVqGxyzSX0MhLNISuFgihF v2e7+M64L/Lz76/r0+At/blio9Q6jm982VtWxUIAQW56z6/aozO8lbDZ4YZSYj9+ RDFNXsVCvoixmvbidYxJB9HjfYhbL1jLLOeSyLN2vqeNCTfskqDHemkvDDf++A6D q03HUeCy+L5Bxn9dtKYPrNOICr0/YGe5uvQLMdIaMtD3bqGSYdy/qtS2rzTbilqh becjXV/GkRp3VgZtH+awX+rbrY9RXjmeGYAFpf8ev74V+3idH+3Px5iBuvCP2rwM OIGdLBkuBzBjDfv3Q2HR3W6fSu4ovLoi68ldUHBsyCg== DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d= messagingengine.com; h=cc:content-type:date:from:in-reply-to :message-id:mime-version:references:subject:to:x-me-proxy :x-me-proxy:x-me-sender:x-me-sender:x-sasl-enc; s=fm1; bh=RkwuP0 pyzfxjQmEOQiOYmHmA3aO1RuDV1FqJqVamqyo=; b=qw/MUtQkP94WX4ZIvzfmyw PYlI4gCsBzIPdxHuCAP407v5lpwJyFFUbzQJWBaz7rJdn2C0gvZ0h81swAlr4q1e eGipvoEUJR3c2SYzg0KJ+eKUcddG4ucyV3j316iSNyaymItLoXPg2b+297mTahg4 h5ScxXI6eGeZLYj5enTLyVRZgyynuFApW8xrX9CcsVn12WmGAiHkIjcAQBHmUGjT M9uG6/jFJVnj8/hK9ucof0vPLjMae8GPokYOCdCG7fublce0w6CivdrWMk6W/nDJ ZHKXUkeSSqqA2yTxRfbAj4c9OpJs526pcuMk0++wtrICfaAg6MmmE86nw3yH6ZsA == X-ME-Sender: X-ME-Proxy-Cause: gggruggvucftvghtrhhoucdtuddrgedujedrvddutddgvdejucetufdoteggodetrfdotf fvucfrrhhofhhilhgvmecuhfgrshhtofgrihhlpdfqfgfvpdfurfetoffkrfgpnffqhgen uceurghilhhouhhtmecufedttdenucesvcftvggtihhpihgvnhhtshculddquddttddmne cujfgurhepfffhvffukfhfgggtuggjsehttdertddttddvnecuhfhrohhmpefvrghkrghs hhhiucfurghkrghmohhtohcuoehoqdhtrghkrghshhhisehsrghkrghmohgttghhihdrjh hpqeenucggtffrrghtthgvrhhnpeegtdefgfehvdefgfehudevhfffleeigfeuiefgkeeg jeekgeeiheehgedutdduvdenucffohhmrghinhepkhgvrhhnvghlrdhorhhgpdgrmhgrii honhgrfihsrdgtohhmpdhgihhthhhusgdrtghomhdpphgrrhhsvgdrphihnecukfhppedu udekrddvgeefrdejkedrheeknecuvehluhhsthgvrhfuihiivgeptdenucfrrghrrghmpe hmrghilhhfrhhomhepohdqthgrkhgrshhhihesshgrkhgrmhhotggthhhirdhjph X-ME-Proxy: Received: from workstation (y078058.dynamic.ppp.asahi-net.or.jp [118.243.78.58]) by mail.messagingengine.com (Postfix) with ESMTPA id 1BD7B24005D; Thu, 24 Dec 2020 19:59:55 -0500 (EST) Date: Fri, 25 Dec 2020 09:59:53 +0900 From: Takashi Sakamoto To: Bert Schiettecatte , Lars-Peter Clausen Subject: Re: question about alsa tracepoints and alsa debugging Message-ID: <20201225005953.GA162573@workstation> Mail-Followup-To: Bert Schiettecatte , Lars-Peter Clausen , alsa-devel@alsa-project.org References: <8fc2a9ae-c87a-03cd-4349-81d0ea3380d3@metafoo.de> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: Cc: alsa-devel@alsa-project.org 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" Hi, > commands used for starting playback / trace capture and for recording - > ./perf record -F 99 -g -e snd_pcm:* -e sched:sched_switch -e > sched:sched_wakeup -e irq:* speaker-test -D > hw:CARD=ak4458ak5558aud,DEV=0 -c8 -r192000 -FS32_LE -tsine & > arecord -Dhw:CARD=ak4458ak5558aud,DEV=1 -fS32_LE -c16 -r192000 > /mnt/ramdisk/rec.wav > > I enabled the kernel options as described at > https://www.kernel.org/doc/html/v5.9/sound/designs/tracepoints.html > and have used perf to record a trace, which can be access here - > https://kernel-debugging.s3-us-west-1.amazonaws.com/perf.data.script.211220202054.txt > (exported using "perf script") > > The trace file shows "lockdep_recursion" at some point so I am > wondering if my problem has to do with a deadlock somehow being > caused. According to the log, speaker-test starts PCM substream for playback direction with below parameters: - bits per sample: 32 bit - samples per frame: 8 - frames per second: 192000 - frames per period: 4096 - frames per buffer: 16384 - ... By calculation with the above parameters, the hardware of I2S interface should be configured to generate harware interrupt every 21.3 msec. I wrote a Python 3 script to check the period of interrupt with a focus on the record including call of 'snd_pcm_period_elapsed' in its backtrace: https://gist.github.com/takaswie/af2b93b58a1154903d6fbe1a6bee3c69 ``` $ ./parse.py /tmp/perf.data.script.211220202054.txt | \ grep -B 3 -A 3 unexpected 73.2000 0.02132900 expected 73.2213 0.02133500 expected 73.2426 0.02135300 expected 110.0207 36.77807000 unexpected 110.0420 0.02133000 expected 110.0634 0.02133400 expected 110.0847 0.02132400 expected ``` I can find around 37 second gap in timestamp 110.0207. It means that the I2S driver failed to control RK3288 I2S interface for periodical hardware interrupt. Furthermore, I can see following records after the gap. It means that speaker-test process successfully detected XRUN of the PCM substream, then recoverd it to continue processing PCM frames for playback expectedly. Thus the I2S driver seems to have few problems about dead-lock issue. With records of tracepoints events for capture PCM substream which Bert's SDIO driver handles as well as for the playback PCM substream which speaker-test starts, we can get more details of runtimes. P.S. diagrams for the case: ``` +-----------+ +----+ +------+ +-------+ |AK5558 x 2 |<-(?)->|FPGA| |RK3288| | AK4458| | (ADC) |<-(?)->| |<-(SDIO)->| |<-(I2S)->| (DAC) | +-----------+ +----+ +------+ +-------+ ``` Regards Takashi Sakamoto