hw_ptr accuracy with intel8x0 -> PulseAudio issue

hw_ptr accuracy with intel8x0 -> PulseAudio issue

[pl bossart]

Hi,
I have been having issues for a while now with PulseAudio running on
an older Thinkpad X41. PulseAudio relies on snd_pcm_avail() to detect
underflows and increases the timer watermark when they happen. There
are actually no audible underflows though...
So I instrumented both PulseAudio (enabling DEBUG_TIMING in the
alsa-sink.c code) and the kernel (latest alsa-kernel git) by adding
the following printk  in pcm.h:

static inline snd_pcm_uframes_t snd_pcm_playback_avail(struct
snd_pcm_runtime *runtime)
{
	snd_pcm_sframes_t avail = runtime->status->hw_ptr +
runtime->buffer_size - runtime->control->appl_ptr;
	if (avail < 0)
		avail += runtime->boundary;
	else if ((snd_pcm_uframes_t) avail >= runtime->boundary)
		avail -= runtime->boundary;
        //plb
        if(avail > runtime->buffer_size) {
            snd_printk(KERN_ERR "avail %d hw_ptr %d buffer %d appl_ptr %d \n",
                       avail, runtime->status->hw_ptr,
runtime->buffer_size, runtime->control->appl_ptr);
        }
	return avail;
}

In my tests this error condition where avail is larger than the ring
buffer happens fairly often. The dmesg log show messages such as
[  834.524479] ALSA include/sound/pcm.h:600: avail 16403 hw_ptr 24351
buffer 16384 appl_ptr 24332
[  835.266937] ALSA include/sound/pcm.h:600: avail 16407 hw_ptr 55841
buffer 16384 appl_ptr 55818
and these messages are correlated with the times when PulseAudio
detects underflows.
The full log can be found at http://pastebin.com/f210aa108.

I believe the issue is the accuracy of the hw_ptr reported by
snd_intel8x0_pcm_pointer. If indeed such a condition occurred, it
should be flagged as underflow, shouldn't it? There's been some
changes in this part of the code to avoid extremely large values, here
the issue seems more subtle, the pointer is only slightly off in most
cases. This does screw-up PulseAudio though, the timer watermark keeps
increasing and low-latency isn't possible.

I'd be more than happy to run more experiments, however I have no idea
what the hardware does to report the position of the hw pointer.
Thanks for your feedback
- Pierre

Re: hw_ptr accuracy with intel8x0 -> PulseAudio issue

[Raymond Yau]

2009/12/2 pl bossart <bossart.nospam@gmail.com>

> Hi,
> I have been having issues for a while now with PulseAudio running on
> an older Thinkpad X41. PulseAudio relies on snd_pcm_avail() to detect
> underflows and increases the timer watermark when they happen. There
> are actually no audible underflows though...
> So I instrumented both PulseAudio (enabling DEBUG_TIMING in the
> alsa-sink.c code) and the kernel (latest alsa-kernel git) by adding
> the following printk  in pcm.h:
>
> static inline snd_pcm_uframes_t snd_pcm_playback_avail(struct
> snd_pcm_runtime *runtime)
> {
>        snd_pcm_sframes_t avail = runtime->status->hw_ptr +
> runtime->buffer_size - runtime->control->appl_ptr;
>        if (avail < 0)
>                avail += runtime->boundary;
>        else if ((snd_pcm_uframes_t) avail >= runtime->boundary)
>                avail -= runtime->boundary;
>        //plb
>        if(avail > runtime->buffer_size) {
>            snd_printk(KERN_ERR "avail %d hw_ptr %d buffer %d appl_ptr %d
> \n",
>                       avail, runtime->status->hw_ptr,
> runtime->buffer_size, runtime->control->appl_ptr);
>        }
>        return avail;
> }
>
> In my tests this error condition where avail is larger than the ring
> buffer happens fairly often. The dmesg log show messages such as
> [  834.524479] ALSA include/sound/pcm.h:600: avail 16403 hw_ptr 24351
> buffer 16384 appl_ptr 24332
> [  835.266937] ALSA include/sound/pcm.h:600: avail 16407 hw_ptr 55841
> buffer 16384 appl_ptr 55818
> and these messages are correlated with the times when PulseAudio
> detects underflows.
> The full log can be found at http://pastebin.com/f210aa108.
>
> I believe the issue is the accuracy of the hw_ptr reported by
> snd_intel8x0_pcm_pointer. If indeed such a condition occurred, it
> should be flagged as underflow, shouldn't it? There's been some
> changes in this part of the code to avoid extremely large values, here
> the issue seems more subtle, the pointer is only slightly off in most
> cases. This does screw-up PulseAudio though, the timer watermark keeps
> increasing and low-latency isn't possible.
>
> I'd be more than happy to run more experiments, however I have no idea
> what the hardware does to report the position of the hw pointer.
> Thanks for your feedback
> - Pierre
>
>

I: main.c: This is PulseAudio 0.9.21-296-gd2ab2


   1. D: alsa-util.c: Trying front:0 with SND_PCM_NO_AUTO_FORMAT ...
   2. D: alsa-util.c: Managed to open front:0
   3. D: alsa-util.c: Maximum hw buffer size is 371 ms
   4. D: alsa-util.c: Set buffer size first (to 4408 samples), period size
   second (to 1102 samples)

What is the purpose of these buffer-size and period size during the probing
phase  ?
The PA server seem use different values



   1. I: sink.c: Created sink 0 "alsa_output.pci-0000_00_1e.2.analog-stereo"
   with sample spec s16le 2ch 44100Hz and channel map front-left,front-right
   2. I: sink.c:     alsa.resolution_bits = "16"
   3. I: sink.c:     device.api = "alsa"
   4. I: sink.c:     device.class = "sound"
   5. I: sink.c:     alsa.class = "generic"
   6. I: sink.c:     alsa.subclass = "generic-mix"
   7. I: sink.c:     alsa.name = "Intel ICH6"
   8. I: sink.c:     alsa.id = "Intel ICH"
   9. I: sink.c:     alsa.subdevice = "0"
   10. I: sink.c:     alsa.subdevice_name = "subdevice #0"
   11. I: sink.c:     alsa.device = "0"
   12. I: sink.c:     alsa.card = "0"
   13. I: sink.c:     alsa.card_name = "Intel ICH6"
   14. I: sink.c:     alsa.long_card_name = "Intel ICH6 with AD1981B at irq
   22"
   15. I: sink.c:     alsa.driver_name = "snd_intel8x0"
   16. I: sink.c:     device.bus_path = "pci-0000:00:1e.2"
   17. I: sink.c:     sysfs.path =
   "/devices/pci0000:00/0000:00:1e.2/sound/card0"
   18. I: sink.c:     device.bus = "pci"
   19. I: sink.c:     device.vendor.id = "8086"
   20. I: sink.c:     device.vendor.name = "Intel Corporation"
   21. I: sink.c:     device.product.id = "266e"
   22. I: sink.c:     device.product.name = "82801FB/FBM/FR/FW/FRW (ICH6
   Family) AC'97 Audio Controller"
   23. I: sink.c:     device.form_factor = "internal"
   24. I: sink.c:     hal.udi =
   "/org/freedesktop/Hal/devices/pci_8086_266e_sound_card_0"
   25. I: sink.c:     hal.product = "Intel ICH6 with AD1981B Sound Card"
   26. I: sink.c:     hal.card_id = "Intel ICH6 with AD1981B"
   27. I: sink.c:     device.string = "front:0"
   28. I: sink.c:     device.buffering.buffer_size = "65536"
   29. I: sink.c:     device.buffering.fragment_size = "65536"
   30. I: sink.c:     device.access_mode = "mmap+timer"
   31. I: sink.c:     device.profile.name = "analog-stereo"
   32. I: sink.c:     device.profile.description = "Analog Stereo"
   33. I: sink.c:     device.description = "Internal Audio Analog Stereo"
   34. I: sink.c:     alsa.mixer_name = "Analog Devices AD1981B"
   35. I: sink.c:     alsa.components = "AC97a:41445374"
   36. I: sink.c:     module-udev-detect.discovered = "1"
   37. I: sink.c:     device.icon_name = "audio-card-pci"


intel8x0 does not has hdmi , it seem PA hardcode hdmi for all sound cards
instead of using namehint for playback device

   1. D: alsa-mixer.c: Looking at profile output:hdmi-stereo
   2. D: alsa-mixer.c: Checking for playback on Digital Stereo (HDMI)
   (hdmi-stereo)
   3. D: alsa-util.c: Trying hdmi:0 with SND_PCM_NO_AUTO_FORMAT ...
   4. I: (alsa-lib)conf.c: Unknown parameters 0
   5. I: (alsa-lib)pcm.c: Unknown PCM hdmi:0
   6. I: alsa-util.c: Error opening PCM device hdmi:0: Invalid argument

Is it possible to add timestamp in alsa-sink.c: Wrote 31792 bytes (of
possible 31792 bytes) statement for debugging


   1. D: alsa-sink.c: Loop
   2. D: alsa-sink.c: Buffer time: 371 ms; Sleep time: 351 ms; Process time:
   20 ms
   3. hwptr 7948 buffer 16384 appl 16384, avail=7948
   4. D: alsa-sink.c: avail: 31792 (samples 7948)
   5. D: alsa-sink.c: 191.29 ms left to play; inc threshold = 0.00 ms; dec
   threshold = 100.00 ms
   6. D: alsa-sink.c: Filling up
   7. hwptr 7948 buffer 16384 appl 16384, avail=7948
   8. hwptr 7948 buffer 16384 appl 16384, avail=7948
   9. D: alsa-sink.c: Wrote 31792 bytes (of possible 31792 bytes)
   10. hwptr 7960 buffer 16384 appl 24332, avail=12
   11. D: alsa-sink.c: avail: 48 (samples 12)
   12. D: alsa-sink.c: 371.25 ms left to play; inc threshold = 0.00 ms; dec
   threshold = 100.00 ms
   13. D: alsa-sink.c: Not filling up, because too early.
   14. D: alsa-sink.c: Wakeup from ALSA!
   15. D: alsa-sink.c: Loop
   16. D: alsa-sink.c: Buffer time: 371 ms; Sleep time: 351 ms; Process
   time: 20 ms
   17. hwptr 24351 buffer 16384 appl 24332, avail=16403
   18. E: alsa-util.c: avail 16403 delay -19
   19. D: alsa-sink.c: avail: 65536 (samples 16384)
   20. D: alsa-sink.c: 0.00 ms left to play; inc threshold = 0.00 ms; dec
   threshold = 100.00 ms
   21. D: alsa-sink.c: Filling up

Re: hw_ptr accuracy with intel8x0 -> PulseAudio issue

[Raymond Yau]

2009/12/4 pl bossart <bossart.nospam@gmail.com>

> Hi Raymond,
> comments below.
> - PL
>
> On Wed, Dec 2, 2009 at 8:26 PM, Raymond Yau <superquad.vortex2@gmail.com>
> wrote:
> >   1. D: alsa-util.c: Trying front:0 with SND_PCM_NO_AUTO_FORMAT ...
> >   2. D: alsa-util.c: Managed to open front:0
> >   3. D: alsa-util.c: Maximum hw buffer size is 371 ms
> >   4. D: alsa-util.c: Set buffer size first (to 4408 samples), period size
> >   second (to 1102 samples)
> >
> > What is the purpose of these buffer-size and period size during the
> probing
> > phase  ?
> > The PA server seem use different values
>
> This is a red herring, PulseAudio tries to open multiple profiles and
> finds out which ones make sense. You want to look at the result below
> which is the final configuration.
>
> >   1. I: sink.c: Created sink 0
> "alsa_output.pci-0000_00_1e.2.analog-stereo"
> >   with sample spec s16le 2ch 44100Hz and channel map
> front-left,front-right
> >   2. I: sink.c:     alsa.resolution_bits = "16"
> >   3. I: sink.c:     device.api = "alsa"
> >   4. I: sink.c:     device.class = "sound"
> >   5. I: sink.c:     alsa.class = "generic"
> >   6. I: sink.c:     alsa.subclass = "generic-mix"
> >   7. I: sink.c:     alsa.name = "Intel ICH6"
> >   8. I: sink.c:     alsa.id = "Intel ICH"
> >   9. I: sink.c:     alsa.subdevice = "0"
> >   10. I: sink.c:     alsa.subdevice_name = "subdevice #0"
> >   11. I: sink.c:     alsa.device = "0"
> >   12. I: sink.c:     alsa.card = "0"
> >   13. I: sink.c:     alsa.card_name = "Intel ICH6"
> >   14. I: sink.c:     alsa.long_card_name = "Intel ICH6 with AD1981B at
> irq
> >   22"
> >   15. I: sink.c:     alsa.driver_name = "snd_intel8x0"
> >   16. I: sink.c:     device.bus_path = "pci-0000:00:1e.2"
> >   17. I: sink.c:     sysfs.path =
> >   "/devices/pci0000:00/0000:00:1e.2/sound/card0"
> >   18. I: sink.c:     device.bus = "pci"
> >   19. I: sink.c:     device.vendor.id = "8086"
> >   20. I: sink.c:     device.vendor.name = "Intel Corporation"
> >   21. I: sink.c:     device.product.id = "266e"
> >   22. I: sink.c:     device.product.name = "82801FB/FBM/FR/FW/FRW (ICH6
> >   Family) AC'97 Audio Controller"
> >   23. I: sink.c:     device.form_factor = "internal"
> >   24. I: sink.c:     hal.udi =
> >   "/org/freedesktop/Hal/devices/pci_8086_266e_sound_card_0"
> >   25. I: sink.c:     hal.product = "Intel ICH6 with AD1981B Sound Card"
> >   26. I: sink.c:     hal.card_id = "Intel ICH6 with AD1981B"
> >   27. I: sink.c:     device.string = "front:0"
> >   28. I: sink.c:     device.buffering.buffer_size = "65536"
> >   29. I: sink.c:     device.buffering.fragment_size = "65536"
> >   30. I: sink.c:     device.access_mode = "mmap+timer"
> >   31. I: sink.c:     device.profile.name = "analog-stereo"
> >   32. I: sink.c:     device.profile.description = "Analog Stereo"
> >   33. I: sink.c:     device.description = "Internal Audio Analog Stereo"
> >   34. I: sink.c:     alsa.mixer_name = "Analog Devices AD1981B"
> >   35. I: sink.c:     alsa.components = "AC97a:41445374"
> >   36. I: sink.c:     module-udev-detect.discovered = "1"
> >   37. I: sink.c:     device.icon_name = "audio-card-pci"
>
> > intel8x0 does not has hdmi , it seem PA hardcode hdmi for all sound cards
> > instead of using namehint for playback device
>
> Yes, PA will try all possible profiles. Not that smart but unrelated
> to my problem.
>
>
> > Is it possible to add timestamp in alsa-sink.c: Wrote 31792 bytes (of
> > possible 31792 bytes) statement for debugging
>
> Not sure why this is needed. In that case the driver reports 7948
> frames are available, which translates to 31792 bytes.
> The problem shows in the next call to snd_pcm_avail down to the kernel
> level, PA only uses the misleading information reported by the driver.
>


>   17. hwptr 24351 buffer 16384 appl 24332, avail=16403

appl pointer is behind hwprtr (  underrun ) , need timestamp to find out
whether PA is unable to write audio data in time since

>   13. D: alsa-sink.c: Not filling up, because too early.
>  14. D: alsa-sink.c: Wakeup from ALSA!
>   15. D: alsa-sink.c: Loop
>   16. D: alsa-sink.c: Buffer time: 371 ms; Sleep time: 351 ms; Process
>   time: 20 ms

did it adjust the sleeping time when it think too early ?


>
> >   1. D: alsa-sink.c: Loop
> >   2. D: alsa-sink.c: Buffer time: 371 ms; Sleep time: 351 ms; Process
> time:
> >   20 ms
> >   3. hwptr 7948 buffer 16384 appl 16384, avail=7948
> >   4. D: alsa-sink.c: avail: 31792 (samples 7948)
> >   5. D: alsa-sink.c: 191.29 ms left to play; inc threshold = 0.00 ms; dec
> >   threshold = 100.00 ms
> >   6. D: alsa-sink.c: Filling up
> >   7. hwptr 7948 buffer 16384 appl 16384, avail=7948
> >   8. hwptr 7948 buffer 16384 appl 16384, avail=7948
> >   9. D: alsa-sink.c: Wrote 31792 bytes (of possible 31792 bytes)
> >   10. hwptr 7960 buffer 16384 appl 24332, avail=12
> >   11. D: alsa-sink.c: avail: 48 (samples 12)
> >   12. D: alsa-sink.c: 371.25 ms left to play; inc threshold = 0.00 ms;
> dec
> >   threshold = 100.00 ms
> >   13. D: alsa-sink.c: Not filling up, because too early.
> >   14. D: alsa-sink.c: Wakeup from ALSA!
> >   15. D: alsa-sink.c: Loop
> >   16. D: alsa-sink.c: Buffer time: 371 ms; Sleep time: 351 ms; Process
> >   time: 20 ms
> >   17. hwptr 24351 buffer 16384 appl 24332, avail=16403
> >   18. E: alsa-util.c: avail 16403 delay -19
> >   19. D: alsa-sink.c: avail: 65536 (samples 16384)
> >   20. D: alsa-sink.c: 0.00 ms left to play; inc threshold = 0.00 ms; dec
> >   threshold = 100.00 ms
> >   21. D: alsa-sink.c: Filling up
>

Re: hw_ptr accuracy with intel8x0 -> PulseAudio issue

[pl bossart]

>>   17. hwptr 24351 buffer 16384 appl 24332, avail=16403
>
> appl pointer is behind hwprtr (  underrun ) , need timestamp to find out
> whether PA is unable to write audio data in time since

Nah, it's not an audio underflow. In the default PulseAudio code, the
timer value is increased by 20ms each time this errror condition is
reached. PA ends-up waking-up 150ms or so before the deadline and yet
it still encounters this error. I don't think it's a problem with PA
not refilling the buffer on time, it's more that the information
provided by snd_pcm_avail() is misleading. I commented out the portion
of the code that increases the watermark and clamped the number of
available samples to the buffer size, and it works just fine, no audio
underflows.
- P

Re: hw_ptr accuracy with intel8x0 -> PulseAudio issue

[Raymond Yau]

2009/12/4 pl bossart <bossart.nospam@gmail.com>

> >>   17. hwptr 24351 buffer 16384 appl 24332, avail=16403
> >
> > appl pointer is behind hwprtr (  underrun ) , need timestamp to find out
> > whether PA is unable to write audio data in time since
>
> Nah, it's not an audio underflow. In the default PulseAudio code, the
> timer value is increased by 20ms each time this errror condition is
> reached. PA ends-up waking-up 150ms or so before the deadline and yet
> it still encounters this error. I don't think it's a problem with PA
> not refilling the buffer on time, it's more that the information
> provided by snd_pcm_avail() is misleading. I commented out the portion
> of the code that increases the watermark and clamped the number of
> available samples to the buffer size, and it works just fine, no audio
> underflows.
> - P
>


Since PA use one period per buffer for intel8x0 ( the hwptr is already at
the outside of the buffer )

It is hard to debug without timestamp since it is not easy to know the value
of sleeping time

Can you explain what is "hwbuf_unused" ?



   1. I: alsa-sink.c: Using 1.0 fragments of size 65536 bytes (371.52ms),
   buffer size is 65536 bytes (371.52ms)
   2. I: alsa-sink.c: Time scheduling watermark is 20.00ms
   3. D: alsa-sink.c: hwbuf_unused=0
   4. D: alsa-sink.c: Buffer time: 371 ms; Sleep time: 351 ms; Process time:
   20 ms
   5. D: alsa-sink.c: setting avail_min=15502
   6. D: alsa-mixer.c: Activating path analog-output
   7. D: alsa-mixer.c: Path analog-output (Analog Output), direction=1,
   priority=99, probed=yes, supported=yes, has_mute=yes, has_volume=yes,
   has_dB=yes, min_volume=0, max_volume=31, min_dB=-81, max_dB=12
   8. D: alsa-mixer.c: Element Master, direction=1, switch=1, volume=1,
   enumeration=0, required=0, required_absent=0, mask=0x3600000000f66,
   n_channels=2, override_map=yes
   9. D: alsa-mixer.c: Element Master Mono, direction=1, switch=2, volume=2,
   enumeration=0, required=0, required_absent=0, mask=0x7ffffffffffff,
   n_channels=1, override_map=no
   10. D: alsa-mixer.c: Element Headphone, direction=1, switch=1, volume=3,
   enumeration=0, required=0, required_absent=0, mask=0x6, n_channels=2,
   override_map=no
   11. D: alsa-mixer.c: Element PCM, direction=1, switch=1, volume=1,
   enumeration=0, required=0, required_absent=0, mask=0x402b600000000f66,
   n_channels=2, override_map=yes
   12. D: alsa-mixer.c: Element External Amplifier, direction=1, switch=4,
   volume=0, enumeration=0, required=0, required_absent=0, mask=0x0,
   n_channels=0, override_map=no
   13. D: alsa-mixer.c: Option on (output-amplifier-on/Amplifier) index=1,
   priority=10
   14. D: alsa-mixer.c: Option off (output-amplifier-off/No Amplifier)
   index=0, priority=0
   15. D: alsa-mixer.c: Setting output-amplifier-on (Amplifier) priority=10
   16. D: alsa-mixer.c: Setting output-amplifier-off (No Amplifier)
   priority=0
   17. I: alsa-sink.c: Hardware volume ranges from -81.00 dB to 12.00 dB.
   18. I: alsa-sink.c: Fixing base volume to -12.00 dB
   19. I: alsa-sink.c: Using hardware volume control. Hardware dB scale
   supported.
   20. I: alsa-sink.c: Using hardware mute control.
   21. D: alsa-util.c: snd_pcm_dump():
   22. D: alsa-util.c: Hardware PCM card 0 'Intel ICH6' device 0 subdevice 0
   23. D: alsa-util.c: Its setup is:
   24. D: alsa-util.c:   stream       : PLAYBACK
   25. D: alsa-util.c:   access       : MMAP_INTERLEAVED
   26. D: alsa-util.c:   format       : S16_LE
   27. D: alsa-util.c:   subformat    : STD
   28. D: alsa-util.c:   channels     : 2
   29. D: alsa-util.c:   rate         : 44100
   30. D: alsa-util.c:   exact rate   : 44100 (44100/1)
   31. D: alsa-util.c:   msbits       : 16
   32. D: alsa-util.c:   buffer_size  : 16384
   33. D: alsa-util.c:   period_size  : 16384
   34. D: alsa-util.c:   period_time  : 371519
   35. D: alsa-util.c:   tstamp_mode  : ENABLE
   36. D: alsa-util.c:   period_step  : 1
   37. D: alsa-util.c:   avail_min    : 16384
   38. D: alsa-util.c:   period_event : 0
   39. D: alsa-util.c:   start_threshold  : -1
   40. D: alsa-util.c:   stop_threshold   : 1073741824
   41. D: alsa-util.c:   silence_threshold: 0
   42. D: alsa-util.c:   silence_size : 0
   43. D: alsa-util.c:   boundary     : 1073741824
   44. D: alsa-util.c:   appl_ptr     : 0
   45. D: alsa-util.c:   hw_ptr       : 0
   46. D: alsa-sink.c: Requested volume: 0:   3% 1:   3%
   47. D: alsa-sink.c: Got hardware volume: 0:   3% 1:   3%
   48. D: alsa-sink.c: Calculated software volume: 0: 100% 1: 100%
   (accurate-enough=yes)
   49. D: alsa-sink.c: Thread starting up
   50. I: core-util.c: Successfully enabled SCHED_RR scheduling for thread,
   with priority 4, which is lower than the requested 5.
   51. D: alsa-sink.c: Loop
   52. D: alsa-sink.c: Loop
   53. D: alsa-sink.c: Buffer time: 371 ms; Sleep time: 351 ms; Process
   time: 20 ms
   54. hwptr 0 buffer 16384 appl 0, avail=16384
   55. D: alsa-sink.c: avail: 65536 (samples 16384)
   56. D: alsa-sink.c: 0.00 ms left to play; inc threshold = 0.00 ms; dec
   threshold = 100.00 ms
   57. D: alsa-sink.c: Filling up
   58. hwptr 0 buffer 16384 appl 0, avail=16384
   59. hwptr 0 buffer 16384 appl 0, avail=16384
   60. D: alsa-sink.c: Wrote 65496 bytes (of possible 65536 bytes)
   61. hwptr 0 buffer 16384 appl 16374, avail=10
   62. hwptr 0 buffer 16384 appl 16374, avail=10
   63. D: alsa-sink.c: Wrote 40 bytes (of possible 40 bytes)
   64. hwptr 0 buffer 16384 appl 16384, avail=0
   65. D: alsa-sink.c: avail: 0 (samples 0)
   66. D: alsa-sink.c: 371.52 ms left to play; inc threshold = 0.00 ms; dec
   threshold = 100.00 ms
   67. D: alsa-sink.c: Not filling up, because too early.
   68. I: alsa-sink.c: Starting playback.
   69. D: alsa-sink.c: Cutting sleep time for the initial iterations by
   half.


In the default PulseAudio code, the
> timer value is increased by 20ms each time this errror condition is
> reached.


D: alsa-sink.c: Cutting sleep time for the initial iterations by half.

Are you sure the time value is increased by 20 ms in pulseaudio-0.9.21 ?


My au8830 work quite well on pulseaudio-0.9.14 ( Fedora 10 )  with 2
fragments


D: module-hal-detect.c: Loading module-alsa-sink with arguments 'device_id=0
sink_name=alsa_output.pci_12eb_2_sound_card_0_alsa_playback_0 tsched=1'

D: alsa-util.c: Trying front:0 with SND_PCM_NO_AUTO_FORMAT ...
D: alsa-util.c: Maximum hw buffer size is 371 ms
I: module-alsa-sink.c: Successfully opened device front:0.
I: module-alsa-sink.c: Successfully enabled mmap() mode.
I: module-alsa-sink.c: Successfully enabled timer-based scheduling mode.
I: (alsa-lib)control.c: Invalid CTL front:0
I: alsa-util.c: Unable to attach to mixer front:0: No such file or directory
I: alsa-util.c: Successfully attached to mixer 'hw:0'
I: alsa-util.c: Using mixer control "Master".
I: sink.c: Created sink 0
"alsa_output.pci_12eb_2_sound_card_0_alsa_playback_0" with sample spec s16le
2ch 44100Hz and channel map front-left,front-right
I: source.c: Created source 0
"alsa_output.pci_12eb_2_sound_card_0_alsa_playback_0.monitor" with sample
spec s16le 2ch 44100Hz and channel map front-left,front-right
I: module-alsa-sink.c: Using 2 fragments of size 4096 bytes, buffer time is
46.44ms
I: module-alsa-sink.c: Time scheduling watermark is 20.00ms
D: module-alsa-sink.c: hwbuf_unused_frames=0
D: module-alsa-sink.c: setting avail_min=4661
I: module-alsa-sink.c: Volume ranges from 0 to 31.
I: module-alsa-sink.c: Volume ranges from -46.50 dB to 0.00 dB.
I: alsa-util.c: All 2 channels can be mapped to mixer channels.
I: module-alsa-sink.c: Using hardware volume control. Hardware dB scale
supported.
D: alsa-util.c: snd_pcm_dump():
D: alsa-util.c: Hardware PCM card 0 'Aureal Vortex au8830' device 0
subdevice 0
D: alsa-util.c: Its setup is:
D: alsa-util.c:   stream       : PLAYBACK
D: alsa-util.c:   access       : MMAP_INTERLEAVED
D: alsa-util.c:   format       : S16_LE
D: alsa-util.c:   subformat    : STD
D: alsa-util.c:   channels     : 2
D: alsa-util.c:   rate         : 44100
D: alsa-util.c:   exact rate   : 44100 (44100/1)
D: alsa-util.c:   msbits       : 16
D: alsa-util.c:   buffer_size  : 2048
D: alsa-util.c:   period_size  : 1024
D: alsa-util.c:   period_time  : 23219
D: alsa-util.c:   tstamp_mode  : NONE
D: alsa-util.c:   period_step  : 1
D: alsa-util.c:   avail_min    : 4661
D: alsa-util.c:   period_event : 0
D: alsa-util.c:   start_threshold  : -1
D: alsa-util.c:   stop_threshold   : -1
D: alsa-util.c:   silence_threshold: 0
D: alsa-util.c:   silence_size : 0
D: alsa-util.c:   boundary     : 1073741824
D: alsa-util.c:   appl_ptr     : 0
D: alsa-util.c:   hw_ptr       : 0
D: module-alsa-sink.c: Read hardware volume: 0:  72% 1:  72%
D: module-alsa-sink.c: Thread starting up
D: rtpoll.c: Acquired POSIX realtime signal SIGRTMIN+29
I: module-alsa-sink.c: Starting playback.

https://bugtrack.alsa-project.org/alsa-bug/view.php?id=4776

hyper_sonic 's au8830 a bit lagged .But if switch to integrated i8x0 sound
chip music played very well. on pulseaudio 0.9.19 ( 16 fragments )



I: alsa-sink.c: Using 16,0 fragments of size 4096 bytes (23,22ms), buffer
size is 65536 bytes (371,52ms)
I: alsa-sink.c: Time scheduling watermark is 20,00ms
D: alsa-sink.c: hwbuf_unused=0
D: alsa-sink.c: setting avail_min=15502
D: alsa-mixer.c: Activating path analog-output-lfe-on-mono
D: alsa-mixer.c: Path analog-output-lfe-on-mono (Analog Output (LFE)),
direction=1, priority=40, probed=yes, supported=yes, has_mute=yes,
has_volume=yes, has_dB=yes, min_volume=0, max_volume=31, min_dB=-81,
max_dB=12
D: alsa-mixer.c: Element Master, direction=1, switch=1, volume=1,
enumeration=0, required=0, required_absent=0, mask=0x3600000000f66,
n_channels=2, override_map=yes
D: alsa-mixer.c: Element Master Mono, direction=1, switch=1, volume=1,
enumeration=0, required=4, required_absent=0, mask=0x80, n_channels=1,
override_map=yes
D: alsa-mixer.c: Element PCM, direction=1, switch=1, volume=1,
enumeration=0, required=0, required_absent=0, mask=0x402b600000000f66,
n_channels=2, override_map=yes
D: alsa-mixer.c: Element External Amplifier, direction=1, switch=4,
volume=0, enumeration=0, required=0, required_absent=0, mask=0x0,
n_channels=0, override_map=no
D: alsa-mixer.c: Option on (output-amplifier-on/Amplifier) index=1,
priority=10
D: alsa-mixer.c: Option off (output-amplifier-off/No Amplifier) index=0,
priority=0
D: alsa-mixer.c: Setting output-amplifier-on (Amplifier) priority=10
D: alsa-mixer.c: Setting output-amplifier-off (No Amplifier) priority=0
I: alsa-sink.c: Hardware volume ranges from -81,00 dB to 12,00 dB.
I: alsa-sink.c: Fixing base volume to -12,00 dB
I: alsa-sink.c: Using hardware volume control. Hardware dB scale supported.
I: alsa-sink.c: Using hardware mute control.
D: alsa-util.c: snd_pcm_dump():
D: alsa-util.c: Hardware PCM card 1 'Aureal Vortex au8830' device 0
subdevice 0
D: alsa-util.c: Its setup is:
D: alsa-util.c:   stream       : PLAYBACK
D: alsa-util.c:   access       : MMAP_INTERLEAVED
D: alsa-util.c:   format       : S16_LE
D: alsa-util.c:   subformat    : STD
D: alsa-util.c:   channels     : 2
D: alsa-util.c:   rate         : 44100
D: alsa-util.c:   exact rate   : 44100 (44100/1)
D: alsa-util.c:   msbits       : 16
D: alsa-util.c:   buffer_size  : 16384
D: alsa-util.c:   period_size  : 1024
D: alsa-util.c:   period_time  : 23219
D: alsa-util.c:   tstamp_mode  : ENABLE
D: alsa-util.c:   period_step  : 1
D: alsa-util.c:   avail_min    : 15502
D: alsa-util.c:   period_event : 0
D: alsa-util.c:   start_threshold  : -1
D: alsa-util.c:   stop_threshold   : 1073741824
D: alsa-util.c:   silence_threshold: 0
D: alsa-util.c:   silence_size : 0
D: alsa-util.c:   boundary     : 1073741824
D: alsa-util.c:   appl_ptr     : 0
D: alsa-util.c:   hw_ptr       : 0
D: alsa-sink.c: Thread starting up
I: core-util.c: Successfully enabled SCHED_RR scheduling for thread, with
priority 4, which is lower than the requested 5.
D: alsa-sink.c: Requested volume: 0:  23% 1:  23%
D: alsa-sink.c: Got hardware volume: 0:  24% 1:  24%
D: alsa-sink.c: Calculated software volume: 0:  97% 1:  97%
(accurate-enough=no)
I: alsa-sink.c: Starting playback.
D: alsa-sink.c: Cutting sleep time for the initial iterations by half.
D: alsa-sink.c: Cutting sleep time for the initial iterations by half.
D: alsa-sink.c: Cutting sleep time for the initial iterations by half.


> PA ends-up waking-up 150ms or so before the deadline and yet
> it still encounters this error. I don't think it's a problem with PA
> not refilling the buffer on time, it's more that the information
> provided by snd_pcm_avail() is misleading. I commented out the portion
> of the code that increases the watermark and clamped the number of
> available samples to the buffer size, and it works just fine, no audio
> underflows.
> - P
>



Adding the timestamp is the easy way to prove the pulseaudio is writing the
audio in time

The problem may be the timer is not running at the same rate as the sound
card 's clock

or

snd_pcm_rewindable() and snd_pcm_rewind() has bug since PA server is the
only application use snd_pcm_rewind()



http://thread.gmane.org/gmane.linux.alsa.devel/66826/focus=66952

Unfortunately there is no test program to test the snd_pcm_rewind() function


http://thread.gmane.org/gmane.linux.alsa.devel/59470/focus=59641

PCI audio controllers fetch audio from memory in brust mode (i.e. fetch data
must faster than sampling rate 48000Hz) , it is doubt that the application
can really rewind the application pointer to hardware pointer and perform an
immedate rewrite

Re: hw_ptr accuracy with intel8x0 -> PulseAudio issue

[Raymond Yau]

2009/12/4 pl bossart <bossart.nospam@gmail.com>

> >>   17. hwptr 24351 buffer 16384 appl 24332, avail=16403
> >
> > appl pointer is behind hwprtr (  underrun ) , need timestamp to find out
> > whether PA is unable to write audio data in time since
>
>  I commented out the portion of the code that increases the watermark and
> clamped the number of available samples to the buffer size, and it works
> just fine, no audio
> underflows.
>

Do you mean that the underrun is related the the portion of code that
increase the watermark (i.e It is a pulseaudio bug instead of driver bug  )
?

Re: hw_ptr accuracy with intel8x0 -> PulseAudio issue

[Takashi Iwai]

At Sat, 5 Dec 2009 10:17:07 +0800,
Raymond Yau wrote:
> 
> 2009/12/4 pl bossart <bossart.nospam@gmail.com>
> 
> > >>   17. hwptr 24351 buffer 16384 appl 24332, avail=16403
> > >
> > > appl pointer is behind hwprtr (  underrun ) , need timestamp to find out
> > > whether PA is unable to write audio data in time since
> >
> >  I commented out the portion of the code that increases the watermark and
> > clamped the number of available samples to the buffer size, and it works
> > just fine, no audio
> > underflows.
> >
> 
> Do you mean that the underrun is related the the portion of code that
> increase the watermark (i.e It is a pulseaudio bug instead of driver bug  )
> ?

Or, we can try simply to change to periods_min = 2 whether this fixes
the PA issues.

periods_min = 1 is anyway fairly fragile.  With that setup, apps are
supposed (implicitly) to wake up frequently enough to get pointers in
sync.  This is because you can't trust whether the IRQ wake up is
really fast enough.  There are machines that aren't. 


thanks,

Takashi

Re: hw_ptr accuracy with intel8x0 -> PulseAudio issue

[Raymond Yau]

2009/12/8 Takashi Iwai <tiwai@suse.de>

> At Sat, 5 Dec 2009 10:17:07 +0800,
> Raymond Yau wrote:
> >
> > 2009/12/4 pl bossart <bossart.nospam@gmail.com>
> >
> > > >>   17. hwptr 24351 buffer 16384 appl 24332, avail=16403
> > > >
> > > > appl pointer is behind hwprtr (  underrun ) , need timestamp to find
> out
> > > > whether PA is unable to write audio data in time since
> > >
> > >  I commented out the portion of the code that increases the watermark
> and
> > > clamped the number of available samples to the buffer size, and it
> works
> > > just fine, no audio
> > > underflows.
> > >
> >
> > Do you mean that the underrun is related the the portion of code that
> > increase the watermark (i.e It is a pulseaudio bug instead of driver bug
>  )
> > ?
>
> Or, we can try simply to change to periods_min = 2 whether this fixes
> the PA issues.
>
> periods_min = 1 is anyway fairly fragile.  With that setup, apps are
> supposed (implicitly) to wake up frequently enough to get pointers in
> sync.  This is because you can't trust whether the IRQ wake up is
> really fast enough.  There are machines that aren't.
>
>
> thanks,
>
> Takashi
>

The intel8x0 driver has code to handle one period per buffer ,

Is the feature "one period per buffer"  designed for dmix ?

static void snd_intel8x0_setup_periods(struct intel8x0 *chip, struct
ichdev *ichdev)
{
	int idx;
	u32 *bdbar = ichdev->bdbar;
	unsigned long port = ichdev->reg_offset;

	iputdword(chip, port + ICH_REG_OFF_BDBAR, ichdev->bdbar_addr);
	if (ichdev->size == ichdev->fragsize) {
		ichdev->ack_reload = ichdev->ack = 2;
		ichdev->fragsize1 = ichdev->fragsize >> 1;
		for (idx = 0; idx < (ICH_REG_LVI_MASK + 1) * 2; idx += 4) {
			bdbar[idx + 0] = cpu_to_le32(ichdev->physbuf);
			bdbar[idx + 1] = cpu_to_le32(0x80000000 | /* interrupt on completion */
						     ichdev->fragsize1 >> ichdev->pos_shift);
			bdbar[idx + 2] = cpu_to_le32(ichdev->physbuf + (ichdev->size >> 1));
			bdbar[idx + 3] = cpu_to_le32(0x80000000 | /* interrupt on completion */
						     ichdev->fragsize1 >> ichdev->pos_shift);
		}
		ichdev->frags = 2;
	} else {

The system timer may be running faster or slower than the sound card
on differnt machine

PA only adjust the watermark/sleeping time in one direction only

Re: hw_ptr accuracy with intel8x0 -> PulseAudio issue

[Takashi Iwai]

At Wed, 9 Dec 2009 19:55:15 +0800,
Raymond Yau wrote:
> 
> 2009/12/8 Takashi Iwai <tiwai@suse.de>
> 
> > At Sat, 5 Dec 2009 10:17:07 +0800,
> > Raymond Yau wrote:
> > >
> > > 2009/12/4 pl bossart <bossart.nospam@gmail.com>
> > >
> > > > >>   17. hwptr 24351 buffer 16384 appl 24332, avail=16403
> > > > >
> > > > > appl pointer is behind hwprtr (  underrun ) , need timestamp to find
> > out
> > > > > whether PA is unable to write audio data in time since
> > > >
> > > >  I commented out the portion of the code that increases the watermark
> > and
> > > > clamped the number of available samples to the buffer size, and it
> > works
> > > > just fine, no audio
> > > > underflows.
> > > >
> > >
> > > Do you mean that the underrun is related the the portion of code that
> > > increase the watermark (i.e It is a pulseaudio bug instead of driver bug
> >  )
> > > ?
> >
> > Or, we can try simply to change to periods_min = 2 whether this fixes
> > the PA issues.
> >
> > periods_min = 1 is anyway fairly fragile.  With that setup, apps are
> > supposed (implicitly) to wake up frequently enough to get pointers in
> > sync.  This is because you can't trust whether the IRQ wake up is
> > really fast enough.  There are machines that aren't.
> >
> >
> > thanks,
> >
> > Takashi
> >
> 
> The intel8x0 driver has code to handle one period per buffer ,

Yes, but it doesn't work so reliably.
That's why I asked for testing periods_min = 2.

> Is the feature "one period per buffer"  designed for dmix ?

No.

> The system timer may be running faster or slower than the sound card
> on differnt machine

Yes.

> PA only adjust the watermark/sleeping time in one direction only

Yes.


thanks,

Takashi

Re: hw_ptr accuracy with intel8x0 -> PulseAudio issue

[Colin Guthrie]

'Twas brillig, and Takashi Iwai at 09/12/09 13:46 did gyre and gimble:
>> PA only adjust the watermark/sleeping time in one direction only
> 
> Yes.

Actually there is code in PA to move the watermark in both ways, but
obviously reverting it backtowards the "underrun zone" is a bit
dangerous, so can't be just a simple "reduce it" back.

http://git.0pointer.de/?p=pulseaudio.git;a=commit;h=050a3a99e1d151b4f55c89f82073ef33f3399646

I can't remember the current status (i.e. if the code is disabled or
not) but AFAICT it's enabled.

Col

-- 

Colin Guthrie
gmane(at)colin.guthr.ie
http://colin.guthr.ie/

Day Job:
  Tribalogic Limited [http://www.tribalogic.net/]
Open Source:
  Mandriva Linux Contributor [http://www.mandriva.com/]
  PulseAudio Hacker [http://www.pulseaudio.org/]
  Trac Hacker [http://trac.edgewall.org/]

Re: hw_ptr accuracy with intel8x0 -> PulseAudio issue

[Raymond Yau]

2009/12/9 Takashi Iwai <tiwai@suse.de>

> At Wed, 9 Dec 2009 19:55:15 +0800,
> Raymond Yau wrote:
> >
> > 2009/12/8 Takashi Iwai <tiwai@suse.de>
> >
> > > At Sat, 5 Dec 2009 10:17:07 +0800,
> > > Raymond Yau wrote:
> > > >
> > > > 2009/12/4 pl bossart <bossart.nospam@gmail.com>
> > > >
> > > > > >>   17. hwptr 24351 buffer 16384 appl 24332, avail=16403
> > > > > >
> > > > > > appl pointer is behind hwprtr (  underrun ) , need timestamp to
> find
> > > out
> > > > > > whether PA is unable to write audio data in time since
> > > > >
> > > > >  I commented out the portion of the code that increases the
> watermark
> > > and
> > > > > clamped the number of available samples to the buffer size, and it
> > > works
> > > > > just fine, no audio
> > > > > underflows.
> > > > >
> > > >
> > > > Do you mean that the underrun is related the the portion of code that
> > > > increase the watermark (i.e It is a pulseaudio bug instead of driver
> bug
> > >  )
> > > > ?
> > >
> > > Or, we can try simply to change to periods_min = 2 whether this fixes
> > > the PA issues.
> > >
> > > periods_min = 1 is anyway fairly fragile.  With that setup, apps are
> > > supposed (implicitly) to wake up frequently enough to get pointers in
> > > sync.  This is because you can't trust whether the IRQ wake up is
> > > really fast enough.  There are machines that aren't.
> > >
> > >
> > > thanks,
> > >
> > > Takashi
> > >
> >
> > The intel8x0 driver has code to handle one period per buffer ,
>
> Yes, but it doesn't work so reliably.
> That's why I asked for testing periods_min = 2.
>
> > Is the feature "one period per buffer"  designed for dmix ?
>
> No.
>
> > The system timer may be running faster or slower than the sound card
> > on differnt machine
>
> Yes.
>
> > PA only adjust the watermark/sleeping time in one direction only
>
> Yes.
>
>
> thanks,
>
> Takashi
>

Unlike the convention sound card which has only one set of hardware
registers, aureal au88x0 chips has 4 set of hardware registers ( sub-buffers
as descibed in patent 6167465 )
The maximum period size is  4k bytes and the driver support 2 to 32 periods.


This is exactly as same as the sound card in the figure

*Image 1:* *Schematic overview of the playback buffer in the traditional
playback model, in the best way the author can visualize this with his
limited drawing abilities.*

http://0pointer.de/blog/projects/pulse-glitch-free.html



1) what is hwbuf_unused_frames ?

2) why PA use  snd_pcm_hw_params_get_buffer_size_max() instead of
snd_pcm_hw_params_get_buffer_size() after snd_pcm_hw_params() ?

D: alsa-util.c: Maximum hw buffer size is 371 ms

I: module-alsa-sink.c: Using 2 fragments of size 4096 bytes, buffer time is
46.44ms
D: alsa-util.c:   buffer_size  : 2048
D: alsa-util.c:   period_size  : 1024

3) why PA alway open CTL device "front:0" instead of "hw:0" ?

I: (alsa-lib)control.c: Invalid CTL front:0
I: alsa-util.c: Unable to attach to mixer front:0: No such file or directory
I: alsa-util.c: Successfully attached to mixer 'hw:0'

4) did PA has any data to play when the server probe the devices ?

D: module-alsa-sink.c: Thread starting up
D: rtpoll.c: Acquired POSIX realtime signal SIGRTMIN+29
I: module-alsa-sink.c: Starting playback.

5) it seem bug in snd_pcm_sw_params_set_avail_min() since 4661 is larger
than the buffer size 2048 since PA still think that 371ms is the maximum
buffer size


D: alsa-util.c:   buffer_size  : 2048
D: alsa-util.c:   period_size  : 1024
D: alsa-util.c:   period_time  : 23219
D: alsa-util.c:   tstamp_mode  : NONE
D: alsa-util.c:   period_step  : 1
D: alsa-util.c:   avail_min    : 4661

6) when using the minimum period size of alsa-pulse plugin and aplay on
pulseaudio 0.9.19

it seem that underrun occur between aplay and PA server

I: alsa-sink.c: Increasing wakeup watermark to 7,98 ms
D: protocol-native.c: Underrun on 'ALSA Playback', 0 bytes in queue.
D: sink-input.c: Requesting rewind due to corking



For pulseaudio-0.9.14 on Fedora 10

D: module-hal-detect.c: Not loaded device
/org/freedesktop/Hal/devices/pci_12eb_2_sound_card_0_alsa_playback_1
D: module-hal-detect.c: Loading module-alsa-sink with arguments 'device_id=0
sink_name=alsa_output.pci_12eb_2_sound_card_0_alsa_playback_0 tsched=1'
D: alsa-util.c: Trying front:0 with SND_PCM_NO_AUTO_FORMAT ...
D: alsa-util.c: Maximum hw buffer size is 371 ms

...

I: module-alsa-sink.c: Successfully opened device front:0.
I: module-alsa-sink.c: Successfully enabled mmap() mode.
I: module-alsa-sink.c: Successfully enabled timer-based scheduling mode.
I: (alsa-lib)control.c: Invalid CTL front:0
I: alsa-util.c: Unable to attach to mixer front:0: No such file or directory
I: alsa-util.c: Successfully attached to mixer 'hw:0'
I: alsa-util.c: Using mixer control "Master".
I: sink.c: Created sink 0
"alsa_output.pci_12eb_2_sound_card_0_alsa_playback_0" with sample spec s16le
2ch 44100Hz and channel map front-left,front-right
I: source.c: Created source 0
"alsa_output.pci_12eb_2_sound_card_0_alsa_playback_0.monitor" with sample
spec s16le 2ch 44100Hz and channel map front-left,front-right
I: module-alsa-sink.c: Using 2 fragments of size 4096 bytes, buffer time is
46.44ms
I: module-alsa-sink.c: Time scheduling watermark is 20.00ms
D: module-alsa-sink.c: hwbuf_unused_frames=0
D: module-alsa-sink.c: setting avail_min=4661
I: module-alsa-sink.c: Volume ranges from 0 to 31.
I: module-alsa-sink.c: Volume ranges from -46.50 dB to 0.00 dB.
I: alsa-util.c: All 2 channels can be mapped to mixer channels.
I: module-alsa-sink.c: Using hardware volume control. Hardware dB scale
supported.
D: alsa-util.c: snd_pcm_dump():
D: alsa-util.c: Hardware PCM card 0 'Aureal Vortex au8830' device 0
subdevice 0
D: alsa-util.c: Its setup is:
D: alsa-util.c:   stream       : PLAYBACK
D: alsa-util.c:   access       : MMAP_INTERLEAVED
D: alsa-util.c:   format       : S16_LE
D: alsa-util.c:   subformat    : STD
D: alsa-util.c:   channels     : 2
D: alsa-util.c:   rate         : 44100
D: alsa-util.c:   exact rate   : 44100 (44100/1)
D: alsa-util.c:   msbits       : 16
D: alsa-util.c:   buffer_size  : 2048
D: alsa-util.c:   period_size  : 1024
D: alsa-util.c:   period_time  : 23219
D: alsa-util.c:   tstamp_mode  : NONE
D: alsa-util.c:   period_step  : 1
D: alsa-util.c:   avail_min    : 4661
D: alsa-util.c:   period_event : 0
D: alsa-util.c:   start_threshold  : -1
D: alsa-util.c:   stop_threshold   : -1
D: alsa-util.c:   silence_threshold: 0
D: alsa-util.c:   silence_size : 0
D: alsa-util.c:   boundary     : 1073741824
D: alsa-util.c:   appl_ptr     : 0
D: alsa-util.c:   hw_ptr       : 0
D: module-alsa-sink.c: Read hardware volume: 0:  64% 1:  64%
D: module-alsa-sink.c: Thread starting up
D: rtpoll.c: Acquired POSIX realtime signal SIGRTMIN+29
I: module-alsa-sink.c: Starting playback.

...


I: module-alsa-sink.c: Trying resume...
D: alsa-util.c: Maximum hw buffer size is 371 ms
D: module-alsa-sink.c: hwbuf_unused_frames=0
D: module-alsa-sink.c: setting avail_min=4661
I: module-alsa-sink.c: Resumed successfully...
I: module-alsa-sink.c: Starting playback.
D: module-suspend-on-idle.c: Sink
alsa_output.pci_12eb_2_sound_card_0_alsa_playback_0 becomes idle.
D: module-suspend-on-idle.c: Sink
alsa_output.pci_12eb_2_sound_card_0_alsa_playback_0 becomes busy.
D: memblockq.c: memblockq requested: maxlength=33554432, tlength=0, base=4,
prebuf=0, minreq=1 maxrewind=0
D: memblockq.c: memblockq sanitized: maxlength=33554432, tlength=33554432,
base=4, prebuf=0, minreq=4 maxrewind=0
I: sink-input.c: Created input 1 "ALSA Playback" on
alsa_output.pci_12eb_2_sound_card_0_alsa_playback_0 with sample spec s16le
2ch 44100Hz and channel map front-left,front-right
I: protocol-native.c: Requested tlength=500.00 ms, minreq=124.99 ms
D: protocol-native.c: Early requests mode enabled, configuring sink latency
to minreq.
D: memblockq.c: memblockq requested: maxlength=4194304, tlength=88200,
base=4, prebuf=66152, minreq=22048 maxrewind=0
D: memblockq.c: memblockq sanitized: maxlength=4194304, tlength=88200,
base=4, prebuf=66152, minreq=22048 maxrewind=0
I: protocol-native.c: Final latency 624.99 ms = 250.02 ms + 2*124.99 ms +
124.99 ms
D: module-alsa-sink.c: latency set to 46.44ms
D: module-alsa-sink.c: hwbuf_unused_frames=1
D: module-alsa-sink.c: setting avail_min=4662
D: module-alsa-sink.c: Requesting rewind due to latency change.
D: module-alsa-sink.c: Requested to rewind 8192 bytes.
D: module-alsa-sink.c: Limited to 3712 bytes.
D: module-alsa-sink.c: before: 928
D: module-alsa-sink.c: after: 928
D: module-alsa-sink.c: Rewound 3712 bytes.
D: sink.c: Processing rewind...
D: sink-input.c: Have to rewind 3712 bytes on render memblockq.


https://bugtrack.alsa-project.org/alsa-bug/view.php?id=4776

hyper_sonic 's au8830 a bit lagged .But if switch to integrated i8x0 sound
chip music played very well. on pulseaudio 0.9.19

PA seem to use 16 fragments instead of 2 fragments for au8830


I: alsa-sink.c: Using 16,0 fragments of size 4096 bytes (23,22ms), buffer
size is 65536 bytes (371,52ms)
I: alsa-sink.c: Time scheduling watermark is 20,00ms
D: alsa-sink.c: hwbuf_unused=0
D: alsa-sink.c: setting avail_min=15502
D: alsa-mixer.c: Activating path analog-output-lfe-on-mono
D: alsa-mixer.c: Path analog-output-lfe-on-mono (Analog Output (LFE)),
direction=1, priority=40, probed=yes, supported=yes, has_mute=yes,
has_volume=yes, has_dB=yes, min_volume=0, max_volume=31, min_dB=-81,
max_dB=12
D: alsa-mixer.c: Element Master, direction=1, switch=1, volume=1,
enumeration=0, required=0, required_absent=0, mask=0x3600000000f66,
n_channels=2, override_map=yes
D: alsa-mixer.c: Element Master Mono, direction=1, switch=1, volume=1,
enumeration=0, required=4, required_absent=0, mask=0x80, n_channels=1,
override_map=yes
D: alsa-mixer.c: Element PCM, direction=1, switch=1, volume=1,
enumeration=0, required=0, required_absent=0, mask=0x402b600000000f66,
n_channels=2, override_map=yes
D: alsa-mixer.c: Element External Amplifier, direction=1, switch=4,
volume=0, enumeration=0, required=0, required_absent=0, mask=0x0,
n_channels=0, override_map=no
D: alsa-mixer.c: Option on (output-amplifier-on/Amplifier) index=1,
priority=10
D: alsa-mixer.c: Option off (output-amplifier-off/No Amplifier) index=0,
priority=0
D: alsa-mixer.c: Setting output-amplifier-on (Amplifier) priority=10
D: alsa-mixer.c: Setting output-amplifier-off (No Amplifier) priority=0
I: alsa-sink.c: Hardware volume ranges from -81,00 dB to 12,00 dB.
I: alsa-sink.c: Fixing base volume to -12,00 dB
I: alsa-sink.c: Using hardware volume control. Hardware dB scale supported.
I: alsa-sink.c: Using hardware mute control.
D: alsa-util.c: snd_pcm_dump():
D: alsa-util.c: Hardware PCM card 1 'Aureal Vortex au8830' device 0
subdevice 0
D: alsa-util.c: Its setup is:
D: alsa-util.c:   stream       : PLAYBACK
D: alsa-util.c:   access       : MMAP_INTERLEAVED
D: alsa-util.c:   format       : S16_LE
D: alsa-util.c:   subformat    : STD

Re: hw_ptr accuracy with intel8x0 -> PulseAudio issue

[pl bossart]

Takashi,
I tested with .periods_min=2 and reduced the period_max by half. The
underruns reported by PulseAudio are no longer present with this
modification.
However, there's still something fishy here. In both cases, with 1 or
2 periods, PulseAudio seems to wake-up more often than it should with
snd_pcm_poll_descriptors_revents returning a null event. See the
sequence below. Not sure if the problem is a bad configuration of the
timers of if the driver generates these events?
I also noticed that the underrun reported with a single period are
associated with the POLLOUT revent. I am not sure this is normal?
Thanks for your feedback.
- Pierre

D: alsa-sink.c: Waking up in 157.78ms (system clock).
>> WAKEUP
E: alsa-sink.c: snd_pcm_poll_descriptors_revents() returned zero
D: alsa-sink.c: Loop
D: alsa-sink.c: Buffer time: 371 ms; Sleep time: 321 ms; Process time: 50 ms
D: alsa-sink.c: avail: 1076 (samples 269)
>> This is not consistent, there are too few samples in the buffer
D: alsa-sink.c: 365.42 ms left to play; inc threshold = 0.00 ms; dec
threshold = 100.00 ms
D: alsa-sink.c: Not filling up, because too early.
>> go back to sleep
D: alsa-sink.c: Waking up in 157.71ms (system clock).
>> WAKEUP
E: alsa-sink.c: snd_pcm_poll_descriptors_revents() returned zero
D: alsa-sink.c: Loop
D: alsa-sink.c: Buffer time: 371 ms; Sleep time: 321 ms; Process time: 50 ms
D: alsa-sink.c: avail: 1136 (samples 284)
>> again the buffer is still almost full and we have nothing to do
D: alsa-sink.c: 365.08 ms left to play; inc threshold = 0.00 ms; dec
threshold = 100.00 ms
D: alsa-sink.c: Not filling up, because too early.

Re: hw_ptr accuracy with intel8x0 -> PulseAudio issue

[pl bossart]

> 2) why PA use  snd_pcm_hw_params_get_buffer_size_max() instead of
> snd_pcm_hw_params_get_buffer_size() after snd_pcm_hw_params() ?

Precisely to use the maximum preallocated buffer size.

> I: module-alsa-sink.c: Using 2 fragments of size 4096 bytes, buffer time is
> 46.44ms
> D: alsa-util.c:   buffer_size  : 2048
> D: alsa-util.c:   period_size  : 1024

With small buffers like this, I don't see the point of the timer-based
scheduling, you will have one interrupt every 23ms.


> 5) it seem bug in snd_pcm_sw_params_set_avail_min() since 4661 is larger
> than the buffer size 2048 since PA still think that 371ms is the maximum
> buffer size
>
>
> D: alsa-util.c:   buffer_size  : 2048
> D: alsa-util.c:   period_size  : 1024
> D: alsa-util.c:   period_time  : 23219
> D: alsa-util.c:   tstamp_mode  : NONE
> D: alsa-util.c:   period_step  : 1
> D: alsa-util.c:   avail_min    : 4661

This doesn't make sense. But avail_min isn't really used with the
timer-based scheduling

>
> For pulseaudio-0.9.14 on Fedora 10

Man, you are using an old version here, the alsa sink code was changed
several times already.

Re: hw_ptr accuracy with intel8x0 -> PulseAudio issue

[Raymond Yau]

2009/12/10 pl bossart <bossart.nospam@gmail.com>

> > 2) why PA use  snd_pcm_hw_params_get_buffer_size_max() instead of
> > snd_pcm_hw_params_get_buffer_size() after snd_pcm_hw_params() ?
>
> Precisely to use the maximum preallocated buffer size.
>

The driver only allocate 8K bytes for the substream when the application
request 2 fragments and 64 Kbytes when the application request 16 fragments

It is wrong for PA to think that 371ms is the buffer size on pulseaudio
0.9.21

If the user select 8 fragements in deamon.conf , the pulseaudio-0.9.21 still
calculated the wrong buffer time and wakeup time.

Do you know what is PA 's "hwbuf_unused_frames"  ?


/* hw_params callback */
static int
snd_vortex_pcm_hw_params(struct snd_pcm_substream *substream,
			 struct snd_pcm_hw_params *hw_params)
{
	vortex_t *chip = snd_pcm_substream_chip(substream);
	stream_t *stream = (stream_t *) (substream->runtime->private_data);
	int err;

	// Alloc buffer memory.
	err =
	    snd_pcm_lib_malloc_pages(substream, params_buffer_bytes(hw_params));




>
> > I: module-alsa-sink.c: Using 2 fragments of size 4096 bytes, buffer time
> is
> > 46.44ms
> > D: alsa-util.c:   buffer_size  : 2048
> > D: alsa-util.c:   period_size  : 1024
>
> With small buffers like this, I don't see the point of the timer-based
> scheduling, you will have one interrupt every 23ms.
>
>
au8810, au8820 and au8830 were designed for those 3D sound game (low
latency) and support multiple DMA connections (i.e. hardware mixing ) , they
does not need any sound server (software mixing) at all.


>
> > 5) it seem bug in snd_pcm_sw_params_set_avail_min() since 4661 is larger
> > than the buffer size 2048 since PA still think that 371ms is the maximum
> > buffer size
> >
> >
> > D: alsa-util.c:   buffer_size  : 2048
> > D: alsa-util.c:   period_size  : 1024
> > D: alsa-util.c:   period_time  : 23219
> > D: alsa-util.c:   tstamp_mode  : NONE
> > D: alsa-util.c:   period_step  : 1
> > D: alsa-util.c:   avail_min    : 4661
>
> This doesn't make sense. But avail_min isn't really used with the
> timer-based scheduling
>
>
Are you sure ?


> >
> > For pulseaudio-0.9.14 on Fedora 10
>
> Man, you are using an old version here, the alsa sink code was changed
> several times already.
>

PA 0.9.14 run quite well with my au8830 with 2 fragements on Fedora 10 but
PA 0.9.19 run badly on hypersonic 's au8830 on Karmic

It seem to be regression of PA

The possible reasons may be

1) PA 's 20ms process time  may not enough for hyper_sonic 's CPU ( ICH2 or
ICH4 since he is using intelx8x0)  and  I am a faster CPU since my
motherboard is using HDA ( ICH8)

2) PA may only handle 1 or 2 periods or use the wrong buffer size in
calculating the watermark

3) snd_pcm_rewindable() is returning a wrong value since au88x0 has FIFO
buffer as described in the patent )

http://0pointer.de/blog/projects/pulse-glitch-free.html

The rewriting of the client buffers causing rewriting of the hardware buffer
complicates the resampling/converting step immensly. In general the code to
implement this model is more complex than for the traditional model. Also,
ALSA has not really been designed with this design in mind, which makes some
things very hard to get right and suboptimal.

The transfer of the audio data (48000Hz) only occur at ac97 link between
AC97 codec and AC97 controller. The AC97 controller fetch audio from memory
at the rate of PCI bus instead of the sampling rate of the audio. Therefore
rewind the application pointer to hardware pointer and immediate rewrite  is
almost impossible

4) the default fragments in daemon.conf seem oboselte in PA 0.9.21 but there
is no proper documentation

Re: hw_ptr accuracy with intel8x0 -> PulseAudio issue

[Raymond Yau]

2009/12/10 pl bossart <bossart.nospam@gmail.com>

> > 2) why PA use  snd_pcm_hw_params_get_buffer_size_max() instead of
> > snd_pcm_hw_params_get_buffer_size() after snd_pcm_hw_params() ?
>
> Precisely to use the maximum preallocated buffer size.
>


D: module-alsa-sink.c: latency set to 46.44ms
D: module-alsa-sink.c: hwbuf_unused_frames=1
D: module-alsa-sink.c: setting avail_min=4662
D: module-alsa-sink.c: Requesting rewind due to latency change.
D: module-alsa-sink.c: Requested to rewind 8192 bytes.
D: module-alsa-sink.c: Limited to 3712 bytes.
D: module-alsa-sink.c: before: 928

The driver only allocated the requested buffer size at hw_param callback

As you can see , PA only rewind 8192 bytes only instead of 371 ms ?

Re: hw_ptr accuracy with intel8x0 -> PulseAudio issue

[Raymond Yau]

2009/12/9 Colin Guthrie <gmane@colin.guthr.ie>

> 'Twas brillig, and Takashi Iwai at 09/12/09 13:46 did gyre and gimble:
> >> PA only adjust the watermark/sleeping time in one direction only
> >
> > Yes.
>
> Actually there is code in PA to move the watermark in both ways, but
> obviously reverting it backtowards the "underrun zone" is a bit
> dangerous, so can't be just a simple "reduce it" back.
>
>
> http://git.0pointer.de/?p=pulseaudio.git;a=commit;h=050a3a99e1d151b4f55c89f82073ef33f3399646
>
> I can't remember the current status (i.e. if the code is disabled or
> not) but AFAICT it's enabled.
>
> Col
>


What is hwbuf_unused in the watermark calculation ?

Refer to *Image 1:* *Schematic overview of the playback buffer in the
traditional playback model, in the best way the author can visualize this
with his limited drawing abilities.*

http://0pointer.de/blog/projects/pulse-glitch-free.html

When the alsa application using 4 periods , the alsa driver is about 75%
full at all time. The data remain in the buffer is many time of the minimum
period bytes ( 32 bytes in the case of intel8x0 )

1) It seem that 32byes is the PCI brust size ? ( hda driver seem has 128
bytes and usb driver ....)

PulseAudio <= 0.9.10 uses a fragment size of 25ms by default, with four
fragments.

Glitch Free mode

If no client specified any requirements we fill up the whole buffer all the
time, i.e. have an actual latency of 2s. However, if some applications
specified requirements, we take the lowest one and only use as much of the
configured hardware buffer as this value allows us. In practice, this means
we only partially fill the buffer each time we wake up. Then, we configure a
system timer to wake us up 10ms before the buffer would run empty and fill
it up again then. If the overall latency is configured to less than 10ms we
wakeup after half the latency requested.

Correct me If I am wrong

1) The function of alsa-plugin is to emulate an ALSA device

2) The hardware pointer of this pulse device is the application pointer of
the pulseaduio server

3) If PA server did not write any thing up when the timer wake up, this mean
that the hardware pointer of  the pulse device also stop moving.

>From the viewpoint of the alsa application , the pulse device is also
inaccurate


   1. hwptr 2858101 buffer 16384 appl 2874469, avail=16
   2. D: alsa-sink.c: avail: 64 (samples 16)
   3. D: alsa-sink.c: 371.16 ms left to play; inc threshold = 0.00 ms; dec
   threshold = 100.00 ms
   4. D: alsa-sink.c: Not filling up, because too early.
   5. D: alsa-sink.c: Wakeup from ALSA!
   6. D: alsa-sink.c: Loop
   7. D: alsa-sink.c: Buffer time: 371 ms; Sleep time: 351 ms; Process time:
   20 ms
   8. hwptr 2874490 buffer 16384 appl 2874469, avail=16405

4) why did alsa-time-test using pulse device , abort immediately

 ./alsa-time-test pulse
alsa-time-test: alsa-time-test.c:46: main: Assertion `r == 0' failed.
Aborted

Re: hw_ptr accuracy with intel8x0 -> PulseAudio issue

[Raymond Yau]

2009/12/10 pl bossart <bossart.nospam@gmail.com>

> Takashi,
> I tested with .periods_min=2 and reduced the period_max by half. The
> underruns reported by PulseAudio are no longer present with this
> modification.
>


why did you reduce periods_max by half since the driver should still support
1024 periods of 32 bytes when you set periods_min = 2 ?

Is it period_bytes_max by half ?

static struct snd_pcm_hardware snd_intel8x0_stream =
{
    .info =            (SNDRV_PCM_INFO_MMAP | SNDRV_PCM_INFO_INTERLEAVED |
                 SNDRV_PCM_INFO_BLOCK_TRANSFER |
                 SNDRV_PCM_INFO_MMAP_VALID |
                 SNDRV_PCM_INFO_PAUSE |
                 SNDRV_PCM_INFO_RESUME),
    .formats =        SNDRV_PCM_FMTBIT_S16_LE,
    .rates =        SNDRV_PCM_RATE_48000,
    .rate_min =        48000,
    .rate_max =        48000,
    .channels_min =        2,
    .channels_max =        2,
    .buffer_bytes_max =    128 * 1024,
    .period_bytes_min =    32,
    .period_bytes_max =    128 * 1024,
    .periods_min =        1,
    .periods_max =        1024,
    .fifo_size =        0,
};

Re: hw_ptr accuracy with intel8x0 -> PulseAudio issue

[pl bossart]

> why did you reduce periods_max by half since the driver should still support
> 1024 periods of 32 bytes when you set periods_min = 2 ?
>
> Is it period_bytes_max by half ?

Yes I meant period_bytes_max.

Re: hw_ptr accuracy with intel8x0 -> PulseAudio issue

[Raymond Yau]

2009/12/10 pl bossart <bossart.nospam@gmail.com>

>
>
> > I: module-alsa-sink.c: Using 2 fragments of size 4096 bytes, buffer time
> is
> > 46.44ms
> > D: alsa-util.c:   buffer_size  : 2048
> > D: alsa-util.c:   period_size  : 1024
>
> With small buffers like this, I don't see the point of the timer-based
> scheduling, you will have one interrupt every 23ms.
>
>
Do you mean that this is a limitation of pulseaudio server timer-based
scheduling  ?

It seem the problem is not related to small buffer since

It work quite well with 2 fragments (8196 bytes) on pulseaudio-0.9.14

D: alsa-util.c: Hardware PCM card 0 'Aureal Vortex au8830' device 0
subdevice 0
D: alsa-util.c: Its setup is:
D: alsa-util.c:   stream       : PLAYBACK
D: alsa-util.c:   access       : MMAP_INTERLEAVED
D: alsa-util.c:   format       : S16_LE
D: alsa-util.c:   subformat    : STD
D: alsa-util.c:   channels     : 2
D: alsa-util.c:   rate         : 44100
D: alsa-util.c:   exact rate   : 44100 (44100/1)
D: alsa-util.c:   msbits       : 16
D: alsa-util.c:   buffer_size  : 2048
D: alsa-util.c:   period_size  : 1024
D: alsa-util.c:   period_time  : 23219
D: alsa-util.c:   tstamp_mode  : NONE
D: alsa-util.c:   period_step  : 1
D: alsa-util.c:   avail_min    : 4661
D: alsa-util.c:   period_event : 0
D: alsa-util.c:   start_threshold  : -1
D: alsa-util.c:   stop_threshold   : -1
D: alsa-util.c:   silence_threshold: 0
D: alsa-util.c:   silence_size : 0
D: alsa-util.c:   boundary     : 1073741824
D: alsa-util.c:   appl_ptr     : 0
D: alsa-util.c:   hw_ptr       : 0


but fail on 16 fragments ( 65536 bytes) on pulseaudio-0.9.19

D: alsa-util.c: Hardware PCM card 1 'Aureal Vortex au8830' device 0
subdevice 0
D: alsa-util.c: Its setup is:
D: alsa-util.c:   stream       : PLAYBACK
D: alsa-util.c:   access       : MMAP_INTERLEAVED
D: alsa-util.c:   format       : S16_LE
D: alsa-util.c:   subformat    : STD
D: alsa-util.c:   channels     : 2
D: alsa-util.c:   rate         : 44100
D: alsa-util.c:   exact rate   : 44100 (44100/1)
D: alsa-util.c:   msbits       : 16
D: alsa-util.c:   buffer_size  : 16384
D: alsa-util.c:   period_size  : 1024
D: alsa-util.c:   period_time  : 23219
D: alsa-util.c:   tstamp_mode  : ENABLE
D: alsa-util.c:   period_step  : 1
D: alsa-util.c:   avail_min    : 15502
D: alsa-util.c:   period_event : 0
D: alsa-util.c:   start_threshold  : -1
D: alsa-util.c:   stop_threshold   : 1073741824
D: alsa-util.c:   silence_threshold: 0
D: alsa-util.c:   silence_size : 0
D: alsa-util.c:   boundary     : 1073741824
D: alsa-util.c:   appl_ptr     : 0
D: alsa-util.c:   hw_ptr       : 0


May be PA server cannot calculate the correct sleeping time when the sound
card use  more than 2 periods ?