ASoC: SOF: Intel: replace dev_vdbg with tracepoints

This patch replaces all dev_vdbg calls with tracepoints to reduce
overhead and enable use of trace collection and analysis tools.

Reviewed-by: Péter Ujfalusi <peter.ujfalusi@linux.intel.com>
Signed-off-by: Noah Klayman <noah.klayman@intel.com>
Signed-off-by: Bard Liao <yung-chuan.liao@linux.intel.com>
Signed-off-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
Link: https://lore.kernel.org/r/20220919122108.43764-6-pierre-louis.bossart@linux.intel.com
Signed-off-by: Mark Brown <broonie@kernel.org>

diff --git a/include/trace/events/sof_intel.h b/include/trace/events/sof_intel.h
index 37a9b92d494ef44ef5208c6c5a48c93e2d9daada..2a77f9d26c0bf68c9e040da88125ed6192cf5854 100644 (file)
--- a/include/trace/events/sof_intel.h
+++ b/include/trace/events/sof_intel.h
@@ -11,6 +11,7 @@
 #if !defined(_TRACE_SOF_INTEL_H) || defined(TRACE_HEADER_MULTI_READ)
 #define _TRACE_SOF_INTEL_H
 #include <linux/tracepoint.h>
+#include <sound/hdaudio.h>
 #include "../../../sound/soc/sof/sof-audio.h"
 
 TRACE_EVENT(sof_intel_hda_irq,
@@ -28,6 +29,119 @@ TRACE_EVENT(sof_intel_hda_irq,
                  __get_str(device_name), __get_str(source))
 );
 
+DECLARE_EVENT_CLASS(sof_intel_ipc_firmware_template,
+       TP_ARGS(struct snd_sof_dev *sdev, u32 msg, u32 msg_ext),
+       TP_PROTO(sdev, msg, msg_ext),
+       TP_STRUCT__entry(
+               __string(device_name, dev_name(sdev->dev))
+               __field(u32, msg)
+               __field(u32, msg_ext)
+       ),
+       TP_fast_assign(
+               __assign_str(device_name, dev_name(sdev->dev));
+               __entry->msg = msg;
+               __entry->msg_ext = msg_ext;
+       ),
+       TP_printk("device_name=%s msg=%#x msg_ext=%#x",
+                 __get_str(device_name), __entry->msg, __entry->msg_ext)
+);
+
+DEFINE_EVENT(sof_intel_ipc_firmware_template, sof_intel_ipc_firmware_response,
+       TP_PROTO(struct snd_sof_dev *sdev, u32 msg, u32 msg_ext),
+       TP_ARGS(sdev, msg, msg_ext)
+);
+
+DEFINE_EVENT(sof_intel_ipc_firmware_template, sof_intel_ipc_firmware_initiated,
+       TP_PROTO(struct snd_sof_dev *sdev, u32 msg, u32 msg_ext),
+       TP_ARGS(sdev, msg, msg_ext)
+);
+
+TRACE_EVENT(sof_intel_D0I3C_updated,
+       TP_PROTO(struct snd_sof_dev *sdev, u8 reg),
+       TP_ARGS(sdev, reg),
+       TP_STRUCT__entry(
+               __string(device_name, dev_name(sdev->dev))
+               __field(u8, reg)
+       ),
+       TP_fast_assign(
+               __assign_str(device_name, dev_name(sdev->dev));
+               __entry->reg = reg;
+       ),
+       TP_printk("device_name=%s register=%#x",
+                 __get_str(device_name), __entry->reg)
+);
+
+TRACE_EVENT(sof_intel_hda_irq_ipc_check,
+       TP_PROTO(struct snd_sof_dev *sdev, u32 irq_status),
+       TP_ARGS(sdev, irq_status),
+       TP_STRUCT__entry(
+               __string(device_name, dev_name(sdev->dev))
+               __field(u32, irq_status)
+       ),
+       TP_fast_assign(
+               __assign_str(device_name, dev_name(sdev->dev));
+               __entry->irq_status = irq_status;
+       ),
+       TP_printk("device_name=%s irq_status=%#x",
+                 __get_str(device_name), __entry->irq_status)
+);
+
+TRACE_EVENT(sof_intel_hda_dsp_pcm,
+       TP_PROTO(struct snd_sof_dev *sdev,
+               struct hdac_stream *hstream,
+               struct snd_pcm_substream *substream,
+               snd_pcm_uframes_t pos
+       ),
+       TP_ARGS(sdev, hstream, substream, pos),
+       TP_STRUCT__entry(
+               __string(device_name, dev_name(sdev->dev))
+               __field(u32, hstream_index)
+               __field(u32, substream)
+               __field(unsigned long, pos)
+       ),
+       TP_fast_assign(
+               __assign_str(device_name, dev_name(sdev->dev));
+               __entry->hstream_index = hstream->index;
+               __entry->substream = substream->stream;
+               __entry->pos = pos;
+       ),
+       TP_printk("device_name=%s hstream_index=%d substream=%d pos=%lu",
+                 __get_str(device_name), __entry->hstream_index,
+                 __entry->substream, __entry->pos)
+);
+
+TRACE_EVENT(sof_intel_hda_dsp_stream_status,
+       TP_PROTO(struct device *dev, struct hdac_stream *s, u32 status),
+       TP_ARGS(dev, s, status),
+       TP_STRUCT__entry(
+               __string(device_name, dev_name(dev))
+               __field(u32, stream)
+               __field(u32, status)
+       ),
+       TP_fast_assign(
+               __assign_str(device_name, dev_name(dev));
+               __entry->stream = s->index;
+               __entry->status = status;
+       ),
+       TP_printk("device_name=%s stream=%d status=%#x",
+                 __get_str(device_name), __entry->stream, __entry->status)
+);
+
+TRACE_EVENT(sof_intel_hda_dsp_check_stream_irq,
+       TP_PROTO(struct snd_sof_dev *sdev, u32 status),
+       TP_ARGS(sdev, status),
+       TP_STRUCT__entry(
+               __string(device_name, dev_name(sdev->dev))
+               __field(u32, status)
+       ),
+       TP_fast_assign(
+               __assign_str(device_name, dev_name(sdev->dev));
+               __entry->status = status;
+       ),
+       TP_printk("device_name=%s status=%#x",
+                 __get_str(device_name), __entry->status)
+);
+
 #endif /* _TRACE_SOF_INTEL_H */
 
 /* This part must be outside protection */

diff --git a/sound/soc/sof/intel/cnl.c b/sound/soc/sof/intel/cnl.c
index 0bb91df27280544ddf9cd1cd42aaad107c4464f3..180001d0a38aeb7c658b18c529ca6c589558dcc1 100644 (file)
--- a/sound/soc/sof/intel/cnl.c
+++ b/sound/soc/sof/intel/cnl.c
@@ -17,6 +17,7 @@
 
 #include <sound/sof/ext_manifest4.h>
 #include <sound/sof/ipc4/header.h>
+#include <trace/events/sof_intel.h>
 #include "../ipc4-priv.h"
 #include "../ops.h"
 #include "hda.h"
@@ -121,9 +122,7 @@ irqreturn_t cnl_ipc_irq_thread(int irq, void *context)
                msg_ext = hipci & CNL_DSP_REG_HIPCIDR_MSG_MASK;
                msg = hipcida & CNL_DSP_REG_HIPCIDA_MSG_MASK;
 
-               dev_vdbg(sdev->dev,
-                        "ipc: firmware response, msg:0x%x, msg_ext:0x%x\n",
-                        msg, msg_ext);
+               trace_sof_intel_ipc_firmware_response(sdev, msg, msg_ext);
 
                /* mask Done interrupt */
                snd_sof_dsp_update_bits(sdev, HDA_DSP_BAR,
@@ -153,9 +152,7 @@ irqreturn_t cnl_ipc_irq_thread(int irq, void *context)
                msg = hipctdr & CNL_DSP_REG_HIPCTDR_MSG_MASK;
                msg_ext = hipctdd & CNL_DSP_REG_HIPCTDD_MSG_MASK;
 
-               dev_vdbg(sdev->dev,
-                        "ipc: firmware initiated, msg:0x%x, msg_ext:0x%x\n",
-                        msg, msg_ext);
+               trace_sof_intel_ipc_firmware_initiated(sdev, msg, msg_ext);
 
                /* handle messages from DSP */
                if ((hipctdr & SOF_IPC_PANIC_MAGIC_MASK) == SOF_IPC_PANIC_MAGIC) {

diff --git a/sound/soc/sof/intel/hda-dsp.c b/sound/soc/sof/intel/hda-dsp.c
index 671c3e02d7df8153bd2d57d722c19f6bf8b56457..1319c8e34021bc5618cbd9fd9a03fde93db5d443 100644 (file)
--- a/sound/soc/sof/intel/hda-dsp.c
+++ b/sound/soc/sof/intel/hda-dsp.c
@@ -18,6 +18,7 @@
 #include <linux/module.h>
 #include <sound/hdaudio_ext.h>
 #include <sound/hda_register.h>
+#include <trace/events/sof_intel.h>
 #include "../sof-audio.h"
 #include "../ops.h"
 #include "hda.h"
@@ -397,8 +398,7 @@ static int hda_dsp_update_d0i3c_register(struct snd_sof_dev *sdev, u8 value)
                return ret;
        }
 
-       dev_vdbg(bus->dev, "D0I3C updated, register = 0x%x\n",
-                snd_hdac_chip_readb(bus, VS_D0I3C));
+       trace_sof_intel_D0I3C_updated(sdev, snd_hdac_chip_readb(bus, VS_D0I3C));
 
        return 0;
 }

diff --git a/sound/soc/sof/intel/hda-ipc.c b/sound/soc/sof/intel/hda-ipc.c
index 65e688f749eaf16955e29d2f7bd52273de024d99..c597ef491d383b4eba0fd7a2b8a69c76f395a7aa 100644 (file)
--- a/sound/soc/sof/intel/hda-ipc.c
+++ b/sound/soc/sof/intel/hda-ipc.c
@@ -16,6 +16,7 @@
  */
 
 #include <sound/sof/ipc4/header.h>
+#include <trace/events/sof_intel.h>
 #include "../ops.h"
 #include "hda.h"
 
@@ -212,9 +213,7 @@ irqreturn_t hda_dsp_ipc_irq_thread(int irq, void *context)
                msg = hipci & HDA_DSP_REG_HIPCI_MSG_MASK;
                msg_ext = hipcie & HDA_DSP_REG_HIPCIE_MSG_MASK;
 
-               dev_vdbg(sdev->dev,
-                        "ipc: firmware response, msg:0x%x, msg_ext:0x%x\n",
-                        msg, msg_ext);
+               trace_sof_intel_ipc_firmware_response(sdev, msg, msg_ext);
 
                /* mask Done interrupt */
                snd_sof_dsp_update_bits(sdev, HDA_DSP_BAR,
@@ -255,9 +254,7 @@ irqreturn_t hda_dsp_ipc_irq_thread(int irq, void *context)
                msg = hipct & HDA_DSP_REG_HIPCT_MSG_MASK;
                msg_ext = hipcte & HDA_DSP_REG_HIPCTE_MSG_MASK;
 
-               dev_vdbg(sdev->dev,
-                        "ipc: firmware initiated, msg:0x%x, msg_ext:0x%x\n",
-                        msg, msg_ext);
+               trace_sof_intel_ipc_firmware_initiated(sdev, msg, msg_ext);
 
                /* mask BUSY interrupt */
                snd_sof_dsp_update_bits(sdev, HDA_DSP_BAR,
@@ -312,7 +309,7 @@ bool hda_dsp_check_ipc_irq(struct snd_sof_dev *sdev)
 
        /* store status */
        irq_status = snd_sof_dsp_read(sdev, HDA_DSP_BAR, HDA_DSP_REG_ADSPIS);
-       dev_vdbg(sdev->dev, "irq handler: irq_status:0x%x\n", irq_status);
+       trace_sof_intel_hda_irq_ipc_check(sdev, irq_status);
 
        /* invalid message ? */
        if (irq_status == 0xffffffff)

diff --git a/sound/soc/sof/intel/hda-pcm.c b/sound/soc/sof/intel/hda-pcm.c
index 6888e0a4665d2d06be1d75719f37983c5d99c83f..0a9c80216a8c29d32878026e31f7169b33830b82 100644 (file)
--- a/sound/soc/sof/intel/hda-pcm.c
+++ b/sound/soc/sof/intel/hda-pcm.c
@@ -18,6 +18,7 @@
 #include <linux/moduleparam.h>
 #include <sound/hda_register.h>
 #include <sound/pcm_params.h>
+#include <trace/events/sof_intel.h>
 #include "../sof-audio.h"
 #include "../ops.h"
 #include "hda.h"
@@ -196,8 +197,7 @@ snd_pcm_uframes_t hda_dsp_pcm_pointer(struct snd_sof_dev *sdev,
 found:
        pos = bytes_to_frames(substream->runtime, pos);
 
-       dev_vdbg(sdev->dev, "PCM: stream %d dir %d position %lu\n",
-                hstream->index, substream->stream, pos);
+       trace_sof_intel_hda_dsp_pcm(sdev, hstream, substream, pos);
        return pos;
 }
 

diff --git a/sound/soc/sof/intel/hda-stream.c b/sound/soc/sof/intel/hda-stream.c
index 8344363beec095e4864da2a88a2787c37d886359..be60e7785da940cd0bbb5ef1b45d30be23a1f4ff 100644 (file)
--- a/sound/soc/sof/intel/hda-stream.c
+++ b/sound/soc/sof/intel/hda-stream.c
@@ -19,6 +19,7 @@
 #include <sound/hdaudio_ext.h>
 #include <sound/hda_register.h>
 #include <sound/sof.h>
+#include <trace/events/sof_intel.h>
 #include "../ops.h"
 #include "../sof-audio.h"
 #include "hda.h"
@@ -697,7 +698,7 @@ bool hda_dsp_check_stream_irq(struct snd_sof_dev *sdev)
        spin_lock_irq(&bus->reg_lock);
 
        status = snd_hdac_chip_readl(bus, INTSTS);
-       dev_vdbg(bus->dev, "stream irq, INTSTS status: 0x%x\n", status);
+       trace_sof_intel_hda_dsp_check_stream_irq(sdev, status);
 
        /* if Register inaccessible, ignore it.*/
        if (status != 0xffffffff)
@@ -736,8 +737,7 @@ static bool hda_dsp_stream_check(struct hdac_bus *bus, u32 status)
                if (status & BIT(s->index) && s->opened) {
                        sd_status = snd_hdac_stream_readb(s, SD_STS);
 
-                       dev_vdbg(bus->dev, "stream %d status 0x%x\n",
-                                s->index, sd_status);
+                       trace_sof_intel_hda_dsp_stream_status(bus->dev, s, sd_status);
 
                        snd_hdac_stream_writeb(s, SD_STS, sd_status);
 

diff --git a/sound/soc/sof/intel/mtl.c b/sound/soc/sof/intel/mtl.c
index 1cc1398336e1ff09091dadd374e4456d7a732d8a..406d58804b5000e5c7ce36bd4f231b5d33ec02c7 100644 (file)
--- a/sound/soc/sof/intel/mtl.c
+++ b/sound/soc/sof/intel/mtl.c
@@ -11,6 +11,7 @@
 
 #include <linux/firmware.h>
 #include <sound/sof/ipc4/header.h>
+#include <trace/events/sof_intel.h>
 #include "../ipc4-priv.h"
 #include "../ops.h"
 #include "hda.h"
@@ -63,7 +64,7 @@ static bool mtl_dsp_check_ipc_irq(struct snd_sof_dev *sdev)
        hfintipptr = snd_sof_dsp_read(sdev, HDA_DSP_BAR, MTL_HFINTIPPTR) & MTL_HFINTIPPTR_PTR_MASK;
        irq_status = snd_sof_dsp_read(sdev, HDA_DSP_BAR, hfintipptr + MTL_DSP_IRQSTS);
 
-       dev_vdbg(sdev->dev, "irq handler: irq_status:0x%x\n", irq_status);
+       trace_sof_intel_hda_irq_ipc_check(sdev, irq_status);
 
        if (irq_status != U32_MAX && (irq_status & MTL_DSP_IRQSTS_IPC))
                return true;