rcar_gen3_phy_usb2: unbalanced disables for USB20_VBUS0

From: Geert Uytterhoeven
Date: Tue Jun 04 2019 - 14:10:28 EST


Hi Shimoda-san,

Using a tree based on renesas-drivers-2019-06-04-v5.2-rc3, I started seeing
the following warning during a second system suspend (s2idle):

unbalanced disables for USB20_VBUS0
WARNING: CPU: 2 PID: 1162 at drivers/regulator/core.c:2593
_regulator_disable+0x58/0x174
Modules linked in:
CPU: 2 PID: 1162 Comm: kworker/u16:22 Not tainted
5.2.0-rc3-salvator-x-02580-g25f69f634d1c7e7d #407
Hardware name: Renesas Salvator-X board based on r8a7795 ES1.x (DT)
Workqueue: events_unbound async_run_entry_fn
pstate: 40400005 (nZcv daif +PAN -UAO)
pc : _regulator_disable+0x58/0x174
lr : _regulator_disable+0x58/0x174
sp : ffffff8012abb9d0
x29: ffffff8012abb9d0 x28: ffffff80110fa0c0
x27: 0000000000000000 x26: ffffff8010cecf66
x25: 0000000000000001 x24: 0000000000000002
x23: 0000000000000001 x22: ffffff801100e000
x21: ffffffc6f80ca700 x20: ffffffc6f80ae800
x19: ffffffc6f80ae800 x18: 000000000000000a
x17: 0000000000000000 x16: 0000000000000000
x15: 000000000002da16 x14: 0720072007200720
x13: 0720072007200720 x12: ffffff8011038000
x11: ffffff8011b412e1 x10: 0000000000000044
x9 : 0000000000000028 x8 : ffffff801112187c
x7 : 0000000000000001 x6 : 0000000000000000
x5 : ffffffc6ff70d240 x4 : 0000000000000001
x3 : 0000000000000007 x2 : 0000000000000007
x1 : 7a369ee2b9d96e00 x0 : 0000000000000000
Call trace:
_regulator_disable+0x58/0x174
regulator_disable+0x40/0x78
rcar_gen3_phy_usb2_power_off+0x40/0x50
phy_power_off+0x50/0xb4
usb_phy_roothub_power_off+0x38/0x44
usb_phy_roothub_suspend+0x1c/0x48
hcd_bus_suspend+0xc8/0x15c
generic_suspend+0x14/0x54
usb_suspend_both+0xec/0x208
usb_suspend+0xe0/0x118
usb_dev_suspend+0x10/0x18
dpm_run_callback+0x170/0x2e8
__device_suspend+0x18c/0x594
async_suspend+0x28/0xa0
async_run_entry_fn+0x4c/0x120
process_one_work+0x354/0x5b4
worker_thread+0x21c/0x324
kthread+0x120/0x130
ret_from_fork+0x10/0x18
irq event stamp: 3436
hardirqs last enabled at (3435): [<ffffff8010159e60>]
vprintk_emit+0x230/0x31c
hardirqs last disabled at (3436): [<ffffff8010081a28>]
do_debug_exception+0x48/0x12c
softirqs last enabled at (3428): [<ffffff8010081ee4>]
__do_softirq+0x18c/0x4a0
softirqs last disabled at (3421): [<ffffff80100f4a60>] irq_exit+0xa4/0x100
---[ end trace ba79265b58264683 ]---
phy phy-ee080200.usb-phy.11: phy poweroff failed --> -5

So far I've seen this on Salvator-X with R-Car H3 ES1.0 or M3-W, and
on Salvator-XS with R-Car M3-N, but not (yet?) on H3 ES2.0.

Unfortunately the issue seems to be fairly timing-sensitive, so I failed
to bisect it.

I have added some debug. While this didn't help me finding the cause
of the above warning, it did discover another imbalance:

A) Boot:

phy phy-ee080200.usb-phy.7: rcar_gen3_phy_usb2_power_on: Enabling regulator
(from ehci_platform_probe)

B) System suspend (s2idle):

phy phy-ee080200.usb-phy.7: rcar_gen3_phy_usb2_power_off:
Disabling regulator
(from async_suspend)

Looks OK.

C) System resume:

phy phy-ee080200.usb-phy.7: rcar_gen3_phy_usb2_power_on: Enabling regulator
phy phy-ee080200.usb-phy.6: rcar_gen3_phy_usb2_power_on: Enabling regulator
(from async_resume)

What's this phy-ee080200.usb-phy.6, which was never enabled before, during boot?

D) System suspend (s2idle):

phy phy-ee080200.usb-phy.7: rcar_gen3_phy_usb2_power_off:
Disabling regulator

E) System resume:

phy phy-ee080200.usb-phy.6: rcar_gen3_phy_usb2_power_on: Enabling regulator
phy phy-ee080200.usb-phy.7: rcar_gen3_phy_usb2_power_on: Enabling regulator

I.e. phy-ee080200.usb-phy.6 keeps on being enabled during each system resume,
but is never disabled

Do you have a clue?

Thanks!

Gr{oetje,eeting}s,

Geert

--
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- geert@xxxxxxxxxxxxxx

In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say "programmer" or something like that.
-- Linus Torvalds