summaryrefslogtreecommitdiffstats
path: root/sound/core
diff options
context:
space:
mode:
Diffstat (limited to 'sound/core')
-rw-r--r--sound/core/pcm.c4
-rw-r--r--sound/core/pcm_lib.c140
2 files changed, 121 insertions, 23 deletions
diff --git a/sound/core/pcm.c b/sound/core/pcm.c
index 6884ae031f6..df57a0e30bf 100644
--- a/sound/core/pcm.c
+++ b/sound/core/pcm.c
@@ -921,6 +921,10 @@ void snd_pcm_detach_substream(struct snd_pcm_substream *substream)
snd_free_pages((void*)runtime->control,
PAGE_ALIGN(sizeof(struct snd_pcm_mmap_control)));
kfree(runtime->hw_constraints.rules);
+#ifdef CONFIG_SND_PCM_XRUN_DEBUG
+ if (runtime->hwptr_log)
+ kfree(runtime->hwptr_log);
+#endif
kfree(runtime);
substream->runtime = NULL;
put_pid(substream->pid);
diff --git a/sound/core/pcm_lib.c b/sound/core/pcm_lib.c
index 9621236b2fe..1990afb8a73 100644
--- a/sound/core/pcm_lib.c
+++ b/sound/core/pcm_lib.c
@@ -126,34 +126,34 @@ void snd_pcm_playback_silence(struct snd_pcm_substream *substream, snd_pcm_ufram
}
}
+static void pcm_debug_name(struct snd_pcm_substream *substream,
+ char *name, size_t len)
+{
+ snprintf(name, len, "pcmC%dD%d%c:%d",
+ substream->pcm->card->number,
+ substream->pcm->device,
+ substream->stream ? 'c' : 'p',
+ 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))
-#else
-#define xrun_debug(substream, mask) 0
-#endif
#define dump_stack_on_xrun(substream) do { \
if (xrun_debug(substream, XRUN_DEBUG_STACK)) \
dump_stack(); \
} while (0)
-static void pcm_debug_name(struct snd_pcm_substream *substream,
- char *name, size_t len)
-{
- snprintf(name, len, "pcmC%dD%d%c:%d",
- substream->pcm->card->number,
- substream->pcm->device,
- substream->stream ? 'c' : 'p',
- substream->number);
-}
-
static void xrun(struct snd_pcm_substream *substream)
{
struct snd_pcm_runtime *runtime = substream->runtime;
@@ -169,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)
@@ -182,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,
@@ -190,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;
}
@@ -220,16 +319,6 @@ static int snd_pcm_update_hw_ptr_post(struct snd_pcm_substream *substream,
return 0;
}
-#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)
-
static int snd_pcm_update_hw_ptr_interrupt(struct snd_pcm_substream *substream)
{
struct snd_pcm_runtime *runtime = substream->runtime;
@@ -270,6 +359,7 @@ static int snd_pcm_update_hw_ptr_interrupt(struct snd_pcm_substream *substream)
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",
@@ -315,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, "
@@ -334,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",
@@ -397,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",
@@ -416,6 +509,7 @@ int snd_pcm_update_hw_ptr(struct snd_pcm_substream *substream)
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",