SolidHal / PrawnOS

Libre Mainline Kernel and Debian for arm laptops
https://www.PrawnOS.com
GNU General Public License v2.0
118 stars 29 forks source link

Usb not recognized after boot #15

Closed SolidHal closed 6 years ago

SolidHal commented 6 years ago

This is a regression after kernel version 4.16.18 Narrowing down which commit caused this.

Starting at core.c https://github.com/torvalds/linux/commits/v4.17/drivers/usb/dwc2/core.c

SolidHal commented 6 years ago

Full list of commits to dwc2 that have made it into 4.17 https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux-stable.git/log/drivers/usb/dwc2?h=linux-4.17.y

params.c has some interesting commits as well https://github.com/torvalds/linux/commits/master/drivers/usb/dwc2/params.c specifically

6d23ee9caa6790aea047f9aca7f3c03cb8d96eb6

Merge tag 'usb-for-v4.17' of git://git.kernel.org/pub/scm/linux/kerne… @gregkh gregkh committed on Mar 23

…l/git/balbi/usb into usb-testing

Felipe writes:

usb: changes for v4.17 merge window

Quite a lot happened in this cycle, with a total of 95 non-merge commits. The most interesting parts are listed below:

Synopsys has been adding better support for USB 3.1 to dwc3. The same series also sets g_mass_storage's max speed to SSP.

Roger Quadros (TI) added support for dual-role using the OTG block available in some dwc3 implementations, this makes sure that AM437x can swap roles in runtime.

We have a new SoC supported in dwc3 now - Amlogic Meson GX - thanks to the work of Martin Blumenstingl.

We also have a ton of changes in dwc2 (51% of all changes, in fact). The most interesting part there is the support for Hibernation (a Synopsys PM feature).

Apart from these, we have our regular set of non-critical fixes all over the place.

SolidHal commented 6 years ago

Reverting the merge at commit 6d23ee9caa6790aea047f9aca7f3c03cb8d96eb6 fixes the issue

SolidHal commented 6 years ago

With and without the commit, there are only a few differences in the dmesg logs with usb_dwc2_debug enabled. The major one is dwc2 ff540000.usb: In host mode, hprt0=00001501 with the commit in question and dwc2 ff540000.usb: In host mode, hprt0=00001101 without the commit.

the only reference to these bits I've found is:

define HPRT0_LNSTS_MASK (0x3 << 10)

define HPRT0_LNSTS_SHIFT 10

SolidHal commented 6 years ago

HPRT may be USB host peripheral interrupt handlers

Found some dwc2 documentation in the implementation in xinu

            /**
             * Current logic of data lines (10: logic of D+; 11: logic of D-).
             *
             * Changed by hardware only.
             */
             uint32_t line_status : 2; /* Bits 10-11*/

This file describes all of the dwc2 registers, including the hprt0 or "Host Port Control and Status Register" https://github.com/xinu-os/xinu/blob/4384915cc63a9c057418015c996f44372eec0a2e/system/platforms/arm-rpi/usb_dwc_regs.h

From this reference https://www.beyondlogic.org/usbnutshell/usb2.shtml:

 A USB device must indicate its speed by pulling either the D+ or D- line high 
to 3.3 volts. A full speed device, pictured below will use a pull up resistor 
attached to D+ to specify itself as a full speed device. These pull up resistors 
at the device end will also be used by the host or hub to detect the presence
 of a device connected to its port. Without a pull up resistor, USB assumes there 
is nothing connected to the bus
...
...
High speed devices will start by connecting as a full speed device (1.5k to 3.3V). 
Once it has been attached, it will do a high speed chirp during reset and establish 
a high speed connection if the hub supports it. If the device operates in
 high speed mode, then the pull up resistor is removed to balance the line. 

So, that bit difference may just be a red herring as the device I've been using for testing is a "full speed" usb 2.0 device and could have been pulling that bit high for the reasons described above.

Other potentially useful references the xinu repo has: https://github.com/xinu-os/xinu/blob/master/system/platforms/arm-rpi/usb_dwc_regs.h https://github.com/xinu-os/xinu/blob/master/system/platforms/arm-rpi/usb_dwc_hcd.c

SolidHal commented 6 years ago

Check if host even enters hibernation:

dev_dbg(hsotg->dev, "Preparing host for hibernation\n"); ret = dwc2_backup_global_registers(hsotg);

Or exits hibernation:

dev_dbg(hsotg->dev, "Host hibernation restore complete\n");

If so, Test this fix from the 4.18 rc1 usb tree https://git.kernel.org/pub/scm/linux/kernel/git/balbi/usb.git/commit/drivers/usb/dwc2?h=fixes-for-v4.18-rc1&id=22bb5cfdf13ae70c6a34508a16cfeee48f162443

SolidHal commented 6 years ago

Next place to checkout is the extra reset in the log for the non-functional

SolidHal commented 6 years ago

Maybe try this patch as well https://git.kernel.org/pub/scm/linux/kernel/git/balbi/usb.git/commit/drivers/usb/dwc2?h=fixes-for-v4.17-rc3&id=438fea2a6325933868aebc20279e2669c9a21207

This is already in linux-4.17.y

SolidHal commented 6 years ago

When a usb device is plugged in, two lines are printed:

[   54.127262] dwc2 ff580000.usb: gintsts=40000001  gintmsk=f0000000
[   54.127326] dwc2 ff580000.usb: Session request interrupt - lx_state=2

the second line referring to the function dwc2_handle_session_req_intr() is not printed in the functional version.

/**
 * dwc2_handle_session_req_intr() - This interrupt indicates that a device is
 * initiating the Session Request Protocol to request the host to turn on bus
 * power so a new session can begin
 *
 * @hsotg: Programming view of DWC_otg controller
 *
 * This handler responds by turning on bus power. If the DWC_otg controller is
 * in low power mode, this handler brings the controller out of low power mode
 * before turning on bus power.
 */
static void dwc2_handle_session_req_intr(struct dwc2_hsotg *hsotg)
{
    int ret;

    /* Clear interrupt */
    dwc2_writel(GINTSTS_SESSREQINT, hsotg->regs + GINTSTS);

    dev_dbg(hsotg->dev, "Session request interrupt - lx_state=%d\n",
        hsotg->lx_state);

    if (dwc2_is_device_mode(hsotg)) {
        if (hsotg->lx_state == DWC2_L2) {
            ret = dwc2_exit_partial_power_down(hsotg, true);
            if (ret && (ret != -ENOTSUPP))
                dev_err(hsotg->dev,
                    "exit power_down failed\n");
        }

        /*
         * Report disconnect if there is any previous session
         * established
         */
        dwc2_hsotg_disconnect(hsotg);
    }
}

This may indicate the host is putting the controller into low power mode. dwc2_handle_session_req_intr() is called by this code in dwc2_handle_common_intr()

    if (gintsts & GINTSTS_SESSREQINT)
        dwc2_handle_session_req_intr(hsotg);

GINTSTS_SESSREQINT is bit 30 of the 32 bit binary number stored at #define GINTSTS HSOTG_REG(0x014)

In the log with nonfunctional usb, upon plug in gintsts and gintmskare defiened as so (shown in hex):

[   54.127262] dwc2 ff580000.usb: gintsts=40000001  gintmsk=f0000000

so gintsts=01000000000000000000000000000001

but in the functional log the are defined as:

[   32.745159] dwc2 ff580000.usb: gintsts=05000021  gintmsk=f3000806

so gintsts should be gintsts=00000101000000000000000000100001

gintsts in the nonfunctional log has a 1 in the 30th bit, so dwc2_handle_session_req_int() is called.

and in the functional log, gintsts has ones in the 5th, 24th and 26th which are defined in hw.h as:

#define GINTSTS_PTXFEMP         BIT(26)
#define GINTSTS_PRTINT          BIT(24)
#define GINTSTS_NPTXFEMP        BIT(5)

GINTSTS_PRTINT is port interrupt, defined by the xinu project as

             /**
             * Host port status changed.  Software must examine the Host Port
             * Control and Status Register to determine the current status of
             * the host port and clear any flags in it that indicate a status
             * change.
             */

GINTSTS_NPTXFEMP and GINTSTS_PTXFEMP are something about TX fifo empty?

So, what we know now is that gintsts and gintmsk are both being set incorrectly, causing the usb controller to not set up the new device properly. The thing to track next seems to be GINTSTS_PRTINT, as that should be set to 1 when a new device is plugged in.

In dwc2_handle_hcd_intr() if GINTSTS_PRTINT is set, dwc2_port_intr() is called. dwc2_port_intr() states that four HPRT0 bits have to be cleared to clear GINTSTS_PRTINT.

    /*
     * Clear appropriate bits in HPRT0 to clear the interrupt bit in
     * GINTSTS
     */
    hprt0_modify &= ~(HPRT0_ENA | HPRT0_CONNDET | HPRT0_ENACHG |
              HPRT0_OVRCURRCHG);

This could indicate that GINTSTS_PRTINT may be set when some subset or all of these bits are set.

This is cleared up by the if tree right below the bit clear which shows GINTSTS_PRTINT may be set by HPRT0_ENA, or HPRT0_ENACHG or HPRT0_OVRCURRCHG, with HPRT0_ENA being handled only if HPRT0_ENACHG is set as well.

    /*
     * Port Connect Detected
     * Set flag and clear if detected
     */
    if (hprt0 & HPRT0_CONNDET) {
        dwc2_writel(hprt0_modify | HPRT0_CONNDET, hsotg->regs + HPRT0);

        dev_vdbg(hsotg->dev,
             "--Port Interrupt HPRT0=0x%08x Port Connect Detected--\n",
             hprt0);
        dwc2_hcd_connect(hsotg);

        /*
         * The Hub driver asserts a reset when it sees port connect
         * status change flag
         */
    }

    /*
     * Port Enable Changed
     * Clear if detected - Set internal flag if disabled
     */
    if (hprt0 & HPRT0_ENACHG) {
        dwc2_writel(hprt0_modify | HPRT0_ENACHG, hsotg->regs + HPRT0);
        dev_vdbg(hsotg->dev,
             "  --Port Interrupt HPRT0=0x%08x Port Enable Changed (now %d)--\n",
             hprt0, !!(hprt0 & HPRT0_ENA));
        if (hprt0 & HPRT0_ENA) {
            hsotg->new_connection = true;
            dwc2_hprt0_enable(hsotg, hprt0, &hprt0_modify);
        } else {
            hsotg->flags.b.port_enable_change = 1;
            if (hsotg->params.dma_desc_fs_enable) {
                u32 hcfg;

                hsotg->params.dma_desc_enable = false;
                hsotg->new_connection = false;
                hcfg = dwc2_readl(hsotg->regs + HCFG);
                hcfg &= ~HCFG_DESCDMA;
                dwc2_writel(hcfg, hsotg->regs + HCFG);
            }
        }
    }

    /* Overcurrent Change Interrupt */
    if (hprt0 & HPRT0_OVRCURRCHG) {
        dwc2_writel(hprt0_modify | HPRT0_OVRCURRCHG,
                hsotg->regs + HPRT0);
        dev_vdbg(hsotg->dev,
             "  --Port Interrupt HPRT0=0x%08x Port Overcurrent Changed--\n",
             hprt0);
        hsotg->flags.b.port_over_current_change = 1;
    }

Unfortunately these only print if verbose_debug is enabled in the kernel, which is nearly unusable if you happen to boot from usb as well as every block transfer spams dmesg with 30 lines.

TODO: Edit these debug messages to use the dev_dbg function instead of dev_vdbg and get logs

We can guess that HPRT0_CONNDET is the like likely suspect, as we are connecting a device however if the port defaults to disabled, HPRT0_ENACHG may be set and checked before HPRT0_CONNDET.

Either way, we'll look into HPRT0_CONNDET first.

SolidHal commented 6 years ago

Call stack when usb device plugged in: dwc2_handle_common_intr() dwc2_handle_session_req_intr()

Add dev_dbg(hsotg->dev, "HAL DEBUG func=%s, GINTSTS=%08x\n",func,gintsts); to everywhere that touches hsotg->regs + HPRT0, sometimes just a variable called hprt, in the functional version to get an idea of what the call stack is supposed to look like.

SolidHal commented 6 years ago

In fucntional GUSBCFG is: 0x20001408 aka 100000000000000001010000001000 In the non functional, it is: 0x2000140F aka 100000000000000001010000001111

Try reversing this part of the commit:

@@ -2320,14 +2346,26 @@ static int dwc2_core_init(struct dwc2_hsotg *hsotg, bool initial_setup)
  * request queues. Host channels are reset to ensure that they are ready for
  * performing transfers.
  */
 static void dwc2_core_host_init(struct dwc2_hsotg *hsotg)
 {
-   u32 hcfg, hfir, otgctl;
+   u32 hcfg, hfir, otgctl, usbcfg;

    dev_dbg(hsotg->dev, "%s(%p)\n", __func__, hsotg);

+   /* Set HS/FS Timeout Calibration to 7 (max available value).
+    * The number of PHY clocks that the application programs in
+    * this field is added to the high/full speed interpacket timeout
+    * duration in the core to account for any additional delays
+    * introduced by the PHY. This can be required, because the delay
+    * introduced by the PHY in generating the linestate condition
+    * can vary from one PHY to another.
+    */
+   usbcfg = dwc2_readl(hsotg->regs + GUSBCFG);
+   usbcfg |= GUSBCFG_TOUTCAL(7);
+   dwc2_writel(usbcfg, hsotg->regs + GUSBCFG);
+
    /* Restart the Phy Clock */
    dwc2_writel(0, hsotg->regs + PCGCTL);

    /* Initialize Host Configuration Register */
    dwc2_init_fs_ls_pclk_sel(hsotg);

Despite this being for gadgets, maybe theres some weird interactions.

The only other things I see sticking out are these lines:

[    1.447823] dwc2 ff580000.usb: dwc2_backup_global_registers
[    1.447829] dwc2 ff580000.usb: dwc2_backup_host_registers

I'd assume these have to be restored right away when a usb device is plugged back in, however they are not.

SolidHal commented 6 years ago

change this to normal debug as well. Located in hcd_intr.c:

/*
 * There are multiple conditions that can cause a port interrupt. This function
 * determines which interrupt conditions have occurred and handles them
 * appropriately.
 */
static void dwc2_port_intr(struct dwc2_hsotg *hsotg)
{
    u32 hprt0;
    u32 hprt0_modify;

    dev_vdbg(hsotg->dev, "--Port Interrupt--\n");
SolidHal commented 6 years ago

In hcd_intr.c

/* This function handles interrupts for the HCD */
irqreturn_t dwc2_handle_hcd_intr(struct dwc2_hsotg *hsotg)

calls dwc2_port_intr()

        if (gintsts & GINTSTS_PRTINT)
            dwc2_port_intr(hsotg);

and sends it down the correct, functional path.

SolidHal commented 6 years ago

and the only line shared by the functional and non-functional versions is printed by:

/*
 * This function returns the Core Interrupt register
 */
static u32 dwc2_read_common_intr(struct dwc2_hsotg *hsotg)
{
    u32 gintsts;
    u32 gintmsk;
    u32 gahbcfg;
    u32 gintmsk_common = GINTMSK_COMMON;

    gintsts = dwc2_readl(hsotg->regs + GINTSTS);
    gintmsk = dwc2_readl(hsotg->regs + GINTMSK);
    gahbcfg = dwc2_readl(hsotg->regs + GAHBCFG);

    /* If any common interrupts set */
    if (gintsts & gintmsk_common)
        dev_dbg(hsotg->dev, "gintsts=%08x  gintmsk=%08x\n",
            gintsts, gintmsk);

    if (gahbcfg & GAHBCFG_GLBL_INTR_EN)
        return gintsts & gintmsk & gintmsk_common;
    else
        return 0;
}

Which was called by

/*
 * Common interrupt handler
 *
 * The common interrupts are those that occur in both Host and Device mode.
 * This handler handles the following interrupts:
 * - Mode Mismatch Interrupt
 * - OTG Interrupt
 * - Connector ID Status Change Interrupt
 * - Disconnect Interrupt
 * - Session Request Interrupt
 * - Resume / Remote Wakeup Detected Interrupt
 * - Suspend Interrupt
 */
irqreturn_t dwc2_handle_common_intr(int irq, void *dev)

which ends up calling

/**
 * dwc2_handle_session_req_intr() - This interrupt indicates that a device is
 * initiating the Session Request Protocol to request the host to turn on bus
 * power so a new session can begin
 *
 * @hsotg: Programming view of DWC_otg controller
 *
 * This handler responds by turning on bus power. If the DWC_otg controller is
 * in low power mode, this handler brings the controller out of low power mode
 * before turning on bus power.
 */
static void dwc2_handle_session_req_intr(struct dwc2_hsotg *hsotg)
{

in the non functional version

SolidHal commented 6 years ago

So the process in the non functional one seems to be correct up until

/**
 * dwc2_handle_session_req_intr() - This interrupt indicates that a device is
 * initiating the Session Request Protocol to request the host to turn on bus
 * power so a new session can begin
 *
 * @hsotg: Programming view of DWC_otg controller
 *
 * This handler responds by turning on bus power. If the DWC_otg controller is
 * in low power mode, this handler brings the controller out of low power mode
 * before turning on bus power.
 */
static void dwc2_handle_session_req_intr(struct dwc2_hsotg *hsotg)
{
    int ret;

    /* Clear interrupt */
    dwc2_writel(GINTSTS_SESSREQINT, hsotg->regs + GINTSTS);

    dev_dbg(hsotg->dev, "Session request interrupt - lx_state=%d\n",
        hsotg->lx_state);

    if (dwc2_is_device_mode(hsotg)) {
        if (hsotg->lx_state == DWC2_L2) {
            ret = dwc2_exit_partial_power_down(hsotg, true);
            if (ret && (ret != -ENOTSUPP))
                dev_err(hsotg->dev,
                    "exit power_down failed\n");
        }

        /*
         * Report disconnect if there is any previous session
         * established
         */
        dwc2_hsotg_disconnect(hsotg);
    }
}

Specifically here:

if (dwc2_is_device_mode(hsotg)) {
        if (hsotg->lx_state == DWC2_L2) {
            ret = dwc2_exit_partial_power_down(hsotg, true);

dwc2_handle_session_req_intr should be checking two things, which LPM is being used and if the device is in host or gadget mode.

If lx_state is DWC_LPM2 then dwc2_exit_hibernation should be used, not dwc2_exit_partial_power_down.

Only dwc2_host_enter_hibernation and dwc2_gadget_enter_hibernation set lx_state to DWC_LPM2 Specifically, dwc2_gadget_enter_hibernation states:

    /* Change to L2(suspend) state */
    hsotg->lx_state = DWC2_L2;

dwc2_enter_partial_power_down does not:

/**
 * dwc2_enter_partial_power_down() - Put controller in Partial Power Down.
 *
 * @hsotg: Programming view of the DWC_otg controller
 */
int dwc2_enter_partial_power_down(struct dwc2_hsotg *hsotg)
{
    u32 pcgcctl;
    int ret = 0;

    if (!hsotg->params.power_down)
        return -ENOTSUPP;

    /* Backup all registers */
    ret = dwc2_backup_global_registers(hsotg);
    if (ret) {
        dev_err(hsotg->dev, "%s: failed to backup global registers\n",
            __func__);
        return ret;
    }

    if (dwc2_is_host_mode(hsotg)) {
        ret = dwc2_backup_host_registers(hsotg);
        if (ret) {
            dev_err(hsotg->dev, "%s: failed to backup host registers\n",
                __func__);
            return ret;
        }
    } else {
        ret = dwc2_backup_device_registers(hsotg);
        if (ret) {
            dev_err(hsotg->dev, "%s: failed to backup device registers\n",
                __func__);
            return ret;
        }
    }

    /*
     * Clear any pending interrupts since dwc2 will not be able to
     * clear them after entering partial_power_down.
     */
    dwc2_writel(0xffffffff, hsotg->regs + GINTSTS);

    /* Put the controller in low power state */
    pcgcctl = dwc2_readl(hsotg->regs + PCGCTL);

    pcgcctl |= PCGCTL_PWRCLMP;
    dwc2_writel(pcgcctl, hsotg->regs + PCGCTL);
    ndelay(20);

    pcgcctl |= PCGCTL_RSTPDWNMODULE;
    dwc2_writel(pcgcctl, hsotg->regs + PCGCTL);
    ndelay(20);

    pcgcctl |= PCGCTL_STOPPCLK;
    dwc2_writel(pcgcctl, hsotg->regs + PCGCTL);

    return ret;
}

This is further supported by fields in struct dwc2_core_params in core.h

/* Device States */
enum dwc2_lx_state {
    DWC2_L0,    /* On state */
    DWC2_L1,    /* LPM sleep state */
    DWC2_L2,    /* USB suspend state */
    DWC2_L3,    /* Off state */
};
 * @power_down:         Specifies whether the controller support power_down.
 *          If power_down is enabled, the controller will enter
 *          power_down in both peripheral and host mode when
 *          needed.
 *          0 - No (default)
 *          1 - Partial power down
 *          2 - Hibernation
#define DWC2_POWER_DOWN_PARAM_NONE      0
#define DWC2_POWER_DOWN_PARAM_PARTIAL       1
#define DWC2_POWER_DOWN_PARAM_HIBERNATION       2
SolidHal commented 6 years ago

dwc2_exit_partial_power_down shows partial power down is marked by:

    if (hsotg->params.power_down != DWC2_POWER_DOWN_PARAM_PARTIAL)
        return -ENOTSUPP;

which is defined as:

#define DWC2_POWER_DOWN_PARAM_NONE      0
#define DWC2_POWER_DOWN_PARAM_PARTIAL       1
#define DWC2_POWER_DOWN_PARAM_HIBERNATION       2

Interestingly, dwc2_enter_partial_power_down is less picky

    if (!hsotg->params.power_down)
        return -ENOTSUPP;

~TODO: This is probably a bug~

Edit: its not, _dwc2_hcd_suspend() which calls dwc2_enter_partial_power_down check for DWC2_POWER_DOWN_PARAM_PARTIAL:

    if (hsotg->params.power_down != DWC2_POWER_DOWN_PARAM_PARTIAL)
        goto skip_power_saving;
SolidHal commented 6 years ago

Not sure whether to pass reset as true or false to `dwc2_exit_hibernation:

    if (reset) {
        hprt0 |= HPRT0_RST;
        dwc2_writel(hprt0, hsotg->regs + HPRT0);

        /* Wait for Resume time and then program HPRT again */
        mdelay(60);
        hprt0 &= ~HPRT0_RST;
        dwc2_writel(hprt0, hsotg->regs + HPRT0);
    } else {
        hprt0 |= HPRT0_RES;
        dwc2_writel(hprt0, hsotg->regs + HPRT0);

        /* Wait for Resume time and then program HPRT again */
        mdelay(100);
        hprt0 &= ~HPRT0_RES;
        dwc2_writel(hprt0, hsotg->regs + HPRT0);
    }

Only difference is the delay?? TODO: Solve this mystery.

SolidHal commented 6 years ago

dwc2_enter_hibernation checks power_down as well:

    if (hsotg->params.power_down != DWC2_POWER_DOWN_PARAM_HIBERNATION)
        return -ENOTSUPP;
SolidHal commented 6 years ago

issue, hsotg->lx_state is set to DWC2_L2 by dwc2_host_enter_hibernation and by _dwc2_hcd_suspend which is the only place dwc2_enter_partial_power_down is called for the host.

static int _dwc2_hcd_suspend(struct usb_hcd *hcd)
{
    struct dwc2_hsotg *hsotg = dwc2_hcd_to_hsotg(hcd);
    unsigned long flags;
    int ret = 0;
    u32 hprt0;

    spin_lock_irqsave(&hsotg->lock, flags);

    if (dwc2_is_device_mode(hsotg))
        goto unlock;

    if (hsotg->lx_state != DWC2_L0)
        goto unlock;

    if (!HCD_HW_ACCESSIBLE(hcd))
        goto unlock;

    if (hsotg->op_state == OTG_STATE_B_PERIPHERAL)
        goto unlock;

    if (hsotg->params.power_down != DWC2_POWER_DOWN_PARAM_PARTIAL)
        goto skip_power_saving;

    /*
     * Drive USB suspend and disable port Power
     * if usb bus is not suspended.
     */
    if (!hsotg->bus_suspended) {
        hprt0 = dwc2_read_hprt0(hsotg);
        hprt0 |= HPRT0_SUSP;
        hprt0 &= ~HPRT0_PWR;
        dwc2_writel(hprt0, hsotg->regs + HPRT0);
        dwc2_vbus_supply_exit(hsotg);
    }

    /* Enter partial_power_down */
    ret = dwc2_enter_partial_power_down(hsotg);
    if (ret) {
        if (ret != -ENOTSUPP)
            dev_err(hsotg->dev,
                "enter partial_power_down failed\n");
        goto skip_power_saving;
    }

    /* Ask phy to be suspended */
    if (!IS_ERR_OR_NULL(hsotg->uphy)) {
        spin_unlock_irqrestore(&hsotg->lock, flags);
        usb_phy_set_suspend(hsotg->uphy, true);
        spin_lock_irqsave(&hsotg->lock, flags);
    }

    /* After entering partial_power_down, hardware is no more accessible */
    clear_bit(HCD_FLAG_HW_ACCESSIBLE, &hcd->flags);

skip_power_saving:
    hsotg->lx_state = DWC2_L2;
unlock:
    spin_unlock_irqrestore(&hsotg->lock, flags);

    return ret;
}

long story short, hsotg->lx_state == DWC2_L2 cannot be used it differentiate these states.

SolidHal commented 6 years ago

dwc2_enter_hibernation() is only called in two places. Once in core_intr.c for gadgets, so not relevant. The other place is in hcd.c in the function dwc2_hcd_hub_control()

switch (wvalue) {
        case USB_PORT_FEAT_SUSPEND:
            dev_dbg(hsotg->dev,
                "SetPortFeature - USB_PORT_FEAT_SUSPEND\n");
            if (windex != hsotg->otg_port)
                goto error;
            if (hsotg->params.power_down == 2)
                dwc2_enter_hibernation(hsotg, 1);
            else
                dwc2_port_suspend(hsotg, windex);
            break;
SolidHal commented 6 years ago

So, which is being called and setting hsotg->lx_state = DWC2_L2? Once we know that, we'll have a better idea of how dwc2_handle_session_req_intr() should be maing a decision.

SolidHal commented 6 years ago

dwc2_hcd_hub_control() is called by _dwc2_hcd_hub_control() and is .hub_control in the dwc2_hc_driver struct.

static struct hc_driver dwc2_hc_driver = {
    .description = "dwc2_hsotg",
    .product_desc = "DWC OTG Controller",
    .hcd_priv_size = sizeof(struct wrapper_priv_data),

    .irq = _dwc2_hcd_irq,
    .flags = HCD_MEMORY | HCD_USB2 | HCD_BH,

    .start = _dwc2_hcd_start,
    .stop = _dwc2_hcd_stop,
    .urb_enqueue = _dwc2_hcd_urb_enqueue,
    .urb_dequeue = _dwc2_hcd_urb_dequeue,
    .endpoint_disable = _dwc2_hcd_endpoint_disable,
    .endpoint_reset = _dwc2_hcd_endpoint_reset,
    .get_frame_number = _dwc2_hcd_get_frame_number,

    .hub_status_data = _dwc2_hcd_hub_status_data,
    .hub_control = _dwc2_hcd_hub_control,
    .clear_tt_buffer_complete = _dwc2_hcd_clear_tt_buffer_complete,

    .bus_suspend = _dwc2_hcd_suspend,
    .bus_resume = _dwc2_hcd_resume,

    .map_urb_for_dma    = dwc2_map_urb_for_dma,
    .unmap_urb_for_dma  = dwc2_unmap_urb_for_dma,
};

dwc2_hc_driver.hub_control is never explicitly called from within the dwc2 driver, but it's possible it is called by the over arching usb driver?

SolidHal commented 6 years ago

so dwc2_enter_partial_power_down is called by _dwc2_hcd_suspend() which then sets hsotg->lx_state = DWC2_L2

_dwc2_hcd_suspend() is .bus_suspend in the dwc2_hc_driver struct, as you can see above.

dwc2_hc_driver.bus_suspend is never explicitly called from within the dwc2 driver, but it's possible it is called by the over arching usb driver?

SolidHal commented 6 years ago

recall:

GINTSTS_SESSREQINT is bit 30 of the 32 bit binary number stored at #define GINTSTS HSOTG_REG(0x014)

In the log with nonfunctional usb, upon plug in gintsts and gintmskare defiened as so (shown in hex):

[   54.127262] dwc2 ff580000.usb: gintsts=40000001  gintmsk=f0000000

so gintsts=01000000000000000000000000000001

but in the functional log the are defined as:

[   32.745159] dwc2 ff580000.usb: gintsts=05000021  gintmsk=f3000806

so gintsts should be gintsts=00000101000000000000000000100001

gintsts in the nonfunctional log has a 1 in the 30th bit, so dwc2_handle_session_req_int() is called.

and in the functional log, gintsts has ones in the 5th, 24th and 26th which are defined in hw.h as:

#define GINTSTS_PTXFEMP           BIT(26)
#define GINTSTS_PRTINT            BIT(24)
#define GINTSTS_NPTXFEMP      BIT(5)

Either one of the two "enter" functions is not setting GINTSTS/ 'GINTMSK' properly, or dwc2_handle_session_req_intr() is not correct.

TODO: Determine which "enter" function is used.

SolidHal commented 6 years ago

Looking closer, hibernation has a print statement not found in the logs:

/**
 * dwc2_host_enter_hibernation() - Put controller in Hibernation.
 *
 * @hsotg: Programming view of the DWC_otg controller
 */
int dwc2_host_enter_hibernation(struct dwc2_hsotg *hsotg)
{
    unsigned long flags;
    int ret = 0;
    u32 hprt0;
    u32 pcgcctl;
    u32 gusbcfg;
    u32 gpwrdn;

    dev_dbg(hsotg->dev, "Preparing host for hibernation\n");

and since

[    1.447823] dwc2 ff580000.usb: dwc2_backup_global_registers
[    1.447829] dwc2 ff580000.usb: dwc2_backup_host_registers

are only printed by those two enter functions, dwc2_enter_partial_power_down must be responsible.

SolidHal commented 6 years ago

param.power_down is defined like this:

static void dwc2_set_param_power_down(struct dwc2_hsotg *hsotg)
{
    int val;

    if (hsotg->hw_params.hibernation)
        val = 2;
    else if (hsotg->hw_params.power_optimized)
        val = 1;
    else
        val = 0;

    hsotg->params.power_down = val;
}
SolidHal commented 6 years ago

And also this

static void dwc2_check_param_power_down(struct dwc2_hsotg *hsotg)
{
    int param = hsotg->params.power_down;

    switch (param) {
    case DWC2_POWER_DOWN_PARAM_NONE:
        break;
    case DWC2_POWER_DOWN_PARAM_PARTIAL:
        if (hsotg->hw_params.power_optimized)
            break;
        dev_dbg(hsotg->dev,
            "Partial power down isn't supported by HW\n");
        param = DWC2_POWER_DOWN_PARAM_NONE;
        break;
    case DWC2_POWER_DOWN_PARAM_HIBERNATION:
        if (hsotg->hw_params.hibernation)
            break;
        dev_dbg(hsotg->dev,
            "Hibernation isn't supported by HW\n");
        param = DWC2_POWER_DOWN_PARAM_NONE;
        break;
    default:
        dev_err(hsotg->dev,
            "%s: Invalid parameter power_down=%d\n",
            __func__, param);
        param = DWC2_POWER_DOWN_PARAM_NONE;
        break;
    }

    hsotg->params.power_down = param;
}
SolidHal commented 6 years ago

TODO: test partially reverting this change

@@ -462,20 +632,17 @@ void dwc2_clear_force_mode(struct dwc2_hsotg *hsotg)
 /*
  * Sets or clears force mode based on the dr_mode parameter.
  */
 void dwc2_force_dr_mode(struct dwc2_hsotg *hsotg)
 {
-   bool ret;
-
    switch (hsotg->dr_mode) {
    case USB_DR_MODE_HOST:
-       ret = dwc2_force_mode(hsotg, true);
        /*
         * NOTE: This is required for some rockchip soc based
         * platforms on their host-only dwc2.
         */
-       if (!ret)
+       if (!dwc2_hw_is_otg(hsotg))
            msleep(50);

        break;
    case USB_DR_MODE_PERIPHERAL:

Re-include dwc2_force_mode(hsotg, true);but without the return variable

SolidHal commented 6 years ago

The changes to dwc2_enter_partial_power_down() were minimal, basically just renaming and changing it to depend on param.power_down instead of param.hibernate

-   if (!hsotg->params.hibernation)
+   if (!hsotg->params.power_down)

_dwc2_hcd_suspend() which calls dwc2_enter_partial_power_down also is changed to call dwc2_vbus_supply_exit(hsotg) as well as depending on the new param

@@ -4412,11 +4395,11 @@ static int _dwc2_hcd_suspend(struct usb_hcd *hcd)
        goto unlock;

    if (hsotg->op_state == OTG_STATE_B_PERIPHERAL)
        goto unlock;

-   if (!hsotg->params.hibernation)
+   if (hsotg->params.power_down != DWC2_POWER_DOWN_PARAM_PARTIAL)
        goto skip_power_saving;

    /*
     * Drive USB suspend and disable port Power
     * if usb bus is not suspended.
@@ -4424,29 +4407,30 @@ static int _dwc2_hcd_suspend(struct usb_hcd *hcd)
    if (!hsotg->bus_suspended) {
        hprt0 = dwc2_read_hprt0(hsotg);
        hprt0 |= HPRT0_SUSP;
        hprt0 &= ~HPRT0_PWR;
        dwc2_writel(hprt0, hsotg->regs + HPRT0);
+       dwc2_vbus_supply_exit(hsotg);
    }

-   /* Enter hibernation */
-   ret = dwc2_enter_hibernation(hsotg);
+   /* Enter partial_power_down */
+   ret = dwc2_enter_partial_power_down(hsotg);

The addition of dwc2_vbus_supply_exit(hsotg) may be interesting

SolidHal commented 6 years ago
+static int dwc2_vbus_supply_init(struct dwc2_hsotg *hsotg)
+{
+   hsotg->vbus_supply = devm_regulator_get_optional(hsotg->dev, "vbus");
+   if (IS_ERR(hsotg->vbus_supply))
+       return 0;
+
+   return regulator_enable(hsotg->vbus_supply);
+}
+
+static int dwc2_vbus_supply_exit(struct dwc2_hsotg *hsotg)
+{
+   if (hsotg->vbus_supply)
+       return regulator_disable(hsotg->vbus_supply);
+
+   return 0;
+}
+
SolidHal commented 6 years ago

dwc2_vbus_supply_init only gets called if _dwc2_hcd_resume is called, so if for some reason it hasn't been the vbus isn't brought back.

It could also be the case that _dwc2_hcd_resume is getting called, but doesnt get to dwc2_exit_partial_power_down() for one of these reasons:


static int _dwc2_hcd_resume(struct usb_hcd *hcd)
{
    struct dwc2_hsotg *hsotg = dwc2_hcd_to_hsotg(hcd);
    unsigned long flags;
    int ret = 0;

    spin_lock_irqsave(&hsotg->lock, flags);

    if (dwc2_is_device_mode(hsotg))
        goto unlock;

    if (hsotg->lx_state != DWC2_L2)
        goto unlock;

    if (hsotg->params.power_down != DWC2_POWER_DOWN_PARAM_PARTIAL) {
        hsotg->lx_state = DWC2_L0;
        goto unlock;
    }

this seems plausible, making image to test

SolidHal commented 6 years ago

Build image that will test:

In another image, test the following instead of the dwc2_force_mode test

In a third image, test these together:

SolidHal commented 6 years ago

SOOOO: _dwc2_hcd_resume calls dwc2_exit_partial_power_down! But, _dwc2_hcd_resume doesnt call dwc2_read_common_intr which prints the first of the two lines

dwc2_read_common_intr is called by dwc2_handle_common_inter and gets called 5 times before it prints the gintsts message

SolidHal commented 6 years ago

Synopsys has requested I try this patch: https://www.spinics.net/lists/linux-usb/msg169664.html

Edit: Didn't help

SolidHal commented 6 years ago

Tool for getting the caller function:

static u32 a_special( char const * caller_name, struct dwc2_hsotg *hsotg )
{

  dev_dbg(hsotg->dev, "HAL DEBUG: READ_COMMON_INTR CALLED BY %s\n", caller_name);
  return dwc2_read_common_intr(hsotg);

}

#define dwc2_read_common_intr(struct dwc2_hsotg *hsotg) a_special(__func__, hsotg)
SolidHal commented 6 years ago

Finally got onto the linux usb mailing list: https://marc.info/?l=linux-usb&m=153204494813919&w=2 The fix was to include: usb: dwc2: in the subject line. The silly spam filters were almost the death of me

SolidHal commented 6 years ago

Building two images to compare gintsts and gintmsk before and after suspend/partial power down with and without the blammed commit.

SolidHal commented 6 years ago

The relevant lines, in the non functional version:

[    1.439830] dwc2 ff580000.usb: HAL DEBUG func=_dwc2_hcd_suspend
[    1.439836] dwc2 ff580000.usb: HAL DEBUG PRE BACKUP func=dwc2_enter_partial_power_down, gintsts=04000021, gintmsk=f3000806
[    1.439840] dwc2 ff580000.usb: dwc2_backup_global_registers
[    1.439844] dwc2 ff580000.usb: dwc2_backup_host_registers
[    1.439854] dwc2 ff580000.usb: HAL DEBUG RETURN func=dwc2_enter_partial_power_down, gintsts=00000001, gintmsk=f0000000
[    1.439858] dwc2 ff580000.usb: HAL DEBUG RETURN func=_dwc2_hcd_suspend, gintsts=00000001, gintmsk=f0000000

In the non functional only one line is printed in _dwc2_hcd_suspend()

[    1.495708] dwc2 ff580000.usb: HAL DEBUG func=_dwc2_hcd_suspend

No return line, no lines about backing up registers or entering hibernation (what partial power down was called in this commit)

SO!

There are a number of reasons for partial powerdown to get skipped:

    if (dwc2_is_device_mode(hsotg)){
    dev_dbg(hsotg->dev, "HAL DEBUG func=%s, LEAVE! in device mode!?!\n",__func__);
        goto unlock;
  }

    if (hsotg->lx_state != DWC2_L0){
    dev_dbg(hsotg->dev, "HAL DEBUG func=%s, LEAVE! state not DWC2_L0\n",__func__);
        goto unlock;
  }

    if (!HCD_HW_ACCESSIBLE(hcd)){
      dev_dbg(hsotg->dev, "HAL DEBUG func=%s, LEAVE! !HCD_HW_ACCESSIBLE(hcd)\n",__func__);
      goto unlock;
    }

    if (hsotg->op_state == OTG_STATE_B_PERIPHERAL){
      dev_dbg(hsotg->dev, "HAL DEBUG func=%s, hsotg->op_state == OTG_STATE_B_PERIPHERAL\n",__func__);
      goto unlock;
    }

    if (!hsotg->params.hibernation){
      dev_dbg(hsotg->dev, "HAL DEBUG func=%s, !hsotg->params.hibernation\n",__func__);
      goto skip_power_saving;
    }

(I added the debug messages just now)

Only one of them prints....

[    1.495757] dwc2 ff580000.usb: HAL DEBUG func=_dwc2_hcd_suspend
[    1.495762] dwc2 ff580000.usb: HAL DEBUG func=_dwc2_hcd_suspend, !hsotg->params.hibernation

Which means it goes to;

skip_power_saving:
    hsotg->lx_state = DWC2_L2;
unlock:
    spin_unlock_irqrestore(&hsotg->lock, flags);

    return ret;

Since the param hibernation was swapped out for power_down, this no longer functions properly

    if (hsotg->params.power_down != DWC2_POWER_DOWN_PARAM_PARTIAL)
        goto skip_power_saving;

So, mystery solved. Now, how to fix it?

SolidHal commented 6 years ago

As I had found above:

param.power_down is defined like this:

static void dwc2_set_param_power_down(struct dwc2_hsotg *hsotg)
{
  int val;

  if (hsotg->hw_params.hibernation)
      val = 2;
  else if (hsotg->hw_params.power_optimized)
      val = 1;
  else
      val = 0;

  hsotg->params.power_down = val;
}
#define DWC2_POWER_DOWN_PARAM_NONE        0
#define DWC2_POWER_DOWN_PARAM_PARTIAL     1
#define DWC2_POWER_DOWN_PARAM_HIBERNATION     2

So something is setting hw_params.power_optimized

and hsotg->hw_params is defined as:

 * @hw_params:          Parameters that were autodetected from the
 *                      hardware registers

and set in params.c like this:

    hw->power_optimized = !!(hwcfg4 & GHWCFG4_POWER_OPTIMIZ);

For example/comparison hibernation is here too:

    hw->hibernation = !!(hwcfg4 & GHWCFG4_HIBER);

Aside: The double exclamation mark confused me for a bit but is used for:

It is just a unary NOT then a unary NOT again.

The effect of this is that it will transform the output of that incredibly long-named function into either 1 or 0. If the return value of the function is greater (or less) than 0, double NOT will produce 1. If it is 0 then double NOTing it will produce 0.

And in hw.h we find:

#define GHWCFG4             HSOTG_REG(0x0050)
.
.
.
#define GHWCFG4_POWER_OPTIMIZ           BIT(4)
SolidHal commented 6 years ago

In params.c

static void dwc2_set_rk_params(struct dwc2_hsotg *hsotg)
{
    struct dwc2_core_params *p = &hsotg->params;

    p->otg_cap = DWC2_CAP_PARAM_NO_HNP_SRP_CAPABLE;
    p->host_rx_fifo_size = 525;
    p->host_nperio_tx_fifo_size = 128;
    p->host_perio_tx_fifo_size = 256;
    p->ahbcfg = GAHBCFG_HBSTLEN_INCR16 <<
        GAHBCFG_HBSTLEN_SHIFT;
    p->power_down = 0;
}

FIXED IT!!

SolidHal commented 6 years ago

Mailing list discussion: Re: REGRESSION: usb: dwc2: USB device not seen after boot

Mailing list patch thread: [PATCH] usb: dwc2: disable power_down on rockchip devices

SolidHal commented 6 years ago

Keeping this issue open until the patch is merged into mainline

SolidHal commented 6 years ago

Fixed the patch to use tabs instead of spaces, can be found in patches-tested

SolidHal commented 6 years ago

Patch has been confirmed working. closing