EHCI: HSIC: Add enhancements to debug logging
This change addresses following enhancements to debug
logging:-
1) Add data payload logging which is not currently
supported. This helps to sniff first 32 bytes of data
being sent and received. Data payload logging is
enabled by default. To disable data payload logging:-
echo 0 > /sys/module/ehci_hcd/parameters/enable_payload_log
2) Current urb submission event logging does not cover
root hub submissions, hence move urb submission logging
to hcd driver.
3) Current urb submission event logging does not return
the correct status if submission fails. Hence log the
return status of urb submission.
CRs-Fixed: 393294
Change-Id: Ic7e555e1545ec7d7b0e4042cd35235e0af26fb01
Signed-off-by: Hemant Kumar <hemantk@codeaurora.org>
diff --git a/drivers/usb/host/ehci-msm-hsic.c b/drivers/usb/host/ehci-msm-hsic.c
index 9ef7e43..e63401e 100644
--- a/drivers/usb/host/ehci-msm-hsic.c
+++ b/drivers/usb/host/ehci-msm-hsic.c
@@ -101,6 +101,8 @@
static bool debug_bus_voting_enabled = true;
+static unsigned int enable_payload_log = 1;
+module_param(enable_payload_log, uint, S_IRUGO | S_IWUSR);
static unsigned int enable_dbg_log = 1;
module_param(enable_dbg_log, uint, S_IRUGO | S_IWUSR);
/*by default log ep0 and efs sync ep*/
@@ -110,12 +112,13 @@
module_param(ep_addr_txdbg_mask, uint, S_IRUGO | S_IWUSR);
/* Maximum debug message length */
-#define DBG_MSG_LEN 100UL
+#define DBG_MSG_LEN 128UL
/* Maximum number of messages */
#define DBG_MAX_MSG 256UL
#define TIME_BUF_LEN 20
+#define HEX_DUMP_LEN 72
enum event_type {
EVENT_UNDEF = -1,
@@ -126,20 +129,6 @@
#define EVENT_STR_LEN 5
-static char *event_to_str(enum event_type e)
-{
- switch (e) {
- case URB_SUBMIT:
- return "S";
- case URB_COMPLETE:
- return "C";
- case EVENT_NONE:
- return "NONE";
- default:
- return "UNDEF";
- }
-}
-
static enum event_type str_to_event(const char *name)
{
if (!strncasecmp("S", name, EVENT_STR_LEN))
@@ -209,11 +198,36 @@
return 0;
}
+static char *get_hex_data(char *dbuf, struct urb *urb, int event, int status)
+{
+ int ep_addr = urb->ep->desc.bEndpointAddress;
+ char *ubuf = urb->transfer_buffer;
+ size_t len = event ? \
+ urb->actual_length : urb->transfer_buffer_length;
+
+ if (status == -EINPROGRESS)
+ status = 0;
+
+ /*Only dump ep in completions and epout submissions*/
+ if (len && !status &&
+ (((ep_addr & USB_DIR_IN) && event) ||
+ (!(ep_addr & USB_DIR_IN) && !event))) {
+ if (len >= 32)
+ len = 32;
+ hex_dump_to_buffer(ubuf, len, 32, 4, dbuf, HEX_DUMP_LEN, 0);
+ } else {
+ dbuf = "";
+ }
+
+ return dbuf;
+}
+
static void dbg_log_event(struct urb *urb, char * event, unsigned extra)
{
unsigned long flags;
int ep_addr;
char tbuf[TIME_BUF_LEN];
+ char dbuf[HEX_DUMP_LEN];
if (!enable_dbg_log)
return;
@@ -221,7 +235,7 @@
if (!urb) {
write_lock_irqsave(&dbg_hsic_ctrl.lck, flags);
scnprintf(dbg_hsic_ctrl.buf[dbg_hsic_ctrl.idx], DBG_MSG_LEN,
- "%s: %s : %u\n", get_timestamp(tbuf), event, extra);
+ "%s: %s : %u", get_timestamp(tbuf), event, extra);
dbg_inc(&dbg_hsic_ctrl.idx);
write_unlock_irqrestore(&dbg_hsic_ctrl.lck, flags);
return;
@@ -237,7 +251,7 @@
write_lock_irqsave(&dbg_hsic_ctrl.lck, flags);
scnprintf(dbg_hsic_ctrl.buf[dbg_hsic_ctrl.idx],
DBG_MSG_LEN, "%s: [%s : %p]:[%s] "
- "%02x %02x %04x %04x %04x %u %d\n",
+ "%02x %02x %04x %04x %04x %u %d",
get_timestamp(tbuf), event, urb,
(ep_addr & USB_DIR_IN) ? "in" : "out",
urb->setup_packet[0], urb->setup_packet[1],
@@ -247,14 +261,14 @@
urb->setup_packet[4],
(urb->setup_packet[7] << 8) |
urb->setup_packet[6],
- urb->transfer_buffer_length, urb->status);
+ urb->transfer_buffer_length, extra);
dbg_inc(&dbg_hsic_ctrl.idx);
write_unlock_irqrestore(&dbg_hsic_ctrl.lck, flags);
} else {
write_lock_irqsave(&dbg_hsic_ctrl.lck, flags);
scnprintf(dbg_hsic_ctrl.buf[dbg_hsic_ctrl.idx],
- DBG_MSG_LEN, "%s: [%s : %p]:[%s] %u %d\n",
+ DBG_MSG_LEN, "%s: [%s : %p]:[%s] %u %d",
get_timestamp(tbuf), event, urb,
(ep_addr & USB_DIR_IN) ? "in" : "out",
urb->actual_length, extra);
@@ -265,12 +279,13 @@
} else {
write_lock_irqsave(&dbg_hsic_data.lck, flags);
scnprintf(dbg_hsic_data.buf[dbg_hsic_data.idx], DBG_MSG_LEN,
- "%s: [%s : %p]:ep%d[%s] %u %d\n",
+ "%s: [%s : %p]:ep%d[%s] %u %d %s",
get_timestamp(tbuf), event, urb, ep_addr & 0x0f,
(ep_addr & USB_DIR_IN) ? "in" : "out",
str_to_event(event) ? urb->actual_length :
- urb->transfer_buffer_length,
- str_to_event(event) ? extra : urb->status);
+ urb->transfer_buffer_length, extra,
+ enable_payload_log ? get_hex_data(dbuf, urb,
+ str_to_event(event), extra) : "");
dbg_inc(&dbg_hsic_data.idx);
write_unlock_irqrestore(&dbg_hsic_data.lck, flags);
@@ -910,13 +925,6 @@
return 0;
}
-static int ehci_hsic_urb_enqueue(struct usb_hcd *hcd, struct urb *urb,
- gfp_t mem_flags)
-{
- dbg_log_event(urb, event_to_str(URB_SUBMIT), 0);
- return ehci_urb_enqueue(hcd, urb, mem_flags);
-}
-
static int ehci_hsic_bus_suspend(struct usb_hcd *hcd)
{
dbg_log_event(NULL, "Suspend RH", 0);
@@ -1130,7 +1138,7 @@
/*
* managing i/o requests and associated device resources
*/
- .urb_enqueue = ehci_hsic_urb_enqueue,
+ .urb_enqueue = ehci_urb_enqueue,
.urb_dequeue = ehci_urb_dequeue,
.endpoint_disable = ehci_endpoint_disable,
.endpoint_reset = ehci_endpoint_reset,
@@ -1155,7 +1163,7 @@
.bus_suspend = ehci_hsic_bus_suspend,
.bus_resume = ehci_hsic_bus_resume,
- .log_urb_complete = dbg_log_event,
+ .log_urb = dbg_log_event,
.dump_regs = dump_hsic_regs,
.enable_ulpi_control = ehci_msm_enable_ulpi_control,