[pulseaudio-commits] [SCM] PulseAudio Sound Server branch, master, updated. v0.9.15-test2-82-g7bc1847

Lennart Poettering gitmailer-noreply at 0pointer.de
Thu Feb 19 18:22:08 PST 2009


This is an automated email from the git hooks/post-receive script. It was
generated because of a push to the "PulseAudio Sound Server" repository.

The master branch has been updated
      from  2e250aaebb7708b25b5342d8ced657364adedc95 (commit)

- Log -----------------------------------------------------------------
7bc1847... Merge branch 'master' of ssh://rootserver/home/lennart/git/public/pulseaudio
26a270a... big alsa module rework to make things more robust to broken sound drivers and make it easier to debug them
adc9c2d... fix comment
fa2e07a... add test tool for debugging broken timing in sound drivers
9f813dd... Make sure we actually call _() for translating profile names
ef189d5... make it easier to debug timing related problems
fdca6ed... make profile names translatable
d69bd03... don't try to use weakref stuff on older compilers that don't really support it
-----------------------------------------------------------------------

Summary of changes:
 src/Makefile.am                                 |   14 +-
 src/modules/alsa/alsa-sink.c                    |  356 +++++++++++++----------
 src/modules/alsa/alsa-source.c                  |  314 ++++++++++++--------
 src/modules/alsa/alsa-util.c                    |   53 +++--
 src/modules/alsa/alsa-util.h                    |    4 +-
 src/modules/alsa/module-alsa-card.c             |   10 +-
 src/modules/bluetooth/module-bluetooth-device.c |    8 +-
 src/pulse/gccmacro.h                            |    2 +-
 src/pulsecore/asyncmsgq.c                       |   10 +-
 src/pulsecore/rtpoll.c                          |   49 +++-
 src/tests/alsa-time-test.c                      |  200 +++++++++++++
 11 files changed, 698 insertions(+), 322 deletions(-)
 create mode 100644 src/tests/alsa-time-test.c

-----------------------------------------------------------------------

commit d69bd0339f77e487bc4db328a892872eb47e4083
Author: Lennart Poettering <lennart at poettering.net>
Date:   Fri Feb 20 00:32:15 2009 +0100

    don't try to use weakref stuff on older compilers that don't really support it

diff --git a/src/pulse/gccmacro.h b/src/pulse/gccmacro.h
index f110a74..58188ee 100644
--- a/src/pulse/gccmacro.h
+++ b/src/pulse/gccmacro.h
@@ -118,7 +118,7 @@
 #endif
 
 #ifndef PA_GCC_WEAKREF
-#ifdef __GNUC__
+#if defined(__GNUC__) && (((__GNUC__ == 4) && (__GNUC_MINOR__ > 1)) || (__GNUC__ > 4))
 /** Macro for usgae of GCC's weakref attribute */
 #define PA_GCC_WEAKREF(x) __attribute__((weakref(#x)));
 #endif

commit fdca6edf20906b151f725b2750dd4733f3eb9c8c
Author: Lennart Poettering <lennart at poettering.net>
Date:   Fri Feb 20 01:18:37 2009 +0100

    make profile names translatable

diff --git a/src/modules/alsa/alsa-sink.c b/src/modules/alsa/alsa-sink.c
index eeac5e7..5290268 100644
--- a/src/modules/alsa/alsa-sink.c
+++ b/src/modules/alsa/alsa-sink.c
@@ -35,6 +35,7 @@
 #include <pulse/xmalloc.h>
 #include <pulse/util.h>
 #include <pulse/timeval.h>
+#include <pulse/i18n.h>
 
 #include <pulsecore/core.h>
 #include <pulsecore/module.h>
@@ -254,9 +255,9 @@ static int mmap_write(struct userdata *u, pa_usec_t *sleep_usec, pa_bool_t polle
         if (PA_UNLIKELY(n <= u->hwbuf_unused_frames)) {
 
             if (polled && pa_log_ratelimit())
-                pa_log("ALSA woke us up to write new data to the device, but there was actually nothing to write! "
-                       "Most likely this is an ALSA driver bug. Please report this issue to the ALSA developers. "
-                       "We were woken up with POLLOUT set -- however a subsequent snd_pcm_avail_update() returned 0.");
+                pa_log(_("ALSA woke us up to write new data to the device, but there was actually nothing to write! "
+                         "Most likely this is an ALSA driver bug. Please report this issue to the ALSA developers. "
+                         "We were woken up with POLLOUT set -- however a subsequent snd_pcm_avail_update() returned 0."));
 
             break;
         }
@@ -377,9 +378,9 @@ static int unix_write(struct userdata *u, pa_usec_t *sleep_usec, pa_bool_t polle
         if (PA_UNLIKELY(n <= u->hwbuf_unused_frames)) {
 
             if (polled && pa_log_ratelimit())
-                pa_log("ALSA woke us up to write new data to the device, but there was actually nothing to write! "
-                       "Most likely this is an ALSA driver bug. Please report this issue to the ALSA developers. "
-                       "We were woken up with POLLOUT set -- however a subsequent snd_pcm_avail_update() returned 0.");
+                pa_log(_("ALSA woke us up to write new data to the device, but there was actually nothing to write! "
+                         "Most likely this is an ALSA driver bug. Please report this issue to the ALSA developers. "
+                         "We were woken up with POLLOUT set -- however a subsequent snd_pcm_avail_update() returned 0."));
 
             break;
         }
diff --git a/src/modules/alsa/alsa-source.c b/src/modules/alsa/alsa-source.c
index 81d7c0b..a5de388 100644
--- a/src/modules/alsa/alsa-source.c
+++ b/src/modules/alsa/alsa-source.c
@@ -35,6 +35,7 @@
 #include <pulse/xmalloc.h>
 #include <pulse/util.h>
 #include <pulse/timeval.h>
+#include <pulse/i18n.h>
 
 #include <pulsecore/core-error.h>
 #include <pulsecore/core.h>
@@ -240,9 +241,9 @@ static int mmap_read(struct userdata *u, pa_usec_t *sleep_usec, pa_bool_t polled
         if (PA_UNLIKELY(n <= 0)) {
 
             if (polled && pa_log_ratelimit())
-                pa_log("ALSA woke us up to read new data from the device, but there was actually nothing to read! "
-                       "Most likely this is an ALSA driver bug. Please report this issue to the ALSA developers. "
-                       "We were woken up with POLLIN set -- however a subsequent snd_pcm_avail_update() returned 0.");
+                pa_log(_("ALSA woke us up to read new data from the device, but there was actually nothing to read! "
+                         "Most likely this is an ALSA driver bug. Please report this issue to the ALSA developers. "
+                         "We were woken up with POLLIN set -- however a subsequent snd_pcm_avail_update() returned 0."));
 
             break;
         }
@@ -348,9 +349,9 @@ static int unix_read(struct userdata *u, pa_usec_t *sleep_usec, pa_bool_t polled
         if (PA_UNLIKELY(n <= 0)) {
 
             if (polled && pa_log_ratelimit())
-                pa_log("ALSA woke us up to read new data from the device, but there was actually nothing to read! "
-                       "Most likely this is an ALSA driver bug. Please report this issue to the ALSA developers. "
-                       "We were woken up with POLLIN set -- however a subsequent snd_pcm_avail_update() returned 0.");
+                pa_log(_("ALSA woke us up to read new data from the device, but there was actually nothing to read! "
+                         "Most likely this is an ALSA driver bug. Please report this issue to the ALSA developers. "
+                         "We were woken up with POLLIN set -- however a subsequent snd_pcm_avail_update() returned 0."));
 
             return work_done;
         }
diff --git a/src/modules/alsa/alsa-util.c b/src/modules/alsa/alsa-util.c
index 1bb7ddf..95e872b 100644
--- a/src/modules/alsa/alsa-util.c
+++ b/src/modules/alsa/alsa-util.c
@@ -32,6 +32,7 @@
 #include <pulse/xmalloc.h>
 #include <pulse/timeval.h>
 #include <pulse/util.h>
+#include <pulse/i18n.h>
 
 #include <pulsecore/log.h>
 #include <pulsecore/macro.h>
@@ -501,39 +502,39 @@ int pa_alsa_set_sw_params(snd_pcm_t *pcm, snd_pcm_uframes_t avail_min) {
 static const struct pa_alsa_profile_info device_table[] = {
     {{ 1, { PA_CHANNEL_POSITION_MONO }},
      "hw",
-     "Analog Mono",
+     N_("Analog Mono"),
      "analog-mono",
      1 },
 
     {{ 2, { PA_CHANNEL_POSITION_LEFT, PA_CHANNEL_POSITION_RIGHT }},
      "front",
-     "Analog Stereo",
+     N_("Analog Stereo"),
      "analog-stereo",
      10 },
 
     {{ 2, { PA_CHANNEL_POSITION_LEFT, PA_CHANNEL_POSITION_RIGHT }},
      "iec958",
-     "IEC958 Digital Stereo",
+     N_("Digital Stereo (IEC958)"),
      "iec958-stereo",
      5 },
 
     {{ 2, { PA_CHANNEL_POSITION_LEFT, PA_CHANNEL_POSITION_RIGHT }},
      "hdmi",
-     "HDMI Digital Stereo",
+     N_("Digital Stereo (HDMI)"),
      "hdmi-stereo",
      4 },
 
     {{ 4, { PA_CHANNEL_POSITION_FRONT_LEFT, PA_CHANNEL_POSITION_FRONT_RIGHT,
             PA_CHANNEL_POSITION_REAR_LEFT, PA_CHANNEL_POSITION_REAR_RIGHT }},
      "surround40",
-     "Analog Surround 4.0",
+     N_("Analog Surround 4.0"),
      "analog-surround-40",
      7 },
 
     {{ 4, { PA_CHANNEL_POSITION_FRONT_LEFT, PA_CHANNEL_POSITION_FRONT_RIGHT,
             PA_CHANNEL_POSITION_REAR_LEFT, PA_CHANNEL_POSITION_REAR_RIGHT }},
      "a52",
-     "IEC958/AC3 Digital Surround 4.0",
+     N_("Digital Surround 4.0 (IEC958/AC3)"),
      "iec958-ac3-surround-40",
      2 },
 
@@ -541,7 +542,7 @@ static const struct pa_alsa_profile_info device_table[] = {
             PA_CHANNEL_POSITION_REAR_LEFT, PA_CHANNEL_POSITION_REAR_RIGHT,
             PA_CHANNEL_POSITION_LFE }},
      "surround41",
-     "Analog Surround 4.1",
+     N_("Analog Surround 4.1"),
      "analog-surround-41",
      7 },
 
@@ -549,7 +550,7 @@ static const struct pa_alsa_profile_info device_table[] = {
             PA_CHANNEL_POSITION_REAR_LEFT, PA_CHANNEL_POSITION_REAR_RIGHT,
             PA_CHANNEL_POSITION_CENTER }},
      "surround50",
-     "Analog Surround 5.0",
+     N_("Analog Surround 5.0"),
      "analog-surround-50",
      7 },
 
@@ -557,7 +558,7 @@ static const struct pa_alsa_profile_info device_table[] = {
             PA_CHANNEL_POSITION_REAR_LEFT, PA_CHANNEL_POSITION_REAR_RIGHT,
             PA_CHANNEL_POSITION_CENTER, PA_CHANNEL_POSITION_LFE }},
      "surround51",
-     "Analog Surround 5.1",
+     N_("Analog Surround 5.1"),
      "analog-surround-51",
      8 },
 
@@ -565,7 +566,7 @@ static const struct pa_alsa_profile_info device_table[] = {
             PA_CHANNEL_POSITION_FRONT_RIGHT, PA_CHANNEL_POSITION_REAR_LEFT,
             PA_CHANNEL_POSITION_REAR_RIGHT, PA_CHANNEL_POSITION_LFE}},
      "a52",
-     "IEC958/AC3 Digital Surround 5.1",
+     N_("Digital Surround 5.1 (IEC958/AC3)"),
      "iec958-ac3-surround-51",
      3 },
 
@@ -574,7 +575,7 @@ static const struct pa_alsa_profile_info device_table[] = {
             PA_CHANNEL_POSITION_CENTER, PA_CHANNEL_POSITION_LFE,
             PA_CHANNEL_POSITION_SIDE_LEFT, PA_CHANNEL_POSITION_SIDE_RIGHT }},
      "surround71",
-     "Analog Surround 7.1",
+     N_("Analog Surround 7.1"),
      "analog-surround-71",
      7 },
 
@@ -1553,8 +1554,8 @@ snd_pcm_sframes_t pa_alsa_safe_avail_update(snd_pcm_t *pcm, size_t hwbuf_size, c
 
     if (k >= hwbuf_size * 3 ||
         k >= pa_bytes_per_second(ss)*10)
-        pa_log("snd_pcm_avail_update() returned a value that is exceptionally large: %lu bytes (%lu ms). "
-               "Most likely this is an ALSA driver bug. Please report this issue to the ALSA developers.",
+        pa_log(_("snd_pcm_avail_update() returned a value that is exceptionally large: %lu bytes (%lu ms). "
+                 "Most likely this is an ALSA driver bug. Please report this issue to the ALSA developers."),
                (unsigned long) k, (unsigned long) (pa_bytes_to_usec(k, ss) / PA_USEC_PER_MSEC));
 
     return n;
@@ -1585,8 +1586,8 @@ int pa_alsa_safe_mmap_begin(snd_pcm_t *pcm, const snd_pcm_channel_area_t **areas
         k >= hwbuf_size * 3 ||
         k >= pa_bytes_per_second(ss)*10)
 
-        pa_log("snd_pcm_mmap_begin() returned a value that is exceptionally large: %lu bytes (%lu ms). "
-               "Most likely this is an ALSA driver bug. Please report this issue to the ALSA developers.",
+        pa_log(_("snd_pcm_mmap_begin() returned a value that is exceptionally large: %lu bytes (%lu ms). "
+                 "Most likely this is an ALSA driver bug. Please report this issue to the ALSA developers."),
                (unsigned long) k, (unsigned long) (pa_bytes_to_usec(k, ss) / PA_USEC_PER_MSEC));
 
     return r;
diff --git a/src/modules/alsa/alsa-util.h b/src/modules/alsa/alsa-util.h
index 9eab644..79d0999 100644
--- a/src/modules/alsa/alsa-util.h
+++ b/src/modules/alsa/alsa-util.h
@@ -59,7 +59,7 @@ int pa_alsa_find_mixer_and_elem(snd_pcm_t *pcm, snd_mixer_t **_m, snd_mixer_elem
 typedef struct pa_alsa_profile_info {
     pa_channel_map map;
     const char *alsa_name;
-    const char *description;
+    const char *description; /* internationalized */
     const char *name;
     unsigned priority;
 } pa_alsa_profile_info;
diff --git a/src/modules/bluetooth/module-bluetooth-device.c b/src/modules/bluetooth/module-bluetooth-device.c
index 6daae83..27f9e7c 100644
--- a/src/modules/bluetooth/module-bluetooth-device.c
+++ b/src/modules/bluetooth/module-bluetooth-device.c
@@ -33,6 +33,8 @@
 #include <pulse/xmalloc.h>
 #include <pulse/timeval.h>
 #include <pulse/sample.h>
+#include <pulse/i18n.h>
+
 #include <pulsecore/module.h>
 #include <pulsecore/modargs.h>
 #include <pulsecore/core-util.h>
@@ -1655,7 +1657,7 @@ static int add_card(struct userdata *u, const char * default_profile) {
     data.profiles = pa_hashmap_new(pa_idxset_string_hash_func, pa_idxset_string_compare_func);
 
     if (u->device->audio_sink_info_valid > 0) {
-        p = pa_card_profile_new("a2dp", "A2DP Advanced Audio Distribution Profile", sizeof(enum profile));
+        p = pa_card_profile_new("a2dp", _("High Fidelity Playback (A2DP)"), sizeof(enum profile));
         p->priority = 10;
         p->n_sinks = 1;
         p->n_sources = 0;
@@ -1669,7 +1671,7 @@ static int add_card(struct userdata *u, const char * default_profile) {
     }
 
     if (u->device->headset_info_valid > 0) {
-        p = pa_card_profile_new("hsp", "HSP/HFP Headset/Hands-Free Profile", sizeof(enum profile));
+        p = pa_card_profile_new("hsp", _("Telephony Duplex (HSP/HFP)"), sizeof(enum profile));
         p->priority = 20;
         p->n_sinks = 1;
         p->n_sources = 1;
@@ -1684,7 +1686,7 @@ static int add_card(struct userdata *u, const char * default_profile) {
 
     pa_assert(!pa_hashmap_isempty(data.profiles));
 
-    p = pa_card_profile_new("off", "Off", sizeof(enum profile));
+    p = pa_card_profile_new("off", _("Off"), sizeof(enum profile));
     d = PA_CARD_PROFILE_DATA(p);
     *d = PROFILE_OFF;
     pa_hashmap_put(data.profiles, p->name, p);

commit ef189d50a7357a7f158c9d6f4e59a0f32fcaa92d
Author: Lennart Poettering <lennart at poettering.net>
Date:   Fri Feb 20 03:16:54 2009 +0100

    make it easier to debug timing related problems

diff --git a/src/pulsecore/rtpoll.c b/src/pulsecore/rtpoll.c
index 183d97c..01dfd62 100644
--- a/src/pulsecore/rtpoll.c
+++ b/src/pulsecore/rtpoll.c
@@ -50,29 +50,39 @@
 #include <pulsecore/rtsig.h>
 #include <pulsecore/flist.h>
 #include <pulsecore/core-util.h>
-
 #include <pulsecore/winsock.h>
+#include <pulsecore/ratelimit.h>
 
 #include "rtpoll.h"
 
+/* #define DEBUG_TIMING */
+
 struct pa_rtpoll {
     struct pollfd *pollfd, *pollfd2;
     unsigned n_pollfd_alloc, n_pollfd_used;
 
-    pa_bool_t timer_enabled;
     struct timeval next_elapse;
+    pa_bool_t timer_enabled:1;
 
-    pa_bool_t scan_for_dead;
-    pa_bool_t running, installed, rebuild_needed, quit;
+    pa_bool_t scan_for_dead:1;
+    pa_bool_t running:1;
+    pa_bool_t installed:1;
+    pa_bool_t rebuild_needed:1;
+    pa_bool_t quit:1;
 
 #ifdef HAVE_PPOLL
+    pa_bool_t timer_armed:1;
+#ifdef __linux__
+    pa_bool_t dont_use_ppoll:1;
+#endif
     int rtsig;
     sigset_t sigset_unblocked;
     timer_t timer;
-    pa_bool_t timer_armed;
-#ifdef __linux__
-    pa_bool_t dont_use_ppoll;
 #endif
+
+#ifdef DEBUG_TIMING
+    pa_usec_t timestamp;
+    pa_usec_t slept, awake;
 #endif
 
     PA_LLIST_HEAD(pa_rtpoll_item, items);
@@ -149,6 +159,11 @@ pa_rtpoll *pa_rtpoll_new(void) {
 
     PA_LLIST_HEAD_INIT(pa_rtpoll_item, p->items);
 
+#ifdef DEBUG_TIMING
+    p->timestamp = pa_rtclock_usec();
+    p->slept = p->awake = 0;
+#endif
+
     return p;
 }
 
@@ -377,6 +392,14 @@ int pa_rtpoll_run(pa_rtpoll *p, pa_bool_t wait) {
             pa_timeval_add(&timeout, pa_timeval_diff(&p->next_elapse, &now));
     }
 
+#ifdef DEBUG_TIMING
+    {
+        pa_usec_t now = pa_rtclock_usec();
+        p->awake = now - p->timestamp;
+        p->timestamp = now;
+    }
+#endif
+
     /* OK, now let's sleep */
 #ifdef HAVE_PPOLL
 
@@ -396,6 +419,18 @@ int pa_rtpoll_run(pa_rtpoll *p, pa_bool_t wait) {
 #endif
         r = poll(p->pollfd, p->n_pollfd_used, (!wait || p->quit || p->timer_enabled) ? (int) ((timeout.tv_sec*1000) + (timeout.tv_usec / 1000)) : -1);
 
+#ifdef DEBUG_TIMING
+    {
+        pa_usec_t now = pa_rtclock_usec();
+        p->slept = now - p->timestamp;
+        p->timestamp = now;
+
+        pa_log("Process time %llu ms; sleep time %llu ms",
+               (unsigned long long) (p->awake / PA_USEC_PER_MSEC),
+               (unsigned long long) (p->slept / PA_USEC_PER_MSEC));
+    }
+#endif
+
     if (r < 0) {
         if (errno == EAGAIN || errno == EINTR)
             r = 0;

commit 9f813dd5b306e59b40c5c88c52406638a8062749
Author: Lennart Poettering <lennart at poettering.net>
Date:   Fri Feb 20 03:17:53 2009 +0100

    Make sure we actually call _() for translating profile names

diff --git a/src/modules/alsa/module-alsa-card.c b/src/modules/alsa/module-alsa-card.c
index e63414e..e517ddc 100644
--- a/src/modules/alsa/module-alsa-card.c
+++ b/src/modules/alsa/module-alsa-card.c
@@ -24,6 +24,8 @@
 #endif
 
 #include <pulse/xmalloc.h>
+#include <pulse/i18n.h>
+
 #include <pulsecore/core-util.h>
 #include <pulsecore/modargs.h>
 #include <pulsecore/queue.h>
@@ -104,14 +106,14 @@ static void enumerate_cb(
 
     if (sink && source) {
         n = pa_sprintf_malloc("output-%s+input-%s", sink->name, source->name);
-        t = pa_sprintf_malloc("Output %s + Input %s", sink->description, source->description);
+        t = pa_sprintf_malloc(_("Output %s + Input %s"), sink->description, _(source->description));
     } else if (sink) {
         n = pa_sprintf_malloc("output-%s", sink->name);
-        t = pa_sprintf_malloc("Output %s", sink->description);
+        t = pa_sprintf_malloc(_("Output %s"), _(sink->description));
     } else {
         pa_assert(source);
         n = pa_sprintf_malloc("input-%s", source->name);
-        t = pa_sprintf_malloc("Input %s", source->description);
+        t = pa_sprintf_malloc(_("Input %s"), _(source->description));
     }
 
     pa_log_info("Found output profile '%s'", t);
@@ -142,7 +144,7 @@ static void add_disabled_profile(pa_hashmap *profiles) {
     pa_card_profile *p;
     struct profile_data *d;
 
-    p = pa_card_profile_new("off", "Off", sizeof(struct profile_data));
+    p = pa_card_profile_new("off", _("Off"), sizeof(struct profile_data));
 
     d = PA_CARD_PROFILE_DATA(p);
     d->sink_profile = d->source_profile = NULL;

commit fa2e07a0bd4d02280c397099b612ce4d56673c10
Author: Lennart Poettering <lennart at poettering.net>
Date:   Fri Feb 20 03:19:33 2009 +0100

    add test tool for debugging broken timing in sound drivers

diff --git a/src/Makefile.am b/src/Makefile.am
index f385c0a..ceafdf7 100644
--- a/src/Makefile.am
+++ b/src/Makefile.am
@@ -313,6 +313,11 @@ TESTS_BINARIES += \
 		gtk-test
 endif
 
+if HAVE_ALSA
+TESTS_BINARIES += \
+		alsa-time-test
+endif
+
 if BUILD_TESTS_DEFAULT
 noinst_PROGRAMS = $(TESTS_BINARIES)
 else
@@ -514,6 +519,11 @@ gtk_test_LDADD = $(AM_LDADD) libpulse.la libpulse-mainloop-glib.la
 gtk_test_CFLAGS = $(AM_CFLAGS) $(GTK20_CFLAGS)
 gtk_test_LDFLAGS = $(AM_LDFLAGS) $(BINLDFLAGS) $(GTK20_LIBS)
 
+alsa_time_test_SOURCES = tests/alsa-time-test.c
+alsa_time_test_LDADD = $(AM_LDADD)
+alsa_time_test_CFLAGS = $(AM_CFLAGS) $(ASOUNDLIB_CFLAGS)
+alsa_time_test_LDFLAGS = $(AM_LDFLAGS) $(BINLDFLAGS) $(ASOUNDLIB_LIBS)
+
 ###################################
 #         Common library          #
 ###################################
@@ -960,6 +970,8 @@ modlibexec_LTLIBRARIES += \
 		module-oss.la
 endif
 
+pulselibexec_PROGRAMS =
+
 if HAVE_ALSA
 modlibexec_LTLIBRARIES += \
 		libalsa-util.la \
@@ -995,8 +1007,6 @@ modlibexec_LTLIBRARIES += \
 		module-jack-source.la
 endif
 
-pulselibexec_PROGRAMS =
-
 if HAVE_GCONF
 modlibexec_LTLIBRARIES += \
 		module-gconf.la
diff --git a/src/tests/alsa-time-test.c b/src/tests/alsa-time-test.c
new file mode 100644
index 0000000..3858bf7
--- /dev/null
+++ b/src/tests/alsa-time-test.c
@@ -0,0 +1,200 @@
+#include <assert.h>
+#include <inttypes.h>
+#include <time.h>
+
+#include <alsa/asoundlib.h>
+
+static uint64_t timespec_us(const struct timespec *ts) {
+    return
+        ts->tv_sec * 1000000LLU +
+        ts->tv_nsec / 1000LLU;
+}
+
+int main(int argc, char *argv[]) {
+    const char *dev;
+    int r;
+    snd_pcm_hw_params_t *hwparams;
+    snd_pcm_sw_params_t *swparams;
+    snd_pcm_status_t *status;
+    snd_pcm_t *pcm;
+    unsigned rate = 44100;
+    unsigned periods = 0;
+    snd_pcm_uframes_t boundary, buffer_size = 44100/10; /* 100s */
+    int dir = 1;
+    struct timespec start, last_timestamp = { 0, 0 };
+    uint64_t start_us;
+    snd_pcm_sframes_t last_avail, last_delay;
+    struct pollfd *pollfds;
+    int n_pollfd;
+    int64_t sample_count = 0;
+
+    snd_pcm_hw_params_alloca(&hwparams);
+    snd_pcm_sw_params_alloca(&swparams);
+    snd_pcm_status_alloca(&status);
+
+    r = clock_gettime(CLOCK_MONOTONIC, &start);
+    assert(r == 0);
+
+    start_us = timespec_us(&start);
+
+    dev = argc > 1 ? argv[1] : "front:AudioPCI";
+
+    r = snd_pcm_open(&pcm, dev, SND_PCM_STREAM_PLAYBACK, 0);
+    assert(r == 0);
+
+    r = snd_pcm_hw_params_any(pcm, hwparams);
+    assert(r == 0);
+
+    r = snd_pcm_hw_params_set_rate_resample(pcm, hwparams, 0);
+    assert(r == 0);
+
+    r = snd_pcm_hw_params_set_access(pcm, hwparams, SND_PCM_ACCESS_RW_INTERLEAVED);
+    assert(r == 0);
+
+    r = snd_pcm_hw_params_set_format(pcm, hwparams, SND_PCM_FORMAT_S16_LE);
+    assert(r == 0);
+
+    r = snd_pcm_hw_params_set_rate_near(pcm, hwparams, &rate, NULL);
+    assert(r == 0);
+
+    r = snd_pcm_hw_params_set_channels(pcm, hwparams, 2);
+    assert(r == 0);
+
+    r = snd_pcm_hw_params_set_periods_integer(pcm, hwparams);
+    assert(r == 0);
+
+    r = snd_pcm_hw_params_set_periods_near(pcm, hwparams, &periods, &dir);
+    assert(r == 0);
+
+    r = snd_pcm_hw_params_set_buffer_size_near(pcm, hwparams, &buffer_size);
+    assert(r == 0);
+
+    r = snd_pcm_hw_params(pcm, hwparams);
+    assert(r == 0);
+
+    r = snd_pcm_hw_params_current(pcm, hwparams);
+    assert(r == 0);
+
+    r = snd_pcm_sw_params_set_avail_min(pcm, swparams, 1);
+    assert(r == 0);
+
+    r = snd_pcm_sw_params_set_period_event(pcm, swparams, 1);
+    assert(r == 0);
+
+    r = snd_pcm_hw_params_get_buffer_size(hwparams, &buffer_size);
+    assert(r == 0);
+    r = snd_pcm_sw_params_set_start_threshold(pcm, swparams, buffer_size);
+    assert(r == 0);
+
+    r = snd_pcm_sw_params_get_boundary(swparams, &boundary);
+    assert(r == 0);
+    r = snd_pcm_sw_params_set_stop_threshold(pcm, swparams, boundary);
+    assert(r == 0);
+
+    r = snd_pcm_sw_params_set_tstamp_mode(pcm, swparams, SND_PCM_TSTAMP_ENABLE);
+    assert(r == 0);
+
+    r = snd_pcm_sw_params(pcm, swparams);
+    assert(r == 0);
+
+    r = snd_pcm_prepare(pcm);
+    assert(r == 0);
+
+    r = snd_pcm_sw_params_current(pcm, swparams);
+    assert(r == 0);
+
+/*     assert(snd_pcm_hw_params_is_monotonic(hwparams) > 0); */
+
+    n_pollfd = snd_pcm_poll_descriptors_count(pcm);
+    assert(n_pollfd > 0);
+
+    pollfds = malloc(sizeof(struct pollfd) * n_pollfd);
+    assert(pollfds);
+
+    r = snd_pcm_poll_descriptors(pcm, pollfds, n_pollfd);
+    assert(r == n_pollfd);
+
+    for (;;) {
+        snd_pcm_sframes_t avail, delay;
+/*         snd_pcm_uframes_t avail2; */
+        struct timespec now, timestamp;
+        unsigned short revents;
+        int written = 0;
+        uint64_t now_us, timestamp_us;
+        snd_pcm_state_t state;
+
+        r = poll(pollfds, n_pollfd, 0);
+        assert(r >= 0);
+
+        r = snd_pcm_poll_descriptors_revents(pcm, pollfds, n_pollfd, &revents);
+        assert(r == 0);
+
+        assert((revents & ~POLLOUT) == 0);
+
+/*         state = snd_pcm_get_state(pcm); */
+
+        avail = snd_pcm_avail(pcm);
+        assert(avail >= 0);
+
+        r = snd_pcm_status(pcm, status);
+        assert(r == 0);
+
+        printf("%lu %lu\n", (unsigned long) avail, (unsigned long) snd_pcm_status_get_avail(status));
+
+        assert(avail == (snd_pcm_sframes_t) snd_pcm_status_get_avail(status));
+        snd_pcm_status_get_htstamp(status, &timestamp);
+        delay = snd_pcm_status_get_delay(status);
+        state = snd_pcm_status_get_state(status);
+
+/*         r = snd_pcm_avail_delay(pcm, &avail, &delay); */
+/*         assert(r == 0); */
+
+/*         r = snd_pcm_htimestamp(pcm, &avail2, &timestamp); */
+/*         assert(r == 0); */
+
+/*         assert(avail == (snd_pcm_sframes_t) avail2); */
+
+        r = clock_gettime(CLOCK_MONOTONIC, &now);
+        assert(r == 0);
+
+        assert(!revents || avail > 0);
+
+        if (avail) {
+            snd_pcm_sframes_t sframes;
+            static const uint16_t samples[2] = { 0, 0 };
+
+            sframes = snd_pcm_writei(pcm, samples, 1);
+            assert(sframes == 1);
+
+            written = 1;
+            sample_count++;
+        }
+
+        if (!written &&
+            memcmp(&timestamp, &last_timestamp, sizeof(timestamp)) == 0 &&
+            avail == last_avail &&
+            delay == last_delay) {
+            /* This is boring */
+            continue;
+        }
+
+        now_us = timespec_us(&now);
+        timestamp_us = timespec_us(&timestamp);
+
+        printf("%llu\t%llu\t%llu\t%li\t%li\t%i\t%i\t%i\n",
+               (unsigned long long) (now_us - start_us),
+               (unsigned long long) (timestamp_us ? timestamp_us - start_us : 0),
+               (unsigned long long) ((sample_count - 1 - delay) * 1000000LU / 44100),
+               (signed long) avail,
+               (signed long) delay,
+               revents,
+               written,
+               state);
+
+        last_avail = avail;
+        last_delay = delay;
+        last_timestamp = timestamp;
+    }
+
+    return 0;
+}

commit adc9c2db6b4820be4d44faae4b0e523468cd3c14
Author: Lennart Poettering <lennart at poettering.net>
Date:   Fri Feb 20 03:20:36 2009 +0100

    fix comment

diff --git a/src/pulsecore/asyncmsgq.c b/src/pulsecore/asyncmsgq.c
index 5c7af2a..e191b05 100644
--- a/src/pulsecore/asyncmsgq.c
+++ b/src/pulsecore/asyncmsgq.c
@@ -159,7 +159,7 @@ int pa_asyncmsgq_send(pa_asyncmsgq *a, pa_msgobject *object, int code, const voi
 
     pa_assert_se(i.semaphore);
 
-    /* Thus mutex makes the queue multiple-writer safe. This lock is only used on the writing side */
+    /* This mutex makes the queue multiple-writer safe. This lock is only used on the writing side */
     pa_mutex_lock(a->mutex);
     pa_assert_se(pa_asyncq_push(a->asyncq, &i, TRUE) == 0);
     pa_mutex_unlock(a->mutex);
@@ -196,7 +196,13 @@ int pa_asyncmsgq_get(pa_asyncmsgq *a, pa_msgobject **object, int *code, void **u
     if (chunk)
         *chunk = a->current->memchunk;
 
-/*     pa_log_debug("Get q=%p object=%p (%s) code=%i data=%p chunk.length=%lu", (void*) a, (void*) a->current->object, a->current->object ? a->current->object->parent.type_name : NULL, a->current->code, (void*) a->current->userdata, (unsigned long) a->current->memchunk.length); */
+/*     pa_log_debug("Get q=%p object=%p (%s) code=%i data=%p chunk.length=%lu", */
+/*                  (void*) a, */
+/*                  (void*) a->current->object, */
+/*                  a->current->object ? a->current->object->parent.type_name : NULL, */
+/*                  a->current->code, */
+/*                  (void*) a->current->userdata, */
+/*                  (unsigned long) a->current->memchunk.length); */
 
     return 0;
 }

commit 26a270a934f0f174f7bd7eb89e85301963721deb
Author: Lennart Poettering <lennart at poettering.net>
Date:   Fri Feb 20 03:21:17 2009 +0100

    big alsa module rework to make things more robust to broken sound drivers and make it easier to debug them

diff --git a/src/modules/alsa/alsa-sink.c b/src/modules/alsa/alsa-sink.c
index 5290268..239a9d7 100644
--- a/src/modules/alsa/alsa-sink.c
+++ b/src/modules/alsa/alsa-sink.c
@@ -56,11 +56,13 @@
 #include "alsa-util.h"
 #include "alsa-sink.h"
 
+/* #define DEBUG_TIMING */
+
 #define DEFAULT_DEVICE "default"
 #define DEFAULT_TSCHED_BUFFER_USEC (2*PA_USEC_PER_SEC)            /* 2s */
 #define DEFAULT_TSCHED_WATERMARK_USEC (20*PA_USEC_PER_MSEC)       /* 20ms */
-#define TSCHED_MIN_SLEEP_USEC (3*PA_USEC_PER_MSEC)                /* 3ms */
-#define TSCHED_MIN_WAKEUP_USEC (3*PA_USEC_PER_MSEC)               /* 3ms */
+#define TSCHED_MIN_SLEEP_USEC (10*PA_USEC_PER_MSEC)               /* 10ms */
+#define TSCHED_MIN_WAKEUP_USEC (4*PA_USEC_PER_MSEC)               /* 4ms */
 
 struct userdata {
     pa_core *core;
@@ -78,17 +80,17 @@ struct userdata {
     snd_mixer_elem_t *mixer_elem;
     long hw_volume_max, hw_volume_min;
     long hw_dB_max, hw_dB_min;
-    pa_bool_t hw_dB_supported;
-    pa_bool_t mixer_seperate_channels;
+    pa_bool_t hw_dB_supported:1;
+    pa_bool_t mixer_seperate_channels:1;
     pa_cvolume hardware_volume;
 
-    size_t frame_size, fragment_size, hwbuf_size, tsched_watermark;
+    size_t frame_size, fragment_size, hwbuf_size, tsched_watermark, hwbuf_unused, min_sleep, min_wakeup;
     unsigned nfragments;
     pa_memchunk memchunk;
 
     char *device_name;
 
-    pa_bool_t use_mmap, use_tsched;
+    pa_bool_t use_mmap:1, use_tsched:1;
 
     pa_bool_t first, after_rewind;
 
@@ -97,39 +99,70 @@ struct userdata {
     snd_mixer_selem_channel_id_t mixer_map[SND_MIXER_SCHN_LAST];
 
     pa_smoother *smoother;
-    int64_t frame_index;
+    uint64_t write_count;
     uint64_t since_start;
-
-    snd_pcm_sframes_t hwbuf_unused_frames;
 };
 
 static void userdata_free(struct userdata *u);
 
+static void fix_min_sleep_wakeup(struct userdata *u) {
+    size_t max_use, max_use_2;
+
+    pa_assert(u);
+
+    max_use = u->hwbuf_size - u->hwbuf_unused;
+    max_use_2 = pa_frame_align(max_use/2, &u->sink->sample_spec);
+
+    u->min_sleep = pa_usec_to_bytes(TSCHED_MIN_SLEEP_USEC, &u->sink->sample_spec);
+    u->min_sleep = PA_CLAMP(u->min_sleep, u->frame_size, max_use_2);
+
+    u->min_wakeup = pa_usec_to_bytes(TSCHED_MIN_WAKEUP_USEC, &u->sink->sample_spec);
+    u->min_wakeup = PA_CLAMP(u->min_wakeup, u->frame_size, max_use_2);
+}
+
 static void fix_tsched_watermark(struct userdata *u) {
     size_t max_use;
-    size_t min_sleep, min_wakeup;
     pa_assert(u);
 
-    max_use = u->hwbuf_size - (size_t) u->hwbuf_unused_frames * u->frame_size;
+    max_use = u->hwbuf_size - u->hwbuf_unused;
 
-    min_sleep = pa_usec_to_bytes(TSCHED_MIN_SLEEP_USEC, &u->sink->sample_spec);
-    min_wakeup = pa_usec_to_bytes(TSCHED_MIN_WAKEUP_USEC, &u->sink->sample_spec);
+    if (u->tsched_watermark > max_use - u->min_sleep)
+        u->tsched_watermark = max_use - u->min_sleep;
 
-    if (min_sleep > max_use/2)
-        min_sleep = pa_frame_align(max_use/2, &u->sink->sample_spec);
-    if (min_sleep < u->frame_size)
-        min_sleep = u->frame_size;
+    if (u->tsched_watermark < u->min_wakeup)
+        u->tsched_watermark = u->min_wakeup;
+}
+
+static void adjust_after_underrun(struct userdata *u) {
+    size_t old_watermark;
+    pa_usec_t old_min_latency, new_min_latency;
 
-    if (min_wakeup > max_use/2)
-        min_wakeup = pa_frame_align(max_use/2, &u->sink->sample_spec);
-    if (min_wakeup < u->frame_size)
-        min_wakeup = u->frame_size;
+    pa_assert(u);
 
-    if (u->tsched_watermark > max_use-min_sleep)
-        u->tsched_watermark = max_use-min_sleep;
+    /* First, just try to increase the watermark */
+    old_watermark = u->tsched_watermark;
+    u->tsched_watermark *= 2;
+    fix_tsched_watermark(u);
 
-    if (u->tsched_watermark < min_wakeup)
-        u->tsched_watermark = min_wakeup;
+    if (old_watermark != u->tsched_watermark) {
+        pa_log_notice("Increasing wakeup watermark to %0.2f ms",
+                      (double) pa_bytes_to_usec(u->tsched_watermark, &u->sink->sample_spec) / PA_USEC_PER_MSEC);
+        return;
+    }
+
+    /* Hmm, we cannot increase the watermark any further, hence let's raise the latency */
+    old_min_latency = u->sink->thread_info.min_latency;
+    new_min_latency = PA_MIN(old_min_latency * 2, u->sink->thread_info.max_latency);
+
+    if (old_min_latency != new_min_latency) {
+        pa_log_notice("Increasing minimal latency to %0.2f ms",
+                      (double) new_min_latency / PA_USEC_PER_MSEC);
+
+        pa_sink_update_latency_range(u->sink, new_min_latency, u->sink->thread_info.max_latency);
+        return;
+    }
+
+    /* When we reach this we're officialy fucked! */
 }
 
 static void hw_sleep_time(struct userdata *u, pa_usec_t *sleep_usec, pa_usec_t*process_usec) {
@@ -145,17 +178,20 @@ static void hw_sleep_time(struct userdata *u, pa_usec_t *sleep_usec, pa_usec_t*p
     if (usec == (pa_usec_t) -1)
         usec = pa_bytes_to_usec(u->hwbuf_size, &u->sink->sample_spec);
 
-/*     pa_log_debug("hw buffer time: %u ms", (unsigned) (usec / PA_USEC_PER_MSEC)); */
-
     wm = pa_bytes_to_usec(u->tsched_watermark, &u->sink->sample_spec);
 
-    if (usec >= wm) {
-        *sleep_usec = usec - wm;
-        *process_usec = wm;
-    } else
-        *process_usec = *sleep_usec = usec / 2;
+    if (wm > usec)
+        wm = usec/2;
+
+    *sleep_usec = usec - wm;
+    *process_usec = wm;
 
-/*     pa_log_debug("after watermark: %u ms", (unsigned) (*sleep_usec / PA_USEC_PER_MSEC)); */
+#ifdef DEBUG_TIMING
+    pa_log_debug("Buffer time: %lu ms; Sleep time: %lu ms; Process time: %lu ms",
+                 (unsigned long) (usec / PA_USEC_PER_MSEC),
+                 (unsigned long) (*sleep_usec / PA_USEC_PER_MSEC),
+                 (unsigned long) (*process_usec / PA_USEC_PER_MSEC));
+#endif
 }
 
 static int try_recover(struct userdata *u, const char *call, int err) {
@@ -170,40 +206,45 @@ static int try_recover(struct userdata *u, const char *call, int err) {
     if (err == -EPIPE)
         pa_log_debug("%s: Buffer underrun!", call);
 
-    if ((err = snd_pcm_recover(u->pcm_handle, err, 1)) == 0) {
-        u->first = TRUE;
-        u->since_start = 0;
-        return 0;
+    if ((err = snd_pcm_recover(u->pcm_handle, err, 1)) < 0) {
+        pa_log("%s: %s", call, snd_strerror(err));
+        return -1;
     }
 
-    pa_log("%s: %s", call, snd_strerror(err));
-    return -1;
+    u->first = TRUE;
+    u->since_start = 0;
+    return 0;
 }
 
-static size_t check_left_to_play(struct userdata *u, snd_pcm_sframes_t n) {
+static size_t check_left_to_play(struct userdata *u, size_t n_bytes) {
     size_t left_to_play;
 
-    if ((size_t) n*u->frame_size < u->hwbuf_size)
-        left_to_play = u->hwbuf_size - ((size_t) n*u->frame_size);
-    else
-        left_to_play = 0;
+    /* We use <= instead of < for this check here because an underrun
+     * only happens after the last sample was processed, not already when
+     * it is removed from the buffer. This is particularly important
+     * when block transfer is used. */
 
-    if (left_to_play > 0) {
-/*         pa_log_debug("%0.2f ms left to play", (double) pa_bytes_to_usec(left_to_play, &u->sink->sample_spec) / PA_USEC_PER_MSEC); */
-    } else if (!u->first && !u->after_rewind) {
+    if (n_bytes <= u->hwbuf_size) {
+        left_to_play = u->hwbuf_size - n_bytes;
 
-        if (pa_log_ratelimit())
-            pa_log_info("Underrun!");
+#ifdef DEBUG_TIMING
+        pa_log_debug("%0.2f ms left to play", (double) pa_bytes_to_usec(left_to_play, &u->sink->sample_spec) / PA_USEC_PER_MSEC);
+#endif
 
-        if (u->use_tsched) {
-            size_t old_watermark = u->tsched_watermark;
+    } else {
+        left_to_play = 0;
 
-            u->tsched_watermark *= 2;
-            fix_tsched_watermark(u);
+#ifdef DEBUG_TIMING
+        PA_DEBUG_TRAP;
+#endif
+
+        if (!u->first && !u->after_rewind) {
+
+            if (pa_log_ratelimit())
+                pa_log_info("Underrun!");
 
-            if (old_watermark != u->tsched_watermark)
-                pa_log_notice("Increasing wakeup watermark to %0.2f ms",
-                              (double) pa_bytes_to_usec(u->tsched_watermark, &u->sink->sample_spec) / PA_USEC_PER_MSEC);
+            if (u->use_tsched)
+                adjust_after_underrun(u);
         }
     }
 
@@ -211,7 +252,7 @@ static size_t check_left_to_play(struct userdata *u, snd_pcm_sframes_t n) {
 }
 
 static int mmap_write(struct userdata *u, pa_usec_t *sleep_usec, pa_bool_t polled) {
-    int work_done = 0;
+    pa_bool_t work_done = TRUE;
     pa_usec_t max_sleep_usec = 0, process_usec = 0;
     size_t left_to_play;
 
@@ -223,22 +264,27 @@ static int mmap_write(struct userdata *u, pa_usec_t *sleep_usec, pa_bool_t polle
 
     for (;;) {
         snd_pcm_sframes_t n;
+        size_t n_bytes;
         int r;
 
-        snd_pcm_hwsync(u->pcm_handle);
-
         /* First we determine how many samples are missing to fill the
          * buffer up to 100% */
 
-        if (PA_UNLIKELY((n = pa_alsa_safe_avail_update(u->pcm_handle, u->hwbuf_size, &u->sink->sample_spec)) < 0)) {
+        if (PA_UNLIKELY((n = pa_alsa_safe_avail(u->pcm_handle, u->hwbuf_size, &u->sink->sample_spec)) < 0)) {
 
-            if ((r = try_recover(u, "snd_pcm_avail_update", (int) n)) == 0)
+            if ((r = try_recover(u, "snd_pcm_avail", (int) n)) == 0)
                 continue;
 
             return r;
         }
 
-        left_to_play = check_left_to_play(u, n);
+        n_bytes = (size_t) n * u->frame_size;
+
+#ifdef DEBUG_TIMING
+        pa_log_debug("avail: %lu", (unsigned long) n_bytes);
+#endif
+
+        left_to_play = check_left_to_play(u, n_bytes);
 
         if (u->use_tsched)
 
@@ -249,33 +295,42 @@ static int mmap_write(struct userdata *u, pa_usec_t *sleep_usec, pa_bool_t polle
             * a single hw buffer length. */
 
             if (!polled &&
-                pa_bytes_to_usec(left_to_play, &u->sink->sample_spec) > process_usec+max_sleep_usec/2)
+                pa_bytes_to_usec(left_to_play, &u->sink->sample_spec) > process_usec+max_sleep_usec/2) {
+#ifdef DEBUG_TIMING
+                pa_log_debug("Not filling up, because too early.");
+#endif
                 break;
+            }
 
-        if (PA_UNLIKELY(n <= u->hwbuf_unused_frames)) {
+        if (PA_UNLIKELY(n_bytes <= u->hwbuf_unused)) {
 
             if (polled && pa_log_ratelimit())
                 pa_log(_("ALSA woke us up to write new data to the device, but there was actually nothing to write! "
                          "Most likely this is an ALSA driver bug. Please report this issue to the ALSA developers. "
                          "We were woken up with POLLOUT set -- however a subsequent snd_pcm_avail_update() returned 0."));
 
+#ifdef DEBUG_TIMING
+            pa_log_debug("Not filling up, because not necessary.");
+#endif
             break;
         }
 
-        n -= u->hwbuf_unused_frames;
-
+        n_bytes -= u->hwbuf_unused;
         polled = FALSE;
 
-/*         pa_log_debug("Filling up"); */
+#ifdef DEBUG_TIMING
+        pa_log_debug("Filling up");
+#endif
 
         for (;;) {
             pa_memchunk chunk;
             void *p;
             int err;
             const snd_pcm_channel_area_t *areas;
-            snd_pcm_uframes_t offset, frames = (snd_pcm_uframes_t) n;
+            snd_pcm_uframes_t offset, frames;
             snd_pcm_sframes_t sframes;
 
+            frames = (snd_pcm_uframes_t) (n_bytes / u->frame_size);
 /*             pa_log_debug("%lu frames to write", (unsigned long) frames); */
 
             if (PA_UNLIKELY((err = pa_alsa_safe_mmap_begin(u->pcm_handle, &areas, &offset, &frames, u->hwbuf_size, &u->sink->sample_spec)) < 0)) {
@@ -305,9 +360,6 @@ static int mmap_write(struct userdata *u, pa_usec_t *sleep_usec, pa_bool_t polle
             chunk.index = 0;
 
             pa_sink_render_into_full(u->sink, &chunk);
-
-            /* FIXME: Maybe we can do something to keep this memory block
-             * a little bit longer around? */
             pa_memblock_unref_fixed(chunk.memblock);
 
             if (PA_UNLIKELY((sframes = snd_pcm_mmap_commit(u->pcm_handle, offset, frames)) < 0)) {
@@ -318,26 +370,28 @@ static int mmap_write(struct userdata *u, pa_usec_t *sleep_usec, pa_bool_t polle
                 return r;
             }
 
-            work_done = 1;
+            work_done = TRUE;
 
-            u->frame_index += (int64_t) frames;
+            u->write_count += frames * u->frame_size;
             u->since_start += frames * u->frame_size;
 
-/*             pa_log_debug("wrote %lu frames", (unsigned long) frames); */
+#ifdef DEBUG_TIMING
+            pa_log_debug("Wrote %lu bytes", (unsigned long) (frames * u->frame_size));
+#endif
 
-            if (frames >= (snd_pcm_uframes_t) n)
+            if ((size_t) frames * u->frame_size >= n_bytes)
                 break;
 
-            n -= (snd_pcm_sframes_t) frames;
+            n_bytes -= (size_t) frames * u->frame_size;
         }
     }
 
     *sleep_usec = pa_bytes_to_usec(left_to_play, &u->sink->sample_spec) - process_usec;
-    return work_done;
+    return work_done ? 1 : 0;
 }
 
 static int unix_write(struct userdata *u, pa_usec_t *sleep_usec, pa_bool_t polled) {
-    int work_done = 0;
+    pa_bool_t work_done = FALSE;
     pa_usec_t max_sleep_usec = 0, process_usec = 0;
     size_t left_to_play;
 
@@ -349,19 +403,19 @@ static int unix_write(struct userdata *u, pa_usec_t *sleep_usec, pa_bool_t polle
 
     for (;;) {
         snd_pcm_sframes_t n;
+        size_t n_bytes;
         int r;
 
-        snd_pcm_hwsync(u->pcm_handle);
+        if (PA_UNLIKELY((n = pa_alsa_safe_avail(u->pcm_handle, u->hwbuf_size, &u->sink->sample_spec)) < 0)) {
 
-        if (PA_UNLIKELY((n = pa_alsa_safe_avail_update(u->pcm_handle, u->hwbuf_size, &u->sink->sample_spec)) < 0)) {
-
-            if ((r = try_recover(u, "snd_pcm_avail_update", (int) n)) == 0)
+            if ((r = try_recover(u, "snd_pcm_avail", (int) n)) == 0)
                 continue;
 
             return r;
         }
 
-        left_to_play = check_left_to_play(u, n);
+        n_bytes = (size_t) n * u->frame_size;
+        left_to_play = check_left_to_play(u, n_bytes);
 
         if (u->use_tsched)
 
@@ -375,7 +429,7 @@ static int unix_write(struct userdata *u, pa_usec_t *sleep_usec, pa_bool_t polle
                 pa_bytes_to_usec(left_to_play, &u->sink->sample_spec) > process_usec+max_sleep_usec/2)
                 break;
 
-        if (PA_UNLIKELY(n <= u->hwbuf_unused_frames)) {
+        if (PA_UNLIKELY(n_bytes <= u->hwbuf_unused)) {
 
             if (polled && pa_log_ratelimit())
                 pa_log(_("ALSA woke us up to write new data to the device, but there was actually nothing to write! "
@@ -385,8 +439,7 @@ static int unix_write(struct userdata *u, pa_usec_t *sleep_usec, pa_bool_t polle
             break;
         }
 
-        n -= u->hwbuf_unused_frames;
-
+        n_bytes -= u->hwbuf_unused;
         polled = FALSE;
 
         for (;;) {
@@ -396,14 +449,14 @@ static int unix_write(struct userdata *u, pa_usec_t *sleep_usec, pa_bool_t polle
 /*         pa_log_debug("%lu frames to write", (unsigned long) frames); */
 
             if (u->memchunk.length <= 0)
-                pa_sink_render(u->sink, (size_t) n * u->frame_size, &u->memchunk);
+                pa_sink_render(u->sink, n_bytes, &u->memchunk);
 
             pa_assert(u->memchunk.length > 0);
 
             frames = (snd_pcm_sframes_t) (u->memchunk.length / u->frame_size);
 
-            if (frames > n)
-                frames = n;
+            if (frames > (snd_pcm_sframes_t) (n_bytes/u->frame_size))
+                frames = (snd_pcm_sframes_t) (n_bytes/u->frame_size);
 
             p = pa_memblock_acquire(u->memchunk.memblock);
             frames = snd_pcm_writei(u->pcm_handle, (const uint8_t*) p + u->memchunk.index, (snd_pcm_uframes_t) frames);
@@ -427,30 +480,29 @@ static int unix_write(struct userdata *u, pa_usec_t *sleep_usec, pa_bool_t polle
                 pa_memchunk_reset(&u->memchunk);
             }
 
-            work_done = 1;
+            work_done = TRUE;
 
-            u->frame_index += frames;
-            u->since_start += (size_t) frames * u->frame_size;
+            u->write_count += frames * u->frame_size;
+            u->since_start += frames * u->frame_size;
 
 /*         pa_log_debug("wrote %lu frames", (unsigned long) frames); */
 
-            if (frames >= n)
+            if ((size_t) frames * u->frame_size >= n_bytes)
                 break;
 
-            n -= frames;
+            n_bytes -= (size_t) frames * u->frame_size;
         }
     }
 
     *sleep_usec = pa_bytes_to_usec(left_to_play, &u->sink->sample_spec) - process_usec;
-    return work_done;
+    return work_done ? 1 : 0;
 }
 
 static void update_smoother(struct userdata *u) {
-    snd_pcm_sframes_t delay  = 0;
-    int64_t frames;
+    snd_pcm_sframes_t delay = 0;
+    int64_t position;
     int err;
-    pa_usec_t now1, now2;
-/*     struct timeval timestamp; */
+    pa_usec_t now1 = 0, now2;
     snd_pcm_status_t *status;
 
     snd_pcm_status_alloca(&status);
@@ -460,36 +512,35 @@ static void update_smoother(struct userdata *u) {
 
     /* Let's update the time smoother */
 
-    snd_pcm_hwsync(u->pcm_handle);
-    snd_pcm_avail_update(u->pcm_handle);
-
-/*     if (PA_UNLIKELY((err = snd_pcm_status(u->pcm_handle, status)) < 0)) { */
-/*         pa_log("Failed to query DSP status data: %s", snd_strerror(err)); */
-/*         return; */
-/*     } */
-
-/*     delay = snd_pcm_status_get_delay(status); */
-
     if (PA_UNLIKELY((err = snd_pcm_delay(u->pcm_handle, &delay)) < 0)) {
-        pa_log("Failed to query DSP status data: %s", snd_strerror(err));
+        pa_log_warn("Failed to query DSP status data: %s", snd_strerror(err));
         return;
     }
 
-    frames = u->frame_index - delay;
+    if (PA_UNLIKELY((err = snd_pcm_status(u->pcm_handle, status)) < 0))
+        pa_log_warn("Failed to get timestamp: %s", snd_strerror(err));
+    else {
+        snd_htimestamp_t htstamp = { 0, 0 };
+        snd_pcm_status_get_htstamp(status, &htstamp);
+        now1 = pa_timespec_load(&htstamp);
+    }
 
-/*     pa_log_debug("frame_index = %llu, delay = %llu, p = %llu", (unsigned long long) u->frame_index, (unsigned long long) delay, (unsigned long long) frames); */
+    position = (int64_t) u->write_count - ((int64_t) delay * (int64_t) u->frame_size);
 
-/*     snd_pcm_status_get_tstamp(status, &timestamp); */
-/*     pa_rtclock_from_wallclock(&timestamp); */
-/*     now1 = pa_timeval_load(&timestamp); */
+    if (PA_UNLIKELY(position < 0))
+        position = 0;
+
+    /* Hmm, if the timestamp is 0, then it wasn't set and we take the current time */
+    if (now1 <= 0)
+        now1 = pa_rtclock_usec();
+
+    now2 = pa_bytes_to_usec((uint64_t) position, &u->sink->sample_spec);
 
-    now1 = pa_rtclock_usec();
-    now2 = pa_bytes_to_usec((uint64_t) frames * u->frame_size, &u->sink->sample_spec);
     pa_smoother_put(u->smoother, now1, now2);
 }
 
 static pa_usec_t sink_get_latency(struct userdata *u) {
-    pa_usec_t r = 0;
+    pa_usec_t r;
     int64_t delay;
     pa_usec_t now1, now2;
 
@@ -498,10 +549,9 @@ static pa_usec_t sink_get_latency(struct userdata *u) {
     now1 = pa_rtclock_usec();
     now2 = pa_smoother_get(u->smoother, now1);
 
-    delay = (int64_t) pa_bytes_to_usec((uint64_t) u->frame_index * u->frame_size, &u->sink->sample_spec) - (int64_t) now2;
+    delay = (int64_t) pa_bytes_to_usec(u->write_count, &u->sink->sample_spec) - (int64_t) now2;
 
-    if (delay > 0)
-        r = (pa_usec_t) delay;
+    r = delay >= 0 ? (pa_usec_t) delay : 0;
 
     if (u->memchunk.memblock)
         r += pa_bytes_to_usec(u->memchunk.length, &u->sink->sample_spec);
@@ -550,7 +600,7 @@ static int update_sw_params(struct userdata *u) {
     pa_assert(u);
 
     /* Use the full buffer if noone asked us for anything specific */
-    u->hwbuf_unused_frames = 0;
+    u->hwbuf_unused = 0;
 
     if (u->use_tsched) {
         pa_usec_t latency;
@@ -558,7 +608,7 @@ static int update_sw_params(struct userdata *u) {
         if ((latency = pa_sink_get_requested_latency_within_thread(u->sink)) != (pa_usec_t) -1) {
             size_t b;
 
-            pa_log_debug("latency set to %0.2fms", (double) latency / PA_USEC_PER_MSEC);
+            pa_log_debug("Latency set to %0.2fms", (double) latency / PA_USEC_PER_MSEC);
 
             b = pa_usec_to_bytes(latency, &u->sink->sample_spec);
 
@@ -567,18 +617,17 @@ static int update_sw_params(struct userdata *u) {
             if (PA_UNLIKELY(b < u->frame_size))
                 b = u->frame_size;
 
-            u->hwbuf_unused_frames = (snd_pcm_sframes_t)
-                (PA_LIKELY(b < u->hwbuf_size) ?
-                 ((u->hwbuf_size - b) / u->frame_size) : 0);
+            u->hwbuf_unused = PA_LIKELY(b < u->hwbuf_size) ? (u->hwbuf_size - b) : 0;
         }
 
+        fix_min_sleep_wakeup(u);
         fix_tsched_watermark(u);
     }
 
-    pa_log_debug("hwbuf_unused_frames=%lu", (unsigned long) u->hwbuf_unused_frames);
+    pa_log_debug("hwbuf_unused=%lu", (unsigned long) u->hwbuf_unused);
 
     /* We need at last one frame in the used part of the buffer */
-    avail_min = (snd_pcm_uframes_t) u->hwbuf_unused_frames + 1;
+    avail_min = (snd_pcm_uframes_t) u->hwbuf_unused / u->frame_size + 1;
 
     if (u->use_tsched) {
         pa_usec_t sleep_usec, process_usec;
@@ -594,7 +643,7 @@ static int update_sw_params(struct userdata *u) {
         return err;
     }
 
-    pa_sink_set_max_request(u->sink, u->hwbuf_size - (size_t) u->hwbuf_unused_frames * u->frame_size);
+    pa_sink_set_max_request(u->sink, u->hwbuf_size - u->hwbuf_unused);
 
     return 0;
 }
@@ -655,8 +704,6 @@ static int unsuspend(struct userdata *u) {
     if (build_pollfd(u) < 0)
         goto fail;
 
-    /* FIXME: We need to reload the volume somehow */
-
     u->first = TRUE;
     u->since_start = 0;
 
@@ -981,13 +1028,13 @@ static void sink_set_mute_cb(pa_sink *s) {
 
 static void sink_update_requested_latency_cb(pa_sink *s) {
     struct userdata *u = s->userdata;
-    snd_pcm_sframes_t before;
+    size_t before;
     pa_assert(u);
 
     if (!u->pcm_handle)
         return;
 
-    before = u->hwbuf_unused_frames;
+    before = u->hwbuf_unused;
     update_sw_params(u);
 
     /* Let's check whether we now use only a smaller part of the
@@ -996,7 +1043,7 @@ static void sink_update_requested_latency_cb(pa_sink *s) {
     current fill level. Thus, let's do a full rewind once, to clear
     things up. */
 
-    if (u->hwbuf_unused_frames > before) {
+    if (u->hwbuf_unused > before) {
         pa_log_debug("Requesting rewind due to latency change.");
         pa_sink_request_rewind(s, (size_t) -1);
     }
@@ -1051,7 +1098,7 @@ static int process_rewind(struct userdata *u) {
         if (rewind_nbytes <= 0)
             pa_log_info("Tried rewind, but was apparently not possible.");
         else {
-            u->frame_index -= out_frames;
+            u->write_count -= out_frames * u->frame_size;
             pa_log_debug("Rewound %lu bytes.", (unsigned long) rewind_nbytes);
             pa_sink_process_rewind(u->sink, rewind_nbytes);
 
@@ -1086,7 +1133,9 @@ static void thread_func(void *userdata) {
     for (;;) {
         int ret;
 
-/*         pa_log_debug("loop"); */
+#ifdef DEBUG_TIMING
+        pa_log_debug("Loop");
+#endif
 
         /* Render some data and write it to the dsp */
         if (PA_SINK_IS_OPENED(u->sink->thread_info.state)) {
@@ -1132,7 +1181,7 @@ static void thread_func(void *userdata) {
                      * we have filled the buffer at least once
                      * completely.*/
 
-                    /*pa_log_debug("Cutting sleep time for the initial iterations by half.");*/
+                    pa_log_debug("Cutting sleep time for the initial iterations by half.");
                     sleep_usec /= 2;
                 }
 
@@ -1178,16 +1227,15 @@ static void thread_func(void *userdata) {
                 goto fail;
             }
 
-            if (revents & (POLLIN|POLLERR|POLLNVAL|POLLHUP|POLLPRI)) {
+            if (revents & ~POLLOUT) {
                 if (pa_alsa_recover_from_poll(u->pcm_handle, revents) < 0)
                     goto fail;
 
                 u->first = TRUE;
                 u->since_start = 0;
-            }
+            } else if (revents && u->use_tsched && pa_log_ratelimit())
+                pa_log_debug("Wakeup from ALSA!");
 
-            if (revents && u->use_tsched && pa_log_ratelimit())
-                pa_log_debug("Wakeup from ALSA!%s%s", (revents & POLLIN) ? " INPUT" : "", (revents & POLLOUT) ? " OUTPUT" : "");
         } else
             revents = 0;
     }
@@ -1382,11 +1430,8 @@ pa_sink *pa_alsa_sink_new(pa_module *m, pa_modargs *ma, const char*driver, pa_ca
     u->use_mmap = use_mmap;
     u->use_tsched = use_tsched;
     u->first = TRUE;
-    u->since_start = 0;
-    u->after_rewind = FALSE;
     u->rtpoll = pa_rtpoll_new();
     pa_thread_mq_init(&u->thread_mq, m->core->mainloop, u->rtpoll);
-    u->alsa_rtpoll_item = NULL;
 
     u->smoother = pa_smoother_new(DEFAULT_TSCHED_BUFFER_USEC*2, DEFAULT_TSCHED_BUFFER_USEC*2, TRUE, 5);
     usec = pa_rtclock_usec();
@@ -1503,17 +1548,13 @@ pa_sink *pa_alsa_sink_new(pa_module *m, pa_modargs *ma, const char*driver, pa_ca
     u->fragment_size = frag_size = (uint32_t) (period_frames * frame_size);
     u->nfragments = nfrags;
     u->hwbuf_size = u->fragment_size * nfrags;
-    u->hwbuf_unused_frames = 0;
     u->tsched_watermark = tsched_watermark;
-    u->frame_index = 0;
-    u->hw_dB_supported = FALSE;
-    u->hw_dB_min = u->hw_dB_max = 0;
-    u->hw_volume_min = u->hw_volume_max = 0;
-    u->mixer_seperate_channels = FALSE;
     pa_cvolume_mute(&u->hardware_volume, u->sink->sample_spec.channels);
 
-    if (use_tsched)
+    if (use_tsched) {
+        fix_min_sleep_wakeup(u);
         fix_tsched_watermark(u);
+    }
 
     u->sink->thread_info.max_rewind = use_tsched ? u->hwbuf_size : 0;
     u->sink->thread_info.max_request = u->hwbuf_size;
diff --git a/src/modules/alsa/alsa-source.c b/src/modules/alsa/alsa-source.c
index a5de388..50cdb31 100644
--- a/src/modules/alsa/alsa-source.c
+++ b/src/modules/alsa/alsa-source.c
@@ -57,11 +57,13 @@
 #include "alsa-util.h"
 #include "alsa-source.h"
 
+/* #define DEBUG_TIMING */
+
 #define DEFAULT_DEVICE "default"
 #define DEFAULT_TSCHED_BUFFER_USEC (2*PA_USEC_PER_SEC)       /* 2s */
 #define DEFAULT_TSCHED_WATERMARK_USEC (20*PA_USEC_PER_MSEC)  /* 20ms */
-#define TSCHED_MIN_SLEEP_USEC (3*PA_USEC_PER_MSEC)           /* 3ms */
-#define TSCHED_MIN_WAKEUP_USEC (3*PA_USEC_PER_MSEC)          /* 3ms */
+#define TSCHED_MIN_SLEEP_USEC (10*PA_USEC_PER_MSEC)          /* 10ms */
+#define TSCHED_MIN_WAKEUP_USEC (4*PA_USEC_PER_MSEC)          /* 4ms */
 
 struct userdata {
     pa_core *core;
@@ -79,55 +81,85 @@ struct userdata {
     snd_mixer_elem_t *mixer_elem;
     long hw_volume_max, hw_volume_min;
     long hw_dB_max, hw_dB_min;
-    pa_bool_t hw_dB_supported;
-    pa_bool_t mixer_seperate_channels;
+    pa_bool_t hw_dB_supported:1;
+    pa_bool_t mixer_seperate_channels:1;
 
     pa_cvolume hardware_volume;
 
-    size_t frame_size, fragment_size, hwbuf_size, tsched_watermark;
+    size_t frame_size, fragment_size, hwbuf_size, tsched_watermark, hwbuf_unused, min_sleep, min_wakeup;
     unsigned nfragments;
 
     char *device_name;
 
-    pa_bool_t use_mmap, use_tsched;
+    pa_bool_t use_mmap:1, use_tsched:1;
 
     pa_rtpoll_item *alsa_rtpoll_item;
 
     snd_mixer_selem_channel_id_t mixer_map[SND_MIXER_SCHN_LAST];
 
     pa_smoother *smoother;
-    int64_t frame_index;
-
-    snd_pcm_sframes_t hwbuf_unused_frames;
+    uint64_t read_count;
 };
 
 static void userdata_free(struct userdata *u);
 
+static void fix_min_sleep_wakeup(struct userdata *u) {
+    size_t max_use, max_use_2;
+    pa_assert(u);
+
+    max_use = u->hwbuf_size - u->hwbuf_unused;
+    max_use_2 = pa_frame_align(max_use/2, &u->source->sample_spec);
+
+    u->min_sleep = pa_usec_to_bytes(TSCHED_MIN_SLEEP_USEC, &u->source->sample_spec);
+    u->min_sleep = PA_CLAMP(u->min_sleep, u->frame_size, max_use_2);
+
+    u->min_wakeup = pa_usec_to_bytes(TSCHED_MIN_WAKEUP_USEC, &u->source->sample_spec);
+    u->min_wakeup = PA_CLAMP(u->min_wakeup, u->frame_size, max_use_2);
+}
+
 static void fix_tsched_watermark(struct userdata *u) {
     size_t max_use;
-    size_t min_sleep, min_wakeup;
     pa_assert(u);
 
-    max_use = u->hwbuf_size - (size_t) u->hwbuf_unused_frames * u->frame_size;
+    max_use = u->hwbuf_size - u->hwbuf_unused;
+
+    if (u->tsched_watermark > max_use - u->min_sleep)
+        u->tsched_watermark = max_use - u->min_sleep;
 
-    min_sleep = pa_usec_to_bytes(TSCHED_MIN_SLEEP_USEC, &u->source->sample_spec);
-    min_wakeup = pa_usec_to_bytes(TSCHED_MIN_WAKEUP_USEC, &u->source->sample_spec);
+    if (u->tsched_watermark < u->min_wakeup)
+        u->tsched_watermark = u->min_wakeup;
+}
+
+static void adjust_after_overrun(struct userdata *u) {
+    size_t old_watermark;
+    pa_usec_t old_min_latency, new_min_latency;
+
+    pa_assert(u);
+
+    /* First, just try to increase the watermark */
+    old_watermark = u->tsched_watermark;
+    u->tsched_watermark *= 2;
+    fix_tsched_watermark(u);
+
+    if (old_watermark != u->tsched_watermark) {
+        pa_log_notice("Increasing wakeup watermark to %0.2f ms",
+                      (double) pa_bytes_to_usec(u->tsched_watermark, &u->source->sample_spec) / PA_USEC_PER_MSEC);
+        return;
+    }
 
-    if (min_sleep > max_use/2)
-        min_sleep = pa_frame_align(max_use/2, &u->source->sample_spec);
-    if (min_sleep < u->frame_size)
-        min_sleep = u->frame_size;
+    /* Hmm, we cannot increase the watermark any further, hence let's raise the latency */
+    old_min_latency = u->source->thread_info.min_latency;
+    new_min_latency = PA_MIN(old_min_latency * 2, u->source->thread_info.max_latency);
 
-    if (min_wakeup > max_use/2)
-        min_wakeup = pa_frame_align(max_use/2, &u->source->sample_spec);
-    if (min_wakeup < u->frame_size)
-        min_wakeup = u->frame_size;
+    if (old_min_latency != new_min_latency) {
+        pa_log_notice("Increasing minimal latency to %0.2f ms",
+                      (double) new_min_latency / PA_USEC_PER_MSEC);
 
-    if (u->tsched_watermark > max_use-min_sleep)
-        u->tsched_watermark = max_use-min_sleep;
+        pa_source_update_latency_range(u->source, new_min_latency, u->source->thread_info.max_latency);
+        return;
+    }
 
-    if (u->tsched_watermark < min_wakeup)
-        u->tsched_watermark = min_wakeup;
+    /* When we reach this we're officialy fucked! */
 }
 
 static pa_usec_t hw_sleep_time(struct userdata *u, pa_usec_t *sleep_usec, pa_usec_t*process_usec) {
@@ -140,17 +172,20 @@ static pa_usec_t hw_sleep_time(struct userdata *u, pa_usec_t *sleep_usec, pa_use
     if (usec == (pa_usec_t) -1)
         usec = pa_bytes_to_usec(u->hwbuf_size, &u->source->sample_spec);
 
-/*     pa_log_debug("hw buffer time: %u ms", (unsigned) (usec / PA_USEC_PER_MSEC)); */
-
     wm = pa_bytes_to_usec(u->tsched_watermark, &u->source->sample_spec);
 
-    if (usec >= wm) {
-        *sleep_usec = usec - wm;
-        *process_usec = wm;
-    } else
-        *process_usec = *sleep_usec = usec /= 2;
+    if (wm > usec)
+        wm = usec/2;
 
-/*     pa_log_debug("after watermark: %u ms", (unsigned) (*sleep_usec / PA_USEC_PER_MSEC)); */
+    *sleep_usec = usec - wm;
+    *process_usec = wm;
+
+#ifdef DEBUG_TIMING
+    pa_log_debug("Buffer time: %lu ms; Sleep time: %lu ms; Process time: %lu ms",
+                 (unsigned long) (usec / PA_USEC_PER_MSEC),
+                 (unsigned long) (*sleep_usec / PA_USEC_PER_MSEC),
+                 (unsigned long) (*process_usec / PA_USEC_PER_MSEC));
+#endif
 
     return usec;
 }
@@ -167,47 +202,50 @@ static int try_recover(struct userdata *u, const char *call, int err) {
     if (err == -EPIPE)
         pa_log_debug("%s: Buffer overrun!", call);
 
-    if ((err = snd_pcm_recover(u->pcm_handle, err, 1)) == 0) {
-        snd_pcm_start(u->pcm_handle);
-        return 0;
+    if ((err = snd_pcm_recover(u->pcm_handle, err, 1)) < 0) {
+        pa_log("%s: %s", call, snd_strerror(err));
+        return -1;
     }
 
-    pa_log("%s: %s", call, snd_strerror(err));
-    return -1;
+    snd_pcm_start(u->pcm_handle);
+    return 0;
 }
 
-static size_t check_left_to_record(struct userdata *u, snd_pcm_sframes_t n) {
+static size_t check_left_to_record(struct userdata *u, size_t n_bytes) {
     size_t left_to_record;
-    size_t rec_space = u->hwbuf_size - (size_t) u->hwbuf_unused_frames*u->frame_size;
+    size_t rec_space = u->hwbuf_size - u->hwbuf_unused;
 
-    if ((size_t) n*u->frame_size < rec_space)
-        left_to_record = rec_space - ((size_t) n*u->frame_size);
-    else
-        left_to_record = 0;
+    /* We use <= instead of < for this check here because an overrun
+     * only happens after the last sample was processed, not already when
+     * it is removed from the buffer. This is particularly important
+     * when block transfer is used. */
+
+    if (n_bytes <= rec_space) {
+        left_to_record = rec_space - n_bytes;
+
+#ifdef DEBUG_TIMING
+        pa_log_debug("%0.2f ms left to record", (double) pa_bytes_to_usec(left_to_record, &u->source->sample_spec) / PA_USEC_PER_MSEC);
+#endif
 
-    if (left_to_record > 0) {
-/*         pa_log_debug("%0.2f ms left to record", (double) pa_bytes_to_usec(left_to_record, &u->source->sample_spec) / PA_USEC_PER_MSEC); */
     } else {
-        if (pa_log_ratelimit())
-            pa_log_info("Overrun!");
+        left_to_record = 0;
 
-        if (u->use_tsched) {
-            size_t old_watermark = u->tsched_watermark;
+#ifdef DEBUG_TIMING
+        PA_DEBUG_TRAP;
+#endif
 
-            u->tsched_watermark *= 2;
-            fix_tsched_watermark(u);
+        if (pa_log_ratelimit())
+            pa_log_info("Overrun!");
 
-            if (old_watermark != u->tsched_watermark)
-                pa_log_notice("Increasing wakeup watermark to %0.2f ms",
-                              (double) pa_bytes_to_usec(u->tsched_watermark, &u->source->sample_spec) / PA_USEC_PER_MSEC);
-        }
+        if (u->use_tsched)
+            adjust_after_overrun(u);
     }
 
     return left_to_record;
 }
 
 static int mmap_read(struct userdata *u, pa_usec_t *sleep_usec, pa_bool_t polled) {
-    int work_done = 0;
+    pa_bool_t work_done = FALSE;
     pa_usec_t max_sleep_usec = 0, process_usec = 0;
     size_t left_to_record;
 
@@ -219,45 +257,63 @@ static int mmap_read(struct userdata *u, pa_usec_t *sleep_usec, pa_bool_t polled
 
     for (;;) {
         snd_pcm_sframes_t n;
+        size_t n_bytes;
         int r;
 
-        snd_pcm_hwsync(u->pcm_handle);
-
-        if (PA_UNLIKELY((n = pa_alsa_safe_avail_update(u->pcm_handle, u->hwbuf_size, &u->source->sample_spec)) < 0)) {
+        if (PA_UNLIKELY((n = pa_alsa_safe_avail(u->pcm_handle, u->hwbuf_size, &u->source->sample_spec)) < 0)) {
 
-            if ((r = try_recover(u, "snd_pcm_avail_update", (int) n)) == 0)
+            if ((r = try_recover(u, "snd_pcm_avail", (int) n)) == 0)
                 continue;
 
             return r;
         }
 
-        left_to_record = check_left_to_record(u, n);
+        n_bytes = (size_t) n * u->frame_size;
+
+#ifdef DEBUG_TIMING
+        pa_log_debug("avail: %lu", (unsigned long) n_bytes);
+#endif
+
+        left_to_record = check_left_to_record(u, n_bytes);
 
         if (u->use_tsched)
             if (!polled &&
-                pa_bytes_to_usec(left_to_record, &u->source->sample_spec) > process_usec+max_sleep_usec/2)
+                pa_bytes_to_usec(left_to_record, &u->source->sample_spec) > process_usec+max_sleep_usec/2) {
+#ifdef DEBUG_TIMING
+                pa_log_debug("Not reading, because too early.");
+#endif
                 break;
+            }
 
-        if (PA_UNLIKELY(n <= 0)) {
+        if (PA_UNLIKELY(n_bytes <= 0)) {
 
             if (polled && pa_log_ratelimit())
                 pa_log(_("ALSA woke us up to read new data from the device, but there was actually nothing to read! "
                          "Most likely this is an ALSA driver bug. Please report this issue to the ALSA developers. "
                          "We were woken up with POLLIN set -- however a subsequent snd_pcm_avail_update() returned 0."));
 
+#ifdef DEBUG_TIMING
+            pa_log_debug("Not reading, because not necessary.");
+#endif
             break;
         }
 
         polled = FALSE;
 
+#ifdef DEBUG_TIMING
+        pa_log_debug("Reading");
+#endif
+
         for (;;) {
             int err;
             const snd_pcm_channel_area_t *areas;
-            snd_pcm_uframes_t offset, frames = (snd_pcm_uframes_t) n;
+            snd_pcm_uframes_t offset, frames;
             pa_memchunk chunk;
             void *p;
             snd_pcm_sframes_t sframes;
 
+            frames = (snd_pcm_uframes_t) (n_bytes / u->frame_size);
+
 /*             pa_log_debug("%lu frames to read", (unsigned long) frames); */
 
             if (PA_UNLIKELY((err = pa_alsa_safe_mmap_begin(u->pcm_handle, &areas, &offset, &frames, u->hwbuf_size, &u->source->sample_spec)) < 0)) {
@@ -297,25 +353,27 @@ static int mmap_read(struct userdata *u, pa_usec_t *sleep_usec, pa_bool_t polled
                 return r;
             }
 
-            work_done = 1;
+            work_done = TRUE;
 
-            u->frame_index += (int64_t) frames;
+            u->read_count += frames * u->frame_size;
 
-/*             pa_log_debug("read %lu frames", (unsigned long) frames); */
+#ifdef DEBUG_TIMING
+            pa_log_debug("Read %lu bytes", (unsigned long) (frames * u->frame_size));
+#endif
 
-            if (frames >= (snd_pcm_uframes_t) n)
+            if ((size_t) frames * u->frame_size >= n_bytes)
                 break;
 
-            n -= (snd_pcm_sframes_t) frames;
+            n_bytes -= (size_t) frames * u->frame_size;
         }
     }
 
     *sleep_usec = pa_bytes_to_usec(left_to_record, &u->source->sample_spec) - process_usec;
-    return work_done;
+    return work_done ? 1 : 0;
 }
 
 static int unix_read(struct userdata *u, pa_usec_t *sleep_usec, pa_bool_t polled) {
-    int work_done = 0;
+    int work_done = FALSE;
     pa_usec_t max_sleep_usec = 0, process_usec = 0;
     size_t left_to_record;
 
@@ -327,33 +385,33 @@ static int unix_read(struct userdata *u, pa_usec_t *sleep_usec, pa_bool_t polled
 
     for (;;) {
         snd_pcm_sframes_t n;
+        size_t n_bytes;
         int r;
 
-        snd_pcm_hwsync(u->pcm_handle);
-
-        if (PA_UNLIKELY((n = pa_alsa_safe_avail_update(u->pcm_handle, u->hwbuf_size, &u->source->sample_spec)) < 0)) {
+        if (PA_UNLIKELY((n = pa_alsa_safe_avail(u->pcm_handle, u->hwbuf_size, &u->source->sample_spec)) < 0)) {
 
-            if ((r = try_recover(u, "snd_pcm_avail_update", (int) n)) == 0)
+            if ((r = try_recover(u, "snd_pcm_avail", (int) n)) == 0)
                 continue;
 
             return r;
         }
 
-        left_to_record = check_left_to_record(u, n);
+        n_bytes = (size_t) n * u->frame_size;
+        left_to_record = check_left_to_record(u, n_bytes);
 
         if (u->use_tsched)
             if (!polled &&
                 pa_bytes_to_usec(left_to_record, &u->source->sample_spec) > process_usec+max_sleep_usec/2)
                 break;
 
-        if (PA_UNLIKELY(n <= 0)) {
+        if (PA_UNLIKELY(n_bytes <= 0)) {
 
             if (polled && pa_log_ratelimit())
                 pa_log(_("ALSA woke us up to read new data from the device, but there was actually nothing to read! "
                          "Most likely this is an ALSA driver bug. Please report this issue to the ALSA developers. "
                          "We were woken up with POLLIN set -- however a subsequent snd_pcm_avail_update() returned 0."));
 
-            return work_done;
+            break;
         }
 
         polled = FALSE;
@@ -367,8 +425,8 @@ static int unix_read(struct userdata *u, pa_usec_t *sleep_usec, pa_bool_t polled
 
             frames = (snd_pcm_sframes_t) (pa_memblock_get_length(chunk.memblock) / u->frame_size);
 
-            if (frames > n)
-                frames = n;
+            if (frames > (snd_pcm_sframes_t) (n_bytes/u->frame_size))
+                frames = (snd_pcm_sframes_t) (n_bytes/u->frame_size);
 
 /*             pa_log_debug("%lu frames to read", (unsigned long) n); */
 
@@ -393,53 +451,63 @@ static int unix_read(struct userdata *u, pa_usec_t *sleep_usec, pa_bool_t polled
             pa_source_post(u->source, &chunk);
             pa_memblock_unref(chunk.memblock);
 
-            work_done = 1;
+            work_done = TRUE;
 
-            u->frame_index += frames;
+            u->read_count += frames * u->frame_size;
 
 /*             pa_log_debug("read %lu frames", (unsigned long) frames); */
 
-            if (frames >= n)
+            if ((size_t) frames * u->frame_size >= n_bytes)
                 break;
 
-            n -= frames;
+            n_bytes -= (size_t) frames * u->frame_size;
         }
     }
 
     *sleep_usec = pa_bytes_to_usec(left_to_record, &u->source->sample_spec) - process_usec;
-    return work_done;
+    return work_done ? 1 : 0;
 }
 
 static void update_smoother(struct userdata *u) {
     snd_pcm_sframes_t delay = 0;
-    int64_t frames;
+    uint64_t position;
     int err;
-    pa_usec_t now1, now2;
+    pa_usec_t now1 = 0, now2;
+    snd_pcm_status_t *status;
+
+    snd_pcm_status_alloca(&status);
 
     pa_assert(u);
     pa_assert(u->pcm_handle);
 
     /* Let's update the time smoother */
 
-    snd_pcm_hwsync(u->pcm_handle);
-    snd_pcm_avail_update(u->pcm_handle);
-
     if (PA_UNLIKELY((err = snd_pcm_delay(u->pcm_handle, &delay)) < 0)) {
         pa_log_warn("Failed to get delay: %s", snd_strerror(err));
         return;
     }
 
-    frames = u->frame_index + delay;
+    if (PA_UNLIKELY((err = snd_pcm_status(u->pcm_handle, status)) < 0))
+        pa_log_warn("Failed to get timestamp: %s", snd_strerror(err));
+    else {
+        snd_htimestamp_t htstamp = { 0, 0 };
+        snd_pcm_status_get_htstamp(status, &htstamp);
+        now1 = pa_timespec_load(&htstamp);
+    }
 
-    now1 = pa_rtclock_usec();
-    now2 = pa_bytes_to_usec((uint64_t) frames * u->frame_size, &u->source->sample_spec);
+    position = u->read_count + ((uint64_t) delay * (uint64_t) u->frame_size);
+
+    /* Hmm, if the timestamp is 0, then it wasn't set and we take the current time */
+    if (now1 <= 0)
+        now1 = pa_rtclock_usec();
+
+    now2 = pa_bytes_to_usec(position, &u->source->sample_spec);
 
     pa_smoother_put(u->smoother, now1, now2);
 }
 
 static pa_usec_t source_get_latency(struct userdata *u) {
-    pa_usec_t r = 0;
-    int64_t delay;
+   int64_t delay;
     pa_usec_t now1, now2;
 
     pa_assert(u);
@@ -447,12 +515,9 @@ static pa_usec_t source_get_latency(struct userdata *u) {
     now1 = pa_rtclock_usec();
     now2 = pa_smoother_get(u->smoother, now1);
 
-    delay = (int64_t) now2 - (int64_t) pa_bytes_to_usec((uint64_t) u->frame_index * u->frame_size, &u->source->sample_spec);
-
-    if (delay > 0)
-        r = (pa_usec_t) delay;
+    delay = (int64_t) now2 - (int64_t) pa_bytes_to_usec(u->read_count, &u->source->sample_spec);
 
-    return r;
+    return delay >= 0 ? (pa_usec_t) delay : 0;
 }
 
 static int build_pollfd(struct userdata *u) {
@@ -495,7 +560,7 @@ static int update_sw_params(struct userdata *u) {
     pa_assert(u);
 
     /* Use the full buffer if noone asked us for anything specific */
-    u->hwbuf_unused_frames = 0;
+    u->hwbuf_unused = 0;
 
     if (u->use_tsched) {
         pa_usec_t latency;
@@ -512,15 +577,14 @@ static int update_sw_params(struct userdata *u) {
             if (PA_UNLIKELY(b < u->frame_size))
                 b = u->frame_size;
 
-            u->hwbuf_unused_frames = (snd_pcm_sframes_t)
-                (PA_LIKELY(b < u->hwbuf_size) ?
-                 ((u->hwbuf_size - b) / u->frame_size) : 0);
+            u->hwbuf_unused = PA_LIKELY(b < u->hwbuf_size) ? (u->hwbuf_size - b) : 0;
         }
 
+        fix_min_sleep_wakeup(u);
         fix_tsched_watermark(u);
     }
 
-    pa_log_debug("hwbuf_unused_frames=%lu", (unsigned long) u->hwbuf_unused_frames);
+    pa_log_debug("hwbuf_unused=%lu", (unsigned long) u->hwbuf_unused);
 
     avail_min = 1;
 
@@ -952,11 +1016,13 @@ static void thread_func(void *userdata) {
     for (;;) {
         int ret;
 
-/*         pa_log_debug("loop"); */
+#ifdef DEBUG_TIMING
+        pa_log_debug("Loop");
+#endif
 
         /* Read some data and pass it to the sources */
         if (PA_SOURCE_IS_OPENED(u->source->thread_info.state)) {
-            int work_done = 0;
+            int work_done;
             pa_usec_t sleep_usec = 0;
 
             if (u->use_mmap)
@@ -1014,15 +1080,14 @@ static void thread_func(void *userdata) {
                 goto fail;
             }
 
-            if (revents & (POLLOUT|POLLERR|POLLNVAL|POLLHUP|POLLPRI)) {
+            if (revents & ~POLLIN) {
                 if (pa_alsa_recover_from_poll(u->pcm_handle, revents) < 0)
                     goto fail;
 
                 snd_pcm_start(u->pcm_handle);
-            }
+            } else if (revents && u->use_tsched && pa_log_ratelimit())
+                pa_log_debug("Wakeup from ALSA!");
 
-            if (revents && u->use_tsched && pa_log_ratelimit())
-                pa_log_debug("Wakeup from ALSA!%s%s", (revents & POLLIN) ? " INPUT" : "", (revents & POLLOUT) ? " OUTPUT" : "");
         } else
             revents = 0;
     }
@@ -1219,7 +1284,7 @@ pa_source *pa_alsa_source_new(pa_module *m, pa_modargs *ma, const char*driver, p
     pa_thread_mq_init(&u->thread_mq, m->core->mainloop, u->rtpoll);
     u->alsa_rtpoll_item = NULL;
 
-    u->smoother = pa_smoother_new(DEFAULT_TSCHED_WATERMARK_USEC, DEFAULT_TSCHED_WATERMARK_USEC, TRUE, 5);
+    u->smoother = pa_smoother_new(DEFAULT_TSCHED_WATERMARK_USEC*2, DEFAULT_TSCHED_WATERMARK_USEC*2, TRUE, 5);
     pa_smoother_set_time_offset(u->smoother, pa_rtclock_usec());
 
     b = use_mmap;
@@ -1329,17 +1394,13 @@ pa_source *pa_alsa_source_new(pa_module *m, pa_modargs *ma, const char*driver, p
     u->fragment_size = frag_size = (uint32_t) (period_frames * frame_size);
     u->nfragments = nfrags;
     u->hwbuf_size = u->fragment_size * nfrags;
-    u->hwbuf_unused_frames = 0;
     u->tsched_watermark = tsched_watermark;
-    u->frame_index = 0;
-    u->hw_dB_supported = FALSE;
-    u->hw_dB_min = u->hw_dB_max = 0;
-    u->hw_volume_min = u->hw_volume_max = 0;
-    u->mixer_seperate_channels = FALSE;
     pa_cvolume_mute(&u->hardware_volume, u->source->sample_spec.channels);
 
-    if (use_tsched)
+    if (use_tsched) {
+        fix_min_sleep_wakeup(u);
         fix_tsched_watermark(u);
+    }
 
     pa_source_set_latency_range(u->source,
                                 !use_tsched ? pa_bytes_to_usec(u->hwbuf_size, &ss) : (pa_usec_t) -1,
diff --git a/src/modules/alsa/alsa-util.c b/src/modules/alsa/alsa-util.c
index 95e872b..8607e46 100644
--- a/src/modules/alsa/alsa-util.c
+++ b/src/modules/alsa/alsa-util.c
@@ -465,6 +465,7 @@ finish:
 
 int pa_alsa_set_sw_params(snd_pcm_t *pcm, snd_pcm_uframes_t avail_min) {
     snd_pcm_sw_params_t *swparams;
+    snd_pcm_uframes_t boundary;
     int err;
 
     pa_assert(pcm);
@@ -476,7 +477,22 @@ int pa_alsa_set_sw_params(snd_pcm_t *pcm, snd_pcm_uframes_t avail_min) {
         return err;
     }
 
-    if ((err = snd_pcm_sw_params_set_stop_threshold(pcm, swparams, (snd_pcm_uframes_t) -1)) < 0) {
+    if ((err = snd_pcm_sw_params_set_period_event(pcm, swparams, 0)) < 0) {
+        pa_log_warn("Unable to disable period event: %s\n", snd_strerror(err));
+        return err;
+    }
+
+    if ((err = snd_pcm_sw_params_set_tstamp_mode(pcm, swparams, SND_PCM_TSTAMP_ENABLE)) < 0) {
+        pa_log_warn("Unable to enable time stamping: %s\n", snd_strerror(err));
+        return err;
+    }
+
+    if ((err = snd_pcm_sw_params_get_boundary(swparams, &boundary)) < 0) {
+        pa_log_warn("Unable to get boundary: %s\n", snd_strerror(err));
+        return err;
+    }
+
+    if ((err = snd_pcm_sw_params_set_stop_threshold(pcm, swparams, boundary)) < 0) {
         pa_log_warn("Unable to set stop threshold: %s\n", snd_strerror(err));
         return err;
     }
@@ -1534,7 +1550,7 @@ pa_rtpoll_item* pa_alsa_build_pollfd(snd_pcm_t *pcm, pa_rtpoll *rtpoll) {
     return item;
 }
 
-snd_pcm_sframes_t pa_alsa_safe_avail_update(snd_pcm_t *pcm, size_t hwbuf_size, const pa_sample_spec *ss) {
+snd_pcm_sframes_t pa_alsa_safe_avail(snd_pcm_t *pcm, size_t hwbuf_size, const pa_sample_spec *ss) {
     snd_pcm_sframes_t n;
     size_t k;
 
@@ -1545,7 +1561,7 @@ snd_pcm_sframes_t pa_alsa_safe_avail_update(snd_pcm_t *pcm, size_t hwbuf_size, c
     /* Some ALSA driver expose weird bugs, let's inform the user about
      * what is going on */
 
-    n = snd_pcm_avail_update(pcm);
+    n = snd_pcm_avail(pcm);
 
     if (n <= 0)
         return n;
diff --git a/src/modules/alsa/alsa-util.h b/src/modules/alsa/alsa-util.h
index 79d0999..2d0f407 100644
--- a/src/modules/alsa/alsa-util.h
+++ b/src/modules/alsa/alsa-util.h
@@ -128,7 +128,7 @@ int pa_alsa_recover_from_poll(snd_pcm_t *pcm, int revents);
 
 pa_rtpoll_item* pa_alsa_build_pollfd(snd_pcm_t *pcm, pa_rtpoll *rtpoll);
 
-snd_pcm_sframes_t pa_alsa_safe_avail_update(snd_pcm_t *pcm, size_t hwbuf_size, const pa_sample_spec *ss);
+snd_pcm_sframes_t pa_alsa_safe_avail(snd_pcm_t *pcm, size_t hwbuf_size, const pa_sample_spec *ss);
 int pa_alsa_safe_mmap_begin(snd_pcm_t *pcm, const snd_pcm_channel_area_t **areas, snd_pcm_uframes_t *offset, snd_pcm_uframes_t *frames, size_t hwbuf_size, const pa_sample_spec *ss);
 
 char *pa_alsa_get_driver_name(int card);

commit 7bc1847596bdedea6a06c8c0a019da773476a965
Merge: 26a270a... 2e250aa...
Author: Lennart Poettering <lennart at poettering.net>
Date:   Fri Feb 20 03:21:46 2009 +0100

    Merge branch 'master' of ssh://rootserver/home/lennart/git/public/pulseaudio


-- 
hooks/post-receive
PulseAudio Sound Server



More information about the pulseaudio-commits mailing list