Created attachment 276431 [details]
.config for my current kernel

may be /proc/asound/card0/pcm0p/sub0/prealloc
64
is really too small even for alsa applications now? But apparently I need to stop everything playing sound currently for changing this setting at runtime...

Created attachment 276433 [details]
.asoundrc

I have this asoundrc file in my home, because sometimes I try to record sound from games + screen capture. This config was working fine before.

Created attachment 276435 [details]
output of alsa-info.sh

If it's really a kernel regression, could you figure out which kernel did work properly?  I don't remember of any recent changes relevant with the PCM timing, so I wonder what broke.

(In reply to Takashi Iwai from comment #4)
> If it's really a kernel regression, could you figure out which kernel did
> work properly?  I don't remember of any recent changes relevant with the PCM
> timing, so I wonder what broke.

sorry, I tested older kernels (4.15, 4.12) - and they all have same problem :/ But downgrading alsa-lib from 1.1.6 to 1.0.29 fixed things :/ Will try to bisect alsa-lib ... Oh, alsa-lib git apparently dislike my compiler?! (gcc 4.9.2 and 4.8.5) ? It compiles with clang (llvm 6.0.0) ...

and alsa-lib bisection result was

38a2d2eda880fda9ed5a4a219db498d9c0856d71 is the first bad commit
commit 38a2d2eda880fda9ed5a4a219db498d9c0856d71
Author: Takashi Iwai <tiwai@suse.de>
Date:   Tue Nov 29 14:53:53 2016 +0100

    pcm: dmix: Do not discard slave reported delay in status result

    Like the change done for dshare plugin, we can calculate the delay
    more precisely from the slave PCM.

    Signed-off-by: Takashi Iwai <tiwai@suse.de>

:040000 040000 8895b01bc495684b7c2f27f0d5432879ee172139 ddb81533abefd0cd22ca0fd0f884574a1aed0001 M      src

git bisect log
git bisect start
# bad: [2bacd7042b785e99591671b6464a3c88e4ed5b4b] Release v1.1.5
git bisect bad 2bacd7042b785e99591671b6464a3c88e4ed5b4b
# good: [6a610e56aeef5048136336f7f54db05f061ee4d4] Release v1.1.1
git bisect good 6a610e56aeef5048136336f7f54db05f061ee4d4
# good: [4298736ddad3e61dee2d379c8042f304317a6f3c] ctl: correct documentation about TLV feature
git bisect good 4298736ddad3e61dee2d379c8042f304317a6f3c
# skip: [97be19cf6f44fc5084828114c53281dff6e365b4] pcm: rate: Add capability to pass configuration node to plugins
git bisect skip 97be19cf6f44fc5084828114c53281dff6e365b4
# skip: [3bad0a21b4d13d8d10691f382c836897fa7a7cb9] Drop ppc64-specific workaround for versioned symbols
git bisect skip 3bad0a21b4d13d8d10691f382c836897fa7a7cb9
# good: [a668a94238dc67b19ae187b52a161e027d79ee5d] mixer: Don't install smixer modules unless python is enabled
git bisect good a668a94238dc67b19ae187b52a161e027d79ee5d
# skip: [ad6957c618676d31b65d1aa38f60542795d6406b] plugin:dshare: wrong state reporting
git bisect skip ad6957c618676d31b65d1aa38f60542795d6406b
# skip: [b5a2c06f6c5d69fc71ef648af95a044ee1dc25d0] pcm: Avoid lock for snd_pcm_nonblock()
git bisect skip b5a2c06f6c5d69fc71ef648af95a044ee1dc25d0
# bad: [996dd33b5f0df06d0b1fdd8f43b7a212c26e2a27] conf: HdmiLpeAudio: remove the "front" pcm definition
git bisect bad 996dd33b5f0df06d0b1fdd8f43b7a212c26e2a27
# skip: [d71f294566e53c967a6a1e2d5c684499ec390d69] rawmidi: virtual: fix reading into a small buffer
git bisect skip d71f294566e53c967a6a1e2d5c684499ec390d69
# bad: [d008e1ac203dde67838effe43bd512d38bd92f24] pcm: fix wrong document references to PCM APIs which perform direct memory access with frame copying
git bisect bad d008e1ac203dde67838effe43bd512d38bd92f24
# good: [2ef7a53c31de47f5f33127a89054a661a31bd310] topology: Update physical link configurations in Broadwell text conf file
git bisect good 2ef7a53c31de47f5f33127a89054a661a31bd310
# good: [ea74ebbe4db81aeaedcff11bc5eb6ce139db1118] pcm: Add the PCM state checks to plugins
git bisect good ea74ebbe4db81aeaedcff11bc5eb6ce139db1118
# bad: [14c930d0c96654bd6f5192792380b3e53e523044] ucm: Parse sequence of component devices
git bisect bad 14c930d0c96654bd6f5192792380b3e53e523044
# bad: [38a2d2eda880fda9ed5a4a219db498d9c0856d71] pcm: dmix: Do not discard slave reported delay in status result
git bisect bad 38a2d2eda880fda9ed5a4a219db498d9c0856d71
# first bad commit: [38a2d2eda880fda9ed5a4a219db498d9c0856d71] pcm: dmix: Do not discard slave reported delay in status result

The commit 38a2d2eda880 is known to be broken, but the fix was applied later as commit 3752e6b8733da. So for bisection, you'd need to apply this manually.

And it's so old commit...  It was almost 1.5 years ago.  If it's by that commit, you must have hit this for long time.  Is it the case?

Created attachment 276491 [details]
Test patch

sorry, guess I was running old alsa-lib for too long, so I missed exact moment when it broke.

Unfortunately, test patch doesn't help (applied on top of 1.1.6) here, mplayer still turns into slideshow after like 400 seconds of movie playback (try to run another alsa application at the same time, like, xmms {yes, I know, it is old, but it still plays OK here} ).

Then retry bisection.  At least, the commit 38a2d2eda880 needs the manual patch application from commit 3752e6b8733da.
If this is still broken and the previous commit (ea74ebbe4db81aeaed) works, it's indeed the breakage in delay.

(In reply to Takashi Iwai from comment #10)
> Then retry bisection.  At least, the commit 38a2d2eda880 needs the manual
> patch application from commit 3752e6b8733da.
> If this is still broken and the previous commit (ea74ebbe4db81aeaed) works,
> it's indeed the breakage in delay.

Unfortunately, situation exactly like you described - ea74ebbe4db81aeaedcff11bc5eb6ce139db1118 works (mplayer plays movie while xmms adding music), while next one + 3752e6b8733dae538d777e726c239d4f723070b1 - not (both applications play sound ok, yet mplayer started to skip frames and complain) ...

Hm, then let's try to revert the whole snd_pcm_dmix_status() changes.
Try the patch below instead of the previous test patch.

Created attachment 276495 [details]
Test patch #2

(In reply to Takashi Iwai from comment #13)
> Created attachment 276495 [details]
> Test patch #2

does not compile:

pcm_dmix.c: In function 'snd_pcm_dmix_status':
pcm_dmix.c:493:3: error: too many arguments to function 'snd_pcm_dmix_sync_ptr'
   snd_pcm_dmix_sync_ptr(pcm, status->hw_ptr);
   ^
pcm_dmix.c:434:12: note: declared here
 static int snd_pcm_dmix_sync_ptr(snd_pcm_t *pcm)
            ^
make[2]: *** [pcm_dmix.lo] Ошибка 1
make[2]: *** Ожидание завершения заданий...
make[2]: Выход из каталога `/dev/shm/tmp/alsa-lib-1.1.6/src/pcm'
make[1]: *** [all-recursive] Ошибка 1
make[1]: Выход из каталога `/dev/shm/tmp/alsa-lib-1.1.6/src'
make: *** [all-recursive] Ошибка 1

Created attachment 276497 [details]
Revised test patch #2

(In reply to Takashi Iwai from comment #15)
> Created attachment 276497 [details]
> Revised test patch #2

This one works:

mplayer -ao alsa /home/guest/6029.mp4 -msglevel ao=9
MPlayer SVN-r38109-4.9.2 (C) 2000-2018 MPlayer Team
224 audio & 464 video codecs

Playing /home/guest/6029.mp4.
libavformat version 58.17.100 (internal)
libavformat file format detected.
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x5751e700]Protocol name not provided, cannot determine if input is local or a network protocol, buffers and access patterns cannot be configured optimally without knowing the protocol
[lavf] stream 0: video (h264), -vid 0
[lavf] stream 1: audio (aac), -aid 0, -alang und
VIDEO:  [H264]  720x400  24bpp  25.000 fps  657.6 kbps (80.3 kbyte/s)
==========================================================================
Opening video decoder: [ffmpeg] FFmpeg's libavcodec codec family
libavcodec version 58.19.105 (internal)
Selected video codec: [ffh264] vfm: ffmpeg (FFmpeg H.264)
==========================================================================
Clip info:
 major_brand: mp42
 minor_version: 0
 compatible_brands: mp42isomavc1
 creation_time: 2011-06-24T09:52:37.000000Z
 encoder: HandBrake 0.9.5 2011043000
Load subtitles in /home/guest/
==========================================================================
Forced audio codec: mad
Opening audio decoder: [ffmpeg] FFmpeg/libavcodec audio decoders
AUDIO: 48000 Hz, 2 ch, floatle, 128.0 kbit/4.17% (ratio: 15996->384000)
Selected audio codec: [ffaac] afm: ffmpeg (FFmpeg AAC (MPEG-2/MPEG-4 Audio))
==========================================================================
Trying preferred audio driver 'alsa', options '[none]'
alsa-init: requested format: 48000 Hz, 2 channels, 1d
alsa-init: using ALSA 1.1.6
alsa-init: setup for 1/2 channel(s)
alsa-init: using device default
alsa-init: opening device in blocking mode
alsa-init: device reopened in blocking mode
alsa-init: got buffersize=65536
alsa-init: got period size 1024
alsa: 48000 Hz/2 channels/8 bpf/65536 bytes buffer/Float 32 bit Little Endian
AO: [alsa] 48000Hz 2ch floatle (4 bytes per sample)
Starting playback...
Movie-Aspect is undefined - no prescaling applied.
VO: [vdpau] 720x400 => 720x400 Planar YV12
A:1625.0 V:1625.0 A-V:  0.000 ct:  0.022   0/  0  0%  4%  0.5% 1 0
alsa-uninit: pcm closed

Exiting... (Quit)
---------------

while broken version quickly resulted in:

mplayer -ao alsa /home/guest/6029.mp4 -msglevel ao=9
MPlayer SVN-r38109-4.9.2 (C) 2000-2018 MPlayer Team
224 audio & 464 video codecs

Playing /home/guest/6029.mp4.
libavformat version 58.17.100 (internal)
libavformat file format detected.
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x574dd700]Protocol name not provided, cannot determine if input is local or a network protocol, buffers and access patterns cannot be configured optimally without knowing the protocol
[lavf] stream 0: video (h264), -vid 0
[lavf] stream 1: audio (aac), -aid 0, -alang und
VIDEO:  [H264]  720x400  24bpp  25.000 fps  657.6 kbps (80.3 kbyte/s)
==========================================================================
Opening video decoder: [ffmpeg] FFmpeg's libavcodec codec family
libavcodec version 58.19.105 (internal)
Selected video codec: [ffh264] vfm: ffmpeg (FFmpeg H.264)
==========================================================================
Clip info:
 major_brand: mp42
 minor_version: 0
 compatible_brands: mp42isomavc1
 creation_time: 2011-06-24T09:52:37.000000Z
 encoder: HandBrake 0.9.5 2011043000
Load subtitles in /home/guest/
==========================================================================
Forced audio codec: mad
Opening audio decoder: [ffmpeg] FFmpeg/libavcodec audio decoders
AUDIO: 48000 Hz, 2 ch, floatle, 128.0 kbit/4.17% (ratio: 15996->384000)
Selected audio codec: [ffaac] afm: ffmpeg (FFmpeg AAC (MPEG-2/MPEG-4 Audio))
==========================================================================
Trying preferred audio driver 'alsa', options '[none]'
alsa-init: requested format: 48000 Hz, 2 channels, 1d
alsa-init: using ALSA 1.1.2
alsa-init: setup for 1/2 channel(s)
alsa-init: using device default
alsa-init: opening device in blocking mode
alsa-init: device reopened in blocking mode
alsa-init: got buffersize=65536
alsa-init: got period size 1024
alsa: 48000 Hz/2 channels/8 bpf/65536 bytes buffer/Float 32 bit Little Endian
AO: [alsa] 48000Hz 2ch floatle (4 bytes per sample)
Starting playback...
Movie-Aspect is undefined - no prescaling applied.
VO: [vdpau] 720x400 => 720x400 Planar YV12
A: 430.7 V: 430.2 A-V:  0.495 ct:  0.030   0/  0  0%  5%  0.5% 99 0


           ************************************************
           **** Your system is too SLOW to play this!  ****
           ************************************************

Possible reasons, problems, workarounds:
- Most common: broken/buggy _audio_ driver
  - Try -ao sdl or use the OSS emulation of ALSA.
  - Experiment with different values for -autosync, 30 is a good start.
- Slow video output
  - Try a different -vo driver (-vo help for a list) or try -framedrop!
- Slow CPU
  - Don't try to play a big DVD/DivX on a slow CPU! Try some of the lavdopts,
    e.g. -vfm ffmpeg -lavdopts lowres=1:fast:skiploopfilter=all.
- Broken file
  - Try various combinations of -nobps -ni -forceidx -mc 0.
- Slow media (NFS/SMB mounts, DVD, VCD etc)
  - Try -cache 8192.
- Are you using -cache to play a non-interleaved AVI file?
  - Try -nocache.
Read DOCS/HTML/en/video.html for tuning/speedup tips.
If none of this helps you, read DOCS/HTML/en/bugreports.html.

A: 530.4 V: 500.6 A-V: 29.771 ct:  0.028   0/  0  0%  8%  0.5% 1284 0
alsa-uninit: pcm closed

Exiting... (Quit)
---------------------

Should I ask someone else to test this patch?

OK, now let's reset again back to the original code.

Then try to fix just the following one line?
--- a/src/pcm/pcm_dmix.c
+++ b/src/pcm/pcm_dmix.c
@@ -398,7 +398,7 @@ static int snd_pcm_dmix_sync_ptr0(snd_pcm_t *pcm, snd_pcm_uframes_t slave_hw_ptr
 	snd_pcm_sframes_t diff;
 	
 	old_slave_hw_ptr = dmix->slave_hw_ptr;
-	dmix->slave_hw_ptr = *dmix->spcm->hw.ptr;
+	dmix->slave_hw_ptr = slave_hw_ptr;
 	diff = slave_hw_ptr - old_slave_hw_ptr;
 	if (diff == 0)		/* fast path */
 		return 0;

(In reply to Takashi Iwai from comment #17)
> OK, now let's reset again back to the original code.
> 
> Then try to fix just the following one line?
> --- a/src/pcm/pcm_dmix.c
> +++ b/src/pcm/pcm_dmix.c
> @@ -398,7 +398,7 @@ static int snd_pcm_dmix_sync_ptr0(snd_pcm_t *pcm,
> snd_pcm_uframes_t slave_hw_ptr
>       snd_pcm_sframes_t diff;
>       
>       old_slave_hw_ptr = dmix->slave_hw_ptr;
> -     dmix->slave_hw_ptr = *dmix->spcm->hw.ptr;
> +     dmix->slave_hw_ptr = slave_hw_ptr;
>       diff = slave_hw_ptr - old_slave_hw_ptr;
>       if (diff == 0)          /* fast path */
>               return 0;

this patch also seems to work! (tested for 630 seconds)

Great, so we nailed down.  This was another forgotten replacement in the commit.
I'm going to fix it in alsa-lib git repo.

Thanks for the patient testing!