linux/sound/core/pcm_trace.h

111 lines
3.7 KiB
C
Raw Normal View History

ALSA: pcm: Replace PCM hwptr tracking with tracepoints ALSA PCM core has a mechanism tracking the PCM hwptr updates for analyzing XRUNs. But its log is limited (up to 10) and its log output is a kernel message, which is hard to handle. In this patch, the hwptr logging is moved to the tracing infrastructure instead of its own. Not only the hwptr updates but also XRUN and hwptr errors are recorded on the trace log, so that user can see such events at the exact timing. The new "snd_pcm" entry will appear in the tracing events: # ls -F /sys/kernel/debug/tracing/events/snd_pcm enable filter hw_ptr_error/ hwptr/ xrun/ The hwptr is for the regular hwptr update events. An event trace looks like: aplay-26187 [004] d..3 4012.834761: hwptr: pcmC0D0p/sub0: POS: pos=488, old=0, base=0, period=1024, buf=16384 "POS" shows the hwptr update by the explicit position update call and "IRQ" means the hwptr update by the interrupt, i.e. snd_pcm_period_elapsed() call. The "pos" is the passed ring-buffer offset by the caller, "old" is the previous hwptr, "base" is the hwptr base position, "period" and "buf" are period- and buffer-size of the target PCM substream. (Note that the hwptr position displayed here isn't the ring-buffer offset. It increments up to the PCM position boundary.) The XRUN event appears similarly, but without "pos" field. The hwptr error events appear with the PCM identifier and its reason string, such as "Lost interrupt?". The XRUN and hwptr error reports on kernel message are still left, can be turned on/off via xrun_debug proc like before. But the bit 3, 4, 5 and 6 bits of xrun_debug proc are dropped by this patch. Also, along with the change, the message strings have been reformatted to be a bit more consistent. Last but not least, the hwptr reporting is enabled only when CONFIG_SND_PCM_XRUN_DEBUG is set. Signed-off-by: Takashi Iwai <tiwai@suse.de>
2014-11-04 11:45:59 +00:00
#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>