Re: Trying to debug alsa xruns
On Sun, 2 May 2021 17:09:25 +0200
Michael Lange <klappnase@freenet.de> wrote:
> Hi,
>
> I have been experiencing audio xruns when playing back audio or video
> files for a while now and thought I might try to get some debugging
> information to find out what's wrong (hardware fault? driver bug?
> something else?).
(...)
Ok, I now compiled a vanilla kernel with the suggested debug flags
enabled. As suggested I tried
# echo 29 > /proc/asound/card0/pcm0p/xrun_debug
This gives me a lot of messages like this:
[ 1794.582338] ALSA: PCM: [P] hw_ptr skipping: (pos=13200, delta=2908, period=1024, jdelta=5/15/0, hw_ptr=403508/403508)
[ 1794.582364] ALSA: PCM: [P] hw_ptr skipping: (pos=13200, delta=2908, period=1024, jdelta=0/15/0, hw_ptr=403508/403508)
[ 1794.584655] ALSA: PCM: [Q] hw_ptr skipping: (pos=13312, delta=3020, period=1024, jdelta=1/15/0, hw_ptr=403508/403508)
[ 1794.602498] ALSA: PCM: [P] hw_ptr skipping: (pos=14168, delta=3876, period=1024, jdelta=4/20/0, hw_ptr=403508/403508)
[ 1807.107315] snd_pcm_update_hw_ptr0: 39 callbacks suppressed
[ 1807.107326] ALSA: PCM: [P] hw_ptr skipping: (pos=7168, delta=15364, period=1024, jdelta=0/80/0, hw_ptr=991228/991228)
[ 1812.952627] ALSA: PCM: [P] hw_ptr skipping: (pos=11260, delta=1088, period=1024, jdelta=1/5/0, hw_ptr=1271740/1271740)
After
# echo 3 > /proc/asound/card0/pcm0p/xrun_debug
the messages become a little more verbose:
[ 323.778213] ALSA: PCM: [Q] Lost interrupts?: (stream=0, delta=15364, new_hw_ptr=487424, old_hw_ptr=472060)
[ 323.778232] CPU: 1 PID: 1926 Comm: mpv Tainted: G E 5.12.1-debugalsa #1
[ 323.778243] Hardware name: Gigabyte Technology Co., Ltd. GA-MA78LMT-S2/GA-MA78LMT-S2, BIOS F14 08/16/2011
[ 323.778248] Call Trace:
[ 323.778255] <IRQ>
[ 323.778261] dump_stack+0x76/0x94
[ 323.778283] snd_pcm_update_hw_ptr0.cold.34+0x42/0xf8 [snd_pcm]
[ 323.778328] ? check_preempt_curr+0x3f/0x70
[ 323.778342] snd_pcm_period_elapsed+0x75/0xb0 [snd_pcm]
[ 323.778379] snd_fm801_interrupt+0xac/0x16a [snd_fm801]
[ 323.778393] __handle_irq_event_percpu+0x42/0x160
[ 323.778405] handle_irq_event_percpu+0x30/0x80
[ 323.778414] handle_irq_event+0x3c/0x60
[ 323.778423] handle_fasteoi_irq+0xa3/0x160
[ 323.778431] __common_interrupt+0x41/0xa0
[ 323.778442] common_interrupt+0x7a/0xa0
[ 323.778451] </IRQ>
[ 323.778455] asm_common_interrupt+0x1e/0x40
[ 323.778463] RIP: 0010:snd_pcm_stream_unlock_irq+0x32/0x40 [snd_pcm]
[ 323.778498] Code: 80 b8 71 07 00 00 00 74 0c 48 81 c7 f8 00 00 00 e9 83 b3 21 cd 48 81 c7 f0 00 00 00 c6 07 00 0f 1f 40 00 fb 66 0f 1f 44 00 00 <c3> 66 66 2e 0f 1f 84 00 00 00 00 00 66 90 0f 1f 44 00 00 55 89 f5
[ 323.778505] RSP: 0018:ffffb08801dffe20 EFLAGS: 00000286
[ 323.778514] RAX: ffff9fe687db6800 RBX: ffff9fe6816b0c00 RCX: 0000000000000000
[ 323.778520] RDX: 0000000000000001 RSI: 0000000000000046 RDI: ffff9fe6816b0cf0
[ 323.778525] RBP: 0000000000000000 R08: 0000000000000000 R09: ffff9fe58fbb9908
[ 323.778530] R10: 0000000000000000 R11: 000000010000171c R12: 0000000000000000
[ 323.778534] R13: ffff9fe6816b0c00 R14: ffff9fe58fa63f00 R15: 0000000000000000
[ 323.778545] snd_pcm_hwsync+0x21/0x30 [snd_pcm]
[ 323.778578] snd_pcm_common_ioctl+0x76b/0xe40 [snd_pcm]
[ 323.778615] snd_pcm_ioctl+0x23/0x30 [snd_pcm]
[ 323.778646] __x64_sys_ioctl+0x84/0xc0
[ 323.778656] do_syscall_64+0x33/0x80
[ 323.778665] entry_SYSCALL_64_after_hwframe+0x44/0xae
[ 323.778675] RIP: 0033:0x7f8d5c1f7427
[ 323.778683] Code: 00 00 90 48 8b 05 69 aa 0c 00 64 c7 00 26 00 00 00 48 c7 c0 ff ff ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 b8 10 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 39 aa 0c 00 f7 d8 64 89 01 48
[ 323.778690] RSP: 002b:00007ffe614bda78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[ 323.778698] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f8d5c1f7427
[ 323.778702] RDX: 0000000000000000 RSI: 0000000000004122 RDI: 0000000000000012
[ 323.778707] RBP: 000055e1659a44b0 R08: 000055e1659a4480 R09: 0000000000013812
[ 323.778711] R10: 0000000000013812 R11: 0000000000000246 R12: 000055e165966ec0
[ 323.778716] R13: 000055e1659a42b0 R14: 0000000000000001 R15: 000055e16596a060
Does anyone have a clue what can possibly cause this?
Regards
Michael
.-.. .. ...- . .-.. --- -. --. .- -. -.. .--. .-. --- ... .--. . .-.
Conquest is easy. Control is not.
-- Kirk, "Mirror, Mirror", stardate unknown
Reply to: