[PATCH 0/7] ath6kl: tracing support

[PATCH 0/7] ath6kl: tracing support

[Kalle Valo]

Finally I added tracing support to ath6kl, should have done that
a long time ago. The tracing framework is new for me so I would
appreciate some more eyeballs to check these.

---

Kalle Valo (7):
      ath6kl: add tracing support and tracing points for wmi packets
      ath6kl: add tracing points for sdio transfers
      ath6kl: add tracing point for hif irqs
      ath6kl: adding tracing points for htc_mbox
      ath6kl: convert ath6kl_info/err/warn macros to real functions
      ath6kl: add tracing support to log functions
      ath6kl: add tracing support to debug message macros


 drivers/net/wireless/ath/ath6kl/Kconfig    |    9 +
 drivers/net/wireless/ath/ath6kl/Makefile   |    5 
 drivers/net/wireless/ath/ath6kl/debug.c    |   12 +
 drivers/net/wireless/ath/ath6kl/debug.h    |   57 +++++-
 drivers/net/wireless/ath/ath6kl/hif.c      |    3 
 drivers/net/wireless/ath/ath6kl/htc_mbox.c |   21 ++
 drivers/net/wireless/ath/ath6kl/sdio.c     |   22 ++
 drivers/net/wireless/ath/ath6kl/trace.c    |   26 +++
 drivers/net/wireless/ath/ath6kl/trace.h    |  283 ++++++++++++++++++++++++++++
 drivers/net/wireless/ath/ath6kl/txrx.c     |    3 
 drivers/net/wireless/ath/ath6kl/wmi.c      |    3 
 11 files changed, 432 insertions(+), 12 deletions(-)
 create mode 100644 drivers/net/wireless/ath/ath6kl/trace.c
 create mode 100644 drivers/net/wireless/ath/ath6kl/trace.h

[PATCH 1/7] ath6kl: add tracing support and tracing points for wmi packets

[Kalle Valo]

Add basic tracing infrastructure support to ath6kl and which can be
enabled with CONFIG_ATH6KL_TRACING.

Signed-off-by: Kalle Valo <kvalo@qca.qualcomm.com>
---
 drivers/net/wireless/ath/ath6kl/Kconfig  |    9 +++
 drivers/net/wireless/ath/ath6kl/Makefile |    5 ++
 drivers/net/wireless/ath/ath6kl/trace.c  |   18 ++++++
 drivers/net/wireless/ath/ath6kl/trace.h  |   87 ++++++++++++++++++++++++++++++
 drivers/net/wireless/ath/ath6kl/txrx.c   |    3 +
 drivers/net/wireless/ath/ath6kl/wmi.c    |    3 +
 6 files changed, 125 insertions(+), 0 deletions(-)
 create mode 100644 drivers/net/wireless/ath/ath6kl/trace.c
 create mode 100644 drivers/net/wireless/ath/ath6kl/trace.h

diff --git a/drivers/net/wireless/ath/ath6kl/Kconfig b/drivers/net/wireless/ath/ath6kl/Kconfig
index 26c4b72..6971b7a 100644
--- a/drivers/net/wireless/ath/ath6kl/Kconfig
+++ b/drivers/net/wireless/ath/ath6kl/Kconfig
@@ -31,6 +31,15 @@ config ATH6KL_DEBUG
 	---help---
 	  Enables debug support
 
+config ATH6KL_TRACING
+	bool "Atheros ath6kl tracing support"
+	depends on ATH6KL
+	depends on EVENT_TRACING
+	---help---
+	  Select this to ath6kl use tracing infrastructure.
+
+	  If unsure, say Y to make it easier to debug problems.
+
 config ATH6KL_REGDOMAIN
 	bool "Atheros ath6kl regdomain support"
 	depends on ATH6KL
diff --git a/drivers/net/wireless/ath/ath6kl/Makefile b/drivers/net/wireless/ath/ath6kl/Makefile
index cab0ec0..dc2b3b4 100644
--- a/drivers/net/wireless/ath/ath6kl/Makefile
+++ b/drivers/net/wireless/ath/ath6kl/Makefile
@@ -35,10 +35,15 @@ ath6kl_core-y += txrx.o
 ath6kl_core-y += wmi.o
 ath6kl_core-y += core.o
 ath6kl_core-y += recovery.o
+
 ath6kl_core-$(CONFIG_NL80211_TESTMODE) += testmode.o
+ath6kl_core-$(CONFIG_ATH6KL_TRACING) += trace.o
 
 obj-$(CONFIG_ATH6KL_SDIO) += ath6kl_sdio.o
 ath6kl_sdio-y += sdio.o
 
 obj-$(CONFIG_ATH6KL_USB) += ath6kl_usb.o
 ath6kl_usb-y += usb.o
+
+# for tracing framework to find trace.h
+CFLAGS_trace.o := -I$(src)
diff --git a/drivers/net/wireless/ath/ath6kl/trace.c b/drivers/net/wireless/ath/ath6kl/trace.c
new file mode 100644
index 0000000..4118a29
--- /dev/null
+++ b/drivers/net/wireless/ath/ath6kl/trace.c
@@ -0,0 +1,18 @@
+/*
+ * Copyright (c) 2012 Qualcomm Atheros, Inc.
+ *
+ * Permission to use, copy, modify, and/or distribute this software for any
+ * purpose with or without fee is hereby granted, provided that the above
+ * copyright notice and this permission notice appear in all copies.
+ *
+ * THE SOFTWARE IS PROVIDED "AS IS" AND THE AUTHOR DISCLAIMS ALL WARRANTIES
+ * WITH REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF
+ * MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR
+ * ANY SPECIAL, DIRECT, INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES
+ * WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN
+ * ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF
+ * OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
+ */
+
+#define CREATE_TRACE_POINTS
+#include "trace.h"
diff --git a/drivers/net/wireless/ath/ath6kl/trace.h b/drivers/net/wireless/ath/ath6kl/trace.h
new file mode 100644
index 0000000..0787619
--- /dev/null
+++ b/drivers/net/wireless/ath/ath6kl/trace.h
@@ -0,0 +1,87 @@
+#if !defined(_ATH6KL_TRACE_H) || defined(TRACE_HEADER_MULTI_READ)
+
+#include <net/cfg80211.h>
+#include <linux/skbuff.h>
+#include <linux/tracepoint.h>
+#include "wmi.h"
+
+#if !defined(_ATH6KL_TRACE_H)
+static inline unsigned int ath6kl_get_wmi_id(void *buf, size_t buf_len)
+{
+	struct wmi_cmd_hdr *hdr = buf;
+
+	if (buf_len < sizeof(*hdr))
+		return 0;
+
+	return le16_to_cpu(hdr->cmd_id);
+}
+#endif /* __ATH6KL_TRACE_H */
+
+#define _ATH6KL_TRACE_H
+
+/* create empty functions when tracing is disabled */
+#if !defined(CONFIG_ATH6KL_TRACING)
+#undef TRACE_EVENT
+#define TRACE_EVENT(name, proto, ...) \
+static inline void trace_ ## name(proto) {}
+#endif /* !CONFIG_ATH6KL_TRACING || __CHECKER__ */
+
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM ath6kl
+
+TRACE_EVENT(ath6kl_wmi_cmd,
+	TP_PROTO(void *buf, size_t buf_len),
+
+	TP_ARGS(buf, buf_len),
+
+	TP_STRUCT__entry(
+		__field(unsigned int, id)
+		__field(size_t, buf_len)
+		__dynamic_array(u8, buf, buf_len)
+	),
+
+	TP_fast_assign(
+		__entry->id = ath6kl_get_wmi_id(buf, buf_len);
+		__entry->buf_len = buf_len;
+		memcpy(__get_dynamic_array(buf), buf, buf_len);
+	),
+
+	TP_printk(
+		"id %d len %d",
+		__entry->id, __entry->buf_len
+	)
+);
+
+TRACE_EVENT(ath6kl_wmi_event,
+	TP_PROTO(void *buf, size_t buf_len),
+
+	TP_ARGS(buf, buf_len),
+
+	TP_STRUCT__entry(
+		__field(unsigned int, id)
+		__field(size_t, buf_len)
+		__dynamic_array(u8, buf, buf_len)
+	),
+
+	TP_fast_assign(
+		__entry->id = ath6kl_get_wmi_id(buf, buf_len);
+		__entry->buf_len = buf_len;
+		memcpy(__get_dynamic_array(buf), buf, buf_len);
+	),
+
+	TP_printk(
+		"id %d len %d",
+		__entry->id, __entry->buf_len
+	)
+);
+
+#endif /* _ ATH6KL_TRACE_H || TRACE_HEADER_MULTI_READ*/
+
+/* we don't want to use include/trace/events */
+#undef TRACE_INCLUDE_PATH
+#define TRACE_INCLUDE_PATH .
+#undef TRACE_INCLUDE_FILE
+#define TRACE_INCLUDE_FILE trace
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>
diff --git a/drivers/net/wireless/ath/ath6kl/txrx.c b/drivers/net/wireless/ath/ath6kl/txrx.c
index 78b3692..43dbdaa 100644
--- a/drivers/net/wireless/ath/ath6kl/txrx.c
+++ b/drivers/net/wireless/ath/ath6kl/txrx.c
@@ -20,6 +20,7 @@
 #include "core.h"
 #include "debug.h"
 #include "htc-ops.h"
+#include "trace.h"
 
 /*
  * tid - tid_mux0..tid_mux3
@@ -288,6 +289,8 @@ int ath6kl_control_tx(void *devt, struct sk_buff *skb,
 	int status = 0;
 	struct ath6kl_cookie *cookie = NULL;
 
+	trace_ath6kl_wmi_cmd(skb->data, skb->len);
+
 	if (WARN_ON_ONCE(ar->state == ATH6KL_STATE_WOW)) {
 		dev_kfree_skb(skb);
 		return -EACCES;
diff --git a/drivers/net/wireless/ath/ath6kl/wmi.c b/drivers/net/wireless/ath/ath6kl/wmi.c
index 214f741..7c8c535 100644
--- a/drivers/net/wireless/ath/ath6kl/wmi.c
+++ b/drivers/net/wireless/ath/ath6kl/wmi.c
@@ -20,6 +20,7 @@
 #include "core.h"
 #include "debug.h"
 #include "testmode.h"
+#include "trace.h"
 #include "../regd.h"
 #include "../regd_common.h"
 
@@ -4086,6 +4087,8 @@ int ath6kl_wmi_control_rx(struct wmi *wmi, struct sk_buff *skb)
 		return -EINVAL;
 	}
 
+	trace_ath6kl_wmi_event(skb->data, skb->len);
+
 	return ath6kl_wmi_proc_events(wmi, skb);
 }
 

[PATCH 2/7] ath6kl: add tracing points for sdio transfers

[Kalle Valo]

Add tracing points for sdio transfers, just dump the address, flags and the
buffer.

Signed-off-by: Kalle Valo <kvalo@qca.qualcomm.com>
---
 drivers/net/wireless/ath/ath6kl/sdio.c  |   22 ++++++++++++++++-
 drivers/net/wireless/ath/ath6kl/trace.c |    5 ++++
 drivers/net/wireless/ath/ath6kl/trace.h |   41 +++++++++++++++++++++++++++++++
 3 files changed, 67 insertions(+), 1 deletions(-)

diff --git a/drivers/net/wireless/ath/ath6kl/sdio.c b/drivers/net/wireless/ath/ath6kl/sdio.c
index d111980..df2131d 100644
--- a/drivers/net/wireless/ath/ath6kl/sdio.c
+++ b/drivers/net/wireless/ath/ath6kl/sdio.c
@@ -28,6 +28,7 @@
 #include "target.h"
 #include "debug.h"
 #include "cfg80211.h"
+#include "trace.h"
 
 struct ath6kl_sdio {
 	struct sdio_func *func;
@@ -179,6 +180,11 @@ static int ath6kl_sdio_io(struct sdio_func *func, u32 request, u32 addr,
 		   request & HIF_FIXED_ADDRESS ? " (fixed)" : "", buf, len);
 	ath6kl_dbg_dump(ATH6KL_DBG_SDIO_DUMP, NULL, "sdio ", buf, len);
 
+	if (request & HIF_WRITE)
+		trace_ath6kl_sdio_wr(addr, request, buf, len);
+	else
+		trace_ath6kl_sdio_rd(addr, request, buf, len);
+
 	return ret;
 }
 
@@ -260,7 +266,7 @@ static int ath6kl_sdio_scat_rw(struct ath6kl_sdio *ar_sdio,
 	struct mmc_data data;
 	struct hif_scatter_req *scat_req;
 	u8 opcode, rw;
-	int status, len;
+	int status, len, i;
 
 	scat_req = req->scat_req;
 
@@ -309,6 +315,20 @@ static int ath6kl_sdio_scat_rw(struct ath6kl_sdio *ar_sdio,
 	sdio_claim_host(ar_sdio->func);
 
 	mmc_set_data_timeout(&data, ar_sdio->func->card);
+
+	for (i = 0; i < scat_req->scat_entries; i++) {
+		if (scat_req->req & HIF_WRITE)
+			trace_ath6kl_sdio_wr(scat_req->addr,
+					     scat_req->req,
+					     scat_req->scat_list[i].buf,
+					     scat_req->scat_list[i].len);
+		else
+			trace_ath6kl_sdio_rd(scat_req->addr,
+					     scat_req->req,
+					     scat_req->scat_list[i].buf,
+					     scat_req->scat_list[i].len);
+	}
+
 	/* synchronous call to process request */
 	mmc_wait_for_req(ar_sdio->func->card->host, &mmc_req);
 
diff --git a/drivers/net/wireless/ath/ath6kl/trace.c b/drivers/net/wireless/ath/ath6kl/trace.c
index 4118a29..adc74a0 100644
--- a/drivers/net/wireless/ath/ath6kl/trace.c
+++ b/drivers/net/wireless/ath/ath6kl/trace.c
@@ -14,5 +14,10 @@
  * OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
  */
 
+#include <linux/module.h>
+
 #define CREATE_TRACE_POINTS
 #include "trace.h"
+
+EXPORT_TRACEPOINT_SYMBOL(ath6kl_sdio_wr);
+EXPORT_TRACEPOINT_SYMBOL(ath6kl_sdio_rd);
diff --git a/drivers/net/wireless/ath/ath6kl/trace.h b/drivers/net/wireless/ath/ath6kl/trace.h
index 0787619..be2e4e2 100644
--- a/drivers/net/wireless/ath/ath6kl/trace.h
+++ b/drivers/net/wireless/ath/ath6kl/trace.h
@@ -75,6 +75,47 @@ TRACE_EVENT(ath6kl_wmi_event,
 	)
 );
 
+/* FIXME: add sg count */
+DECLARE_EVENT_CLASS(ath6kl_sdio_transaction,
+	TP_PROTO(unsigned int addr, int flags,
+		 void *buf, size_t buf_len),
+
+	TP_ARGS(addr, flags, buf, buf_len),
+
+	TP_STRUCT__entry(
+		__field(unsigned int, addr)
+		__field(int, flags)
+		__field(size_t, buf_len)
+		__dynamic_array(u8, buf, buf_len)
+	),
+
+	TP_fast_assign(
+		__entry->addr = addr;
+		__entry->flags = flags;
+		__entry->buf_len = buf_len;
+		memcpy(__get_dynamic_array(buf), buf, buf_len);
+	),
+
+	TP_printk(
+		"addr 0x%x flags 0x%x len %d\n",
+		__entry->addr,
+		__entry->flags,
+		__entry->buf_len
+	)
+);
+
+DEFINE_EVENT(ath6kl_sdio_transaction, ath6kl_sdio_wr,
+	TP_PROTO(unsigned int addr, int flags,
+		 void *buf, size_t buf_len),
+	TP_ARGS(addr, flags, buf, buf_len)
+);
+
+DEFINE_EVENT(ath6kl_sdio_transaction, ath6kl_sdio_rd,
+	TP_PROTO(unsigned int addr, int flags,
+		 void *buf, size_t buf_len),
+	TP_ARGS(addr, flags, buf, buf_len)
+);
+
 #endif /* _ ATH6KL_TRACE_H || TRACE_HEADER_MULTI_READ*/
 
 /* we don't want to use include/trace/events */

[PATCH 3/7] ath6kl: add tracing point for hif irqs

[Kalle Valo]

Add a tracing point for hif irq and dump the register content to user space.
This is in hif.c as we could use the same code also with SPI but, as ath6kl
doesn't SPI and most likely never will be, this is used just by SDIO so
name the trace point as ath6kl_sdio_irq to make it easier to manage filters.

Signed-off-by: Kalle Valo <kvalo@qca.qualcomm.com>
---
 drivers/net/wireless/ath/ath6kl/hif.c   |    3 +++
 drivers/net/wireless/ath/ath6kl/trace.h |   20 ++++++++++++++++++++
 2 files changed, 23 insertions(+), 0 deletions(-)

diff --git a/drivers/net/wireless/ath/ath6kl/hif.c b/drivers/net/wireless/ath/ath6kl/hif.c
index a6b6144..fea7709 100644
--- a/drivers/net/wireless/ath/ath6kl/hif.c
+++ b/drivers/net/wireless/ath/ath6kl/hif.c
@@ -22,6 +22,7 @@
 #include "target.h"
 #include "hif-ops.h"
 #include "debug.h"
+#include "trace.h"
 
 #define MAILBOX_FOR_BLOCK_SIZE          1
 
@@ -436,6 +437,8 @@ static int proc_pending_irqs(struct ath6kl_device *dev, bool *done)
 
 		ath6kl_dump_registers(dev, &dev->irq_proc_reg,
 				      &dev->irq_en_reg);
+		trace_ath6kl_sdio_irq(&dev->irq_en_reg,
+				      sizeof(dev->irq_en_reg));
 
 		/* Update only those registers that are enabled */
 		host_int_status = dev->irq_proc_reg.host_int_status &
diff --git a/drivers/net/wireless/ath/ath6kl/trace.h b/drivers/net/wireless/ath/ath6kl/trace.h
index be2e4e2..6553dc1 100644
--- a/drivers/net/wireless/ath/ath6kl/trace.h
+++ b/drivers/net/wireless/ath/ath6kl/trace.h
@@ -116,6 +116,26 @@ DEFINE_EVENT(ath6kl_sdio_transaction, ath6kl_sdio_rd,
 	TP_ARGS(addr, flags, buf, buf_len)
 );
 
+TRACE_EVENT(ath6kl_sdio_irq,
+	TP_PROTO(void *buf, size_t buf_len),
+
+	TP_ARGS(buf, buf_len),
+
+	TP_STRUCT__entry(
+		__field(size_t, buf_len)
+		__dynamic_array(u8, buf, buf_len)
+	),
+
+	TP_fast_assign(
+		__entry->buf_len = buf_len;
+		memcpy(__get_dynamic_array(buf), buf, buf_len);
+	),
+
+	TP_printk(
+		"irq len %d\n", __entry->buf_len
+	)
+);
+
 #endif /* _ ATH6KL_TRACE_H || TRACE_HEADER_MULTI_READ*/
 
 /* we don't want to use include/trace/events */

[PATCH 4/7] ath6kl: adding tracing points for htc_mbox

[Kalle Valo]

Add tracing points for htc layer, just dumping the packets to user space.
I wasn't really sure what to do with the status value, it might not always
be accurate, but I included it anyway.

I skipped htc_pipe (and usb) implementation for now. Need to add those
tracepoints later.

Signed-off-by: Kalle Valo <kvalo@qca.qualcomm.com>
---
 drivers/net/wireless/ath/ath6kl/htc_mbox.c |   21 ++++++++++-
 drivers/net/wireless/ath/ath6kl/trace.h    |   56 ++++++++++++++++++++++++++++
 2 files changed, 76 insertions(+), 1 deletions(-)

diff --git a/drivers/net/wireless/ath/ath6kl/htc_mbox.c b/drivers/net/wireless/ath/ath6kl/htc_mbox.c
index fbb78df..65e5b71 100644
--- a/drivers/net/wireless/ath/ath6kl/htc_mbox.c
+++ b/drivers/net/wireless/ath/ath6kl/htc_mbox.c
@@ -19,6 +19,8 @@
 #include "hif.h"
 #include "debug.h"
 #include "hif-ops.h"
+#include "trace.h"
+
 #include <asm/unaligned.h>
 
 #define CALC_TXRX_PADDED_LEN(dev, len)  (__ALIGN_MASK((len), (dev)->block_mask))
@@ -537,6 +539,8 @@ static int ath6kl_htc_tx_issue(struct htc_target *target,
 				packet->buf, padded_len,
 				HIF_WR_ASYNC_BLOCK_INC, packet);
 
+	trace_ath6kl_htc_tx(status, packet->endpoint, packet->buf, send_len);
+
 	return status;
 }
 
@@ -757,7 +761,8 @@ static void ath6kl_htc_tx_bundle(struct htc_endpoint *endpoint,
 {
 	struct htc_target *target = endpoint->target;
 	struct hif_scatter_req *scat_req = NULL;
-	int n_scat, n_sent_bundle = 0, tot_pkts_bundle = 0;
+	int n_scat, n_sent_bundle = 0, tot_pkts_bundle = 0, i;
+	struct htc_packet *packet;
 	int status;
 	u32 txb_mask;
 	u8 ac = WMM_NUM_AC;
@@ -832,6 +837,13 @@ static void ath6kl_htc_tx_bundle(struct htc_endpoint *endpoint,
 		ath6kl_dbg(ATH6KL_DBG_HTC,
 			   "htc tx scatter bytes %d entries %d\n",
 			   scat_req->len, scat_req->scat_entries);
+
+		for (i = 0; i < scat_req->scat_entries; i++) {
+			packet = scat_req->scat_list[i].packet;
+			trace_ath6kl_htc_tx(packet->status, packet->endpoint,
+					    packet->buf, packet->act_len);
+		}
+
 		ath6kl_hif_submit_scat_req(target->dev, scat_req, false);
 
 		if (status)
@@ -1903,6 +1915,7 @@ static void ath6kl_htc_rx_complete(struct htc_endpoint *endpoint,
 		ath6kl_dbg(ATH6KL_DBG_HTC,
 			   "htc rx complete ep %d packet 0x%p\n",
 			   endpoint->eid, packet);
+
 		endpoint->ep_cb.rx(endpoint->target, packet);
 }
 
@@ -2011,6 +2024,9 @@ static int ath6kl_htc_rx_process_packets(struct htc_target *target,
 	list_for_each_entry_safe(packet, tmp_pkt, comp_pktq, list) {
 		ep = &target->endpoint[packet->endpoint];
 
+		trace_ath6kl_htc_rx(packet->status, packet->endpoint,
+				    packet->buf, packet->act_len);
+
 		/* process header for each of the recv packet */
 		status = ath6kl_htc_rx_process_hdr(target, packet, lk_ahds,
 						   n_lk_ahd);
@@ -2291,6 +2307,9 @@ static struct htc_packet *htc_wait_for_ctrl_msg(struct htc_target *target)
 	if (ath6kl_htc_rx_packet(target, packet, packet->act_len))
 		goto fail_ctrl_rx;
 
+	trace_ath6kl_htc_rx(packet->status, packet->endpoint,
+			    packet->buf, packet->act_len);
+
 	/* process receive header */
 	packet->status = ath6kl_htc_rx_process_hdr(target, packet, NULL, NULL);
 
diff --git a/drivers/net/wireless/ath/ath6kl/trace.h b/drivers/net/wireless/ath/ath6kl/trace.h
index 6553dc1..f5838e0 100644
--- a/drivers/net/wireless/ath/ath6kl/trace.h
+++ b/drivers/net/wireless/ath/ath6kl/trace.h
@@ -136,6 +136,62 @@ TRACE_EVENT(ath6kl_sdio_irq,
 	)
 );
 
+TRACE_EVENT(ath6kl_htc_rx,
+	TP_PROTO(int status, int endpoint, void *buf,
+		 size_t buf_len),
+
+	TP_ARGS(status, endpoint, buf, buf_len),
+
+	TP_STRUCT__entry(
+		__field(int, status)
+		__field(int, endpoint)
+		__field(size_t, buf_len)
+		__dynamic_array(u8, buf, buf_len)
+	),
+
+	TP_fast_assign(
+		__entry->status = status;
+		__entry->endpoint = endpoint;
+		__entry->buf_len = buf_len;
+		memcpy(__get_dynamic_array(buf), buf, buf_len);
+	),
+
+	TP_printk(
+		"status %d endpoint %d len %d\n",
+		__entry->status,
+		__entry->endpoint,
+		__entry->buf_len
+	)
+);
+
+TRACE_EVENT(ath6kl_htc_tx,
+	TP_PROTO(int status, int endpoint, void *buf,
+		 size_t buf_len),
+
+	TP_ARGS(status, endpoint, buf, buf_len),
+
+	TP_STRUCT__entry(
+		__field(int, status)
+		__field(int, endpoint)
+		__field(size_t, buf_len)
+		__dynamic_array(u8, buf, buf_len)
+	),
+
+	TP_fast_assign(
+		__entry->status = status;
+		__entry->endpoint = endpoint;
+		__entry->buf_len = buf_len;
+		memcpy(__get_dynamic_array(buf), buf, buf_len);
+	),
+
+	TP_printk(
+		"status %d endpoint %d len %d\n",
+		__entry->status,
+		__entry->endpoint,
+		__entry->buf_len
+	)
+);
+
 #endif /* _ ATH6KL_TRACE_H || TRACE_HEADER_MULTI_READ*/
 
 /* we don't want to use include/trace/events */

[PATCH 5/7] ath6kl: convert ath6kl_info/err/warn macros to real functions

[Kalle Valo]

After this it's cleaner to add trace calls. And besides, I prefer C over
CPP.

Signed-off-by: Kalle Valo <kvalo@qca.qualcomm.com>
---
 drivers/net/wireless/ath/ath6kl/debug.h |   53 +++++++++++++++++++++++++++----
 1 files changed, 47 insertions(+), 6 deletions(-)

diff --git a/drivers/net/wireless/ath/ath6kl/debug.h b/drivers/net/wireless/ath/ath6kl/debug.h
index f97cd4e..06f47f5 100644
--- a/drivers/net/wireless/ath/ath6kl/debug.h
+++ b/drivers/net/wireless/ath/ath6kl/debug.h
@@ -52,12 +52,53 @@ extern unsigned int debug_mask;
 extern __printf(2, 3)
 int ath6kl_printk(const char *level, const char *fmt, ...);
 
-#define ath6kl_info(fmt, ...)				\
-	ath6kl_printk(KERN_INFO, fmt, ##__VA_ARGS__)
-#define ath6kl_err(fmt, ...)					\
-	ath6kl_printk(KERN_ERR, fmt, ##__VA_ARGS__)
-#define ath6kl_warn(fmt, ...)					\
-	ath6kl_printk(KERN_WARNING, fmt, ##__VA_ARGS__)
+static inline __printf(1,2) int ath6kl_info(const char *fmt, ...)
+{
+	struct va_format vaf = {
+		.fmt = fmt,
+	};
+	va_list args;
+	int ret;
+
+	va_start(args, fmt);
+	vaf.va = &args;
+	ret = ath6kl_printk(KERN_INFO, "%pV", &vaf);
+	va_end(args);
+
+	return ret;
+}
+
+static inline __printf(1,2) int ath6kl_err(const char *fmt, ...)
+{
+	struct va_format vaf = {
+		.fmt = fmt,
+	};
+	va_list args;
+	int ret;
+
+	va_start(args, fmt);
+	vaf.va = &args;
+	ret = ath6kl_printk(KERN_ERR, "%pV", &vaf);
+	va_end(args);
+
+	return ret;
+}
+
+static inline __printf(1,2) int ath6kl_warn(const char *fmt, ...)
+{
+	struct va_format vaf = {
+		.fmt = fmt,
+	};
+	va_list args;
+	int ret;
+
+	va_start(args, fmt);
+	vaf.va = &args;
+	ret = ath6kl_printk(KERN_WARNING, "%pV", &vaf);
+	va_end(args);
+
+	return ret;
+}
 
 enum ath6kl_war {
 	ATH6KL_WAR_INVALID_RATE,

[PATCH 6/7] ath6kl: add tracing support to log functions

[Kalle Valo]

All log messages are now sent through tracing interface as well if
ATH6KL_TRACING is enabled.

Signed-off-by: Kalle Valo <kvalo@qca.qualcomm.com>
---
 drivers/net/wireless/ath/ath6kl/debug.h |    4 +++
 drivers/net/wireless/ath/ath6kl/trace.c |    3 +++
 drivers/net/wireless/ath/ath6kl/trace.h |   37 +++++++++++++++++++++++++++++++
 3 files changed, 44 insertions(+), 0 deletions(-)

diff --git a/drivers/net/wireless/ath/ath6kl/debug.h b/drivers/net/wireless/ath/ath6kl/debug.h
index 06f47f5..b6c7ff1 100644
--- a/drivers/net/wireless/ath/ath6kl/debug.h
+++ b/drivers/net/wireless/ath/ath6kl/debug.h
@@ -19,6 +19,7 @@
 #define DEBUG_H
 
 #include "hif.h"
+#include "trace.h"
 
 enum ATH6K_DEBUG_MASK {
 	ATH6KL_DBG_CREDIT	= BIT(0),
@@ -63,6 +64,7 @@ static inline __printf(1,2) int ath6kl_info(const char *fmt, ...)
 	va_start(args, fmt);
 	vaf.va = &args;
 	ret = ath6kl_printk(KERN_INFO, "%pV", &vaf);
+	trace_ath6kl_log_info(&vaf);
 	va_end(args);
 
 	return ret;
@@ -79,6 +81,7 @@ static inline __printf(1,2) int ath6kl_err(const char *fmt, ...)
 	va_start(args, fmt);
 	vaf.va = &args;
 	ret = ath6kl_printk(KERN_ERR, "%pV", &vaf);
+	trace_ath6kl_log_err(&vaf);
 	va_end(args);
 
 	return ret;
@@ -95,6 +98,7 @@ static inline __printf(1,2) int ath6kl_warn(const char *fmt, ...)
 	va_start(args, fmt);
 	vaf.va = &args;
 	ret = ath6kl_printk(KERN_WARNING, "%pV", &vaf);
+	trace_ath6kl_log_warn(&vaf);
 	va_end(args);
 
 	return ret;
diff --git a/drivers/net/wireless/ath/ath6kl/trace.c b/drivers/net/wireless/ath/ath6kl/trace.c
index adc74a0..68eece7 100644
--- a/drivers/net/wireless/ath/ath6kl/trace.c
+++ b/drivers/net/wireless/ath/ath6kl/trace.c
@@ -21,3 +21,6 @@
 
 EXPORT_TRACEPOINT_SYMBOL(ath6kl_sdio_wr);
 EXPORT_TRACEPOINT_SYMBOL(ath6kl_sdio_rd);
+EXPORT_TRACEPOINT_SYMBOL(ath6kl_log_info);
+EXPORT_TRACEPOINT_SYMBOL(ath6kl_log_warn);
+EXPORT_TRACEPOINT_SYMBOL(ath6kl_log_err);
diff --git a/drivers/net/wireless/ath/ath6kl/trace.h b/drivers/net/wireless/ath/ath6kl/trace.h
index f5838e0..8278143 100644
--- a/drivers/net/wireless/ath/ath6kl/trace.h
+++ b/drivers/net/wireless/ath/ath6kl/trace.h
@@ -24,6 +24,11 @@ static inline unsigned int ath6kl_get_wmi_id(void *buf, size_t buf_len)
 #undef TRACE_EVENT
 #define TRACE_EVENT(name, proto, ...) \
 static inline void trace_ ## name(proto) {}
+#undef DECLARE_EVENT_CLASS
+#define DECLARE_EVENT_CLASS(...)
+#undef DEFINE_EVENT
+#define DEFINE_EVENT(evt_class, name, proto, ...) \
+static inline void trace_ ## name(proto) {}
 #endif /* !CONFIG_ATH6KL_TRACING || __CHECKER__ */
 
 #undef TRACE_SYSTEM
@@ -192,6 +197,38 @@ TRACE_EVENT(ath6kl_htc_tx,
 	)
 );
 
+#define ATH6KL_MSG_MAX 200
+
+DECLARE_EVENT_CLASS(ath6kl_log_event,
+	TP_PROTO(struct va_format *vaf),
+	TP_ARGS(vaf),
+	TP_STRUCT__entry(
+		__dynamic_array(char, msg, ATH6KL_MSG_MAX)
+	),
+	TP_fast_assign(
+		WARN_ON_ONCE(vsnprintf(__get_dynamic_array(msg),
+				       ATH6KL_MSG_MAX,
+				       vaf->fmt,
+				       *vaf->va) >= ATH6KL_MSG_MAX);
+	),
+	TP_printk("%s", __get_str(msg))
+);
+
+DEFINE_EVENT(ath6kl_log_event, ath6kl_log_err,
+	     TP_PROTO(struct va_format *vaf),
+	     TP_ARGS(vaf)
+);
+
+DEFINE_EVENT(ath6kl_log_event, ath6kl_log_warn,
+	     TP_PROTO(struct va_format *vaf),
+	     TP_ARGS(vaf)
+);
+
+DEFINE_EVENT(ath6kl_log_event, ath6kl_log_info,
+	     TP_PROTO(struct va_format *vaf),
+	     TP_ARGS(vaf)
+);
+
 #endif /* _ ATH6KL_TRACE_H || TRACE_HEADER_MULTI_READ*/
 
 /* we don't want to use include/trace/events */

[PATCH 7/7] ath6kl: add tracing support to debug message macros

[Kalle Valo]

Now all log messages are sent through the tracing infrastruture as well.
Tracing point doesn't follow debug_mask module parameter, instead it sends
all debug messages, so once you enable ath6kl_log_dbg tracing point you will
get a lot of messages. Needs to be discussed if this is sensible or not.
The overhead should be small enough and we anyway include debug level as
well so it's easy to filter in user space.

I wasn't really sure what to do with ath6kl_dbg_dump() and for now decided
that it also sends the buffer to user space. But most likely in the future
ath6kl_dbg_dump() should go away in favor of using proper tracing points but
we will see.

Signed-off-by: Kalle Valo <kvalo@qca.qualcomm.com>
---
 drivers/net/wireless/ath/ath6kl/debug.c |   12 ++++++---
 drivers/net/wireless/ath/ath6kl/trace.h |   42 +++++++++++++++++++++++++++++++
 2 files changed, 50 insertions(+), 4 deletions(-)

diff --git a/drivers/net/wireless/ath/ath6kl/debug.c b/drivers/net/wireless/ath/ath6kl/debug.c
index 15cfe30..2620910 100644
--- a/drivers/net/wireless/ath/ath6kl/debug.c
+++ b/drivers/net/wireless/ath/ath6kl/debug.c
@@ -63,15 +63,15 @@ void ath6kl_dbg(enum ATH6K_DEBUG_MASK mask, const char *fmt, ...)
 	struct va_format vaf;
 	va_list args;
 
-	if (!(debug_mask & mask))
-		return;
-
 	va_start(args, fmt);
 
 	vaf.fmt = fmt;
 	vaf.va = &args;
 
-	ath6kl_printk(KERN_DEBUG, "%pV", &vaf);
+	if (debug_mask & mask)
+		ath6kl_printk(KERN_DEBUG, "%pV", &vaf);
+
+	trace_ath6kl_log_dbg(mask, &vaf);
 
 	va_end(args);
 }
@@ -87,6 +87,10 @@ void ath6kl_dbg_dump(enum ATH6K_DEBUG_MASK mask,
 
 		print_hex_dump_bytes(prefix, DUMP_PREFIX_OFFSET, buf, len);
 	}
+
+	/* tracing code doesn't like null strings :/ */
+	trace_ath6kl_log_dbg_dump(msg ? msg : "", prefix ? prefix : "",
+				  buf, len);
 }
 EXPORT_SYMBOL(ath6kl_dbg_dump);
 
diff --git a/drivers/net/wireless/ath/ath6kl/trace.h b/drivers/net/wireless/ath/ath6kl/trace.h
index 8278143..0676ef0 100644
--- a/drivers/net/wireless/ath/ath6kl/trace.h
+++ b/drivers/net/wireless/ath/ath6kl/trace.h
@@ -229,6 +229,48 @@ DEFINE_EVENT(ath6kl_log_event, ath6kl_log_info,
 	     TP_ARGS(vaf)
 );
 
+TRACE_EVENT(ath6kl_log_dbg,
+	TP_PROTO(unsigned int level, struct va_format *vaf),
+	TP_ARGS(level, vaf),
+	TP_STRUCT__entry(
+		__field(unsigned int, level)
+		__dynamic_array(char, msg, ATH6KL_MSG_MAX)
+	),
+	TP_fast_assign(
+		__entry->level = level;
+		WARN_ON_ONCE(vsnprintf(__get_dynamic_array(msg),
+				       ATH6KL_MSG_MAX,
+				       vaf->fmt,
+				       *vaf->va) >= ATH6KL_MSG_MAX);
+	),
+	TP_printk("%s", __get_str(msg))
+);
+
+TRACE_EVENT(ath6kl_log_dbg_dump,
+	TP_PROTO(const char *msg, const char *prefix,
+		 const void *buf, size_t buf_len),
+
+	TP_ARGS(msg, prefix, buf, buf_len),
+
+	TP_STRUCT__entry(
+		__string(msg, msg)
+		__string(prefix, prefix)
+		__field(size_t, buf_len)
+		__dynamic_array(u8, buf, buf_len)
+	),
+
+	TP_fast_assign(
+		__assign_str(msg, msg);
+		__assign_str(prefix, prefix);
+		__entry->buf_len = buf_len;
+		memcpy(__get_dynamic_array(buf), buf, buf_len);
+	),
+
+	TP_printk(
+		"%s/%s\n", __get_str(prefix), __get_str(msg)
+	)
+);
+
 #endif /* _ ATH6KL_TRACE_H || TRACE_HEADER_MULTI_READ*/
 
 /* we don't want to use include/trace/events */

Re: [PATCH 2/7] ath6kl: add tracing points for sdio transfers

[Johannes Berg]

On Thu, 2012-12-27 at 13:44 +0200, Kalle Valo wrote:

> +	if (request & HIF_WRITE)
> +		trace_ath6kl_sdio_wr(addr, request, buf, len);
> +	else
> +		trace_ath6kl_sdio_rd(addr, request, buf, len);

It would be more efficient to use a single tracepoint and have a
"direction" field or so -- then the if doesn't have to be executed when
tracing is disabled.


> +	for (i = 0; i < scat_req->scat_entries; i++) {
> +		if (scat_req->req & HIF_WRITE)
> +			trace_ath6kl_sdio_wr(scat_req->addr,
> +					     scat_req->req,
> +					     scat_req->scat_list[i].buf,
> +					     scat_req->scat_list[i].len);
> +		else
> +			trace_ath6kl_sdio_rd(scat_req->addr,
> +					     scat_req->req,
> +					     scat_req->scat_list[i].buf,
> +					     scat_req->scat_list[i].len);
> +	}

Same here, although it would be even better to move the loop into the
tracepoint ... is there a small upper bound on "scat_entries"? If yes,
you could do something like here:

http://git.kernel.org/?p=linux/kernel/git/iwlwifi/iwlwifi-next.git;a=blob;f=drivers/net/wireless/iwlwifi/iwl-devtrace.h;hb=HEAD#l325

where I put a function call into the __entry to figure out how much
space is needed.

johannes

Re: [PATCH 5/7] ath6kl: convert ath6kl_info/err/warn macros to real functions

[Johannes Berg]

On Thu, 2012-12-27 at 13:44 +0200, Kalle Valo wrote:

> +	va_start(args, fmt);
> +	vaf.va = &args;
> +	ret = ath6kl_printk(KERN_WARNING, "%pV", &vaf);
> +	va_end(args);

Note that by inserting the tracing here later, you're relying on the
fact that "%pV" does va_copy(). This isn't true in all kernel versions,
I think there's on version or so where %pV is supported but didn't
va_copy(). That may lead to problems (I don't remember what kind) here.

This is relevant for compat only, I think I carry a patch there to add
va_copy() into the tracing or something.

johannes

Re: [PATCH 2/7] ath6kl: add tracing points for sdio transfers

[Kalle Valo]

Johannes Berg <johannes@sipsolutions.net> writes:

> On Thu, 2012-12-27 at 13:44 +0200, Kalle Valo wrote:
>
>> +	if (request & HIF_WRITE)
>> +		trace_ath6kl_sdio_wr(addr, request, buf, len);
>> +	else
>> +		trace_ath6kl_sdio_rd(addr, request, buf, len);
>
> It would be more efficient to use a single tracepoint and have a
> "direction" field or so -- then the if doesn't have to be executed when
> tracing is disabled.

Heh, I first had a single tracepoint with an int (1 == tx, 0 == rx) for
this but then I split it to two tracepoints just to make it easier for
filtering. But it would be good to get rid of that extra if.

One way would be to just remove if the clause and let user space parse
the request variable (btw which should be renamed to flags) but then
implementing printk for the trace point is more difficult as HIF_WRITE
is defined for the printk. Is there any easy way to "export" some of the
defines, like HIF_WRITE, for the printk part in a tracepoint?

>> +	for (i = 0; i < scat_req->scat_entries; i++) {
>> +		if (scat_req->req & HIF_WRITE)
>> +			trace_ath6kl_sdio_wr(scat_req->addr,
>> +					     scat_req->req,
>> +					     scat_req->scat_list[i].buf,
>> +					     scat_req->scat_list[i].len);
>> +		else
>> +			trace_ath6kl_sdio_rd(scat_req->addr,
>> +					     scat_req->req,
>> +					     scat_req->scat_list[i].buf,
>> +					     scat_req->scat_list[i].len);
>> +	}
>
> Same here, although it would be even better to move the loop into the
> tracepoint ... is there a small upper bound on "scat_entries"?

Yes, the limit should be 8.

> If yes, you could do something like here:
>
> http://git.kernel.org/?p=linux/kernel/git/iwlwifi/iwlwifi-next.git;a=blob;f=drivers/net/wireless/iwlwifi/iwl-devtrace.h;hb=HEAD#l325
>
> where I put a function call into the __entry to figure out how much
> space is needed.

That looks good, I'll take a look and try to implement the same for
ath6kl.

Thank you for the review!

Kalle

Re: [PATCH 5/7] ath6kl: convert ath6kl_info/err/warn macros to real functions

[Kalle Valo]

Johannes Berg <johannes@sipsolutions.net> writes:

> On Thu, 2012-12-27 at 13:44 +0200, Kalle Valo wrote:
>
>> +	va_start(args, fmt);
>> +	vaf.va = &args;
>> +	ret = ath6kl_printk(KERN_WARNING, "%pV", &vaf);
>> +	va_end(args);
>
> Note that by inserting the tracing here later, you're relying on the
> fact that "%pV" does va_copy(). This isn't true in all kernel versions,
> I think there's on version or so where %pV is supported but didn't
> va_copy(). That may lead to problems (I don't remember what kind) here.
>
> This is relevant for compat only, I think I carry a patch there to add
> va_copy() into the tracing or something.

Compat-drivers has 55-iwlwifi-msg-trace-fix.patch which says:

"In recent kernels, %pV will copy the va_list before using it.
This isn't true for all kernels, so copy the va_list for use
by the dev_*() functions, otherwise the kernel will crash if
the message is printed and traced."

I take it that the problem happens when the message is both printed and
traced at the same time. So ath6kl will need a similar patch as well.

Thanks for the heads up.

Kalle

Re: [PATCH 5/7] ath6kl: convert ath6kl_info/err/warn macros to real functions

[Kalle Valo]

Kalle Valo <kvalo@qca.qualcomm.com> writes:

>> Note that by inserting the tracing here later, you're relying on the
>> fact that "%pV" does va_copy(). This isn't true in all kernel versions,
>> I think there's on version or so where %pV is supported but didn't
>> va_copy(). That may lead to problems (I don't remember what kind) here.
>>
>> This is relevant for compat only, I think I carry a patch there to add
>> va_copy() into the tracing or something.
>
> Compat-drivers has 55-iwlwifi-msg-trace-fix.patch which says:
>
> "In recent kernels, %pV will copy the va_list before using it.
> This isn't true for all kernels, so copy the va_list for use
> by the dev_*() functions, otherwise the kernel will crash if
> the message is printed and traced."
>
> I take it that the problem happens when the message is both printed and
> traced at the same time. So ath6kl will need a similar patch as well.

For the archives: I'm guessing this is the commit which fixed the issue:

commit 5756b76e4db643d8f75174a9a50038523d4b9e32
Author: Jan Beulich <JBeulich@suse.com>
Date:   Mon Mar 5 16:49:24 2012 +0000

    vsprintf: make %pV handling compatible with kasprintf()

And git-describe tells me that it was introduced in 3.3-rc7, so quite
recent.

Kalle