aboutsummaryrefslogtreecommitdiff
path: root/sound/core
diff options
context:
space:
mode:
Diffstat (limited to 'sound/core')
-rw-r--r--sound/core/Makefile3
-rw-r--r--sound/core/pcm_lib.c146
-rw-r--r--sound/core/pcm_trace.h110
3 files changed, 137 insertions, 122 deletions
diff --git a/sound/core/Makefile b/sound/core/Makefile
index 394a38909f6b..4daf2f58261c 100644
--- a/sound/core/Makefile
+++ b/sound/core/Makefile
@@ -14,6 +14,9 @@ snd-pcm-y := pcm.o pcm_native.o pcm_lib.o pcm_timer.o pcm_misc.o \
pcm_memory.o memalloc.o
snd-pcm-$(CONFIG_SND_DMA_SGBUF) += sgbuf.o
+# for trace-points
+CFLAGS_pcm_lib.o := -I$(src)
+
snd-pcm-dmaengine-objs := pcm_dmaengine.o
snd-rawmidi-objs := rawmidi.o
diff --git a/sound/core/pcm_lib.c b/sound/core/pcm_lib.c
index 7b9e2fb35a86..ec9e7866177f 100644
--- a/sound/core/pcm_lib.c
+++ b/sound/core/pcm_lib.c
@@ -32,6 +32,15 @@
#include <sound/pcm_params.h>
#include <sound/timer.h>
+#ifdef CONFIG_SND_PCM_XRUN_DEBUG
+#define CREATE_TRACE_POINTS
+#include "pcm_trace.h"
+#else
+#define trace_hwptr(substream, pos, in_interrupt)
+#define trace_xrun(substream)
+#define trace_hw_ptr_error(substream, reason)
+#endif
+
/*
* fill ring buffer with silence
* runtime->silence_start: starting pointer to silence area
@@ -146,10 +155,6 @@ EXPORT_SYMBOL(snd_pcm_debug_name);
#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
@@ -168,6 +173,7 @@ static void xrun(struct snd_pcm_substream *substream)
{
struct snd_pcm_runtime *runtime = substream->runtime;
+ trace_xrun(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);
@@ -180,97 +186,19 @@ static void xrun(struct snd_pcm_substream *substream)
}
#ifdef CONFIG_SND_PCM_XRUN_DEBUG
-#define hw_ptr_error(substream, fmt, args...) \
+#define hw_ptr_error(substream, in_interrupt, reason, fmt, args...) \
do { \
+ trace_hw_ptr_error(substream, reason); \
if (xrun_debug(substream, XRUN_DEBUG_BASIC)) { \
- xrun_log_show(substream); \
- pr_err_ratelimited("ALSA: PCM: " fmt, ##args); \
+ pr_err_ratelimited("ALSA: PCM: [%c] " reason ": " fmt, \
+ (in_interrupt) ? 'Q' : 'P', ##args); \
dump_stack_on_xrun(substream); \
} \
} while (0)
-#define XRUN_LOG_CNT 10
-
-struct hwptr_log_entry {
- unsigned int in_interrupt;
- 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;
-};
-
-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, int in_interrupt)
-{
- 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->in_interrupt = in_interrupt;
- 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;
- 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;
- snd_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;
- pr_info("hwptr log: %s: %sj=%lu, pos=%ld/%ld/%ld, "
- "hwptr=%ld/%ld\n",
- name, entry->in_interrupt ? "[Q] " : "",
- 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);
- idx++;
- idx %= XRUN_LOG_CNT;
- }
- log->hit = 1;
-}
-
#else /* ! CONFIG_SND_PCM_XRUN_DEBUG */
#define hw_ptr_error(substream, fmt, args...) do { } while (0)
-#define xrun_log(substream, pos, in_interrupt) do { } while (0)
-#define xrun_log_show(substream) do { } while (0)
#endif
@@ -343,7 +271,6 @@ static int snd_pcm_update_hw_ptr0(struct snd_pcm_substream *substream,
if (printk_ratelimit()) {
char name[16];
snd_pcm_debug_name(substream, name, sizeof(name));
- xrun_log_show(substream);
pcm_err(substream->pcm,
"BUG: %s, pos = %ld, buffer size = %ld, period size = %ld\n",
name, pos, runtime->buffer_size,
@@ -352,8 +279,7 @@ static int snd_pcm_update_hw_ptr0(struct snd_pcm_substream *substream,
pos = 0;
}
pos -= pos % runtime->min_align;
- if (xrun_debug(substream, XRUN_DEBUG_LOG))
- xrun_log(substream, pos, in_interrupt);
+ trace_hwptr(substream, pos, in_interrupt);
hw_base = runtime->hw_ptr_base;
new_hw_ptr = hw_base + pos;
if (in_interrupt) {
@@ -388,22 +314,6 @@ static int snd_pcm_update_hw_ptr0(struct snd_pcm_substream *substream,
delta = new_hw_ptr - old_hw_ptr;
if (delta < 0)
delta += runtime->boundary;
- if (xrun_debug(substream, in_interrupt ?
- XRUN_DEBUG_PERIODUPDATE : XRUN_DEBUG_HWPTRUPDATE)) {
- char name[16];
- snd_pcm_debug_name(substream, name, sizeof(name));
- pcm_dbg(substream->pcm,
- "%s_update: %s: pos=%u/%u/%u, hwptr=%ld/%ld/%ld/%ld\n",
- in_interrupt ? "period" : "hwptr",
- name,
- (unsigned int)pos,
- (unsigned int)runtime->period_size,
- (unsigned int)runtime->buffer_size,
- (unsigned long)delta,
- (unsigned long)old_hw_ptr,
- (unsigned long)new_hw_ptr,
- (unsigned long)runtime->hw_ptr_base);
- }
if (runtime->no_period_wakeup) {
snd_pcm_sframes_t xrun_threshold;
@@ -431,13 +341,10 @@ static int snd_pcm_update_hw_ptr0(struct snd_pcm_substream *substream,
/* something must be really wrong */
if (delta >= runtime->buffer_size + runtime->period_size) {
- hw_ptr_error(substream,
- "Unexpected hw_pointer value %s"
- "(stream=%i, pos=%ld, new_hw_ptr=%ld, "
- "old_hw_ptr=%ld)\n",
- in_interrupt ? "[Q] " : "[P]",
- substream->stream, (long)pos,
- (long)new_hw_ptr, (long)old_hw_ptr);
+ hw_ptr_error(substream, in_interrupt, "Unexpected hw_ptr",
+ "(stream=%i, pos=%ld, new_hw_ptr=%ld, old_hw_ptr=%ld)\n",
+ substream->stream, (long)pos,
+ (long)new_hw_ptr, (long)old_hw_ptr);
return 0;
}
@@ -474,11 +381,8 @@ static int snd_pcm_update_hw_ptr0(struct snd_pcm_substream *substream,
delta--;
}
/* align hw_base to buffer_size */
- hw_ptr_error(substream,
- "hw_ptr skipping! %s"
- "(pos=%ld, delta=%ld, period=%ld, "
- "jdelta=%lu/%lu/%lu, hw_ptr=%ld/%ld)\n",
- in_interrupt ? "[Q] " : "",
+ hw_ptr_error(substream, in_interrupt, "hw_ptr skipping",
+ "(pos=%ld, delta=%ld, period=%ld, jdelta=%lu/%lu/%lu, hw_ptr=%ld/%ld)\n",
(long)pos, (long)hdelta,
(long)runtime->period_size, jdelta,
((hdelta * HZ) / runtime->rate), hw_base,
@@ -490,11 +394,9 @@ static int snd_pcm_update_hw_ptr0(struct snd_pcm_substream *substream,
}
no_jiffies_check:
if (delta > runtime->period_size + runtime->period_size / 2) {
- hw_ptr_error(substream,
- "Lost interrupts? %s"
- "(stream=%i, delta=%ld, new_hw_ptr=%ld, "
- "old_hw_ptr=%ld)\n",
- in_interrupt ? "[Q] " : "",
+ hw_ptr_error(substream, in_interrupt,
+ "Lost interrupts?",
+ "(stream=%i, delta=%ld, new_hw_ptr=%ld, old_hw_ptr=%ld)\n",
substream->stream, (long)delta,
(long)new_hw_ptr,
(long)old_hw_ptr);
diff --git a/sound/core/pcm_trace.h b/sound/core/pcm_trace.h
new file mode 100644
index 000000000000..b63b654da5ff
--- /dev/null
+++ b/sound/core/pcm_trace.h
@@ -0,0 +1,110 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM snd_pcm
+#define TRACE_INCLUDE_FILE pcm_trace
+
+#if !defined(_PCM_TRACE_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _PCM_TRACE_H
+
+#include <linux/tracepoint.h>
+
+TRACE_EVENT(hwptr,
+ TP_PROTO(struct snd_pcm_substream *substream, snd_pcm_uframes_t pos, bool irq),
+ TP_ARGS(substream, pos, irq),
+ TP_STRUCT__entry(
+ __field( bool, in_interrupt )
+ __field( unsigned int, card )
+ __field( unsigned int, device )
+ __field( unsigned int, number )
+ __field( unsigned int, stream )
+ __field( snd_pcm_uframes_t, pos )
+ __field( snd_pcm_uframes_t, period_size )
+ __field( snd_pcm_uframes_t, buffer_size )
+ __field( snd_pcm_uframes_t, old_hw_ptr )
+ __field( snd_pcm_uframes_t, hw_ptr_base )
+ ),
+ TP_fast_assign(
+ __entry->in_interrupt = (irq);
+ __entry->card = (substream)->pcm->card->number;
+ __entry->device = (substream)->pcm->device;
+ __entry->number = (substream)->number;
+ __entry->stream = (substream)->stream;
+ __entry->pos = (pos);
+ __entry->period_size = (substream)->runtime->period_size;
+ __entry->buffer_size = (substream)->runtime->buffer_size;
+ __entry->old_hw_ptr = (substream)->runtime->status->hw_ptr;
+ __entry->hw_ptr_base = (substream)->runtime->hw_ptr_base;
+ ),
+ TP_printk("pcmC%dD%d%c/sub%d: %s: pos=%lu, old=%lu, base=%lu, period=%lu, buf=%lu",
+ __entry->card, __entry->device,
+ __entry->stream == SNDRV_PCM_STREAM_PLAYBACK ? 'p' : 'c',
+ __entry->number,
+ __entry->in_interrupt ? "IRQ" : "POS",
+ (unsigned long)__entry->pos,
+ (unsigned long)__entry->old_hw_ptr,
+ (unsigned long)__entry->hw_ptr_base,
+ (unsigned long)__entry->period_size,
+ (unsigned long)__entry->buffer_size)
+);
+
+TRACE_EVENT(xrun,
+ TP_PROTO(struct snd_pcm_substream *substream),
+ TP_ARGS(substream),
+ TP_STRUCT__entry(
+ __field( unsigned int, card )
+ __field( unsigned int, device )
+ __field( unsigned int, number )
+ __field( unsigned int, stream )
+ __field( snd_pcm_uframes_t, period_size )
+ __field( snd_pcm_uframes_t, buffer_size )
+ __field( snd_pcm_uframes_t, old_hw_ptr )
+ __field( snd_pcm_uframes_t, hw_ptr_base )
+ ),
+ TP_fast_assign(
+ __entry->card = (substream)->pcm->card->number;
+ __entry->device = (substream)->pcm->device;
+ __entry->number = (substream)->number;
+ __entry->stream = (substream)->stream;
+ __entry->period_size = (substream)->runtime->period_size;
+ __entry->buffer_size = (substream)->runtime->buffer_size;
+ __entry->old_hw_ptr = (substream)->runtime->status->hw_ptr;
+ __entry->hw_ptr_base = (substream)->runtime->hw_ptr_base;
+ ),
+ TP_printk("pcmC%dD%d%c/sub%d: XRUN: old=%lu, base=%lu, period=%lu, buf=%lu",
+ __entry->card, __entry->device,
+ __entry->stream == SNDRV_PCM_STREAM_PLAYBACK ? 'p' : 'c',
+ __entry->number,
+ (unsigned long)__entry->old_hw_ptr,
+ (unsigned long)__entry->hw_ptr_base,
+ (unsigned long)__entry->period_size,
+ (unsigned long)__entry->buffer_size)
+);
+
+TRACE_EVENT(hw_ptr_error,
+ TP_PROTO(struct snd_pcm_substream *substream, const char *why),
+ TP_ARGS(substream, why),
+ TP_STRUCT__entry(
+ __field( unsigned int, card )
+ __field( unsigned int, device )
+ __field( unsigned int, number )
+ __field( unsigned int, stream )
+ __field( const char *, reason )
+ ),
+ TP_fast_assign(
+ __entry->card = (substream)->pcm->card->number;
+ __entry->device = (substream)->pcm->device;
+ __entry->number = (substream)->number;
+ __entry->stream = (substream)->stream;
+ __entry->reason = (why);
+ ),
+ TP_printk("pcmC%dD%d%c/sub%d: ERROR: %s",
+ __entry->card, __entry->device,
+ __entry->stream == SNDRV_PCM_STREAM_PLAYBACK ? 'p' : 'c',
+ __entry->number, __entry->reason)
+);
+
+#endif /* _PCM_TRACE_H */
+
+/* This part must be outside protection */
+#undef TRACE_INCLUDE_PATH
+#define TRACE_INCLUDE_PATH .
+#include <trace/define_trace.h>
generated by cgit v1.2.3 (git 2.39.1) at 2024-11-23 21:06:53 +0000