usb: musb: Implement tracing for state change events

The devctl register on musb is the only way to get state information
on musb. The hardware can easily get confused because it tries to do
things on it's own automagically, and things like slow VBUS rise can
make things fail.

Let's make it easier to debug the ongoing state change issues that
keep popping up on regular basis and add tracing support.

With these changes we can easily trace musb state change events with:

echo 1 > /sys/kernel/debug/tracing/events/musb/musb_state/enable
cat /sys/kernel/debug/tracing/trace_pipe
echo 0 > /sys/kernel/debug/tracing/events/musb/musb_state/enable

Cc: Alexandre Belloni <alexandre.belloni@bootlin.com>
Cc: Andreas Kemnade <andreas@kemnade.info>
Cc: Bhushan Shah <bshah@kde.org>
Cc: Drew Fustini <drew@beagleboard.org>
Cc: Thomas Petazzoni <thomas.petazzoni@bootlin.com>
Signed-off-by: Tony Lindgren <tony@atomide.com>
Link: https://lore.kernel.org/r/20210604080536.12185-2-tony@atomide.com
Signed-off-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org>

diff --git a/drivers/usb/musb/musb_core.c b/drivers/usb/musb/musb_core.c
index 2dde2ddc2046865efd3cc51dc0ea7cea89f16d48..f7b1d5993f8c1a72d335302bb14fc35e99f046ee 100644 (file)
--- a/drivers/usb/musb/musb_core.c
+++ b/drivers/usb/musb/musb_core.c
@@ -480,9 +480,7 @@ int musb_set_host(struct musb *musb)
 
        devctl = musb_read_devctl(musb);
        if (!(devctl & MUSB_DEVCTL_BDEVICE)) {
-               dev_info(musb->controller,
-                        "%s: already in host mode: %02x\n",
-                        __func__, devctl);
+               trace_musb_state(musb, devctl, "Already in host mode");
                goto init_data;
        }
 
@@ -499,6 +497,9 @@ int musb_set_host(struct musb *musb)
                return error;
        }
 
+       devctl = musb_read_devctl(musb);
+       trace_musb_state(musb, devctl, "Host mode set");
+
 init_data:
        musb->is_active = 1;
        musb->xceiv->otg->state = OTG_STATE_A_IDLE;
@@ -526,10 +527,7 @@ int musb_set_peripheral(struct musb *musb)
 
        devctl = musb_read_devctl(musb);
        if (devctl & MUSB_DEVCTL_BDEVICE) {
-               dev_info(musb->controller,
-                        "%s: already in peripheral mode: %02x\n",
-                        __func__, devctl);
-
+               trace_musb_state(musb, devctl, "Already in peripheral mode");
                goto init_data;
        }
 
@@ -546,6 +544,9 @@ int musb_set_peripheral(struct musb *musb)
                return error;
        }
 
+       devctl = musb_read_devctl(musb);
+       trace_musb_state(musb, devctl, "Peripheral mode set");
+
 init_data:
        musb->is_active = 0;
        musb->xceiv->otg->state = OTG_STATE_B_IDLE;
@@ -1984,10 +1985,11 @@ ATTRIBUTE_GROUPS(musb);
 #define MUSB_QUIRK_A_DISCONNECT_19     ((3 << MUSB_DEVCTL_VBUS_SHIFT) | \
                                         MUSB_DEVCTL_SESSION)
 
-static bool musb_state_needs_recheck(struct musb *musb, const char *desc)
+static bool musb_state_needs_recheck(struct musb *musb, u8 devctl,
+                                    const char *desc)
 {
        if (musb->quirk_retries && !musb->flush_irq_work) {
-               musb_dbg(musb, desc);
+               trace_musb_state(musb, devctl, desc);
                schedule_delayed_work(&musb->irq_work,
                                      msecs_to_jiffies(1000));
                musb->quirk_retries--;
@@ -2018,21 +2020,21 @@ static void musb_pm_runtime_check_session(struct musb *musb)
                MUSB_DEVCTL_HR;
        switch (devctl & ~s) {
        case MUSB_QUIRK_B_DISCONNECT_99:
-               musb_state_needs_recheck(musb,
-                       "Poll devctl in case of suspend after disconnect\n");
+               musb_state_needs_recheck(musb, devctl,
+                       "Poll devctl in case of suspend after disconnect");
                break;
        case MUSB_QUIRK_B_INVALID_VBUS_91:
-               if (musb_state_needs_recheck(musb,
+               if (musb_state_needs_recheck(musb, devctl,
                                "Poll devctl on invalid vbus, assume no session"))
                        return;
                fallthrough;
        case MUSB_QUIRK_A_DISCONNECT_19:
-               if (musb_state_needs_recheck(musb,
+               if (musb_state_needs_recheck(musb, devctl,
                                "Poll devctl on possible host mode disconnect"))
                        return;
                if (!musb->session)
                        break;
-               musb_dbg(musb, "Allow PM on possible host mode disconnect");
+               trace_musb_state(musb, devctl, "Allow PM on possible host mode disconnect");
                pm_runtime_mark_last_busy(musb->controller);
                pm_runtime_put_autosuspend(musb->controller);
                musb->session = false;
@@ -2048,7 +2050,7 @@ static void musb_pm_runtime_check_session(struct musb *musb)
 
        /* Block PM or allow PM? */
        if (s) {
-               musb_dbg(musb, "Block PM on active session: %02x", devctl);
+               trace_musb_state(musb, devctl, "Block PM on active session");
                error = pm_runtime_get_sync(musb->controller);
                if (error < 0)
                        dev_err(musb->controller, "Could not enable: %i\n",
@@ -2064,7 +2066,7 @@ static void musb_pm_runtime_check_session(struct musb *musb)
                        schedule_delayed_work(&musb->irq_work,
                                              msecs_to_jiffies(3000));
        } else {
-               musb_dbg(musb, "Allow PM with no session: %02x", devctl);
+               trace_musb_state(musb, devctl, "Allow PM with no session");
                pm_runtime_mark_last_busy(musb->controller);
                pm_runtime_put_autosuspend(musb->controller);
        }

diff --git a/drivers/usb/musb/musb_trace.h b/drivers/usb/musb/musb_trace.h
index 380ebc77eab1f5e664443f7a41096ee58f99a5aa..ec28b57167961cdd685794a043d28188f353a1f4 100644 (file)
--- a/drivers/usb/musb/musb_trace.h
+++ b/drivers/usb/musb/musb_trace.h
@@ -37,6 +37,23 @@ TRACE_EVENT(musb_log,
        TP_printk("%s: %s", __get_str(name), __get_str(msg))
 );
 
+TRACE_EVENT(musb_state,
+       TP_PROTO(struct musb *musb, u8 devctl, const char *desc),
+       TP_ARGS(musb, devctl, desc),
+       TP_STRUCT__entry(
+               __string(name, dev_name(musb->controller))
+               __field(u8, devctl)
+               __string(desc, desc)
+       ),
+       TP_fast_assign(
+               __assign_str(name, dev_name(musb->controller));
+               __entry->devctl = devctl;
+               __assign_str(desc, desc);
+       ),
+       TP_printk("%s: devctl: %02x %s", __get_str(name), __entry->devctl,
+                 __get_str(desc))
+);
+
 DECLARE_EVENT_CLASS(musb_regb,
        TP_PROTO(void *caller, const void  __iomem *addr,
                 unsigned int offset, u8 data),