Commit c009b7ef authored by Takashi Iwai's avatar Takashi Iwai

Merge branch 'topic/pcm-locking' into for-next

here is a small series of patches for cleaning up / enhancing the
PCM core stuff.
parents ae366c20 2b30d411
......@@ -101,10 +101,6 @@ card*/pcm*/xrun_debug
bit 0 = Enable XRUN/jiffies debug messages
bit 1 = Show stack trace at XRUN / jiffies check
bit 2 = Enable additional jiffies check
bit 3 = Log hwptr update at each period interrupt
bit 4 = Log hwptr update at each snd_pcm_update_hw_ptr()
bit 5 = Show last 10 positions on error
bit 6 = Do above only once
When the bit 0 is set, the driver will show the messages to
kernel log when an xrun is detected. The debug message is
......@@ -121,15 +117,6 @@ card*/pcm*/xrun_debug
buggy) hardware that doesn't give smooth pointer updates.
This feature is enabled via the bit 2.
Bits 3 and 4 are for logging the hwptr records. Note that
these will give flood of kernel messages.
When bit 5 is set, the driver logs the last 10 xrun errors and
the proc file shows each jiffies, position, period_size,
buffer_size, old_hw_ptr, and hw_ptr_base values.
When bit 6 is set, the full xrun log is shown only once.
card*/pcm*/sub*/info
The general information of this PCM sub-stream.
......@@ -146,6 +133,10 @@ card*/pcm*/sub*/sw_params
card*/pcm*/sub*/prealloc
The buffer pre-allocation information.
card*/pcm*/sub*/xrun_injection
Triggers an XRUN to the running stream when any value is
written to this proc file. Used for fault injection.
This entry is write-only.
AC97 Codec Information
----------------------
......
......@@ -416,7 +416,10 @@ struct snd_pcm_substream {
struct snd_info_entry *proc_status_entry;
struct snd_info_entry *proc_prealloc_entry;
struct snd_info_entry *proc_prealloc_max_entry;
#ifdef CONFIG_SND_PCM_XRUN_DEBUG
struct snd_info_entry *proc_xrun_injection_entry;
#endif
#endif /* CONFIG_SND_VERBOSE_PROCFS */
/* misc flags */
unsigned int hw_opened: 1;
};
......
......@@ -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
......
......@@ -483,6 +483,19 @@ static void snd_pcm_substream_proc_status_read(struct snd_info_entry *entry,
}
#ifdef CONFIG_SND_PCM_XRUN_DEBUG
static void snd_pcm_xrun_injection_write(struct snd_info_entry *entry,
struct snd_info_buffer *buffer)
{
struct snd_pcm_substream *substream = entry->private_data;
struct snd_pcm_runtime *runtime;
snd_pcm_stream_lock_irq(substream);
runtime = substream->runtime;
if (runtime && runtime->status->state == SNDRV_PCM_STATE_RUNNING)
snd_pcm_stop(substream, SNDRV_PCM_STATE_XRUN);
snd_pcm_stream_unlock_irq(substream);
}
static void snd_pcm_xrun_debug_read(struct snd_info_entry *entry,
struct snd_info_buffer *buffer)
{
......@@ -614,6 +627,22 @@ static int snd_pcm_substream_proc_init(struct snd_pcm_substream *substream)
}
substream->proc_status_entry = entry;
#ifdef CONFIG_SND_PCM_XRUN_DEBUG
entry = snd_info_create_card_entry(card, "xrun_injection",
substream->proc_root);
if (entry) {
entry->private_data = substream;
entry->c.text.read = NULL;
entry->c.text.write = snd_pcm_xrun_injection_write;
entry->mode = S_IFREG | S_IWUSR;
if (snd_info_register(entry) < 0) {
snd_info_free_entry(entry);
entry = NULL;
}
}
substream->proc_xrun_injection_entry = entry;
#endif /* CONFIG_SND_PCM_XRUN_DEBUG */
return 0;
}
......@@ -627,6 +656,10 @@ static int snd_pcm_substream_proc_done(struct snd_pcm_substream *substream)
substream->proc_sw_params_entry = NULL;
snd_info_free_entry(substream->proc_status_entry);
substream->proc_status_entry = NULL;
#ifdef CONFIG_SND_PCM_XRUN_DEBUG
snd_info_free_entry(substream->proc_xrun_injection_entry);
substream->proc_xrun_injection_entry = NULL;
#endif
snd_info_free_entry(substream->proc_root);
substream->proc_root = NULL;
return 0;
......
......@@ -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,17 +271,15 @@ 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,
"XRUN: %s, pos = %ld, buffer size = %ld, period size = %ld\n",
"BUG: %s, pos = %ld, buffer size = %ld, period size = %ld\n",
name, pos, runtime->buffer_size,
runtime->period_size);
}
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);
......
......@@ -900,14 +900,19 @@ static int snd_pcm_action_single(struct action_ops *ops,
return res;
}
/* call in mutex-protected context */
static int snd_pcm_action_mutex(struct action_ops *ops,
struct snd_pcm_substream *substream,
int state)
/*
* Note: call with stream lock
*/
static int snd_pcm_action(struct action_ops *ops,
struct snd_pcm_substream *substream,
int state)
{
int res;
if (snd_pcm_stream_linked(substream)) {
if (!snd_pcm_stream_linked(substream))
return snd_pcm_action_single(ops, substream, state);
if (substream->pcm->nonatomic) {
if (!mutex_trylock(&substream->group->mutex)) {
mutex_unlock(&substream->self_group.mutex);
mutex_lock(&substream->group->mutex);
......@@ -916,24 +921,6 @@ static int snd_pcm_action_mutex(struct action_ops *ops,
res = snd_pcm_action_group(ops, substream, state, 1);
mutex_unlock(&substream->group->mutex);
} else {
res = snd_pcm_action_single(ops, substream, state);
}
return res;
}
/*
* Note: call with stream lock
*/
static int snd_pcm_action(struct action_ops *ops,
struct snd_pcm_substream *substream,
int state)
{
int res;
if (substream->pcm->nonatomic)
return snd_pcm_action_mutex(ops, substream, state);
if (snd_pcm_stream_linked(substream)) {
if (!spin_trylock(&substream->group->lock)) {
spin_unlock(&substream->self_group.lock);
spin_lock(&substream->group->lock);
......@@ -941,34 +928,10 @@ static int snd_pcm_action(struct action_ops *ops,
}
res = snd_pcm_action_group(ops, substream, state, 1);
spin_unlock(&substream->group->lock);
} else {
res = snd_pcm_action_single(ops, substream, state);
}
return res;
}
static int snd_pcm_action_lock_mutex(struct action_ops *ops,
struct snd_pcm_substream *substream,
int state)
{
int res;
down_read(&snd_pcm_link_rwsem);
if (snd_pcm_stream_linked(substream)) {
mutex_lock(&substream->group->mutex);
mutex_lock(&substream->self_group.mutex);
res = snd_pcm_action_group(ops, substream, state, 1);
mutex_unlock(&substream->self_group.mutex);
mutex_unlock(&substream->group->mutex);
} else {
mutex_lock(&substream->self_group.mutex);
res = snd_pcm_action_single(ops, substream, state);
mutex_unlock(&substream->self_group.mutex);
}
up_read(&snd_pcm_link_rwsem);
return res;
}
/*
* Note: don't use any locks before
*/
......@@ -978,22 +941,9 @@ static int snd_pcm_action_lock_irq(struct action_ops *ops,
{
int res;
if (substream->pcm->nonatomic)
return snd_pcm_action_lock_mutex(ops, substream, state);
read_lock_irq(&snd_pcm_link_rwlock);
if (snd_pcm_stream_linked(substream)) {
spin_lock(&substream->group->lock);
spin_lock(&substream->self_group.lock);
res = snd_pcm_action_group(ops, substream, state, 1);
spin_unlock(&substream->self_group.lock);
spin_unlock(&substream->group->lock);
} else {
spin_lock(&substream->self_group.lock);
res = snd_pcm_action_single(ops, substream, state);
spin_unlock(&substream->self_group.lock);
}
read_unlock_irq(&snd_pcm_link_rwlock);
snd_pcm_stream_lock_irq(substream);
res = snd_pcm_action(ops, substream, state);
snd_pcm_stream_unlock_irq(substream);
return res;
}
......
#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>
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment