mmc: sdhci: Add tracepoints to enhance debugging

Instrument the sdhci driver with tracepoints to aid in
debugging issues and identifying latencies in the following
path:
* CMD completion
* DATA completion
* DMA preparation
* Post DMA cleanup

Change-Id: Ie8cd0c2fb6c1bd6ab13883123be021081f8b8f78
Signed-off-by: Venkat Gopalakrishnan <venkatg@codeaurora.org>
[subhashj@codeaurora.org: fixed minor merge conflict]
Signed-off-by: Subhash Jadavani <subhashj@codeaurora.org>

drivers/mmc/host/sdhci.c

@@ -32,6 +32,8 @@
 #include <linux/mmc/slot-gpio.h>
 #include <linux/mmc/sdio.h>
 
+#include <trace/events/mmc.h>
+
 #include "sdhci.h"
 
 #define DRIVER_NAME "sdhci"
@@ -663,7 +665,10 @@ static void sdhci_adma_table_post(struct sdhci_host *host,
 	void *align;
 	char *buffer;
 	unsigned long flags;
-	bool has_unaligned;
+	bool has_unaligned = false;
+	u32 command = SDHCI_GET_CMD(sdhci_readw(host, SDHCI_COMMAND));
+
+	trace_mmc_adma_table_post(command, data->sg_len);
 
 	if (data->flags & MMC_DATA_READ)
 		direction = DMA_FROM_DEVICE;
@@ -903,6 +908,7 @@ static void sdhci_prepare_data(struct sdhci_host *host, struct mmc_command *cmd)
 
 	if (host->flags & SDHCI_REQ_USE_DMA) {
 		if (host->flags & SDHCI_USE_ADMA) {
+			trace_mmc_adma_table_pre(cmd->opcode, data->sg_len);
 			ret = sdhci_adma_table_pre(host, data);
 			if (ret) {
 				/*
@@ -1165,6 +1171,7 @@ void sdhci_send_command(struct sdhci_host *host, struct mmc_command *cmd)
 
 	if (cmd->data)
 		host->data_start_time = ktime_get();
+	trace_mmc_cmd_rw_start(cmd->opcode, cmd->arg, cmd->flags);
 	sdhci_writew(host, SDHCI_MAKE_CMD(cmd->opcode, flags), SDHCI_COMMAND);
 }
 EXPORT_SYMBOL_GPL(sdhci_send_command);
@@ -2623,6 +2630,9 @@ static void sdhci_cmd_irq(struct sdhci_host *host, u32 intmask, u32 *mask)
 		return;
 	}
 
+	trace_mmc_cmd_rw_end(host->cmd->opcode, intmask,
+				sdhci_readl(host, SDHCI_RESPONSE));
+
 	if (intmask & SDHCI_INT_TIMEOUT)
 		host->cmd->error = -ETIMEDOUT;
 	else if (intmask & (SDHCI_INT_CRC | SDHCI_INT_END_BIT |
@@ -2720,9 +2730,11 @@ static void sdhci_data_irq(struct sdhci_host *host, u32 intmask)
 	bool pr_msg = false;
 	BUG_ON(intmask == 0);
 
+	command = SDHCI_GET_CMD(sdhci_readw(host, SDHCI_COMMAND));
+	trace_mmc_data_rw_end(command, intmask);
+
 	/* CMD19 generates _only_ Buffer Read Ready interrupt */
 	if (intmask & SDHCI_INT_DATA_AVAIL) {
-		command = SDHCI_GET_CMD(sdhci_readw(host, SDHCI_COMMAND));
 		if (command == MMC_SEND_TUNING_BLOCK ||
 		    command == MMC_SEND_TUNING_BLOCK_HS200) {
 			host->tuning_done = 1;
@@ -2773,8 +2785,7 @@ static void sdhci_data_irq(struct sdhci_host *host, u32 intmask)
 	else if (intmask & SDHCI_INT_DATA_END_BIT)
 		host->data->error = -EILSEQ;
 	else if ((intmask & SDHCI_INT_DATA_CRC) &&
-		SDHCI_GET_CMD(sdhci_readw(host, SDHCI_COMMAND))
-			!= MMC_BUS_TEST_R)
+		(command != MMC_BUS_TEST_R))
 		host->data->error = -EILSEQ;
 	else if (intmask & SDHCI_INT_ADMA_ERROR) {
 		pr_err("%s: ADMA error\n", mmc_hostname(host->mmc));

include/trace/events/mmc.h

@@ -1,5 +1,6 @@
 /*
  * Copyright (C) 2013 Google, Inc.
+ * Copyright (c) 2013-2014, The Linux Foundation. All rights reserved.
  *
  * This software is licensed under the terms of the GNU General Public
  * License version 2, as published by the Free Software Foundation, and
@@ -85,6 +86,78 @@ DEFINE_EVENT_CONDITION(mmc_blk_rw_class, mmc_blk_rw_end,
 	TP_CONDITION(((cmd == MMC_READ_MULTIPLE_BLOCK) ||
 		      (cmd == MMC_WRITE_MULTIPLE_BLOCK)) &&
 		      data));
+
+TRACE_EVENT(mmc_cmd_rw_start,
+	TP_PROTO(unsigned int cmd, unsigned int arg, unsigned int flags),
+	TP_ARGS(cmd, arg, flags),
+	TP_STRUCT__entry(
+		__field(unsigned int, cmd)
+		__field(unsigned int, arg)
+		__field(unsigned int, flags)
+	),
+	TP_fast_assign(
+		__entry->cmd = cmd;
+		__entry->arg = arg;
+		__entry->flags = flags;
+	),
+	TP_printk("cmd=%u,arg=0x%08x,flags=0x%08x",
+		  __entry->cmd, __entry->arg, __entry->flags)
+);
+
+TRACE_EVENT(mmc_cmd_rw_end,
+	TP_PROTO(unsigned int cmd, unsigned int status, unsigned int resp),
+	TP_ARGS(cmd, status, resp),
+	TP_STRUCT__entry(
+		__field(unsigned int, cmd)
+		__field(unsigned int, status)
+		__field(unsigned int, resp)
+	),
+	TP_fast_assign(
+		__entry->cmd = cmd;
+		__entry->status = status;
+		__entry->resp = resp;
+	),
+	TP_printk("cmd=%u,int_status=0x%08x,response=0x%08x",
+		  __entry->cmd, __entry->status, __entry->resp)
+);
+
+TRACE_EVENT(mmc_data_rw_end,
+	TP_PROTO(unsigned int cmd, unsigned int status),
+	TP_ARGS(cmd, status),
+	TP_STRUCT__entry(
+		__field(unsigned int, cmd)
+		__field(unsigned int, status)
+	),
+	TP_fast_assign(
+		__entry->cmd = cmd;
+		__entry->status = status;
+	),
+	TP_printk("cmd=%u,int_status=0x%08x",
+		  __entry->cmd, __entry->status)
+);
+
+DECLARE_EVENT_CLASS(mmc_adma_class,
+	TP_PROTO(unsigned int cmd, unsigned int len),
+	TP_ARGS(cmd, len),
+	TP_STRUCT__entry(
+		__field(unsigned int, cmd)
+		__field(unsigned int, len)
+	),
+	TP_fast_assign(
+		__entry->cmd = cmd;
+		__entry->len = len;
+	),
+	TP_printk("cmd=%u,sg_len=0x%08x", __entry->cmd, __entry->len)
+);
+
+DEFINE_EVENT(mmc_adma_class, mmc_adma_table_pre,
+	TP_PROTO(unsigned int cmd, unsigned int len),
+	TP_ARGS(cmd, len));
+
+DEFINE_EVENT(mmc_adma_class, mmc_adma_table_post,
+	TP_PROTO(unsigned int cmd, unsigned int len),
+	TP_ARGS(cmd, len));
+
 #endif /* _TRACE_MMC_H */
 
 /* This part must be outside protection */