ALSA: pcm_lib - add possibility to log last 10 DMA ring buffer positions
[safe/jmp/linux-2.6] / sound / core / pcm_lib.c
index 065eaf0..1990afb 100644 (file)
@@ -126,17 +126,6 @@ void snd_pcm_playback_silence(struct snd_pcm_substream *substream, snd_pcm_ufram
        }
 }
 
-#ifdef CONFIG_SND_PCM_XRUN_DEBUG
-#define xrun_debug(substream, mask)    ((substream)->pstr->xrun_debug & (mask))
-#else
-#define xrun_debug(substream, mask)    0
-#endif
-
-#define dump_stack_on_xrun(substream) do {             \
-               if (xrun_debug(substream, 2))           \
-                       dump_stack();                   \
-       } while (0)
-
 static void pcm_debug_name(struct snd_pcm_substream *substream,
                           char *name, size_t len)
 {
@@ -147,6 +136,24 @@ static void pcm_debug_name(struct snd_pcm_substream *substream,
                 substream->number);
 }
 
+#define XRUN_DEBUG_BASIC       (1<<0)
+#define XRUN_DEBUG_STACK       (1<<1)  /* dump also stack */
+#define XRUN_DEBUG_JIFFIESCHECK        (1<<2)  /* do jiffies check */
+#define XRUN_DEBUG_PERIODUPDATE        (1<<3)  /* full period update info */
+#define XRUN_DEBUG_HWPTRUPDATE (1<<4)  /* full hwptr update info */
+#define XRUN_DEBUG_LOG         (1<<5)  /* show last 10 positions on err */
+#define XRUN_DEBUG_LOGONCE     (1<<6)  /* do above only once */
+
+#ifdef CONFIG_SND_PCM_XRUN_DEBUG
+
+#define xrun_debug(substream, mask) \
+                       ((substream)->pstr->xrun_debug & (mask))
+
+#define dump_stack_on_xrun(substream) do {                     \
+               if (xrun_debug(substream, XRUN_DEBUG_STACK))    \
+                       dump_stack();                           \
+       } while (0)
+
 static void xrun(struct snd_pcm_substream *substream)
 {
        struct snd_pcm_runtime *runtime = substream->runtime;
@@ -154,7 +161,7 @@ static void xrun(struct snd_pcm_substream *substream)
        if (runtime->tstamp_mode == SNDRV_PCM_TSTAMP_ENABLE)
                snd_pcm_gettime(runtime, (struct timespec *)&runtime->status->tstamp);
        snd_pcm_stop(substream, SNDRV_PCM_STATE_XRUN);
-       if (xrun_debug(substream, 1)) {
+       if (xrun_debug(substream, XRUN_DEBUG_BASIC)) {
                char name[16];
                pcm_debug_name(substream, name, sizeof(name));
                snd_printd(KERN_DEBUG "XRUN: %s\n", name);
@@ -162,6 +169,102 @@ static void xrun(struct snd_pcm_substream *substream)
        }
 }
 
+#define hw_ptr_error(substream, fmt, args...)                          \
+       do {                                                            \
+               if (xrun_debug(substream, XRUN_DEBUG_BASIC)) {          \
+                       if (printk_ratelimit()) {                       \
+                               snd_printd("PCM: " fmt, ##args);        \
+                       }                                               \
+                       dump_stack_on_xrun(substream);                  \
+               }                                                       \
+       } while (0)
+
+#define XRUN_LOG_CNT   10
+
+struct hwptr_log_entry {
+       unsigned long jiffies;
+       snd_pcm_uframes_t pos;
+       snd_pcm_uframes_t period_size;
+       snd_pcm_uframes_t buffer_size;
+       snd_pcm_uframes_t old_hw_ptr;
+       snd_pcm_uframes_t hw_ptr_base;
+       snd_pcm_uframes_t hw_ptr_interrupt;
+};
+
+struct snd_pcm_hwptr_log {
+       unsigned int idx;
+       unsigned int hit: 1;
+       struct hwptr_log_entry entries[XRUN_LOG_CNT];
+};
+
+static void xrun_log(struct snd_pcm_substream *substream,
+                    snd_pcm_uframes_t pos)
+{
+       struct snd_pcm_runtime *runtime = substream->runtime;
+       struct snd_pcm_hwptr_log *log = runtime->hwptr_log;
+       struct hwptr_log_entry *entry;
+
+       if (log == NULL) {
+               log = kzalloc(sizeof(*log), GFP_ATOMIC);
+               if (log == NULL)
+                       return;
+               runtime->hwptr_log = log;
+       } else {
+               if (xrun_debug(substream, XRUN_DEBUG_LOGONCE) && log->hit)
+                       return;
+       }
+       entry = &log->entries[log->idx];
+       entry->jiffies = jiffies;
+       entry->pos = pos;
+       entry->period_size = runtime->period_size;
+       entry->buffer_size = runtime->buffer_size;;
+       entry->old_hw_ptr = runtime->status->hw_ptr;
+       entry->hw_ptr_base = runtime->hw_ptr_base;
+       entry->hw_ptr_interrupt = runtime->hw_ptr_interrupt;;
+       log->idx = (log->idx + 1) % XRUN_LOG_CNT;
+}
+
+static void xrun_log_show(struct snd_pcm_substream *substream)
+{
+       struct snd_pcm_hwptr_log *log = substream->runtime->hwptr_log;
+       struct hwptr_log_entry *entry;
+       char name[16];
+       unsigned int idx;
+       int cnt;
+
+       if (log == NULL)
+               return;
+       if (xrun_debug(substream, XRUN_DEBUG_LOGONCE) && log->hit)
+               return;
+       pcm_debug_name(substream, name, sizeof(name));
+       for (cnt = 0, idx = log->idx; cnt < XRUN_LOG_CNT; cnt++) {
+               entry = &log->entries[idx];
+               if (entry->period_size == 0)
+                       break;
+               snd_printd("hwptr log: %s: j=%lu, pos=0x%lx/0x%lx/0x%lx, "
+                          "hwptr=0x%lx, hw_base=0x%lx, hw_intr=0x%lx\n",
+                          name, entry->jiffies, (unsigned long)entry->pos,
+                          (unsigned long)entry->period_size,
+                          (unsigned long)entry->buffer_size,
+                          (unsigned long)entry->old_hw_ptr,
+                          (unsigned long)entry->hw_ptr_base,
+                          (unsigned long)entry->hw_ptr_interrupt);
+               idx++;
+               idx %= XRUN_LOG_CNT;
+       }
+       log->hit = 1;
+}
+
+#else /* ! CONFIG_SND_PCM_XRUN_DEBUG */
+
+#define xrun_debug(substream, mask)    0
+#define xrun(substream)                        do { } while (0)
+#define hw_ptr_error(substream, fmt, args...) do { } while (0)
+#define xrun_log(substream, pos)       do { } while (0)
+#define xrun_log_show(substream)       do { } while (0)
+
+#endif
+
 static snd_pcm_uframes_t
 snd_pcm_update_hw_ptr_pos(struct snd_pcm_substream *substream,
                          struct snd_pcm_runtime *runtime)
@@ -175,6 +278,7 @@ snd_pcm_update_hw_ptr_pos(struct snd_pcm_substream *substream,
                if (printk_ratelimit()) {
                        char name[16];
                        pcm_debug_name(substream, name, sizeof(name));
+                       xrun_log_show(substream);
                        snd_printd(KERN_ERR  "BUG: %s, pos = 0x%lx, "
                                   "buffer size = 0x%lx, period size = 0x%lx\n",
                                   name, pos, runtime->buffer_size,
@@ -183,6 +287,8 @@ snd_pcm_update_hw_ptr_pos(struct snd_pcm_substream *substream,
                pos = 0;
        }
        pos -= pos % runtime->min_align;
+       if (xrun_debug(substream, XRUN_DEBUG_LOG))
+               xrun_log(substream, pos);
        return pos;
 }
 
@@ -197,28 +303,22 @@ static int snd_pcm_update_hw_ptr_post(struct snd_pcm_substream *substream,
                avail = snd_pcm_capture_avail(runtime);
        if (avail > runtime->avail_max)
                runtime->avail_max = avail;
-       if (avail >= runtime->stop_threshold) {
-               if (substream->runtime->status->state == SNDRV_PCM_STATE_DRAINING)
+       if (runtime->status->state == SNDRV_PCM_STATE_DRAINING) {
+               if (avail >= runtime->buffer_size) {
                        snd_pcm_drain_done(substream);
-               else
+                       return -EPIPE;
+               }
+       } else {
+               if (avail >= runtime->stop_threshold) {
                        xrun(substream);
-               return -EPIPE;
+                       return -EPIPE;
+               }
        }
        if (avail >= runtime->control->avail_min)
                wake_up(&runtime->sleep);
        return 0;
 }
 
-#define hw_ptr_error(substream, fmt, args...)                          \
-       do {                                                            \
-               if (xrun_debug(substream, 1)) {                         \
-                       if (printk_ratelimit()) {                       \
-                               snd_printd("PCM: " fmt, ##args);        \
-                       }                                               \
-                       dump_stack_on_xrun(substream);                  \
-               }                                                       \
-       } while (0)
-
 static int snd_pcm_update_hw_ptr_interrupt(struct snd_pcm_substream *substream)
 {
        struct snd_pcm_runtime *runtime = substream->runtime;
@@ -233,17 +333,17 @@ static int snd_pcm_update_hw_ptr_interrupt(struct snd_pcm_substream *substream)
                xrun(substream);
                return -EPIPE;
        }
-       if (xrun_debug(substream, 8)) {
+       if (xrun_debug(substream, XRUN_DEBUG_PERIODUPDATE)) {
                char name[16];
                pcm_debug_name(substream, name, sizeof(name));
                snd_printd("period_update: %s: pos=0x%x/0x%x/0x%x, "
                           "hwptr=0x%lx, hw_base=0x%lx, hw_intr=0x%lx\n",
-                          name, pos,
-                          (int)runtime->period_size,
-                          (int)runtime->buffer_size,
-                          (long)old_hw_ptr,
-                          (long)runtime->hw_ptr_base,
-                          (long)runtime->hw_ptr_interrupt);
+                          name, (unsigned int)pos,
+                          (unsigned int)runtime->period_size,
+                          (unsigned int)runtime->buffer_size,
+                          (unsigned long)old_hw_ptr,
+                          (unsigned long)runtime->hw_ptr_base,
+                          (unsigned long)runtime->hw_ptr_interrupt);
        }
        hw_base = runtime->hw_ptr_base;
        new_hw_ptr = hw_base + pos;
@@ -256,9 +356,10 @@ static int snd_pcm_update_hw_ptr_interrupt(struct snd_pcm_substream *substream)
                        delta = new_hw_ptr - hw_ptr_interrupt;
        }
        if (delta < 0) {
-               if (runtime->periods == 1)
+               if (runtime->periods == 1 || new_hw_ptr < old_hw_ptr)
                        delta += runtime->buffer_size;
                if (delta < 0) {
+                       xrun_log_show(substream);
                        hw_ptr_error(substream, 
                                     "Unexpected hw_pointer value "
                                     "(stream=%i, pos=%ld, intr_ptr=%ld)\n",
@@ -286,7 +387,7 @@ static int snd_pcm_update_hw_ptr_interrupt(struct snd_pcm_substream *substream)
        }
 
        /* Do jiffies check only in xrun_debug mode */
-       if (!xrun_debug(substream, 4))
+       if (!xrun_debug(substream, XRUN_DEBUG_JIFFIESCHECK))
                goto no_jiffies_check;
 
        /* Skip the jiffies check for hardwares with BATCH flag.
@@ -304,6 +405,7 @@ static int snd_pcm_update_hw_ptr_interrupt(struct snd_pcm_substream *substream)
                delta = jdelta /
                        (((runtime->period_size * HZ) / runtime->rate)
                                                                + HZ/100);
+               xrun_log_show(substream);
                hw_ptr_error(substream,
                             "hw_ptr skipping! [Q] "
                             "(pos=%ld, delta=%ld, period=%ld, "
@@ -323,6 +425,7 @@ static int snd_pcm_update_hw_ptr_interrupt(struct snd_pcm_substream *substream)
        }
  no_jiffies_check:
        if (delta > runtime->period_size + runtime->period_size / 2) {
+               xrun_log_show(substream);
                hw_ptr_error(substream,
                             "Lost interrupts? "
                             "(stream=%i, delta=%ld, intr_ptr=%ld)\n",
@@ -365,17 +468,17 @@ int snd_pcm_update_hw_ptr(struct snd_pcm_substream *substream)
                xrun(substream);
                return -EPIPE;
        }
-       if (xrun_debug(substream, 16)) {
+       if (xrun_debug(substream, XRUN_DEBUG_HWPTRUPDATE)) {
                char name[16];
                pcm_debug_name(substream, name, sizeof(name));
                snd_printd("hw_update: %s: pos=0x%x/0x%x/0x%x, "
                           "hwptr=0x%lx, hw_base=0x%lx, hw_intr=0x%lx\n",
-                          name, pos,
-                          (int)runtime->period_size,
-                          (int)runtime->buffer_size,
-                          (long)old_hw_ptr,
-                          (long)runtime->hw_ptr_base,
-                          (long)runtime->hw_ptr_interrupt);
+                          name, (unsigned int)pos,
+                          (unsigned int)runtime->period_size,
+                          (unsigned int)runtime->buffer_size,
+                          (unsigned long)old_hw_ptr,
+                          (unsigned long)runtime->hw_ptr_base,
+                          (unsigned long)runtime->hw_ptr_interrupt);
        }
 
        hw_base = runtime->hw_ptr_base;
@@ -386,6 +489,7 @@ int snd_pcm_update_hw_ptr(struct snd_pcm_substream *substream)
        if (delta < 0) {
                delta += runtime->buffer_size;
                if (delta < 0) {
+                       xrun_log_show(substream);
                        hw_ptr_error(substream, 
                                     "Unexpected hw_pointer value [2] "
                                     "(stream=%i, pos=%ld, old_ptr=%ld, jdelta=%li)\n",
@@ -399,12 +503,13 @@ int snd_pcm_update_hw_ptr(struct snd_pcm_substream *substream)
                new_hw_ptr = hw_base + pos;
        }
        /* Do jiffies check only in xrun_debug mode */
-       if (!xrun_debug(substream, 4))
+       if (!xrun_debug(substream, XRUN_DEBUG_JIFFIESCHECK))
                goto no_jiffies_check;
        if (delta < runtime->delay)
                goto no_jiffies_check;
        delta -= runtime->delay;
        if (((delta * HZ) / runtime->rate) > jdelta + HZ/100) {
+               xrun_log_show(substream);
                hw_ptr_error(substream,
                             "hw_ptr skipping! "
                             "(pos=%ld, delta=%ld, period=%ld, jdelta=%lu/%lu)\n",
@@ -943,47 +1048,24 @@ static int snd_interval_ratden(struct snd_interval *i,
 int snd_interval_list(struct snd_interval *i, unsigned int count, unsigned int *list, unsigned int mask)
 {
         unsigned int k;
-       int changed = 0;
+       struct snd_interval list_range;
 
        if (!count) {
                i->empty = 1;
                return -EINVAL;
        }
+       snd_interval_any(&list_range);
+       list_range.min = UINT_MAX;
+       list_range.max = 0;
         for (k = 0; k < count; k++) {
                if (mask && !(mask & (1 << k)))
                        continue;
-                if (i->min == list[k] && !i->openmin)
-                        goto _l1;
-                if (i->min < list[k]) {
-                        i->min = list[k];
-                       i->openmin = 0;
-                       changed = 1;
-                        goto _l1;
-                }
-        }
-        i->empty = 1;
-        return -EINVAL;
- _l1:
-        for (k = count; k-- > 0;) {
-               if (mask && !(mask & (1 << k)))
+               if (!snd_interval_test(i, list[k]))
                        continue;
-                if (i->max == list[k] && !i->openmax)
-                        goto _l2;
-                if (i->max > list[k]) {
-                        i->max = list[k];
-                       i->openmax = 0;
-                       changed = 1;
-                        goto _l2;
-                }
+               list_range.min = min(list_range.min, list[k]);
+               list_range.max = max(list_range.max, list[k]);
         }
-        i->empty = 1;
-        return -EINVAL;
- _l2:
-       if (snd_interval_checkempty(i)) {
-               i->empty = 1;
-               return -EINVAL;
-       }
-        return changed;
+       return snd_interval_refine(i, &list_range);
 }
 
 EXPORT_SYMBOL(snd_interval_list);