[PPA 0.9.12 regression], Wakeup from ALSA!, Underruns > rewinds

With kernel 2.6.27-2, much more stable

Only a few "rewinds", mostly "Checking for dead streams".

I: module-alsa-sink.c: Underrun!
N: module-alsa-sink.c: Increasing wakeup watermark to 80,00 ms
D: protocol-native.c: Requesting rewind due to end of underrun.
D: module-alsa-sink.c: Requested to rewind 39540 bytes.
D: module-alsa-sink.c: Limited to 16804 bytes.
D: module-alsa-sink.c: before: 4201
D: module-alsa-sink.c: after: 4201
D: module-alsa-sink.c: Rewound 16804 bytes.
D: sink.c: Processing rewind...
D: sink-input.c: Have to rewind 16804 bytes on render memblockq.
D: sink-input.c: Have to rewind 16804 bytes on render memblockq.
D: sink-input.c: Have to rewind 16804 bytes on render memblockq.
D: module-rtp-recv.c: Checking for dead streams ...
D: module-rtp-recv.c: Checking for dead streams ...
D: module-rtp-recv.c: Checking for dead streams ...
D: module-rtp-recv.c: Checking for dead streams ...
D: module-rtp-recv.c: Checking for dead streams ...
D: module-rtp-recv.c: Checking for dead streams ...

Playing.... ;)

"Solved" but I am unsure whats correct settings

Relevant parts for Intrepid

http://ubuntuforums.org/showthread.php?t=866965
http://ubuntuforums.org/showthread.php?p=4928900

The alsa sink cannot be loaded..... but it works.. ????

Please look out for an update to pulseaudio from my PPA, which hopefully addresses this issue. Turns out I wasn't building against policykit, so hopefully that will make a difference.

Thanks

Luke

Thanks for updating ! ;)

It works but I can still see "rewinds".

I think there is a problem with Rhythmbox also, probably gstreamer-ugly and mp3 codecs.
I usually uses Exaile from source and its much more stable, I gave Rhythmbox a chance.

Just to test further.

Rock on... :)
http://www.youtube.com/watch?v=jZ5zXXUJsyc

Followup:

My memory is short.... deleted all files within ./pulse
(The same procedure as yesterday)

Magic sound and no rewinds....:)

Never had better sound with a Linux PC.....

Nope....change its again.

LastFM is terrible, Exaile better.

Every crackling = rewind is this:

I: module-alsa-sink.c: Underrun!
D: module-alsa-sink.c: latency set to 250,00
D: module-alsa-sink.c: hwbuf_unused_frames=5359
D: module-alsa-sink.c: setting avail_min=5888
I: sink-input.c: Freeing input 67 "ALSA Playback"
D: module-alsa-sink.c: Requested to rewind 65536 bytes.
D: module-alsa-sink.c: Mhmm, actually there is nothing to rewind.
I: module-stream-restore.c: Restoring device for stream sink-input-by-application-name:ALSA plug-in [last.fm].
I: module-stream-restore.c: Restoring volume for sink input sink-input-by-application-name:ALSA plug-in [last.fm].
D: module-stream-restore.c: Not restoring mute state for sink input sink-input-by-application-name:ALSA plug-in [last.fm], because already set.
D: module-suspend-on-idle.c: Sink alsa_output.pci_1102_4_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 68 "ALSA Playback" on alsa_output.pci_1102_4_alsa_playback_0 with sample spec s16le 2ch 44100Hz and channel map front-left,front-right
I: protocol-native.c: Requested tlength=371,52 ms, minreq=23,22 ms
D: protocol-native.c: Traditional mode enabled, modifying sink usec only for compat with minreq.
D: memblockq.c: memblockq requested: maxlength=65536, tlength=65536, base=4, prebuf=61440, minreq=4096 maxrewind=0
D: memblockq.c: memblockq sanitized: maxlength=65536, tlength=65536, base=4, prebuf=61440, minreq=4096 maxrewind=0
I: protocol-native.c: Final latency 696,60 ms = 325,08 ms + 2*23,22 ms + 325,08 ms
D: module-alsa-sink.c: latency set to 250,00
D: module-alsa-sink.c: hwbuf_unused_frames=5359
D: module-alsa-sink.c: setting avail_min=5888
D: protocol-native.c: Requesting rewind due to end of underrun.
D: module-alsa-sink.c: Requested to rewind 65536 bytes.
D: module-alsa-sink.c: Limited to 340 bytes.
D: module-alsa-sink.c: before: 85
D: module-alsa-sink.c: after: 85
D: module-alsa-sink.c: Rewound 340 bytes.
D: sink.c: Processing rewind...
D: sink-input.c: Have to rewind 340 bytes on render memblockq.
D: sink-input.c: Have to rewind 340 bytes on render memblockq.
D: sink-input.c: Have to rewind 340 bytes on render memblockq.
D: module-rtp-recv.c: Checking for dead streams ...

Over the network, i.e. with a remote PULSE_SERVER set, I get a lot of rewinds when a stream is playing. The frequency is high, in the 2-4 Hz range. Acoustically it sounds like about three fadeouts per second, as if someone would move a fader up and down all the time. I have Kernel 2.6.27-3 and PA 0.9.12. The log looks like this:

D: sink-input.c: Have to rewind 368 bytes on render memblockq.
I: module-alsa-sink.c: Underrun!
D: protocol-native.c: Requesting rewind due to end of underrun.
D: module-alsa-sink.c: Requested to rewind 37968 bytes.
D: module-alsa-sink.c: Limited to 272 bytes.
D: module-alsa-sink.c: before: 68
D: module-alsa-sink.c: after: 68
D: module-alsa-sink.c: Rewound 272 bytes.
D: sink.c: Processing rewind...
D: sink-input.c: Have to rewind 272 bytes on render memblockq.
I: module-alsa-sink.c: Underrun!
D: protocol-native.c: Requesting rewind due to end of underrun.
D: module-alsa-sink.c: Requested to rewind 38576 bytes.
D: module-alsa-sink.c: Limited to 240 bytes.
D: module-alsa-sink.c: before: 60
D: module-alsa-sink.c: after: 60
D: module-alsa-sink.c: Rewound 240 bytes.
D: sink.c: Processing rewind...
D: sink-input.c: Have to rewind 240 bytes on render memblockq.
I: module-alsa-sink.c: Underrun!
D: protocol-native.c: Requesting rewind due to end of underrun.
D: module-alsa-sink.c: Requested to rewind 37680 bytes.
D: module-alsa-sink.c: Limited to 272 bytes.
D: module-alsa-sink.c: before: 68
D: module-alsa-sink.c: after: 68
D: module-alsa-sink.c: Rewound 272 bytes.
D: sink.c: Processing rewind...

I’m unsure if the frequency somehow correlates with this:

D: alsa-util.c: Maximum hw buffer size is 371 ms
[...]
I: module-alsa-sink.c: Using 1 fragments of size 65536 bytes, buffer time is 371.52ms

I wonder if this is "short" ms kernel freezes... ?

If I am doing nothing and just play music its rather OK.

Todays round ended in a great success ;)

sudo gedit /etc/pulse/daemon.conf

high-priority = yes
nice-level = -11

realtime-scheduling = yes
realtime-priority = 5

Config files removed from /.pulse, only using pulse default files.

No rewinds..... Rock On !

Todays finding after new version update

I: module-alsa-sink.c: Underrun!
N: module-alsa-sink.c: Increasing wakeup watermark to 80,00 ms
D: module-rtp-recv.c: Checking for dead streams ...
D: module-rtp-recv.c: Checking for dead streams ...
D: module-rtp-recv.c: Checking for dead streams ...
D: module-rtp-recv.c: Checking for dead streams ...
D: module-rtp-recv.c: Checking for dead streams ...

Wakeup is a new entry which I haven't seen before

Perfect sound !!!

I'm still having this problem.
Version of package is: 0.9.12-0ubuntu1~ppa5
I've added my user to all the pulse-groups and edited the daemon.conf file according to the suggestion above.
I'm still experiencing rewinds and underruns.

Even when I enable realtime schedule in daemon.conf, it seems like PulseAudio is not getting realtime scheduling applied. Here's the initial output from when I run pulseaudio -vv with the realtime enabled:

pulseaudio -vv
I: caps.c: Limited capabilities successfully to CAP_SYS_NICE.
I: caps.c: Dropping root priviliges.
I: caps.c: Limited capabilities successfully to CAP_SYS_NICE.
D: main.c: Started as real root: no, suid root: yes
I: main.c: We're in the group 'pulse-rt', allowing high-priority scheduling.
I: main.c: We're in the group 'pulse-rt', allowing real-time scheduling.
I: main.c: setrlimit(RLIMIT_NICE, (31, 31)) failed: Operation not permitted
I: main.c: setrlimit(RLIMIT_RTPRIO, (9, 9)) failed: Operation not permitted
I: core-util.c: Successfully gained nice level -11.
W: main.c: RLIMIT_RTPRIO failed: Operation not permitted
D: main.c: Can realtime: yes, can high-priority: yes
W: ltdl-bind-now.c: Failed to find original dlopen loader.
I: main.c: This is PulseAudio 0.9.12
D: main.c: Compilation host: i486-pc-linux-gnu
D: main.c: Compilation CFLAGS: -g -O2 -g -Wall -O2 -Wall -W -Wextra -pedantic -pipe -Wno-long-long -Wvla -Wno-overlength-strings -Wconversion -Wundef -Wformat -Wlogical-op -Wpacked -Wformat-security -Wmissing-include-dirs -Wformat-nonliteral -Wold-style-definition -Wdeclaration-after-statement -Wfloat-equal -Wmissing-declarations -Wmissing-prototypes -Wstrict-prototypes -Wredundant-decls -Wmissing-noreturn -Wshadow -Wendif-labels -Wpointer-arith -Wcast-align -Wwrite-strings -Wno-unused-parameter -ffast-math
D: main.c: Running on host: Linux i686 2.6.27-3-generic #1 SMP Wed Sep 10 16:02:00 UTC 2008
I: main.c: Page size is 4096 bytes
D: main.c: Compiled with Valgrind support: no
D: main.c: Optimized build: yes
I: main.c: Machine ID is 26488061d7a163866298020046345cbd.
I: main.c: Using runtime directory /home/dana/.pulse/26488061d7a163866298020046345cbd:runtime.
I: main.c: Using state directory /home/dana/.pulse.
I: main.c: Running in system mode: no
I: main.c: Fresh high-resolution timers available! Bon appetit!

... and here's the output of "schedtool `pidof pulseaudio`":
PID 30294: PRIO 0, POLICY N: SCHED_NORMAL , NICE -11

Fixed in git trunk

This bug was fixed in the package pulseaudio - 0.9.13-2ubuntu5

---------------
pulseaudio (0.9.13-2ubuntu5) jaunty; urgency=low

  [ Daniel T Chen ]
  * Add fixes from git:
    - 0015_use_fionread.patch,
    - 0016_add_pa-source-message-get-latency.patch,
    - 0017_allow_dev_dsp_w-ok.patch,
    - 0018_fix_return_val_pa-frame-aligned.patch,
    - 0019_fix_macro_pa-unlikely.patch,
    - 0020_catch_driver_errors.patch (LP: #312373),
    - 0021_convert_to_pa-bool-t.patch,
    - 0022_fix_return_val_dump-resample-methods.patch,
    - 0023_use_gdbm-nolock.patch,
    - 0024_dont_mix_front-center_into_rear.patch,
    - 0025_drop_cap-nice_properly.patch,
    - 0027_handle_multicast_sdp_with_same_ip_ttl_as_rtp.patch,
    - 0028_prefer_mixer_controls_with_vols.patch (LP: #281605),
    - 0029_add_minor_fixes.patch
  * Forward-port workaround from hardy branch for source/sink and
    suspend-on-idle race (LP: #203654):
    - 0026_work_around_suspend-on-idle_source_sink_race.patch
  * debian/control: Drop padevchooser(Recommends) and pavucontrol
    (Suggests) completely - functionality has been subsumed by
    jaunty's gnome-volume-control.
  * debian/pulseaudio.init:
    - Make initscript more informative in the default case of per-user
      sessions (LP: #259522),
    - Make initscript retry (until three-second timeout) if stopping
      fails when restarting (LP: #244414),
    - LSB {Required-*,Should-*} should specify hal instead of dbus,
      since hal is required (and already requires dbus) (LP: #244679)
  * Previous upload contains patches to close:
    LP: #193491, #268891, #295164, #298301

  [ Luke Yelavich ]
  * 0008_regen_autotools.patch: Pull some libtool 2.2 updates from git,
    and regenerate autotools glue.
  * debian/rules: Add --enable-static to force creation of libpulse.a,
    a side-effect of messing with the autotools files. This shouldn't
    be needed for the 0.9.14 release.

 -- Luke Yelavich <email address hidden> Fri, 09 Jan 2009 17:05:38 +1100