ALSA: pcm - Add logging of hwptr updates and interrupt updates

Added the logging functionality to xrun_debug to record the hwptr
updates via snd_pcm_update_hw_ptr() and snd_pcm_update_hwptr_interrupt(),
corresponding to 16 and 8, respectively.

For example,
	# echo 9 > /proc/asound/card0/pcm0p/xrun_debug
will record the position and other parameters at each period interrupt
together with the normal XRUN debugging.

Signed-off-by: Takashi Iwai <tiwai@suse.de>

2 files changed, 30 insertions, 0 deletions

diff --git a/Documentation/sound/alsa/Procfile.txt b/Documentation/sound/alsa/Procfile.txt
index 381908d8ca42..719a819f8cc2 100644
--- a/Documentation/sound/alsa/Procfile.txt
+++ b/Documentation/sound/alsa/Procfile.txt
@@ -101,6 +101,8 @@ 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()
 
         When the bit 0 is set, the driver will show the messages to
         kernel log when an xrun is detected.  The debug message is
@@ -117,6 +119,9 @@ 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.
+
 card*/pcm*/sub*/info
         The general information of this PCM sub-stream.
 
diff --git a/sound/core/pcm_lib.c b/sound/core/pcm_lib.c
index 3b673e2f991d..065eaf0a386c 100644
--- a/sound/core/pcm_lib.c
+++ b/sound/core/pcm_lib.c
@@ -233,6 +233,18 @@ static int snd_pcm_update_hw_ptr_interrupt(struct snd_pcm_substream *substream)
                 xrun(substream);
                 return -EPIPE;
         }
+        if (xrun_debug(substream, 8)) {
+                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);
+        }
         hw_base = runtime->hw_ptr_base;
         new_hw_ptr = hw_base + pos;
         hw_ptr_interrupt = runtime->hw_ptr_interrupt + runtime->period_size;
@@ -353,6 +365,19 @@ int snd_pcm_update_hw_ptr(struct snd_pcm_substream *substream)
                 xrun(substream);
                 return -EPIPE;
         }
+        if (xrun_debug(substream, 16)) {
+                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);
+        }
+
         hw_base = runtime->hw_ptr_base;
         new_hw_ptr = hw_base + pos;