2019-03-18 15:07:19

by Marc Zyngier

[permalink] [raw]
Subject: [PATCH] usb: typec: fusb302: Fix debugfs mutex initialisation

Running a kernel with the fusb302 driver and lockdep enabled
leads to an unpleasant warning:

[ 4.617477] INFO: trying to register non-static key.
[ 4.617930] the code is fine but needs lockdep annotation.
[ 4.618418] turning off the locking correctness validator.
[ 4.618913] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.1.0-rc1-00007-g3542533f3fc9 #13
[ 4.619620] Hardware name: rockchip evb_rk3399/evb_rk3399, BIOS 2019.04-rc3-00124-g2feec69fb1 03/15/2019
[ 4.620454] Call trace:
[ 4.620693] dump_backtrace+0x0/0x138
[ 4.621028] show_stack+0x24/0x30
[ 4.621336] dump_stack+0xbc/0x104
[ 4.621649] register_lock_class+0x594/0x598
[ 4.622036] __lock_acquire+0x80/0x11b8
[ 4.622384] lock_acquire+0xdc/0x260
[ 4.622711] __mutex_lock+0x90/0x8a0
[ 4.623037] mutex_lock_nested+0x3c/0x50
[ 4.623394] _fusb302_log+0x88/0x1f0
[ 4.623721] fusb302_log+0x7c/0xa0
[ 4.624033] tcpm_init+0x5c/0x190
[ 4.624336] tcpm_init+0x3c/0x130
[ 4.624640] tcpm_register_port+0x574/0x878
[ 4.625019] fusb302_probe+0x2c8/0x590

Despite what the message says, the code isn't fine, as it tries to
make use of the fusb302_log facility pretty early. This requires the
logbuffer_lock mutex to be initialised, but that only happens much
later. Boo.

Hoist the fusb302_debugfs_init call before tcpm_register_port so that
we can enjoy a working mutex.

Signed-off-by: Marc Zyngier <[email protected]>
---
drivers/usb/typec/tcpm/fusb302.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/drivers/usb/typec/tcpm/fusb302.c b/drivers/usb/typec/tcpm/fusb302.c
index e9344997329c..7e3f8901daf6 100644
--- a/drivers/usb/typec/tcpm/fusb302.c
+++ b/drivers/usb/typec/tcpm/fusb302.c
@@ -1790,6 +1790,7 @@ static int fusb302_probe(struct i2c_client *client,
goto destroy_workqueue;
}

+ fusb302_debugfs_init(chip);
chip->tcpm_port = tcpm_register_port(&client->dev, &chip->tcpc_dev);
if (IS_ERR(chip->tcpm_port)) {
ret = PTR_ERR(chip->tcpm_port);
@@ -1807,7 +1808,6 @@ static int fusb302_probe(struct i2c_client *client,
goto tcpm_unregister_port;
}
enable_irq_wake(chip->gpio_int_n_irq);
- fusb302_debugfs_init(chip);
i2c_set_clientdata(client, chip);

return ret;
--
2.20.1



2019-03-18 15:40:22

by Guenter Roeck

[permalink] [raw]
Subject: Re: [PATCH] usb: typec: fusb302: Fix debugfs mutex initialisation

On Mon, Mar 18, 2019 at 03:06:00PM +0000, Marc Zyngier wrote:
> Running a kernel with the fusb302 driver and lockdep enabled
> leads to an unpleasant warning:
>
> [ 4.617477] INFO: trying to register non-static key.
> [ 4.617930] the code is fine but needs lockdep annotation.
> [ 4.618418] turning off the locking correctness validator.
> [ 4.618913] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.1.0-rc1-00007-g3542533f3fc9 #13
> [ 4.619620] Hardware name: rockchip evb_rk3399/evb_rk3399, BIOS 2019.04-rc3-00124-g2feec69fb1 03/15/2019
> [ 4.620454] Call trace:
> [ 4.620693] dump_backtrace+0x0/0x138
> [ 4.621028] show_stack+0x24/0x30
> [ 4.621336] dump_stack+0xbc/0x104
> [ 4.621649] register_lock_class+0x594/0x598
> [ 4.622036] __lock_acquire+0x80/0x11b8
> [ 4.622384] lock_acquire+0xdc/0x260
> [ 4.622711] __mutex_lock+0x90/0x8a0
> [ 4.623037] mutex_lock_nested+0x3c/0x50
> [ 4.623394] _fusb302_log+0x88/0x1f0
> [ 4.623721] fusb302_log+0x7c/0xa0
> [ 4.624033] tcpm_init+0x5c/0x190
> [ 4.624336] tcpm_init+0x3c/0x130
> [ 4.624640] tcpm_register_port+0x574/0x878
> [ 4.625019] fusb302_probe+0x2c8/0x590
>
> Despite what the message says, the code isn't fine, as it tries to
> make use of the fusb302_log facility pretty early. This requires the
> logbuffer_lock mutex to be initialised, but that only happens much
> later. Boo.
>
> Hoist the fusb302_debugfs_init call before tcpm_register_port so that
> we can enjoy a working mutex.
>
> Signed-off-by: Marc Zyngier <[email protected]>
> ---
> drivers/usb/typec/tcpm/fusb302.c | 2 +-
> 1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/drivers/usb/typec/tcpm/fusb302.c b/drivers/usb/typec/tcpm/fusb302.c
> index e9344997329c..7e3f8901daf6 100644
> --- a/drivers/usb/typec/tcpm/fusb302.c
> +++ b/drivers/usb/typec/tcpm/fusb302.c
> @@ -1790,6 +1790,7 @@ static int fusb302_probe(struct i2c_client *client,
> goto destroy_workqueue;
> }
>
> + fusb302_debugfs_init(chip);

This needs another error exit label right after destroy_workqueue,
and an added call to fusb302_debugfs_exit() after that label.

> chip->tcpm_port = tcpm_register_port(&client->dev, &chip->tcpc_dev);
> if (IS_ERR(chip->tcpm_port)) {
> ret = PTR_ERR(chip->tcpm_port);
> @@ -1807,7 +1808,6 @@ static int fusb302_probe(struct i2c_client *client,
> goto tcpm_unregister_port;
> }
> enable_irq_wake(chip->gpio_int_n_irq);
> - fusb302_debugfs_init(chip);
> i2c_set_clientdata(client, chip);
>
> return ret;
> --
> 2.20.1
>

2019-03-18 17:34:25

by Marc Zyngier

[permalink] [raw]
Subject: Re: [PATCH] usb: typec: fusb302: Fix debugfs mutex initialisation

On Mon, 18 Mar 2019 08:39:22 -0700
Guenter Roeck <[email protected]> wrote:

> On Mon, Mar 18, 2019 at 03:06:00PM +0000, Marc Zyngier wrote:
> > Running a kernel with the fusb302 driver and lockdep enabled
> > leads to an unpleasant warning:
> >
> > [ 4.617477] INFO: trying to register non-static key.
> > [ 4.617930] the code is fine but needs lockdep annotation.
> > [ 4.618418] turning off the locking correctness validator.
> > [ 4.618913] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.1.0-rc1-00007-g3542533f3fc9 #13
> > [ 4.619620] Hardware name: rockchip evb_rk3399/evb_rk3399, BIOS 2019.04-rc3-00124-g2feec69fb1 03/15/2019
> > [ 4.620454] Call trace:
> > [ 4.620693] dump_backtrace+0x0/0x138
> > [ 4.621028] show_stack+0x24/0x30
> > [ 4.621336] dump_stack+0xbc/0x104
> > [ 4.621649] register_lock_class+0x594/0x598
> > [ 4.622036] __lock_acquire+0x80/0x11b8
> > [ 4.622384] lock_acquire+0xdc/0x260
> > [ 4.622711] __mutex_lock+0x90/0x8a0
> > [ 4.623037] mutex_lock_nested+0x3c/0x50
> > [ 4.623394] _fusb302_log+0x88/0x1f0
> > [ 4.623721] fusb302_log+0x7c/0xa0
> > [ 4.624033] tcpm_init+0x5c/0x190
> > [ 4.624336] tcpm_init+0x3c/0x130
> > [ 4.624640] tcpm_register_port+0x574/0x878
> > [ 4.625019] fusb302_probe+0x2c8/0x590
> >
> > Despite what the message says, the code isn't fine, as it tries to
> > make use of the fusb302_log facility pretty early. This requires the
> > logbuffer_lock mutex to be initialised, but that only happens much
> > later. Boo.
> >
> > Hoist the fusb302_debugfs_init call before tcpm_register_port so that
> > we can enjoy a working mutex.
> >
> > Signed-off-by: Marc Zyngier <[email protected]>
> > ---
> > drivers/usb/typec/tcpm/fusb302.c | 2 +-
> > 1 file changed, 1 insertion(+), 1 deletion(-)
> >
> > diff --git a/drivers/usb/typec/tcpm/fusb302.c b/drivers/usb/typec/tcpm/fusb302.c
> > index e9344997329c..7e3f8901daf6 100644
> > --- a/drivers/usb/typec/tcpm/fusb302.c
> > +++ b/drivers/usb/typec/tcpm/fusb302.c
> > @@ -1790,6 +1790,7 @@ static int fusb302_probe(struct i2c_client *client,
> > goto destroy_workqueue;
> > }
> >
> > + fusb302_debugfs_init(chip);
>
> This needs another error exit label right after destroy_workqueue,
> and an added call to fusb302_debugfs_exit() after that label.

You do mean before destroy_workqueue, right? Otherwise, the error
handling doesn't nest properly... Something like this:

diff --git a/drivers/usb/typec/tcpm/fusb302.c b/drivers/usb/typec/tcpm/fusb302.c
index 7e3f8901daf6..76cb8be6f3eb 100644
--- a/drivers/usb/typec/tcpm/fusb302.c
+++ b/drivers/usb/typec/tcpm/fusb302.c
@@ -1796,7 +1796,7 @@ static int fusb302_probe(struct i2c_client *client,
ret = PTR_ERR(chip->tcpm_port);
if (ret != -EPROBE_DEFER)
dev_err(dev, "cannot register tcpm port, ret=%d", ret);
- goto destroy_workqueue;
+ goto unregister_debugfs;
}

ret = devm_request_threaded_irq(chip->dev, chip->gpio_int_n_irq,
@@ -1814,6 +1814,8 @@ static int fusb302_probe(struct i2c_client *client,

tcpm_unregister_port:
tcpm_unregister_port(chip->tcpm_port);
+unregister_debugfs:
+ fusb302_debugfs_exit(chip);
destroy_workqueue:
destroy_workqueue(chip->wq);

Thanks,

M.
--
Without deviation from the norm, progress is not possible.

2019-03-18 17:41:49

by Guenter Roeck

[permalink] [raw]
Subject: Re: [PATCH] usb: typec: fusb302: Fix debugfs mutex initialisation

On Mon, Mar 18, 2019 at 05:32:56PM +0000, Marc Zyngier wrote:
> On Mon, 18 Mar 2019 08:39:22 -0700
> Guenter Roeck <[email protected]> wrote:
>
> > On Mon, Mar 18, 2019 at 03:06:00PM +0000, Marc Zyngier wrote:
> > > Running a kernel with the fusb302 driver and lockdep enabled
> > > leads to an unpleasant warning:
> > >
> > > [ 4.617477] INFO: trying to register non-static key.
> > > [ 4.617930] the code is fine but needs lockdep annotation.
> > > [ 4.618418] turning off the locking correctness validator.
> > > [ 4.618913] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.1.0-rc1-00007-g3542533f3fc9 #13
> > > [ 4.619620] Hardware name: rockchip evb_rk3399/evb_rk3399, BIOS 2019.04-rc3-00124-g2feec69fb1 03/15/2019
> > > [ 4.620454] Call trace:
> > > [ 4.620693] dump_backtrace+0x0/0x138
> > > [ 4.621028] show_stack+0x24/0x30
> > > [ 4.621336] dump_stack+0xbc/0x104
> > > [ 4.621649] register_lock_class+0x594/0x598
> > > [ 4.622036] __lock_acquire+0x80/0x11b8
> > > [ 4.622384] lock_acquire+0xdc/0x260
> > > [ 4.622711] __mutex_lock+0x90/0x8a0
> > > [ 4.623037] mutex_lock_nested+0x3c/0x50
> > > [ 4.623394] _fusb302_log+0x88/0x1f0
> > > [ 4.623721] fusb302_log+0x7c/0xa0
> > > [ 4.624033] tcpm_init+0x5c/0x190
> > > [ 4.624336] tcpm_init+0x3c/0x130
> > > [ 4.624640] tcpm_register_port+0x574/0x878
> > > [ 4.625019] fusb302_probe+0x2c8/0x590
> > >
> > > Despite what the message says, the code isn't fine, as it tries to
> > > make use of the fusb302_log facility pretty early. This requires the
> > > logbuffer_lock mutex to be initialised, but that only happens much
> > > later. Boo.
> > >
> > > Hoist the fusb302_debugfs_init call before tcpm_register_port so that
> > > we can enjoy a working mutex.
> > >
> > > Signed-off-by: Marc Zyngier <[email protected]>
> > > ---
> > > drivers/usb/typec/tcpm/fusb302.c | 2 +-
> > > 1 file changed, 1 insertion(+), 1 deletion(-)
> > >
> > > diff --git a/drivers/usb/typec/tcpm/fusb302.c b/drivers/usb/typec/tcpm/fusb302.c
> > > index e9344997329c..7e3f8901daf6 100644
> > > --- a/drivers/usb/typec/tcpm/fusb302.c
> > > +++ b/drivers/usb/typec/tcpm/fusb302.c
> > > @@ -1790,6 +1790,7 @@ static int fusb302_probe(struct i2c_client *client,
> > > goto destroy_workqueue;
> > > }
> > >
> > > + fusb302_debugfs_init(chip);
> >
> > This needs another error exit label right after destroy_workqueue,
> > and an added call to fusb302_debugfs_exit() after that label.
>
> You do mean before destroy_workqueue, right? Otherwise, the error
> handling doesn't nest properly... Something like this:
>
Yes, you are correct. Sorry for the confusion.

Guenter

> diff --git a/drivers/usb/typec/tcpm/fusb302.c b/drivers/usb/typec/tcpm/fusb302.c
> index 7e3f8901daf6..76cb8be6f3eb 100644
> --- a/drivers/usb/typec/tcpm/fusb302.c
> +++ b/drivers/usb/typec/tcpm/fusb302.c
> @@ -1796,7 +1796,7 @@ static int fusb302_probe(struct i2c_client *client,
> ret = PTR_ERR(chip->tcpm_port);
> if (ret != -EPROBE_DEFER)
> dev_err(dev, "cannot register tcpm port, ret=%d", ret);
> - goto destroy_workqueue;
> + goto unregister_debugfs;
> }
>
> ret = devm_request_threaded_irq(chip->dev, chip->gpio_int_n_irq,
> @@ -1814,6 +1814,8 @@ static int fusb302_probe(struct i2c_client *client,
>
> tcpm_unregister_port:
> tcpm_unregister_port(chip->tcpm_port);
> +unregister_debugfs:
> + fusb302_debugfs_exit(chip);
> destroy_workqueue:
> destroy_workqueue(chip->wq);
>
> Thanks,
>
> M.
> --
> Without deviation from the norm, progress is not possible.