diff mbox

[1/2] clk: imx: do not sleep if IRQ's are still disabled

Message ID 1454107764-19876-1-git-send-email-stefan@agner.ch (mailing list archive)
State New, archived
Headers show

Commit Message

Stefan Agner Jan. 29, 2016, 10:49 p.m. UTC
If a clock gets enabled early during boot time, it can lead to a PLL
startup. The wait_lock function makes sure that the PLL is really
stareted up before it gets used. However, the function sleeps which
leads to scheduling and an error:
bad: scheduling from the idle thread!
...

Use udelay in case IRQ's are still disabled.

Signed-off-by: Stefan Agner <stefan@agner.ch>
---
 drivers/clk/imx/clk-pllv3.c | 5 ++++-
 1 file changed, 4 insertions(+), 1 deletion(-)

Comments

Joshua Clayton Jan. 29, 2016, 11:35 p.m. UTC | #1
On Fri, 29 Jan 2016 14:49:23 -0800
Stefan Agner <stefan@agner.ch> wrote:

> If a clock gets enabled early during boot time, it can lead to a PLL
> startup. The wait_lock function makes sure that the PLL is really
> stareted up before it gets used. However, the function sleeps which
s/stareted/started/
Stephen Boyd Jan. 30, 2016, 1:16 a.m. UTC | #2
On 01/29, Stefan Agner wrote:
> If a clock gets enabled early during boot time, it can lead to a PLL
> startup. The wait_lock function makes sure that the PLL is really
> stareted up before it gets used. However, the function sleeps which
> leads to scheduling and an error:
> bad: scheduling from the idle thread!
> ...

Can you please share the full splat? I have no clue what's going
on.
Stephen Boyd April 16, 2016, 1 a.m. UTC | #3
On 01/29, Stefan Agner wrote:
> If a clock gets enabled early during boot time, it can lead to a PLL
> startup. The wait_lock function makes sure that the PLL is really
> stareted up before it gets used. However, the function sleeps which
> leads to scheduling and an error:
> bad: scheduling from the idle thread!
> ...
> 
> Use udelay in case IRQ's are still disabled.
> 
> Signed-off-by: Stefan Agner <stefan@agner.ch>

This is really old. Shawn, are you picking these up? I'm removing
these from my queue for now.
Shawn Guo April 18, 2016, 1:58 a.m. UTC | #4
On Fri, Apr 15, 2016 at 06:00:53PM -0700, Stephen Boyd wrote:
> On 01/29, Stefan Agner wrote:
> > If a clock gets enabled early during boot time, it can lead to a PLL
> > startup. The wait_lock function makes sure that the PLL is really
> > stareted up before it gets used. However, the function sleeps which
> > leads to scheduling and an error:
> > bad: scheduling from the idle thread!
> > ...
> > 
> > Use udelay in case IRQ's are still disabled.
> > 
> > Signed-off-by: Stefan Agner <stefan@agner.ch>
> 
> This is really old. Shawn, are you picking these up? I'm removing
> these from my queue for now.

Yes, I'm picking them up.

Shawn
Dong Aisheng April 21, 2016, 3:45 a.m. UTC | #5
On Fri, Jan 29, 2016 at 02:49:23PM -0800, Stefan Agner wrote:
> If a clock gets enabled early during boot time, it can lead to a PLL
> startup. The wait_lock function makes sure that the PLL is really
> stareted up before it gets used. However, the function sleeps which
> leads to scheduling and an error:
> bad: scheduling from the idle thread!
> ...
> 
> Use udelay in case IRQ's are still disabled.
> 
> Signed-off-by: Stefan Agner <stefan@agner.ch>
> ---
>  drivers/clk/imx/clk-pllv3.c | 5 ++++-
>  1 file changed, 4 insertions(+), 1 deletion(-)
> 
> diff --git a/drivers/clk/imx/clk-pllv3.c b/drivers/clk/imx/clk-pllv3.c
> index c05c43d..b5ff561 100644
> --- a/drivers/clk/imx/clk-pllv3.c
> +++ b/drivers/clk/imx/clk-pllv3.c
> @@ -63,7 +63,10 @@ static int clk_pllv3_wait_lock(struct clk_pllv3 *pll)
>  			break;
>  		if (time_after(jiffies, timeout))
>  			break;
> -		usleep_range(50, 500);
> +		if (unlikely(irqs_disabled()))

This causes a bit confusion that clk_pllv3_prepare is sleepable.
But this line indicates it's possible to be called in irq context.
Although it's only happened during kernel boot phase where irq is
still not enabled.
It seems schedule_debug() somehow did not catch it during early boot
phase. Maybe schedule guys can help explain.

My question is if it's really worthy to introduce this confusion
to fix the issue since the delay is minor?

Furthermore, shouldn't it be udelay(500)?

Shawn,
What's your idea?

Regards
Dong Aisheng

> +			udelay(50);
> +		else
> +			usleep_range(50, 500);
>  	} while (1);
>  
>  	return readl_relaxed(pll->base) & BM_PLL_LOCK ? 0 : -ETIMEDOUT;
> -- 
> 2.7.0
> 
> --
> To unsubscribe from this list: send the line "unsubscribe linux-clk" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
Shawn Guo April 26, 2016, 1:23 a.m. UTC | #6
On Thu, Apr 21, 2016 at 11:45:20AM +0800, Dong Aisheng wrote:
> On Fri, Jan 29, 2016 at 02:49:23PM -0800, Stefan Agner wrote:
> > If a clock gets enabled early during boot time, it can lead to a PLL
> > startup. The wait_lock function makes sure that the PLL is really
> > stareted up before it gets used. However, the function sleeps which
> > leads to scheduling and an error:
> > bad: scheduling from the idle thread!
> > ...
> > 
> > Use udelay in case IRQ's are still disabled.
> > 
> > Signed-off-by: Stefan Agner <stefan@agner.ch>
> > ---
> >  drivers/clk/imx/clk-pllv3.c | 5 ++++-
> >  1 file changed, 4 insertions(+), 1 deletion(-)
> > 
> > diff --git a/drivers/clk/imx/clk-pllv3.c b/drivers/clk/imx/clk-pllv3.c
> > index c05c43d..b5ff561 100644
> > --- a/drivers/clk/imx/clk-pllv3.c
> > +++ b/drivers/clk/imx/clk-pllv3.c
> > @@ -63,7 +63,10 @@ static int clk_pllv3_wait_lock(struct clk_pllv3 *pll)
> >  			break;
> >  		if (time_after(jiffies, timeout))
> >  			break;
> > -		usleep_range(50, 500);
> > +		if (unlikely(irqs_disabled()))
> 
> This causes a bit confusion that clk_pllv3_prepare is sleepable.
> But this line indicates it's possible to be called in irq context.
> Although it's only happened during kernel boot phase where irq is
> still not enabled.
> It seems schedule_debug() somehow did not catch it during early boot
> phase. Maybe schedule guys can help explain.
> 
> My question is if it's really worthy to introduce this confusion
> to fix the issue since the delay is minor?

I do not understand why it's confusing.  The code already obviously
indicates this is a special handling for cases where irq is still not
enabled, rather than for irq context.

The patch is to fix the "bad: scheduling from the idle thread!" warning
rather than minimize the delay.  Do you have an opinion on how to fix
the warning?

> Furthermore, shouldn't it be udelay(500)?

500 is for the worst case of sleep, and 50 is good enough for delay.

Shawn
Dong Aisheng April 26, 2016, 5:51 a.m. UTC | #7
Hi Shawn,

On Tue, Apr 26, 2016 at 9:23 AM, Shawn Guo <shawnguo@kernel.org> wrote:
> On Thu, Apr 21, 2016 at 11:45:20AM +0800, Dong Aisheng wrote:
>> On Fri, Jan 29, 2016 at 02:49:23PM -0800, Stefan Agner wrote:
>> > If a clock gets enabled early during boot time, it can lead to a PLL
>> > startup. The wait_lock function makes sure that the PLL is really
>> > stareted up before it gets used. However, the function sleeps which
>> > leads to scheduling and an error:
>> > bad: scheduling from the idle thread!
>> > ...
>> >
>> > Use udelay in case IRQ's are still disabled.
>> >
>> > Signed-off-by: Stefan Agner <stefan@agner.ch>
>> > ---
>> >  drivers/clk/imx/clk-pllv3.c | 5 ++++-
>> >  1 file changed, 4 insertions(+), 1 deletion(-)
>> >
>> > diff --git a/drivers/clk/imx/clk-pllv3.c b/drivers/clk/imx/clk-pllv3.c
>> > index c05c43d..b5ff561 100644
>> > --- a/drivers/clk/imx/clk-pllv3.c
>> > +++ b/drivers/clk/imx/clk-pllv3.c
>> > @@ -63,7 +63,10 @@ static int clk_pllv3_wait_lock(struct clk_pllv3 *pll)
>> >                     break;
>> >             if (time_after(jiffies, timeout))
>> >                     break;
>> > -           usleep_range(50, 500);
>> > +           if (unlikely(irqs_disabled()))
>>
>> This causes a bit confusion that clk_pllv3_prepare is sleepable.
>> But this line indicates it's possible to be called in irq context.
>> Although it's only happened during kernel boot phase where irq is
>> still not enabled.
>> It seems schedule_debug() somehow did not catch it during early boot
>> phase. Maybe schedule guys can help explain.
>>
>> My question is if it's really worthy to introduce this confusion
>> to fix the issue since the delay is minor?
>
> I do not understand why it's confusing.  The code already obviously
> indicates this is a special handling for cases where irq is still not
> enabled, rather than for irq context.
>

The code itself has nothing telling it's a special handling for the
case where irq is
still not enabled.
Even it tells, it may still cause confusing by adding complexity in
clk_pllv3_prepare()
which actually should be called in non-atomic context as it could sleep.

> The patch is to fix the "bad: scheduling from the idle thread!" warning
> rather than minimize the delay.  Do you have an opinion on how to fix
> the warning?
>

I just wonder maybe we could simply just using udelay(50) instead of
usleep_range(50, 500) to eliminate the confusing since it's minor cast.
What do you think of it?

>> Furthermore, shouldn't it be udelay(500)?
>
> 500 is for the worst case of sleep, and 50 is good enough for delay.
>

Yes, you''re right.
We have a loop, so 50ns one time should be good.

> Shawn

Regards
Dong Aisheng
Shawn Guo April 26, 2016, 9:24 a.m. UTC | #8
On Tue, Apr 26, 2016 at 01:51:13PM +0800, Dong Aisheng wrote:
> Hi Shawn,
> 
> On Tue, Apr 26, 2016 at 9:23 AM, Shawn Guo <shawnguo@kernel.org> wrote:
> > On Thu, Apr 21, 2016 at 11:45:20AM +0800, Dong Aisheng wrote:
> >> On Fri, Jan 29, 2016 at 02:49:23PM -0800, Stefan Agner wrote:
> >> > If a clock gets enabled early during boot time, it can lead to a PLL
> >> > startup. The wait_lock function makes sure that the PLL is really
> >> > stareted up before it gets used. However, the function sleeps which
> >> > leads to scheduling and an error:
> >> > bad: scheduling from the idle thread!
> >> > ...
> >> >
> >> > Use udelay in case IRQ's are still disabled.
> >> >
> >> > Signed-off-by: Stefan Agner <stefan@agner.ch>
> >> > ---
> >> >  drivers/clk/imx/clk-pllv3.c | 5 ++++-
> >> >  1 file changed, 4 insertions(+), 1 deletion(-)
> >> >
> >> > diff --git a/drivers/clk/imx/clk-pllv3.c b/drivers/clk/imx/clk-pllv3.c
> >> > index c05c43d..b5ff561 100644
> >> > --- a/drivers/clk/imx/clk-pllv3.c
> >> > +++ b/drivers/clk/imx/clk-pllv3.c
> >> > @@ -63,7 +63,10 @@ static int clk_pllv3_wait_lock(struct clk_pllv3 *pll)
> >> >                     break;
> >> >             if (time_after(jiffies, timeout))
> >> >                     break;
> >> > -           usleep_range(50, 500);
> >> > +           if (unlikely(irqs_disabled()))
> >>
> >> This causes a bit confusion that clk_pllv3_prepare is sleepable.
> >> But this line indicates it's possible to be called in irq context.
> >> Although it's only happened during kernel boot phase where irq is
> >> still not enabled.
> >> It seems schedule_debug() somehow did not catch it during early boot
> >> phase. Maybe schedule guys can help explain.
> >>
> >> My question is if it's really worthy to introduce this confusion
> >> to fix the issue since the delay is minor?
> >
> > I do not understand why it's confusing.  The code already obviously
> > indicates this is a special handling for cases where irq is still not
> > enabled, rather than for irq context.
> >
> 
> The code itself has nothing telling it's a special handling for the
> case where irq is
> still not enabled.

I think the following if-clause is telling that.

	if (unlikely(irqs_disabled()))

> Even it tells, it may still cause confusing by adding complexity in
> clk_pllv3_prepare()
> which actually should be called in non-atomic context as it could sleep.

I agree with you on that.

> > The patch is to fix the "bad: scheduling from the idle thread!" warning
> > rather than minimize the delay.  Do you have an opinion on how to fix
> > the warning?
> >
> 
> I just wonder maybe we could simply just using udelay(50) instead of
> usleep_range(50, 500) to eliminate the confusing since it's minor cast.
> What do you think of it?

I'm fine with it.  Since I haven't sent the patch to clk maintainers, I
could replace Stefan's patch with yours, if you can send me a patch
quickly.

Shawn
Lucas Stach April 26, 2016, 9:31 a.m. UTC | #9
Am Dienstag, den 26.04.2016, 13:51 +0800 schrieb Dong Aisheng:
> Hi Shawn,
> 
> On Tue, Apr 26, 2016 at 9:23 AM, Shawn Guo <shawnguo@kernel.org> wrote:
> > On Thu, Apr 21, 2016 at 11:45:20AM +0800, Dong Aisheng wrote:
> >> On Fri, Jan 29, 2016 at 02:49:23PM -0800, Stefan Agner wrote:
> >> > If a clock gets enabled early during boot time, it can lead to a PLL
> >> > startup. The wait_lock function makes sure that the PLL is really
> >> > stareted up before it gets used. However, the function sleeps which
> >> > leads to scheduling and an error:
> >> > bad: scheduling from the idle thread!
> >> > ...
> >> >
> >> > Use udelay in case IRQ's are still disabled.
> >> >
> >> > Signed-off-by: Stefan Agner <stefan@agner.ch>
> >> > ---
> >> >  drivers/clk/imx/clk-pllv3.c | 5 ++++-
> >> >  1 file changed, 4 insertions(+), 1 deletion(-)
> >> >
> >> > diff --git a/drivers/clk/imx/clk-pllv3.c b/drivers/clk/imx/clk-pllv3.c
> >> > index c05c43d..b5ff561 100644
> >> > --- a/drivers/clk/imx/clk-pllv3.c
> >> > +++ b/drivers/clk/imx/clk-pllv3.c
> >> > @@ -63,7 +63,10 @@ static int clk_pllv3_wait_lock(struct clk_pllv3 *pll)
> >> >                     break;
> >> >             if (time_after(jiffies, timeout))
> >> >                     break;
> >> > -           usleep_range(50, 500);
> >> > +           if (unlikely(irqs_disabled()))
> >>
> >> This causes a bit confusion that clk_pllv3_prepare is sleepable.
> >> But this line indicates it's possible to be called in irq context.
> >> Although it's only happened during kernel boot phase where irq is
> >> still not enabled.
> >> It seems schedule_debug() somehow did not catch it during early boot
> >> phase. Maybe schedule guys can help explain.
> >>
> >> My question is if it's really worthy to introduce this confusion
> >> to fix the issue since the delay is minor?
> >
> > I do not understand why it's confusing.  The code already obviously
> > indicates this is a special handling for cases where irq is still not
> > enabled, rather than for irq context.
> >
> 
> The code itself has nothing telling it's a special handling for the
> case where irq is
> still not enabled.
> Even it tells, it may still cause confusing by adding complexity in
> clk_pllv3_prepare()
> which actually should be called in non-atomic context as it could sleep.
> 
> > The patch is to fix the "bad: scheduling from the idle thread!" warning
> > rather than minimize the delay.  Do you have an opinion on how to fix
> > the warning?
> >
> 
> I just wonder maybe we could simply just using udelay(50) instead of
> usleep_range(50, 500) to eliminate the confusing since it's minor cast.
> What do you think of it?

Why should we needless burn CPU time in the likely case of
clk_pllv3_prepare() being called in sleepable context?

Using udelay() in a sleepable context is even more confusing than having
the special case for clk_prepare() being called in atomic context IMHO.

Regards,
Lucas
Dong Aisheng April 26, 2016, 11:16 a.m. UTC | #10
On Tue, Apr 26, 2016 at 5:31 PM, Lucas Stach <l.stach@pengutronix.de> wrote:
> Am Dienstag, den 26.04.2016, 13:51 +0800 schrieb Dong Aisheng:
>> Hi Shawn,
>>
>> On Tue, Apr 26, 2016 at 9:23 AM, Shawn Guo <shawnguo@kernel.org> wrote:
>> > On Thu, Apr 21, 2016 at 11:45:20AM +0800, Dong Aisheng wrote:
>> >> On Fri, Jan 29, 2016 at 02:49:23PM -0800, Stefan Agner wrote:
>> >> > If a clock gets enabled early during boot time, it can lead to a PLL
>> >> > startup. The wait_lock function makes sure that the PLL is really
>> >> > stareted up before it gets used. However, the function sleeps which
>> >> > leads to scheduling and an error:
>> >> > bad: scheduling from the idle thread!
>> >> > ...
>> >> >
>> >> > Use udelay in case IRQ's are still disabled.
>> >> >
>> >> > Signed-off-by: Stefan Agner <stefan@agner.ch>
>> >> > ---
>> >> >  drivers/clk/imx/clk-pllv3.c | 5 ++++-
>> >> >  1 file changed, 4 insertions(+), 1 deletion(-)
>> >> >
>> >> > diff --git a/drivers/clk/imx/clk-pllv3.c b/drivers/clk/imx/clk-pllv3.c
>> >> > index c05c43d..b5ff561 100644
>> >> > --- a/drivers/clk/imx/clk-pllv3.c
>> >> > +++ b/drivers/clk/imx/clk-pllv3.c
>> >> > @@ -63,7 +63,10 @@ static int clk_pllv3_wait_lock(struct clk_pllv3 *pll)
>> >> >                     break;
>> >> >             if (time_after(jiffies, timeout))
>> >> >                     break;
>> >> > -           usleep_range(50, 500);
>> >> > +           if (unlikely(irqs_disabled()))
>> >>
>> >> This causes a bit confusion that clk_pllv3_prepare is sleepable.
>> >> But this line indicates it's possible to be called in irq context.
>> >> Although it's only happened during kernel boot phase where irq is
>> >> still not enabled.
>> >> It seems schedule_debug() somehow did not catch it during early boot
>> >> phase. Maybe schedule guys can help explain.
>> >>
>> >> My question is if it's really worthy to introduce this confusion
>> >> to fix the issue since the delay is minor?
>> >
>> > I do not understand why it's confusing.  The code already obviously
>> > indicates this is a special handling for cases where irq is still not
>> > enabled, rather than for irq context.
>> >
>>
>> The code itself has nothing telling it's a special handling for the
>> case where irq is
>> still not enabled.
>> Even it tells, it may still cause confusing by adding complexity in
>> clk_pllv3_prepare()
>> which actually should be called in non-atomic context as it could sleep.
>>
>> > The patch is to fix the "bad: scheduling from the idle thread!" warning
>> > rather than minimize the delay.  Do you have an opinion on how to fix
>> > the warning?
>> >
>>
>> I just wonder maybe we could simply just using udelay(50) instead of
>> usleep_range(50, 500) to eliminate the confusing since it's minor cast.
>> What do you think of it?
>
> Why should we needless burn CPU time in the likely case of
> clk_pllv3_prepare() being called in sleepable context?
>

I think because the delay time is not big.
And pll clks are system basic clocks and less likely to be frequently
enabled/disabled.

> Using udelay() in a sleepable context is even more confusing than having
> the special case for clk_prepare() being called in atomic context IMHO.
>

I can't agree having special case by checking
unlikely(irqs_disabled()) is better
which is obviously more confusing IMHO.
I'd more like to hide it from users.

I see other platforms like samsung&tegra also implements pll using udelay.
But difference is that they implement it in .enable(I) clalback not prepare.

How about simply remove usleep_range to poll instead of using udelay?
Cause most PLL enable may be more faster than 50ns.

And according to kernel doc, for delay time less than 10ns,
udelay or polling is recommended.

> Regards,
> Lucas
>

Regards
Dong Aisheng
Dong Aisheng April 26, 2016, 11:27 a.m. UTC | #11
On Tue, Apr 26, 2016 at 7:16 PM, Dong Aisheng <dongas86@gmail.com> wrote:
> On Tue, Apr 26, 2016 at 5:31 PM, Lucas Stach <l.stach@pengutronix.de> wrote:
>> Am Dienstag, den 26.04.2016, 13:51 +0800 schrieb Dong Aisheng:
>>> Hi Shawn,
>>>
>>> On Tue, Apr 26, 2016 at 9:23 AM, Shawn Guo <shawnguo@kernel.org> wrote:
>>> > On Thu, Apr 21, 2016 at 11:45:20AM +0800, Dong Aisheng wrote:
>>> >> On Fri, Jan 29, 2016 at 02:49:23PM -0800, Stefan Agner wrote:
>>> >> > If a clock gets enabled early during boot time, it can lead to a PLL
>>> >> > startup. The wait_lock function makes sure that the PLL is really
>>> >> > stareted up before it gets used. However, the function sleeps which
>>> >> > leads to scheduling and an error:
>>> >> > bad: scheduling from the idle thread!
>>> >> > ...
>>> >> >
>>> >> > Use udelay in case IRQ's are still disabled.
>>> >> >
>>> >> > Signed-off-by: Stefan Agner <stefan@agner.ch>
>>> >> > ---
>>> >> >  drivers/clk/imx/clk-pllv3.c | 5 ++++-
>>> >> >  1 file changed, 4 insertions(+), 1 deletion(-)
>>> >> >
>>> >> > diff --git a/drivers/clk/imx/clk-pllv3.c b/drivers/clk/imx/clk-pllv3.c
>>> >> > index c05c43d..b5ff561 100644
>>> >> > --- a/drivers/clk/imx/clk-pllv3.c
>>> >> > +++ b/drivers/clk/imx/clk-pllv3.c
>>> >> > @@ -63,7 +63,10 @@ static int clk_pllv3_wait_lock(struct clk_pllv3 *pll)
>>> >> >                     break;
>>> >> >             if (time_after(jiffies, timeout))
>>> >> >                     break;
>>> >> > -           usleep_range(50, 500);
>>> >> > +           if (unlikely(irqs_disabled()))
>>> >>
>>> >> This causes a bit confusion that clk_pllv3_prepare is sleepable.
>>> >> But this line indicates it's possible to be called in irq context.
>>> >> Although it's only happened during kernel boot phase where irq is
>>> >> still not enabled.
>>> >> It seems schedule_debug() somehow did not catch it during early boot
>>> >> phase. Maybe schedule guys can help explain.
>>> >>
>>> >> My question is if it's really worthy to introduce this confusion
>>> >> to fix the issue since the delay is minor?
>>> >
>>> > I do not understand why it's confusing.  The code already obviously
>>> > indicates this is a special handling for cases where irq is still not
>>> > enabled, rather than for irq context.
>>> >
>>>
>>> The code itself has nothing telling it's a special handling for the
>>> case where irq is
>>> still not enabled.
>>> Even it tells, it may still cause confusing by adding complexity in
>>> clk_pllv3_prepare()
>>> which actually should be called in non-atomic context as it could sleep.
>>>
>>> > The patch is to fix the "bad: scheduling from the idle thread!" warning
>>> > rather than minimize the delay.  Do you have an opinion on how to fix
>>> > the warning?
>>> >
>>>
>>> I just wonder maybe we could simply just using udelay(50) instead of
>>> usleep_range(50, 500) to eliminate the confusing since it's minor cast.
>>> What do you think of it?
>>
>> Why should we needless burn CPU time in the likely case of
>> clk_pllv3_prepare() being called in sleepable context?
>>
>
> I think because the delay time is not big.
> And pll clks are system basic clocks and less likely to be frequently
> enabled/disabled.
>
>> Using udelay() in a sleepable context is even more confusing than having
>> the special case for clk_prepare() being called in atomic context IMHO.
>>
>
> I can't agree having special case by checking
> unlikely(irqs_disabled()) is better
> which is obviously more confusing IMHO.
> I'd more like to hide it from users.
>
> I see other platforms like samsung&tegra also implements pll using udelay.
> But difference is that they implement it in .enable(I) clalback not prepare.
>
> How about simply remove usleep_range to poll instead of using udelay?
> Cause most PLL enable may be more faster than 50ns.
>
> And according to kernel doc, for delay time less than 10ns,
> udelay or polling is recommended.
>

Shawn,
What's your suggestion?

Regards
Dong Aisheng

>> Regards,
>> Lucas
>>
>
> Regards
> Dong Aisheng
Stefan Agner April 26, 2016, 5:04 p.m. UTC | #12
On 2016-01-29 17:16, Stephen Boyd wrote:
> On 01/29, Stefan Agner wrote:
>> If a clock gets enabled early during boot time, it can lead to a PLL
>> startup. The wait_lock function makes sure that the PLL is really
>> stareted up before it gets used. However, the function sleeps which
>> leads to scheduling and an error:
>> bad: scheduling from the idle thread!
>> ...
> 
> Can you please share the full splat? I have no clue what's going
> on.

Finally, full splat:

...
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2,
Nodes=1
[    0.000000] Running RCU self tests
[    0.000000] Hierarchical RCU implementation.
[    0.000000]  RCU lockdep checking is enabled.
[    0.000000]  Build-time adjustment of leaf fanout to 32.
[    0.000000]  RCU restricting CPUs from NR_CPUS=4 to nr_cpu_ids=2.
[    0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=32,
nr_cpu_ids=2
[    0.000000] NR_IRQS:16 nr_irqs:16 16
[    0.000000] ------------[ cut here ]------------
[    0.000000] WARNING: CPU: 0 PID: 0 at kernel/locking/lockdep.c:3407
lock_release+0x398/0x3a0()
[    0.000000] releasing a pinned lock
[    0.000000] Modules linked in:
[    0.000000] CPU: 0 PID: 0 Comm: swapper/0 Not tainted
4.5.0-rc1-00013-gdb45d67 #40
[    0.000000] Hardware name: Freescale i.MX7 Dual (Device Tree)
[    0.000000] Backtrace:
[    0.000000] [<c0014230>] (dump_backtrace) from [<c001442c>]
(show_stack+0x18/0x1c)
[    0.000000]  r7:c006f8f8 r6:00000d4f r5:00000000 r4:c0ad541c
[    0.000000] [<c0014414>] (show_stack) from [<c02de8fc>]
(dump_stack+0x80/0x90)
[    0.000000] [<c02de87c>] (dump_stack) from [<c00263c0>]
(warn_slowpath_common+0x88/0xb8)
[    0.000000]  r5:00000009 r4:c0abdc58
[    0.000000] [<c0026338>] (warn_slowpath_common) from [<c0026428>]
(warn_slowpath_fmt+0x38/0x40)
[    0.000000]  r8:00000002 r7:00000001 r6:cedc3fd0 r5:c0ac24e0
r4:c0984048
[    0.000000] [<c00263f4>] (warn_slowpath_fmt) from [<c006f8f8>]
(lock_release+0x398/0x3a0)
[    0.000000]  r3:0000fff0 r2:c0984048
[    0.000000]  r4:c0ac2500
[    0.000000] [<c006f560>] (lock_release) from [<c07cc298>]
(_raw_spin_unlock_irq+0x20/0x34)
[    0.000000]  r10:00000000 r9:c0ac2384 r8:cedc3fd0 r7:c0abe6d0
r6:00000001 r5:cedc3fc0
[    0.000000]  r4:cedc3fc0
[    0.000000] [<c07cc278>] (_raw_spin_unlock_irq) from [<c0055298>]
(dequeue_task_idle+0x14/0x30)
[    0.000000]  r5:cedc3fc0 r4:cedc3fc0
[    0.000000] [<c0055284>] (dequeue_task_idle) from [<c004d764>]
(deactivate_task+0x64/0x68)
[    0.000000]  r5:cedc3fc0 r4:c0ac2040
[    0.000000] [<c004d700>] (deactivate_task) from [<c07c6fd0>]
(__schedule+0x29c/0x67c)
[    0.000000]  r7:c0abe6d0 r6:c0abafc0 r5:c0ac2040 r4:cedc3fc0
[    0.000000] [<c07c6d34>] (__schedule) from [<c07c73f8>]
(schedule+0x48/0xa0)
[    0.000000]  r10:c0b0d91c r9:00000036 r8:c1331c3c r7:00000000
r6:0006ddd0 r5:c0abde08
[    0.000000]  r4:c0abc000
[    0.000000] [<c07c73b0>] (schedule) from [<c07cbd38>]
(schedule_hrtimeout_range_clock+0xbc/0x130)
[    0.000000]  r5:c0abde08 r4:00000001
[    0.000000] [<c07cbc7c>] (schedule_hrtimeout_range_clock) from
[<c07cbdc0>] (schedule_hrtimeout_range+0x14/0x18)
[    0.000000]  r7:00000003 r6:ffff8ad1 r5:ce804fc0 r4:c0abe100
[    0.000000] [<c07cbdac>] (schedule_hrtimeout_range) from [<c07cb854>]
(usleep_range+0x64/0x6c)
[    0.000000] [<c07cb7f0>] (usleep_range) from [<c0578468>]
(clk_pllv3_wait_lock+0x80/0xbc)
[    0.000000] [<c05783e8>] (clk_pllv3_wait_lock) from [<c05784d0>]
(clk_pllv3_prepare+0x2c/0x30)
[    0.000000]  r7:00000003 r6:d0864490 r5:c1331c3c r4:ce807680
[    0.000000] [<c05784a4>] (clk_pllv3_prepare) from [<c0571d28>]
(clk_core_prepare+0xa0/0xc4)
[    0.000000] [<c0571c88>] (clk_core_prepare) from [<c0572230>]
(clk_prepare+0x20/0x38)
[    0.000000]  r5:c1331c3c r4:ce80c040
[    0.000000] [<c0572210>] (clk_prepare) from [<c0a8e980>]
(imx7d_clocks_init+0x5ee0/0x5f6c)
[    0.000000]  r5:c1331c3c r4:ce80c040
[    0.000000] [<c0a88aa0>] (imx7d_clocks_init) from [<c0a88618>]
(of_clk_init+0x148/0x1d8)
[    0.000000]  r10:cede50b4 r9:00000003 r8:00000001 r7:c0abdf60
r6:c0abdf68 r5:00000000
[    0.000000]  r4:ce8043c0
[    0.000000] [<c0a884d0>] (of_clk_init) from [<c0a63918>]
(time_init+0x30/0x38)
[    0.000000]  r10:cefffb80 r9:c0aa6a48 r8:c0b24000 r7:ffffffff
r6:c0abe4c0 r5:c0b24000
[    0.000000]  r4:00000000
[    0.000000] [<c0a638e8>] (time_init) from [<c0a5fc38>]
(start_kernel+0x2b4/0x3ec)
[    0.000000] [<c0a5f984>] (start_kernel) from [<8000807c>]
(0x8000807c)
[    0.000000]  r10:00000000 r9:410fc075 r8:8000406a r7:c0ac39b4
r6:c0aa6a44 r5:c0abe540
[    0.000000]  r4:c0b24294
[    0.000000] ---[ end trace cb88537fdc8fa200 ]---
[    0.000000] ------------[ cut here ]------------
[    0.000000] WARNING: CPU: 0 PID: 0 at kernel/locking/lockdep.c:2601
trace_hardirqs_on_caller+0x1e8/0x1fc()
[    0.000000] DEBUG_LOCKS_WARN_ON(unlikely(early_boot_irqs_disabled))
[    0.000000] Modules linked in:
[    0.000000] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G        W      
4.5.0-rc1-00013-gdb45d67 #40
[    0.000000] Hardware name: Freescale i.MX7 Dual (Device Tree)   
[    0.000000] Backtrace:
[    0.000000] [<c0014230>] (dump_backtrace) from [<c001442c>]
(show_stack+0x18/0x1c)
[    0.000000]  r7:c006cb24 r6:00000a29 r5:00000000 r4:c0ad541c
[    0.000000] [<c0014414>] (show_stack) from [<c02de8fc>]
(dump_stack+0x80/0x90)
[    0.000000] [<c02de87c>] (dump_stack) from [<c00263c0>]
(warn_slowpath_common+0x88/0xb8)
[    0.000000]  r5:00000009 r4:c0abdc88
[    0.000000] [<c0026338>] (warn_slowpath_common) from [<c0026428>]
(warn_slowpath_fmt+0x38/0x40)
[    0.000000]  r8:cedc3fd0 r7:c0abe6d0 r6:00000001 r5:cedc3fc0
r4:c098066c
[    0.000000] [<c00263f4>] (warn_slowpath_fmt) from [<c006cb24>]
(trace_hardirqs_on_caller+0x1e8/0x1fc)
[    0.000000]  r3:c0983e1c r2:c098066c
[    0.000000]  r4:c07cc2a4
[    0.000000] [<c006c93c>] (trace_hardirqs_on_caller) from [<c006cb4c>]
(trace_hardirqs_on+0x14/0x18)
[    0.000000]  r7:c0abe6d0 r6:00000001 r5:cedc3fc0 r4:cedc3fc0
[    0.000000] [<c006cb38>] (trace_hardirqs_on) from [<c07cc2a4>]
(_raw_spin_unlock_irq+0x2c/0x34)
[    0.000000] [<c07cc278>] (_raw_spin_unlock_irq) from [<c0055298>]
(dequeue_task_idle+0x14/0x30)
[    0.000000]  r5:cedc3fc0 r4:cedc3fc0
[    0.000000] [<c0055284>] (dequeue_task_idle) from [<c004d764>]
(deactivate_task+0x64/0x68)
[    0.000000]  r5:cedc3fc0 r4:c0ac2040
[    0.000000] [<c004d700>] (deactivate_task) from [<c07c6fd0>]
(__schedule+0x29c/0x67c)
[    0.000000]  r7:c0abe6d0 r6:c0abafc0 r5:c0ac2040 r4:cedc3fc0
[    0.000000] [<c07c6d34>] (__schedule) from [<c07c73f8>]
(schedule+0x48/0xa0)
[    0.000000]  r10:c0b0d91c r9:00000036 r8:c1331c3c r7:00000000
r6:0006ddd0 r5:c0abde08
[    0.000000]  r4:c0abc000
[    0.000000] [<c07c73b0>] (schedule) from [<c07cbd38>]
(schedule_hrtimeout_range_clock+0xbc/0x130)
[    0.000000]  r5:c0abde08 r4:00000001
[    0.000000] [<c07c73b0>] (schedule) from [<c07cbd38>]
(schedule_hrtimeout_range_clock+0xbc/0x130)
[    0.000000]  r5:c0abde08 r4:00000001
[    0.000000] [<c07cbc7c>] (schedule_hrtimeout_range_clock) from
[<c07cbdc0>] (schedule_hrtimeout_range+0x14/0x18)
[    0.000000]  r7:00000003 r6:ffff8ad1 r5:ce804fc0 r4:c0abe100
[    0.000000] [<c07cbdac>] (schedule_hrtimeout_range) from [<c07cb854>]
(usleep_range+0x64/0x6c)
[    0.000000] [<c07cb7f0>] (usleep_range) from [<c0578468>]
(clk_pllv3_wait_lock+0x80/0xbc)
[    0.000000] [<c05783e8>] (clk_pllv3_wait_lock) from [<c05784d0>]
(clk_pllv3_prepare+0x2c/0x30)
[    0.000000]  r7:00000003 r6:d0864490 r5:c1331c3c r4:ce807680
[    0.000000] [<c05784a4>] (clk_pllv3_prepare) from [<c0571d28>]
(clk_core_prepare+0xa0/0xc4)
[    0.000000] [<c0571c88>] (clk_core_prepare) from [<c0572230>]
(clk_prepare+0x20/0x38)
[    0.000000]  r5:c1331c3c r4:ce80c040
[    0.000000] [<c0572210>] (clk_prepare) from [<c0a8e980>]
(imx7d_clocks_init+0x5ee0/0x5f6c)
[    0.000000]  r5:c1331c3c r4:ce80c040
[    0.000000] [<c0a88aa0>] (imx7d_clocks_init) from [<c0a88618>]
(of_clk_init+0x148/0x1d8)
[    0.000000]  r10:cede50b4 r9:00000003 r8:00000001 r7:c0abdf60
r6:c0abdf68 r5:00000000
[    0.000000]  r4:ce8043c0
[    0.000000] [<c0a884d0>] (of_clk_init) from [<c0a63918>]
(time_init+0x30/0x38)
[    0.000000]  r10:cefffb80 r9:c0aa6a48 r8:c0b24000 r7:ffffffff
r6:c0abe4c0 r5:c0b24000
[    0.000000]  r4:00000000
[    0.000000] [<c0a638e8>] (time_init) from [<c0a5fc38>]
(start_kernel+0x2b4/0x3ec)
[    0.000000] [<c0a5f984>] (start_kernel) from [<8000807c>]
(0x8000807c)
[    0.000000]  r10:00000000 r9:410fc075 r8:8000406a r7:c0ac39b4
r6:c0aa6a44 r5:c0abe540
[    0.000000]  r4:c0b24294
[    0.000000] ---[ end trace cb88537fdc8fa201 ]---
[    0.000000] bad: scheduling from the idle thread!                    
                                                                        
                                                                  
[    0.000000] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G        W      
4.5.0-rc1-00013-gdb45d67 #40
[    0.000000] Hardware name: Freescale i.MX7 Dual (Device Tree)
[    0.000000] Backtrace:
[    0.000000] [<c0014230>] (dump_backtrace) from [<c001442c>]
(show_stack+0x18/0x1c)
...
Shawn Guo April 27, 2016, 1:58 a.m. UTC | #13
On Tue, Apr 26, 2016 at 07:27:03PM +0800, Dong Aisheng wrote:
> Shawn,
> What's your suggestion?

I think this needs more discussion, and I just dropped Stefan's patch
from my tree.

We need to firstly understand why this is happening.  The .prepare hook
is defined to be non-atomic context, and so that we call sleep function
in there.  We did everything right.  Why are we getting the warning?  If
I'm correct, this warning only happens on i.MX7D.  Why is that?

Shawn
Dong Aisheng April 27, 2016, 2:45 a.m. UTC | #14
On Wed, Apr 27, 2016 at 9:58 AM, Shawn Guo <shawnguo@kernel.org> wrote:
> On Tue, Apr 26, 2016 at 07:27:03PM +0800, Dong Aisheng wrote:
>> Shawn,
>> What's your suggestion?
>
> I think this needs more discussion, and I just dropped Stefan's patch
> from my tree.
>
> We need to firstly understand why this is happening.  The .prepare hook
> is defined to be non-atomic context, and so that we call sleep function
> in there.  We did everything right.  Why are we getting the warning?  If
> I'm correct, this warning only happens on i.MX7D.  Why is that?
>

This is mainly caused by during kernel early booting, there's only one init idle
task running.
See:
void __init sched_init(void)
{
.....
        /*
         * Make us the idle thread. Technically, schedule() should not be
         * called from this thread, however somewhere below it might be,
         * but because we are the idle thread, we just pick up running again
         * when this runqueue becomes "idle".
         */
        init_idle(current, smp_processor_id());
...
}

And the idle sched class indicates it's not valid to schedule for idle task.
const struct sched_class idle_sched_class = {
        /* .next is NULL */
        /* no enqueue/yield_task for idle tasks */

        /* dequeue is not valid, we print a debug message there: */
        .dequeue_task           = dequeue_task_idle,
...........

}

/*
 * It is not legal to sleep in the idle task - print a warning
 * message if some code attempts to do it:
 */
static void
dequeue_task_idle(struct rq *rq, struct task_struct *p, int flags)
{
        raw_spin_unlock_irq(&rq->lock);
        printk(KERN_ERR "bad: scheduling from the idle thread!\n");
        dump_stack();
        raw_spin_lock_irq(&rq->lock);
}


Below is the full log of imx7d booting FYI.

You can ignore the first two warning (releasing a pinned lock) which
is a side affection
of idle task schedule during booting.

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 4.6.0-rc1-00011-gee55b3d17805-dirty
(b29396@shlinux2) (gcc version 4.9.1 (GCC) ) #779 SMP Tue Apr 26
18:17:26 CST 2016
[    0.000000] CPU: ARMv7 Processor [410fc075] revision 5 (ARMv7), cr=10c5387d
[    0.000000] CPU: div instructions available: patching division code
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing
instruction cache
[    0.000000] Machine model: Freescale i.MX7 SabreSD Board
[    0.000000] cma: Reserved 16 MiB at 0xbf000000
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] On node 0 totalpages: 262144
[    0.000000] free_area_init_node: node 0, pgdat c0d72900,
node_mem_map ef7f9000
[    0.000000]   Normal zone: 1536 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 196608 pages, LIFO batch:31
[    0.000000]   HighMem zone: 65536 pages, LIFO batch:15
[    0.000000] percpu: Embedded 13 pages/cpu @ef7bd000 s20544 r8192
d24512 u53248
[    0.000000] pcpu-alloc: s20544 r8192 d24512 u53248 alloc=13*4096
[    0.000000] pcpu-alloc: [0] 0 [0] 1
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.
Total pages: 260608
[    0.000000] Kernel command line: console=ttymxc0,115200
root=/dev/nfs ip=dhcp
nfsroot=10.192.224.44:/data/rootfs_home/b29396/rootfs-yocto-L4.1.X-RC5,v3,tcp
log_buf_len=2M
[    0.000000] log_buf_len: 2097152 bytes
[    0.000000] early log buf free: 260724(99%)
[    0.000000] PID hash table entries: 4096 (order: 2, 16384 bytes)
[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
[    0.000000] Memory: 999884K/1048576K available (8196K kernel code,
464K rwdata, 2828K rodata, 1024K init, 8223K bss, 32308K reserved,
16384K cma-reserved, 245760K highmem)
[    0.000000] Virtual kernel memory layout:
[    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
[    0.000000]     fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
[    0.000000]     vmalloc : 0xf0800000 - 0xff800000   ( 240 MB)
[    0.000000]     lowmem  : 0xc0000000 - 0xf0000000   ( 768 MB)
[    0.000000]     pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)
[    0.000000]     modules : 0xbf000000 - 0xbfe00000   (  14 MB)
[    0.000000]       .text : 0xc0008000 - 0xc0bc406c   (12017 kB)
[    0.000000]       .init : 0xc0c00000 - 0xc0d00000   (1024 kB)
[    0.000000]       .data : 0xc0d00000 - 0xc0d74100   ( 465 kB)
[    0.000000]        .bss : 0xc0d76000 - 0xc157dfa0   (8224 kB)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
[    0.000000] Running RCU self tests
[    0.000000] Hierarchical RCU implementation.
[    0.000000]  RCU lockdep checking is enabled.
[    0.000000]  Build-time adjustment of leaf fanout to 32.
[    0.000000]  RCU restricting CPUs from NR_CPUS=4 to nr_cpu_ids=2.
[    0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=32, nr_cpu_ids=2
[    0.000000] NR_IRQS:16 nr_irqs:16 16
[    0.000000] ------------[ cut here ]------------
[    0.000000] WARNING: CPU: 0 PID: 0 at kernel/locking/lockdep.c:3422
lock_release+0x340/0x378
[    0.000000] releasing a pinned lock
[    0.000000] Modules linked in:
[    0.000000] CPU: 0 PID: 0 Comm: swapper/0 Not tainted
4.6.0-rc1-00011-gee55b3d17805-dirty #779
[    0.000000] Hardware name: Freescale i.MX7 Dual (Device Tree)
[    0.000000] Backtrace:
[    0.000000] [<c010c42c>] (dump_backtrace) from [<c010c624>]
(show_stack+0x18/0x1c)
[    0.000000]  r6:600000d3 r5:00000000 r4:c0d21f9c r3:00000000
[    0.000000] [<c010c60c>] (show_stack) from [<c03dfec8>]
(dump_stack+0xb4/0xe8)
[    0.000000] [<c03dfe14>] (dump_stack) from [<c0124ce8>] (__warn+0xd8/0x104)
[    0.000000]  r10:c0d069c0 r9:c016e7ec r8:00000d5e r7:00000009
r6:c0ad6a04 r5:00000000
[    0.000000]  r4:c0d01ad8 r3:00000001
[    0.000000] [<c0124c10>] (__warn) from [<c0124d54>]
(warn_slowpath_fmt+0x40/0x48)
[    0.000000]  r9:00000001 r8:c154243c r7:00000002 r6:00000020
r5:c0d06500 r4:c0ad7ac4
[    0.000000] [<c0124d18>] (warn_slowpath_fmt) from [<c016e7ec>]
(lock_release+0x340/0x378)
[    0.000000]  r3:00000001 r2:c0ad7ac4
[    0.000000]  r4:00000001
[    0.000000] [<c016e4ac>] (lock_release) from [<c08f9cf4>]
(_raw_spin_unlock_irq+0x20/0x34)
[    0.000000]  r10:c08f4fdc r9:c0d02b0c r8:c0d06844 r7:ef7c14d0
r6:00000001 r5:ef7c14c0
[    0.000000]  r4:ef7c14c0
[    0.000000] [<c08f9cd4>] (_raw_spin_unlock_irq) from [<c015437c>]
(dequeue_task_idle+0x14/0x30)
[    0.000000]  r4:ef7c14c0 r3:c0154368
[    0.000000] [<c0154368>] (dequeue_task_idle) from [<c014c96c>]
(deactivate_task+0x64/0x68)
[    0.000000]  r4:c0d06500 r3:c0154368
[    0.000000] [<c014c908>] (deactivate_task) from [<c08f4b44>]
(__schedule+0x2e8/0x738)
[    0.000000]  r6:c0d06500 r5:ef7c14c0 r4:c0c754c0 r3:00000002
[    0.000000] [<c08f485c>] (__schedule) from [<c08f4fdc>] (schedule+0x48/0xa0)
[    0.000000]  r10:00000018 r9:0000001c r8:00000003 r7:00000000
r6:0007a120 r5:00000000
[    0.000000]  r4:c0d00000
[    0.000000] [<c08f4f94>] (schedule) from [<c08f9750>]
(schedule_hrtimeout_range_clock+0xac/0x12c)
[    0.000000]  r4:0006ddd0 r3:c0d06500
[    0.000000] [<c08f96a4>] (schedule_hrtimeout_range_clock) from
[<c08f97f4>] (schedule_hrtimeout_range+0x24/0x2c)
[    0.000000]  r7:00000001 r6:c0d02100 r5:ffff8ad1 r4:ef004f80
[    0.000000] [<c08f97d0>] (schedule_hrtimeout_range) from
[<c08f922c>] (usleep_range+0x54/0x5c)
[    0.000000] [<c08f91d8>] (usleep_range) from [<c0698148>]
(clk_pllv3_wait_lock+0x7c/0xb4)
[    0.000000] [<c06980cc>] (clk_pllv3_wait_lock) from [<c06981b0>]
(clk_pllv3_prepare+0x30/0x34)
[    0.000000]  r6:ef007080 r5:ef00ef00 r4:ef007600 r3:000017c0
[    0.000000] [<c0698180>] (clk_pllv3_prepare) from [<c069203c>]
(clk_core_prepare+0x98/0xc4)
[    0.000000] [<c0691fa4>] (clk_core_prepare) from [<c069201c>]
(clk_core_prepare+0x78/0xc4)
[    0.000000]  r5:ef00ef00 r4:ef007900
[    0.000000] [<c0691fa4>] (clk_core_prepare) from [<c069201c>]
(clk_core_prepare+0x78/0xc4)
[    0.000000]  r5:ef00ef00 r4:ef00e800
[    0.000000] [<c0691fa4>] (clk_core_prepare) from [<c069201c>]
(clk_core_prepare+0x78/0xc4)
[    0.000000]  r5:ef00ef00 r4:ef00eb80
[    0.000000] [<c0691fa4>] (clk_core_prepare) from [<c069201c>]
(clk_core_prepare+0x78/0xc4)
[    0.000000]  r5:ef00ef00 r4:ef00ef00
[    0.000000] [<c0691fa4>] (clk_core_prepare) from [<c0692be8>]
(clk_core_prepare_enable+0x1c/0x5c)
[    0.000000]  r5:ef00ef00 r4:ef011f80
[    0.000000] [<c0692bcc>] (clk_core_prepare_enable) from
[<c0692eb4>] (__clk_set_parent_before+0x38/0x7c)
[    0.000000]  r5:ef00ef00 r4:ef011f80
[    0.000000] [<c0692e7c>] (__clk_set_parent_before) from
[<c0693004>] (clk_core_set_parent+0x10c/0x170)
[    0.000000]  r7:00000001 r6:ef00ef00 r5:00000000 r4:ef011f80
[    0.000000] [<c0692ef8>] (clk_core_set_parent) from [<c069308c>]
(clk_set_parent+0x24/0x28)
[    0.000000]  r8:00000003 r7:c0d5d434 r6:00000000 r5:ef02b440
r4:00000009 r3:c15603bc
[    0.000000] [<c0693068>] (clk_set_parent) from [<c0c4ade8>]
(imx7d_clocks_init+0x5f4c/0x5f8c)
[    0.000000] [<c0c44e9c>] (imx7d_clocks_init) from [<c0c30e00>]
(of_clk_init+0x10c/0x1d4)
[    0.000000]  r10:00000001 r9:c0d01f68 r8:00000000 r7:c0d01f60
r6:ef7e3d60 r5:ef004340
[    0.000000]  r4:00000002
[    0.000000] [<c0c30cf4>] (of_clk_init) from [<c0c048d4>]
(time_init+0x2c/0x38)
[    0.000000]  r10:efffcac0 r9:c0c5da48 r8:c0d76000 r7:c0d028c0
r6:ffffffff r5:c0d76000
[    0.000000]  r4:00000000
[    0.000000] [<c0c048a8>] (time_init) from [<c0c00b7c>]
(start_kernel+0x218/0x398)
[    0.000000] [<c0c00964>] (start_kernel) from [<8000807c>] (0x8000807c)
[    0.000000]  r10:00000000 r9:410fc075 r8:8000406a r7:c0d07e8c
r6:c0c5da44 r5:c0d0296c
[    0.000000]  r4:c0d76294
[    0.000000] ---[ end trace cb88537fdc8fa200 ]---
[    0.000000] ------------[ cut here ]------------
[    0.000000] WARNING: CPU: 0 PID: 0 at kernel/locking/lockdep.c:2617
trace_hardirqs_on_caller+0x1ac/0x1f0
[    0.000000] DEBUG_LOCKS_WARN_ON(unlikely(early_boot_irqs_disabled))
[    0.000000] Modules linked in:
[    0.000000] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G        W
4.6.0-rc1-00011-gee55b3d17805-dirty #779
[    0.000000] Hardware name: Freescale i.MX7 Dual (Device Tree)
[    0.000000] Backtrace:
[    0.000000] [<c010c42c>] (dump_backtrace) from [<c010c624>]
(show_stack+0x18/0x1c)
[    0.000000]  r6:600000d3 r5:00000000 r4:c0d21f9c r3:00000000
[    0.000000] [<c010c60c>] (show_stack) from [<c03dfec8>]
(dump_stack+0xb4/0xe8)
[    0.000000] [<c03dfe14>] (dump_stack) from [<c0124ce8>] (__warn+0xd8/0x104)
[    0.000000]  r10:c08f4fdc r9:c016b918 r8:00000a39 r7:00000009
r6:c0ad6a04 r5:00000000
[    0.000000]  r4:c0d01af8 r3:00000000
[    0.000000] [<c0124c10>] (__warn) from [<c0124d54>]
(warn_slowpath_fmt+0x40/0x48)
[    0.000000]  r9:c0d02b0c r8:c0d06844 r7:ef7c14d0 r6:00000001
r5:ef7c14c0 r4:c0ad3ea0
[    0.000000] [<c0124d18>] (warn_slowpath_fmt) from [<c016b918>]
(trace_hardirqs_on_caller+0x1ac/0x1f0)
[    0.000000]  r3:c0ad7890 r2:c0ad3ea0
[    0.000000]  r4:c08f9d00
[    0.000000] [<c016b76c>] (trace_hardirqs_on_caller) from
[<c016b970>] (trace_hardirqs_on+0x14/0x18)
[    0.000000]  r6:00000001 r5:ef7c14c0 r4:ef7c14c0 r3:600000d3
[    0.000000] [<c016b95c>] (trace_hardirqs_on) from [<c08f9d00>]
(_raw_spin_unlock_irq+0x2c/0x34)
[    0.000000] [<c08f9cd4>] (_raw_spin_unlock_irq) from [<c015437c>]
(dequeue_task_idle+0x14/0x30)
[    0.000000]  r4:ef7c14c0 r3:c0154368
[    0.000000] [<c0154368>] (dequeue_task_idle) from [<c014c96c>]
(deactivate_task+0x64/0x68)
[    0.000000]  r4:c0d06500 r3:c0154368
[    0.000000] [<c014c908>] (deactivate_task) from [<c08f4b44>]
(__schedule+0x2e8/0x738)
[    0.000000]  r6:c0d06500 r5:ef7c14c0 r4:c0c754c0 r3:00000002
[    0.000000] [<c08f485c>] (__schedule) from [<c08f4fdc>] (schedule+0x48/0xa0)
[    0.000000]  r10:00000018 r9:0000001c r8:00000003 r7:00000000
r6:0007a120 r5:00000000
[    0.000000]  r4:c0d00000
[    0.000000] [<c08f4f94>] (schedule) from [<c08f9750>]
(schedule_hrtimeout_range_clock+0xac/0x12c)
[    0.000000]  r4:0006ddd0 r3:c0d06500
[    0.000000] [<c08f96a4>] (schedule_hrtimeout_range_clock) from
[<c08f97f4>] (schedule_hrtimeout_range+0x24/0x2c)
[    0.000000]  r7:00000001 r6:c0d02100 r5:ffff8ad1 r4:ef004f80
[    0.000000] [<c08f97d0>] (schedule_hrtimeout_range) from
[<c08f922c>] (usleep_range+0x54/0x5c)
[    0.000000] [<c08f91d8>] (usleep_range) from [<c0698148>]
(clk_pllv3_wait_lock+0x7c/0xb4)
[    0.000000] [<c06980cc>] (clk_pllv3_wait_lock) from [<c06981b0>]
(clk_pllv3_prepare+0x30/0x34)
[    0.000000]  r6:ef007080 r5:ef00ef00 r4:ef007600 r3:000017c0
[    0.000000] [<c0698180>] (clk_pllv3_prepare) from [<c069203c>]
(clk_core_prepare+0x98/0xc4)
[    0.000000] [<c0691fa4>] (clk_core_prepare) from [<c069201c>]
(clk_core_prepare+0x78/0xc4)
[    0.000000]  r5:ef00ef00 r4:ef007900
[    0.000000] [<c0691fa4>] (clk_core_prepare) from [<c069201c>]
(clk_core_prepare+0x78/0xc4)
[    0.000000]  r5:ef00ef00 r4:ef00e800
[    0.000000] [<c0691fa4>] (clk_core_prepare) from [<c069201c>]
(clk_core_prepare+0x78/0xc4)
[    0.000000]  r5:ef00ef00 r4:ef00eb80
[    0.000000] [<c0691fa4>] (clk_core_prepare) from [<c069201c>]
(clk_core_prepare+0x78/0xc4)
[    0.000000]  r5:ef00ef00 r4:ef00ef00
[    0.000000] [<c0691fa4>] (clk_core_prepare) from [<c0692be8>]
(clk_core_prepare_enable+0x1c/0x5c)
[    0.000000]  r5:ef00ef00 r4:ef011f80
[    0.000000] [<c0692bcc>] (clk_core_prepare_enable) from
[<c0692eb4>] (__clk_set_parent_before+0x38/0x7c)
[    0.000000]  r5:ef00ef00 r4:ef011f80
[    0.000000] [<c0692e7c>] (__clk_set_parent_before) from
[<c0693004>] (clk_core_set_parent+0x10c/0x170)
[    0.000000]  r7:00000001 r6:ef00ef00 r5:00000000 r4:ef011f80
[    0.000000] [<c0692ef8>] (clk_core_set_parent) from [<c069308c>]
(clk_set_parent+0x24/0x28)
[    0.000000]  r8:00000003 r7:c0d5d434 r6:00000000 r5:ef02b440
r4:00000009 r3:c15603bc
[    0.000000] [<c0693068>] (clk_set_parent) from [<c0c4ade8>]
(imx7d_clocks_init+0x5f4c/0x5f8c)
[    0.000000] [<c0c44e9c>] (imx7d_clocks_init) from [<c0c30e00>]
(of_clk_init+0x10c/0x1d4)
[    0.000000]  r10:00000001 r9:c0d01f68 r8:00000000 r7:c0d01f60
r6:ef7e3d60 r5:ef004340
[    0.000000]  r4:00000002
[    0.000000] [<c0c30cf4>] (of_clk_init) from [<c0c048d4>]
(time_init+0x2c/0x38)
[    0.000000]  r10:efffcac0 r9:c0c5da48 r8:c0d76000 r7:c0d028c0
r6:ffffffff r5:c0d76000
[    0.000000]  r4:00000000
[    0.000000] [<c0c048a8>] (time_init) from [<c0c00b7c>]
(start_kernel+0x218/0x398)
[    0.000000] [<c0c00964>] (start_kernel) from [<8000807c>] (0x8000807c)
[    0.000000]  r10:00000000 r9:410fc075 r8:8000406a r7:c0d07e8c
r6:c0c5da44 r5:c0d0296c
[    0.000000]  r4:c0d76294
[    0.000000] ---[ end trace cb88537fdc8fa201 ]---
[    0.000000] bad: scheduling from the idle thread!
[    0.000000] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G        W
4.6.0-rc1-00011-gee55b3d17805-dirty #779
[    0.000000] Hardware name: Freescale i.MX7 Dual (Device Tree)
[    0.000000] Backtrace:
[    0.000000] [<c010c42c>] (dump_backtrace) from [<c010c624>]
(show_stack+0x18/0x1c)
[    0.000000]  r6:60000053 r5:00000000 r4:c0d21f9c r3:00000000
[    0.000000] [<c010c60c>] (show_stack) from [<c03dfec8>]
(dump_stack+0xb4/0xe8)
[    0.000000] [<c03dfe14>] (dump_stack) from [<c0154388>]
(dequeue_task_idle+0x20/0x30)
[    0.000000]  r10:c08f4fdc r9:c0d02b0c r8:c0d06844 r7:ef7c14d0
r6:00000001 r5:ef7c14c0
[    0.000000]  r4:ef7c14c0 r3:00000000
[    0.000000] [<c0154368>] (dequeue_task_idle) from [<c014c96c>]
(deactivate_task+0x64/0x68)
[    0.000000]  r4:c0d06500 r3:c0154368
[    0.000000] [<c014c908>] (deactivate_task) from [<c08f4b44>]
(__schedule+0x2e8/0x738)
[    0.000000]  r6:c0d06500 r5:ef7c14c0 r4:c0c754c0 r3:00000002
[    0.000000] [<c08f485c>] (__schedule) from [<c08f4fdc>] (schedule+0x48/0xa0)
[    0.000000]  r10:00000018 r9:0000001c r8:00000003 r7:00000000
r6:0007a120 r5:00000000
[    0.000000]  r4:c0d00000
[    0.000000] [<c08f4f94>] (schedule) from [<c08f9750>]
(schedule_hrtimeout_range_clock+0xac/0x12c)
[    0.000000]  r4:0006ddd0 r3:c0d06500
[    0.000000] [<c08f96a4>] (schedule_hrtimeout_range_clock) from
[<c08f97f4>] (schedule_hrtimeout_range+0x24/0x2c)
[    0.000000]  r7:00000001 r6:c0d02100 r5:ffff8ad1 r4:ef004f80
[    0.000000] [<c08f97d0>] (schedule_hrtimeout_range) from
[<c08f922c>] (usleep_range+0x54/0x5c)
[    0.000000] [<c08f91d8>] (usleep_range) from [<c0698148>]
(clk_pllv3_wait_lock+0x7c/0xb4)
[    0.000000] [<c06980cc>] (clk_pllv3_wait_lock) from [<c06981b0>]
(clk_pllv3_prepare+0x30/0x34)
[    0.000000]  r6:ef007080 r5:ef00ef00 r4:ef007600 r3:000017c0
[    0.000000] [<c0698180>] (clk_pllv3_prepare) from [<c069203c>]
(clk_core_prepare+0x98/0xc4)
[    0.000000] [<c0691fa4>] (clk_core_prepare) from [<c069201c>]
(clk_core_prepare+0x78/0xc4)
[    0.000000]  r5:ef00ef00 r4:ef007900
[    0.000000] [<c0691fa4>] (clk_core_prepare) from [<c069201c>]
(clk_core_prepare+0x78/0xc4)
[    0.000000]  r5:ef00ef00 r4:ef00e800
[    0.000000] [<c0691fa4>] (clk_core_prepare) from [<c069201c>]
(clk_core_prepare+0x78/0xc4)
[    0.000000]  r5:ef00ef00 r4:ef00eb80
[    0.000000] [<c0691fa4>] (clk_core_prepare) from [<c069201c>]
(clk_core_prepare+0x78/0xc4)
[    0.000000]  r5:ef00ef00 r4:ef00ef00
[    0.000000] [<c0691fa4>] (clk_core_prepare) from [<c0692be8>]
(clk_core_prepare_enable+0x1c/0x5c)
[    0.000000]  r5:ef00ef00 r4:ef011f80
[    0.000000] [<c0692bcc>] (clk_core_prepare_enable) from
[<c0692eb4>] (__clk_set_parent_before+0x38/0x7c)
[    0.000000]  r5:ef00ef00 r4:ef011f80
[    0.000000] [<c0692e7c>] (__clk_set_parent_before) from
[<c0693004>] (clk_core_set_parent+0x10c/0x170)
[    0.000000]  r7:00000001 r6:ef00ef00 r5:00000000 r4:ef011f80
[    0.000000] [<c0692ef8>] (clk_core_set_parent) from [<c069308c>]
(clk_set_parent+0x24/0x28)
[    0.000000]  r8:00000003 r7:c0d5d434 r6:00000000 r5:ef02b440
r4:00000009 r3:c15603bc
[    0.000000] [<c0693068>] (clk_set_parent) from [<c0c4ade8>]
(imx7d_clocks_init+0x5f4c/0x5f8c)
[    0.000000] [<c0c44e9c>] (imx7d_clocks_init) from [<c0c30e00>]
(of_clk_init+0x10c/0x1d4)
[    0.000000]  r10:00000001 r9:c0d01f68 r8:00000000 r7:c0d01f60
r6:ef7e3d60 r5:ef004340
[    0.000000]  r4:00000002
[    0.000000] [<c0c30cf4>] (of_clk_init) from [<c0c048d4>]
(time_init+0x2c/0x38)
[    0.000000]  r10:efffcac0 r9:c0c5da48 r8:c0d76000 r7:c0d028c0
r6:ffffffff r5:c0d76000
[    0.000000]  r4:00000000
[    0.000000] [<c0c048a8>] (time_init) from [<c0c00b7c>]
(start_kernel+0x218/0x398)
[    0.000000] [<c0c00964>] (start_kernel) from [<8000807c>] (0x8000807c)
[    0.000000]  r10:00000000 r9:410fc075 r8:8000406a r7:c0d07e8c
r6:c0c5da44 r5:c0d0296c
[    0.000000]  r4:c0d76294
[    0.000000] Architected cp15 timer(s) running at 8.00MHz (virt).
[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff
max_cycles: 0x1d854df40, max_idle_ns: 440795202120 ns
[    0.000000] ------------[ cut here ]------------
[    0.000000] WARNING: CPU: 0 PID: 0 at kernel/time/sched_clock.c:179
sched_clock_register+0x44/0x21c
[    0.000000] Modules linked in:
[    0.000000] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G        W
4.6.0-rc1-00011-gee55b3d17805-dirty #779
[    0.000000] Hardware name: Freescale i.MX7 Dual (Device Tree)
[    0.000000] Backtrace:
[    0.000000] [<c010c42c>] (dump_backtrace) from [<c010c624>]
(show_stack+0x18/0x1c)
[    0.000000]  r6:60000053 r5:00000000 r4:c0d21f9c r3:00000000
[    0.000000] [<c010c60c>] (show_stack) from [<c03dfec8>]
(dump_stack+0xb4/0xe8)
[    0.000000] [<c03dfe14>] (dump_stack) from [<c0124ce8>] (__warn+0xd8/0x104)
[    0.000000]  r10:c0b55504 r9:c0c13a04 r8:000000b3 r7:00000009
r6:c0adb860 r5:00000000
[    0.000000]  r4:00000000 r3:00000000
[    0.000000] [<c0124c10>] (__warn) from [<c0124dc8>]
(warn_slowpath_null+0x28/0x30)
[    0.000000]  r9:6fbdeeb3 r8:07c96afc r7:c067a55c r6:00000038
r5:007a1200 r4:c0d164c0
[    0.000000] [<c0124da0>] (warn_slowpath_null) from [<c0c13a04>]
(sched_clock_register+0x44/0x21c)
[    0.000000] [<c0c139c0>] (sched_clock_register) from [<c0c2e148>]
(arch_timer_common_init+0x1c8/0x22c)
[    0.000000]  r9:6fbdeeb3 r8:07c96afc r7:c155ec88 r6:c0ae143c
r5:c0b5551c r4:c0d5bf00
[    0.000000] [<c0c2df80>] (arch_timer_common_init) from [<c0c2e438>]
(arch_timer_of_init+0x28c/0x2d8)
[    0.000000]  r10:efffcac0 r9:c0c5da48 r8:c0d76000 r7:c0d5bf00
r6:00000000 r5:c155ec88
[    0.000000]  r4:00000012
[    0.000000] [<c0c2e1ac>] (arch_timer_of_init) from [<c0c2de38>]
(clocksource_probe+0x50/0x90)
[    0.000000]  r8:c0d76000 r7:c0d028c0 r6:ffffffff r5:00000001
r4:ef7dae9c r3:c0c2e1ac
[    0.000000] [<c0c2dde8>] (clocksource_probe) from [<c0c048d8>]
(time_init+0x30/0x38)
[    0.000000]  r5:c0d76000 r4:00000000
[    0.000000] [<c0c048a8>] (time_init) from [<c0c00b7c>]
(start_kernel+0x218/0x398)
[    0.000000] [<c0c00964>] (start_kernel) from [<8000807c>] (0x8000807c)
[    0.000000]  r10:00000000 r9:410fc075 r8:8000406a r7:c0d07e8c
r6:c0c5da44 r5:c0d0296c
[    0.000000]  r4:c0d76294
[    0.000000] ---[ end trace cb88537fdc8fa202 ]---
[    0.000007] sched_clock: 56 bits at 8MHz, resolution 125ns, wraps
every 2199023255500ns
[    0.000022] Switching to timer-based delay loop, resolution 125ns
[    0.000575] Switching to timer-based delay loop, resolution 41ns
[    0.000587] ------------[ cut here ]------------
[    0.000604] WARNING: CPU: 0 PID: 0 at kernel/time/sched_clock.c:179
sched_clock_register+0x44/0x21c
[    0.000613] Modules linked in:
[    0.000629] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G        W
4.6.0-rc1-00011-gee55b3d17805-dirty #779
[    0.000638] Hardware name: Freescale i.MX7 Dual (Device Tree)
[    0.000646] Backtrace:
[    0.000667] [<c010c42c>] (dump_backtrace) from [<c010c624>]
(show_stack+0x18/0x1c)
[    0.000676]  r6:60000053 r5:00000000 r4:c0d21f9c r3:00000000
[    0.000712] [<c010c60c>] (show_stack) from [<c03dfec8>]
(dump_stack+0xb4/0xe8)
[    0.000730] [<c03dfe14>] (dump_stack) from [<c0124ce8>] (__warn+0xd8/0x104)
[    0.000739]  r10:efffcac0 r9:c0c13a04 r8:000000b3 r7:00000009
r6:c0adb860 r5:00000000
[    0.000772]  r4:00000000 r3:00000000
[    0.000795] [<c0124c10>] (__warn) from [<c0124dc8>]
(warn_slowpath_null+0x28/0x30)
[    0.000805]  r9:c0c5da48 r8:00000003 r7:c067b098 r6:00000020
r5:016e3600 r4:c0d164c0
[    0.000846] [<c0124da0>] (warn_slowpath_null) from [<c0c13a04>]
(sched_clock_register+0x44/0x21c)
[    0.000866] [<c0c139c0>] (sched_clock_register) from [<c0c2eb5c>]
(_mxc_timer_init+0x144/0x240)
[    0.000875]  r9:c0c5da48 r8:00000003 r7:016e3600 r6:c155ece8
r5:f0880024 r4:ef002400
[    0.000919] [<c0c2ea18>] (_mxc_timer_init) from [<c0c2ed14>]
(mxc_timer_init_dt+0xbc/0xe8)
[    0.000928]  r7:00000000 r6:ef7e084c r5:ef002400 r4:c155ece8
[    0.000965] [<c0c2ec58>] (mxc_timer_init_dt) from [<c0c2ed84>]
(imx6dl_timer_init_dt+0x14/0x18)
[    0.000975]  r8:c0d76000 r7:c0d028c0 r6:ffffffff r5:00000002
r4:ef7e084c r3:c0c2ed70
[    0.001018] [<c0c2ed70>] (imx6dl_timer_init_dt) from [<c0c2de38>]
(clocksource_probe+0x50/0x90)
[    0.001035] [<c0c2dde8>] (clocksource_probe) from [<c0c048d8>]
(time_init+0x30/0x38)
[    0.001045]  r5:c0d76000 r4:00000000
[    0.001069] [<c0c048a8>] (time_init) from [<c0c00b7c>]
(start_kernel+0x218/0x398)
[    0.001083] [<c0c00964>] (start_kernel) from [<8000807c>] (0x8000807c)
[    0.001092]  r10:00000000 r9:410fc075 r8:8000406a r7:c0d07e8c
r6:c0c5da44 r5:c0d0296c
[    0.001125]  r4:c0d76294
[    0.001137] ---[ end trace cb88537fdc8fa203 ]---
[    0.001156] sched_clock: 32 bits at 24MHz, resolution 41ns, wraps
every 89478484971ns
[    0.001174] clocksource: mxc_timer1: mask: 0xffffffff max_cycles:
0xffffffff, max_idle_ns: 79635851949 ns
[    0.002055] ------------[ cut here ]------------
[    0.002073] WARNING: CPU: 0 PID: 0 at init/main.c:575
start_kernel+0x240/0x398
[    0.002082] Interrupts were enabled early
[    0.002090] Modules linked in:
[    0.002106] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G        W
4.6.0-rc1-00011-gee55b3d17805-dirty #779
[    0.002116] Hardware name: Freescale i.MX7 Dual (Device Tree)
[    0.002124] Backtrace:
[    0.002145] [<c010c42c>] (dump_backtrace) from [<c010c624>]
(show_stack+0x18/0x1c)
[    0.002155]  r6:60000053 r5:00000000 r4:c0d21f9c r3:00000000
[    0.002191] [<c010c60c>] (show_stack) from [<c03dfec8>]
(dump_stack+0xb4/0xe8)
[    0.002209] [<c03dfe14>] (dump_stack) from [<c0124ce8>] (__warn+0xd8/0x104)
[    0.002219]  r10:efffcac0 r9:c0c00ba4 r8:0000023f r7:00000009
r6:c0acc620 r5:00000000
[    0.002252]  r4:c0d01f88 r3:00000000
[    0.002276] [<c0124c10>] (__warn) from [<c0124d54>]
(warn_slowpath_fmt+0x40/0x48)
[    0.002285]  r9:c0c5da48 r8:c0d76000 r7:c0d028c0 r6:ffffffff
r5:c0d76000 r4:c0acc660
[    0.002326] [<c0124d18>] (warn_slowpath_fmt) from [<c0c00ba4>]
(start_kernel+0x240/0x398)
[    0.002335]  r3:60000053 r2:c0acc660
[    0.002352]  r4:00000000
[    0.002368] [<c0c00964>] (start_kernel) from [<8000807c>] (0x8000807c)
[    0.002378]  r10:00000000 r9:410fc075 r8:8000406a r7:c0d07e8c
r6:c0c5da44 r5:c0d0296c
[    0.002411]  r4:c0d76294
[    0.002423] ---[ end trace cb88537fdc8fa204 ]---
[    0.002536] Console: colour dummy device 80x30
[    0.002550] Lock dependency validator: Copyright (c) 2006 Red Hat,
Inc., Ingo Molnar
[    0.002559] ... MAX_LOCKDEP_SUBCLASSES:  8
[    0.002568] ... MAX_LOCK_DEPTH:          48
[    0.002576] ... MAX_LOCKDEP_KEYS:        8191
[    0.002585] ... CLASSHASH_SIZE:          4096
[    0.002594] ... MAX_LOCKDEP_ENTRIES:     32768
[    0.002602] ... MAX_LOCKDEP_CHAINS:      65536
[    0.002611] ... CHAINHASH_SIZE:          32768
[    0.002620]  memory used by lock dependency info: 5167 kB
[    0.002629]  per task-struct memory footprint: 1536 bytes
[    0.002652] Calibrating delay loop (skipped), value calculated
using timer frequency.. 48.00 BogoMIPS (lpj=240000)
[    0.002669] pid_max: default: 32768 minimum: 301
[    0.002826] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.002842] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
.....................

Regards
Dong Aisheng
Fabio Estevam April 27, 2016, 2:56 a.m. UTC | #15
On Tue, Apr 26, 2016 at 11:45 PM, Dong Aisheng <dongas86@gmail.com> wrote:

>> We need to firstly understand why this is happening.  The .prepare hook
>> is defined to be non-atomic context, and so that we call sleep function
>> in there.  We did everything right.  Why are we getting the warning?  If
>> I'm correct, this warning only happens on i.MX7D.  Why is that?
>>
>
> This is mainly caused by during kernel early booting, there's only one init idle
> task running.
> See:
> void __init sched_init(void)
> {
> .....
>         /*
>          * Make us the idle thread. Technically, schedule() should not be
>          * called from this thread, however somewhere below it might be,
>          * but because we are the idle thread, we just pick up running again
>          * when this runqueue becomes "idle".
>          */
>         init_idle(current, smp_processor_id());
> ...
> }
>
> And the idle sched class indicates it's not valid to schedule for idle task.
> const struct sched_class idle_sched_class = {
>         /* .next is NULL */
>         /* no enqueue/yield_task for idle tasks */
>
>         /* dequeue is not valid, we print a debug message there: */
>         .dequeue_task           = dequeue_task_idle,
> ...........
>
> }
>
> /*
>  * It is not legal to sleep in the idle task - print a warning
>  * message if some code attempts to do it:
>  */
> static void
> dequeue_task_idle(struct rq *rq, struct task_struct *p, int flags)
> {
>         raw_spin_unlock_irq(&rq->lock);
>         printk(KERN_ERR "bad: scheduling from the idle thread!\n");
>         dump_stack();
>         raw_spin_lock_irq(&rq->lock);
> }
>
>
> Below is the full log of imx7d booting FYI.

This does not answer Shawn's question: why do we see this only on mx7d?
Dong Aisheng April 27, 2016, 2:57 a.m. UTC | #16
On Wed, Apr 27, 2016 at 9:58 AM, Shawn Guo <shawnguo@kernel.org> wrote:
> On Tue, Apr 26, 2016 at 07:27:03PM +0800, Dong Aisheng wrote:
>> Shawn,
>> What's your suggestion?
>
> I think this needs more discussion, and I just dropped Stefan's patch
> from my tree.
>
> We need to firstly understand why this is happening.  The .prepare hook
> is defined to be non-atomic context, and so that we call sleep function
> in there.  We did everything right.  Why are we getting the warning?  If
> I'm correct, this warning only happens on i.MX7D.  Why is that?
>

Why Stefan's patch works (checking irqs_disabled()) is because during kernel
time init, the irq is still not enabled. It fixes the issue indirectly.
See:
asmlinkage __visible void __init start_kernel(void)
{
        /*
         * Set up the scheduler prior starting any interrupts (such as the
         * timer interrupt). Full topology setup happens at smp_init()
         * time - but meanwhile we still have a functioning scheduler.
         */
        sched_init();
        .............
        time_init();
        ..............
        WARN(!irqs_disabled(), "Interrupts were enabled early\n");
        early_boot_irqs_disabled = false;
        local_irq_enable();
}

The issue can only happen when PLL enable causes a schedule during
imx_clock_init().
Not all PLL has this issue.
The issue happens on MX7D pll_audio_main_clk/pll_video_main_clk
which requires more delay time and cause usleep.
Because clk framework does not support MX7D clock types (operation requires
parents on), we simply enable all clocks in imx7d_clocks_init().

If apply my this patch series:
https://lkml.org/lkml/2016/4/20/199
The issue can also be gone.

Regards
Dong Aisheng

> Shawn
Shawn Guo April 27, 2016, 7:24 a.m. UTC | #17
On Wed, Apr 27, 2016 at 10:57:21AM +0800, Dong Aisheng wrote:
> On Wed, Apr 27, 2016 at 9:58 AM, Shawn Guo <shawnguo@kernel.org> wrote:
> > On Tue, Apr 26, 2016 at 07:27:03PM +0800, Dong Aisheng wrote:
> >> Shawn,
> >> What's your suggestion?
> >
> > I think this needs more discussion, and I just dropped Stefan's patch
> > from my tree.
> >
> > We need to firstly understand why this is happening.  The .prepare hook
> > is defined to be non-atomic context, and so that we call sleep function
> > in there.  We did everything right.  Why are we getting the warning?  If
> > I'm correct, this warning only happens on i.MX7D.  Why is that?
> >
> 
> Why Stefan's patch works (checking irqs_disabled()) is because during kernel
> time init, the irq is still not enabled. It fixes the issue indirectly.
> See:
> asmlinkage __visible void __init start_kernel(void)
> {
>         /*
>          * Set up the scheduler prior starting any interrupts (such as the
>          * timer interrupt). Full topology setup happens at smp_init()
>          * time - but meanwhile we still have a functioning scheduler.
>          */
>         sched_init();
>         .............
>         time_init();
>         ..............
>         WARN(!irqs_disabled(), "Interrupts were enabled early\n");
>         early_boot_irqs_disabled = false;
>         local_irq_enable();
> }
> 
> The issue can only happen when PLL enable causes a schedule during
> imx_clock_init().
> Not all PLL has this issue.
> The issue happens on MX7D pll_audio_main_clk/pll_video_main_clk
> which requires more delay time and cause usleep.
> Because clk framework does not support MX7D clock types (operation requires
> parents on), we simply enable all clocks in imx7d_clocks_init().
> 
> If apply my this patch series:
> https://lkml.org/lkml/2016/4/20/199
> The issue can also be gone.

Thanks for the info.  It sounds like that we are fixing the problem in
the wrong place, i.e. clk_pllv3_prepare().  The function does nothing
wrong, since the .prepare hook is defined to be one that can sleep.  If
we see sleep warning in a context calling clk_prepare(), that probably
means we shouldn't make the function call from that context.

Shawn
Stefan Agner April 27, 2016, 7:26 a.m. UTC | #18
On 2016-04-27 00:24, Shawn Guo wrote:
> On Wed, Apr 27, 2016 at 10:57:21AM +0800, Dong Aisheng wrote:
>> On Wed, Apr 27, 2016 at 9:58 AM, Shawn Guo <shawnguo@kernel.org> wrote:
>> > On Tue, Apr 26, 2016 at 07:27:03PM +0800, Dong Aisheng wrote:
>> >> Shawn,
>> >> What's your suggestion?
>> >
>> > I think this needs more discussion, and I just dropped Stefan's patch
>> > from my tree.
>> >
>> > We need to firstly understand why this is happening.  The .prepare hook
>> > is defined to be non-atomic context, and so that we call sleep function
>> > in there.  We did everything right.  Why are we getting the warning?  If
>> > I'm correct, this warning only happens on i.MX7D.  Why is that?
>> >
>>
>> Why Stefan's patch works (checking irqs_disabled()) is because during kernel
>> time init, the irq is still not enabled. It fixes the issue indirectly.
>> See:
>> asmlinkage __visible void __init start_kernel(void)
>> {
>>         /*
>>          * Set up the scheduler prior starting any interrupts (such as the
>>          * timer interrupt). Full topology setup happens at smp_init()
>>          * time - but meanwhile we still have a functioning scheduler.
>>          */
>>         sched_init();
>>         .............
>>         time_init();
>>         ..............
>>         WARN(!irqs_disabled(), "Interrupts were enabled early\n");
>>         early_boot_irqs_disabled = false;
>>         local_irq_enable();
>> }
>>
>> The issue can only happen when PLL enable causes a schedule during
>> imx_clock_init().
>> Not all PLL has this issue.
>> The issue happens on MX7D pll_audio_main_clk/pll_video_main_clk
>> which requires more delay time and cause usleep.
>> Because clk framework does not support MX7D clock types (operation requires
>> parents on), we simply enable all clocks in imx7d_clocks_init().
>>
>> If apply my this patch series:
>> https://lkml.org/lkml/2016/4/20/199
>> The issue can also be gone.
> 
> Thanks for the info.  It sounds like that we are fixing the problem in
> the wrong place, i.e. clk_pllv3_prepare().  The function does nothing
> wrong, since the .prepare hook is defined to be one that can sleep.  If
> we see sleep warning in a context calling clk_prepare(), that probably
> means we shouldn't make the function call from that context.
> 

According to the stack trace in the answer to Stephens question the call
comes from imx7d_clocks_init. I doubt we can avoid that those clocks get
enabled there...

--
Stefan
Stefan Agner April 27, 2016, 7:28 a.m. UTC | #19
On 2016-04-26 19:56, Fabio Estevam wrote:
> On Tue, Apr 26, 2016 at 11:45 PM, Dong Aisheng <dongas86@gmail.com> wrote:
> 
>>> We need to firstly understand why this is happening.  The .prepare hook
>>> is defined to be non-atomic context, and so that we call sleep function
>>> in there.  We did everything right.  Why are we getting the warning?  If
>>> I'm correct, this warning only happens on i.MX7D.  Why is that?
>>>
>>
>> This is mainly caused by during kernel early booting, there's only one init idle
>> task running.
>> See:
>> void __init sched_init(void)
>> {
>> .....
>>         /*
>>          * Make us the idle thread. Technically, schedule() should not be
>>          * called from this thread, however somewhere below it might be,
>>          * but because we are the idle thread, we just pick up running again
>>          * when this runqueue becomes "idle".
>>          */
>>         init_idle(current, smp_processor_id());
>> ...
>> }
>>
>> And the idle sched class indicates it's not valid to schedule for idle task.
>> const struct sched_class idle_sched_class = {
>>         /* .next is NULL */
>>         /* no enqueue/yield_task for idle tasks */
>>
>>         /* dequeue is not valid, we print a debug message there: */
>>         .dequeue_task           = dequeue_task_idle,
>> ...........
>>
>> }
>>
>> /*
>>  * It is not legal to sleep in the idle task - print a warning
>>  * message if some code attempts to do it:
>>  */
>> static void
>> dequeue_task_idle(struct rq *rq, struct task_struct *p, int flags)
>> {
>>         raw_spin_unlock_irq(&rq->lock);
>>         printk(KERN_ERR "bad: scheduling from the idle thread!\n");
>>         dump_stack();
>>         raw_spin_lock_irq(&rq->lock);
>> }
>>
>>
>> Below is the full log of imx7d booting FYI.
> 
> This does not answer Shawn's question: why do we see this only on mx7d?

I was wondering that too.... My theory is that either on i.MX 6 the
clocks enable almost instantly leading to no sleep, or they are just
bootloader/firmware on...?

--
Stefan
Stefan Agner April 27, 2016, 7:34 a.m. UTC | #20
On 2016-04-26 19:57, Dong Aisheng wrote:
> On Wed, Apr 27, 2016 at 9:58 AM, Shawn Guo <shawnguo@kernel.org> wrote:
>> On Tue, Apr 26, 2016 at 07:27:03PM +0800, Dong Aisheng wrote:
>>> Shawn,
>>> What's your suggestion?
>>
>> I think this needs more discussion, and I just dropped Stefan's patch
>> from my tree.
>>
>> We need to firstly understand why this is happening.  The .prepare hook
>> is defined to be non-atomic context, and so that we call sleep function
>> in there.  We did everything right.  Why are we getting the warning?  If
>> I'm correct, this warning only happens on i.MX7D.  Why is that?
>>
> 
> Why Stefan's patch works (checking irqs_disabled()) is because during kernel
> time init, the irq is still not enabled. It fixes the issue indirectly.
> See:
> asmlinkage __visible void __init start_kernel(void)
> {
>         /*
>          * Set up the scheduler prior starting any interrupts (such as the
>          * timer interrupt). Full topology setup happens at smp_init()
>          * time - but meanwhile we still have a functioning scheduler.
>          */
>         sched_init();
>         .............
>         time_init();
>         ..............
>         WARN(!irqs_disabled(), "Interrupts were enabled early\n");
>         early_boot_irqs_disabled = false;
>         local_irq_enable();
> }
> 
> The issue can only happen when PLL enable causes a schedule during
> imx_clock_init().
> Not all PLL has this issue.
> The issue happens on MX7D pll_audio_main_clk/pll_video_main_clk
> which requires more delay time and cause usleep.
> Because clk framework does not support MX7D clock types (operation requires
> parents on), we simply enable all clocks in imx7d_clocks_init().
> 
> If apply my this patch series:
> https://lkml.org/lkml/2016/4/20/199
> The issue can also be gone.

Oh ok, it does make sense to enable as few clocks as possible.

However, even if we do not enable lots of clocks at that time, and this
helps to avoid the problem for now, it could still be that
someone/something requests a clock early during boot, leading to a PLL
enable... Shouldn't we make sure that those base clocks can be enabled
even during early boot..?

--
Stefan
Dong Aisheng April 27, 2016, 8:48 a.m. UTC | #21
On Wed, Apr 27, 2016 at 3:24 PM, Shawn Guo <shawnguo@kernel.org> wrote:
> On Wed, Apr 27, 2016 at 10:57:21AM +0800, Dong Aisheng wrote:
>> On Wed, Apr 27, 2016 at 9:58 AM, Shawn Guo <shawnguo@kernel.org> wrote:
>> > On Tue, Apr 26, 2016 at 07:27:03PM +0800, Dong Aisheng wrote:
>> >> Shawn,
>> >> What's your suggestion?
>> >
>> > I think this needs more discussion, and I just dropped Stefan's patch
>> > from my tree.
>> >
>> > We need to firstly understand why this is happening.  The .prepare hook
>> > is defined to be non-atomic context, and so that we call sleep function
>> > in there.  We did everything right.  Why are we getting the warning?  If
>> > I'm correct, this warning only happens on i.MX7D.  Why is that?
>> >
>>
>> Why Stefan's patch works (checking irqs_disabled()) is because during kernel
>> time init, the irq is still not enabled. It fixes the issue indirectly.
>> See:
>> asmlinkage __visible void __init start_kernel(void)
>> {
>>         /*
>>          * Set up the scheduler prior starting any interrupts (such as the
>>          * timer interrupt). Full topology setup happens at smp_init()
>>          * time - but meanwhile we still have a functioning scheduler.
>>          */
>>         sched_init();
>>         .............
>>         time_init();
>>         ..............
>>         WARN(!irqs_disabled(), "Interrupts were enabled early\n");
>>         early_boot_irqs_disabled = false;
>>         local_irq_enable();
>> }
>>
>> The issue can only happen when PLL enable causes a schedule during
>> imx_clock_init().
>> Not all PLL has this issue.
>> The issue happens on MX7D pll_audio_main_clk/pll_video_main_clk
>> which requires more delay time and cause usleep.
>> Because clk framework does not support MX7D clock types (operation requires
>> parents on), we simply enable all clocks in imx7d_clocks_init().
>>
>> If apply my this patch series:
>> https://lkml.org/lkml/2016/4/20/199
>> The issue can also be gone.
>
> Thanks for the info.  It sounds like that we are fixing the problem in
> the wrong place, i.e. clk_pllv3_prepare().  The function does nothing
> wrong, since the .prepare hook is defined to be one that can sleep.  If
> we see sleep warning in a context calling clk_prepare(), that probably
> means we shouldn't make the function call from that context.
>

Yes, i agree.
I'm trying to get rid of these calls.

Simply remove them or delay to arch_init will cause kernel fail to boot.
Still checking the root cause.

> Shawn

Regards
Dong Aisheng
Dong Aisheng April 27, 2016, 8:53 a.m. UTC | #22
On Wed, Apr 27, 2016 at 3:28 PM, Stefan Agner <stefan@agner.ch> wrote:
> On 2016-04-26 19:56, Fabio Estevam wrote:
>> On Tue, Apr 26, 2016 at 11:45 PM, Dong Aisheng <dongas86@gmail.com> wrote:
>>
>>>> We need to firstly understand why this is happening.  The .prepare hook
>>>> is defined to be non-atomic context, and so that we call sleep function
>>>> in there.  We did everything right.  Why are we getting the warning?  If
>>>> I'm correct, this warning only happens on i.MX7D.  Why is that?
>>>>
>>>
>>> This is mainly caused by during kernel early booting, there's only one init idle
>>> task running.
>>> See:
>>> void __init sched_init(void)
>>> {
>>> .....
>>>         /*
>>>          * Make us the idle thread. Technically, schedule() should not be
>>>          * called from this thread, however somewhere below it might be,
>>>          * but because we are the idle thread, we just pick up running again
>>>          * when this runqueue becomes "idle".
>>>          */
>>>         init_idle(current, smp_processor_id());
>>> ...
>>> }
>>>
>>> And the idle sched class indicates it's not valid to schedule for idle task.
>>> const struct sched_class idle_sched_class = {
>>>         /* .next is NULL */
>>>         /* no enqueue/yield_task for idle tasks */
>>>
>>>         /* dequeue is not valid, we print a debug message there: */
>>>         .dequeue_task           = dequeue_task_idle,
>>> ...........
>>>
>>> }
>>>
>>> /*
>>>  * It is not legal to sleep in the idle task - print a warning
>>>  * message if some code attempts to do it:
>>>  */
>>> static void
>>> dequeue_task_idle(struct rq *rq, struct task_struct *p, int flags)
>>> {
>>>         raw_spin_unlock_irq(&rq->lock);
>>>         printk(KERN_ERR "bad: scheduling from the idle thread!\n");
>>>         dump_stack();
>>>         raw_spin_lock_irq(&rq->lock);
>>> }
>>>
>>>
>>> Below is the full log of imx7d booting FYI.
>>
>> This does not answer Shawn's question: why do we see this only on mx7d?
>
> I was wondering that too.... My theory is that either on i.MX 6 the
> clocks enable almost instantly leading to no sleep, or they are just
> bootloader/firmware on...?
>

Yes, for core plls, they're already enabled in bootloader.
We observed this issue on MX7D is because we rudely enable all clocks
for it and MX7D AV PLLs which will lead to sleep reveals this issue.

Regards
Dong Aisheng

> --
> Stefan
Dong Aisheng April 27, 2016, 8:57 a.m. UTC | #23
On Wed, Apr 27, 2016 at 3:34 PM, Stefan Agner <stefan@agner.ch> wrote:
> On 2016-04-26 19:57, Dong Aisheng wrote:
>> On Wed, Apr 27, 2016 at 9:58 AM, Shawn Guo <shawnguo@kernel.org> wrote:
>>> On Tue, Apr 26, 2016 at 07:27:03PM +0800, Dong Aisheng wrote:
>>>> Shawn,
>>>> What's your suggestion?
>>>
>>> I think this needs more discussion, and I just dropped Stefan's patch
>>> from my tree.
>>>
>>> We need to firstly understand why this is happening.  The .prepare hook
>>> is defined to be non-atomic context, and so that we call sleep function
>>> in there.  We did everything right.  Why are we getting the warning?  If
>>> I'm correct, this warning only happens on i.MX7D.  Why is that?
>>>
>>
>> Why Stefan's patch works (checking irqs_disabled()) is because during kernel
>> time init, the irq is still not enabled. It fixes the issue indirectly.
>> See:
>> asmlinkage __visible void __init start_kernel(void)
>> {
>>         /*
>>          * Set up the scheduler prior starting any interrupts (such as the
>>          * timer interrupt). Full topology setup happens at smp_init()
>>          * time - but meanwhile we still have a functioning scheduler.
>>          */
>>         sched_init();
>>         .............
>>         time_init();
>>         ..............
>>         WARN(!irqs_disabled(), "Interrupts were enabled early\n");
>>         early_boot_irqs_disabled = false;
>>         local_irq_enable();
>> }
>>
>> The issue can only happen when PLL enable causes a schedule during
>> imx_clock_init().
>> Not all PLL has this issue.
>> The issue happens on MX7D pll_audio_main_clk/pll_video_main_clk
>> which requires more delay time and cause usleep.
>> Because clk framework does not support MX7D clock types (operation requires
>> parents on), we simply enable all clocks in imx7d_clocks_init().
>>
>> If apply my this patch series:
>> https://lkml.org/lkml/2016/4/20/199
>> The issue can also be gone.
>
> Oh ok, it does make sense to enable as few clocks as possible.
>
> However, even if we do not enable lots of clocks at that time, and this
> helps to avoid the problem for now, it could still be that
> someone/something requests a clock early during boot, leading to a PLL
> enable... Shouldn't we make sure that those base clocks can be enabled
> even during early boot..?
>

The point as Shawn pointed is that we even shouldn't call clk_prepare_enable
at that time.
So we may first try to eliminate those callings in imx7d_clocks_init.

> --
> Stefan

Regards
Dong Aisheng
Thomas Gleixner April 27, 2016, 10:15 a.m. UTC | #24
On Wed, 27 Apr 2016, Dong Aisheng wrote:
> On Wed, Apr 27, 2016 at 9:58 AM, Shawn Guo <shawnguo@kernel.org> wrote:
> > On Tue, Apr 26, 2016 at 07:27:03PM +0800, Dong Aisheng wrote:
> >> Shawn,
> >> What's your suggestion?
> >
> > I think this needs more discussion, and I just dropped Stefan's patch
> > from my tree.
> >
> > We need to firstly understand why this is happening.  The .prepare hook
> > is defined to be non-atomic context, and so that we call sleep function
> > in there.  We did everything right.  Why are we getting the warning?  If
> > I'm correct, this warning only happens on i.MX7D.  Why is that?
> >
> 
> Why Stefan's patch works (checking irqs_disabled()) is because during kernel
> time init, the irq is still not enabled. It fixes the issue indirectly.
> See:
> asmlinkage __visible void __init start_kernel(void)
> {
>         /*
>          * Set up the scheduler prior starting any interrupts (such as the
>          * timer interrupt). Full topology setup happens at smp_init()
>          * time - but meanwhile we still have a functioning scheduler.
>          */
>         sched_init();
>         .............
>         time_init();
>         ..............
>         WARN(!irqs_disabled(), "Interrupts were enabled early\n");
>         early_boot_irqs_disabled = false;
>         local_irq_enable();
> }
> 
> The issue can only happen when PLL enable causes a schedule during
> imx_clock_init().

Calling a function which might sleep _BEFORE_ kernel_init() is wrong. Don't
try to work around such an issue by doing magic irq_disabled() checks and busy
loops. Fix the call site and be done with it.

Thanks,

	tglx
Stefan Agner May 25, 2016, 9:54 p.m. UTC | #25
On 2016-04-27 03:15, Thomas Gleixner wrote:
> On Wed, 27 Apr 2016, Dong Aisheng wrote:
>> Why Stefan's patch works (checking irqs_disabled()) is because during kernel
>> time init, the irq is still not enabled. It fixes the issue indirectly.
>> See:
>> asmlinkage __visible void __init start_kernel(void)
>> {
>>         /*
>>          * Set up the scheduler prior starting any interrupts (such as the
>>          * timer interrupt). Full topology setup happens at smp_init()
>>          * time - but meanwhile we still have a functioning scheduler.
>>          */
>>         sched_init();
>>         .............
>>         time_init();
>>         ..............
>>         WARN(!irqs_disabled(), "Interrupts were enabled early\n");
>>         early_boot_irqs_disabled = false;
>>         local_irq_enable();
>> }
>>
>> The issue can only happen when PLL enable causes a schedule during
>> imx_clock_init().
> 
> Calling a function which might sleep _BEFORE_ kernel_init() is wrong. Don't
> try to work around such an issue by doing magic irq_disabled() checks and busy
> loops. Fix the call site and be done with it.

What do you mean exactly by fix the call site? The patch I proposed
(https://lkml.org/lkml/2016/1/29/695) fixes the call site...

But I see Dong's argument here, irqs_disabled is the wrong way to figure
out whether we are in kernel_init. What is the right approach to
distinguish whether we are allowed to sleep?

--
Stefan
Dong Aisheng June 2, 2016, 2:59 p.m. UTC | #26
Hi Thomas,

On Wed, Apr 27, 2016 at 12:15:00PM +0200, Thomas Gleixner wrote:
> On Wed, 27 Apr 2016, Dong Aisheng wrote:
> > On Wed, Apr 27, 2016 at 9:58 AM, Shawn Guo <shawnguo@kernel.org> wrote:
> > > On Tue, Apr 26, 2016 at 07:27:03PM +0800, Dong Aisheng wrote:
> > >> Shawn,
> > >> What's your suggestion?
> > >
> > > I think this needs more discussion, and I just dropped Stefan's patch
> > > from my tree.
> > >
> > > We need to firstly understand why this is happening.  The .prepare hook
> > > is defined to be non-atomic context, and so that we call sleep function
> > > in there.  We did everything right.  Why are we getting the warning?  If
> > > I'm correct, this warning only happens on i.MX7D.  Why is that?
> > >
> > 
> > Why Stefan's patch works (checking irqs_disabled()) is because during kernel
> > time init, the irq is still not enabled. It fixes the issue indirectly.
> > See:
> > asmlinkage __visible void __init start_kernel(void)
> > {
> >         /*
> >          * Set up the scheduler prior starting any interrupts (such as the
> >          * timer interrupt). Full topology setup happens at smp_init()
> >          * time - but meanwhile we still have a functioning scheduler.
> >          */
> >         sched_init();
> >         .............
> >         time_init();
> >         ..............
> >         WARN(!irqs_disabled(), "Interrupts were enabled early\n");
> >         early_boot_irqs_disabled = false;
> >         local_irq_enable();
> > }
> > 
> > The issue can only happen when PLL enable causes a schedule during
> > imx_clock_init().
> 
> Calling a function which might sleep _BEFORE_ kernel_init() is wrong. Don't
> try to work around such an issue by doing magic irq_disabled() checks and busy
> loops. Fix the call site and be done with it.
> 

IRQ chip and clocksource are also initialised before kernel_init()
which may call clk APIs like clk_prepare_enable().
We may not be able to guarantee those clocks are unsleepable.

e.g.
For IRQ chip, the arm,gic documents the optional clocks property in
Documentation/devicetree/bindings/interrupt-controller/arm,gic.txt.
Although there seems no user currently, not sure there might be
a exception in the future.

For clocksource driver, it's quite common to call clk APIs to
enable and get clock rate which may also cause sleep.
e.g. ARM twd clock in arch/arm/kernel/smp_twd.c.

If we have to avoid the possible sleep caused by these clocks,
we may need to manually check it and change the related clocks
(e.g PLLs) from sleepable to busy loops.
But that is not a good solution and may also not stable when
clock varies.

It looks like not easy to find a generic solution for them.
What's your suggestion?

And Stephen,

Besides above possible sleep, the clk framework itself may also
cause unexpected sleep before kernel_init().
1) clk framework now supports CLK_IS_CRITICAL flag which allows to
enable the clock during register in __clk_core_init(), it usually
can happen in time_init()->of_clk_init();

2) clk framework also support set default configuration like set_parent
and set_rate during register clk providers which also happens in
time_init()->of_clk_init().

Any ideas?
Do you think if we should move them onto a bit later stage after
kernel_init()?

Regards
Dong Aisheng

> Thanks,
> 
> 	tglx
> 
>
Thomas Gleixner June 6, 2016, 1:20 p.m. UTC | #27
On Thu, 2 Jun 2016, Dong Aisheng wrote:
> On Wed, Apr 27, 2016 at 12:15:00PM +0200, Thomas Gleixner wrote:
> > Calling a function which might sleep _BEFORE_ kernel_init() is wrong. Don't
> > try to work around such an issue by doing magic irq_disabled() checks and busy
> > loops. Fix the call site and be done with it.
> > 
> 
> IRQ chip and clocksource are also initialised before kernel_init()
> which may call clk APIs like clk_prepare_enable().
> We may not be able to guarantee those clocks are unsleepable.
> 
> e.g.
> For IRQ chip, the arm,gic documents the optional clocks property in
> Documentation/devicetree/bindings/interrupt-controller/arm,gic.txt.
> Although there seems no user currently, not sure there might be
> a exception in the future.
> 
> For clocksource driver, it's quite common to call clk APIs to
> enable and get clock rate which may also cause sleep.
> e.g. ARM twd clock in arch/arm/kernel/smp_twd.c.
> 
> If we have to avoid the possible sleep caused by these clocks,
> we may need to manually check it and change the related clocks
> (e.g PLLs) from sleepable to busy loops.
> But that is not a good solution and may also not stable when
> clock varies.
> 
> It looks like not easy to find a generic solution for them.
> What's your suggestion?

I think we should split the prepare callbacks up and move the handling logic
into the core.

clk_ops.prepare()	Legacy callback
clk_ops.prepare_hw()	Callback which writes to the hardware
clk_ops.prepare_done()	Callback which checks whether the prepare is completed

So now the core can do:

clk_prepare()
{
	/* Legacy code should go away */
	if (ops->prepare) {
	      ops->prepare();
	      return;
	}

	if (ops->prepare_hw)
	      ops->prepare_hw();

   	if (!ops->prepare_done())
		return;

	if (early_boot_or_suspend_resume()) {
		/*
		 * Busy loop when we can't schedule in early boot,
		 * suspend and resume.
		 */
		while (!ops->prepare_done())
		      ;
	} else {
		while (!ops->prepare_done())
		      usleep(clk->prepare_delay);
	}
}

As a side effect that allows us to remove the gazillion of

     	    while (!hw_ready)
	    	  usleep();

copies all over the place and we have a single point of control where we allow
the clocks to busy loop.

Toughts?

Thanks,

	tglx
Dong Aisheng June 7, 2016, 7:04 a.m. UTC | #28
On Mon, Jun 06, 2016 at 03:20:03PM +0200, Thomas Gleixner wrote:
> On Thu, 2 Jun 2016, Dong Aisheng wrote:
> > On Wed, Apr 27, 2016 at 12:15:00PM +0200, Thomas Gleixner wrote:
> > > Calling a function which might sleep _BEFORE_ kernel_init() is wrong. Don't
> > > try to work around such an issue by doing magic irq_disabled() checks and busy
> > > loops. Fix the call site and be done with it.
> > > 
> > 
> > IRQ chip and clocksource are also initialised before kernel_init()
> > which may call clk APIs like clk_prepare_enable().
> > We may not be able to guarantee those clocks are unsleepable.
> > 
> > e.g.
> > For IRQ chip, the arm,gic documents the optional clocks property in
> > Documentation/devicetree/bindings/interrupt-controller/arm,gic.txt.
> > Although there seems no user currently, not sure there might be
> > a exception in the future.
> > 
> > For clocksource driver, it's quite common to call clk APIs to
> > enable and get clock rate which may also cause sleep.
> > e.g. ARM twd clock in arch/arm/kernel/smp_twd.c.
> > 
> > If we have to avoid the possible sleep caused by these clocks,
> > we may need to manually check it and change the related clocks
> > (e.g PLLs) from sleepable to busy loops.
> > But that is not a good solution and may also not stable when
> > clock varies.
> > 
> > It looks like not easy to find a generic solution for them.
> > What's your suggestion?
> 
> I think we should split the prepare callbacks up and move the handling logic
> into the core.
> 
> clk_ops.prepare()	Legacy callback
> clk_ops.prepare_hw()	Callback which writes to the hardware
> clk_ops.prepare_done()	Callback which checks whether the prepare is completed
> 
> So now the core can do:
> 
> clk_prepare()
> {
> 	/* Legacy code should go away */
> 	if (ops->prepare) {
> 	      ops->prepare();
> 	      return;
> 	}
> 
> 	if (ops->prepare_hw)
> 	      ops->prepare_hw();
> 
>    	if (!ops->prepare_done())
> 		return;
> 
> 	if (early_boot_or_suspend_resume()) {
> 		/*
> 		 * Busy loop when we can't schedule in early boot,
> 		 * suspend and resume.
> 		 */
> 		while (!ops->prepare_done())
> 		      ;
> 	} else {
> 		while (!ops->prepare_done())
> 		      usleep(clk->prepare_delay);
> 	}
> }
> 
> As a side effect that allows us to remove the gazillion of
> 
>      	    while (!hw_ready)
> 	    	  usleep();
> 
> copies all over the place and we have a single point of control where we allow
> the clocks to busy loop.
> 
> Toughts?
> 

Great, that looks like a possible solution.
If we doing this way there's one more question that
should we do it for other clk APIs hold by prepare_lock which
all may sleep too in theory?
e.g. clk_{set|get}_rate/clk_{set|get}_parent. (possible more)
(clk_recalc_rate/clk_round_rate may also need be considered due to
it may be called within above function.)

And it seems many exist platforms doing that work in
CLK_OF_DECLARE init function in time_init().
e.g.
drivers/clk/imx/clk-imx6ul.c
drivers/clk/rockchip/clk-rk3188.c
drivers/clk/ti/clk-44xx.c
...

Then it may need introduce a lot changes and increase many new core APIs.
Is that a problem?

> Thanks,
> 
> 	tglx

Regards
Dong Aisheng
Thomas Gleixner June 9, 2016, 8:08 p.m. UTC | #29
On Tue, 7 Jun 2016, Dong Aisheng wrote:
> Then it may need introduce a lot changes and increase many new core APIs.
> Is that a problem?

No. That's all better than each driver having broken workarounds. It's a
common problem so it wants to be addressed at the core level. There you have a
central point to do this and you can still catch abusers which call stuff from
the wrong context. The hacks in the drivers don't allow that because they look
at the context, i.e. irq disabled, instead of checking the system state.

Thanks,

	tglx
Stefan Agner June 9, 2016, 10:14 p.m. UTC | #30
On 2016-06-09 13:08, Thomas Gleixner wrote:
> On Tue, 7 Jun 2016, Dong Aisheng wrote:
>> Then it may need introduce a lot changes and increase many new core APIs.
>> Is that a problem?
> 
> No. That's all better than each driver having broken workarounds. It's a
> common problem so it wants to be addressed at the core level. There you have a
> central point to do this and you can still catch abusers which call stuff from
> the wrong context. The hacks in the drivers don't allow that because they look
> at the context, i.e. irq disabled, instead of checking the system state.

IMHO, the hacky part of my patch was how I detected whether to use sleep
or delay. That said I am ok with API extension too, I guess it is fairly
common use case... I found at least 6 clock prepare functions with sleep
in it (and some udelays, all between 1-100).

Your proposed solution uses "early_boot_or_suspend_resume" which I did
not found as a convenient function in the wild :-)

How would you implement that?

--
Stefan
Dong Aisheng June 12, 2016, 12:24 p.m. UTC | #31
On Thu, Jun 09, 2016 at 10:08:01PM +0200, Thomas Gleixner wrote:
> On Tue, 7 Jun 2016, Dong Aisheng wrote:
> > Then it may need introduce a lot changes and increase many new core APIs.
> > Is that a problem?
> 
> No. That's all better than each driver having broken workarounds. It's a
> common problem so it wants to be addressed at the core level. There you have a
> central point to do this and you can still catch abusers which call stuff from
> the wrong context. The hacks in the drivers don't allow that because they look
> at the context, i.e. irq disabled, instead of checking the system state.
> 

Okay, thanks.
If you wouldn't mind i could send out a patch based on your
suggestion for further discussion.

Thanks

Regards
Dong Aisheng

> Thanks,
> 
> 	tglx
diff mbox

Patch

diff --git a/drivers/clk/imx/clk-pllv3.c b/drivers/clk/imx/clk-pllv3.c
index c05c43d..b5ff561 100644
--- a/drivers/clk/imx/clk-pllv3.c
+++ b/drivers/clk/imx/clk-pllv3.c
@@ -63,7 +63,10 @@  static int clk_pllv3_wait_lock(struct clk_pllv3 *pll)
 			break;
 		if (time_after(jiffies, timeout))
 			break;
-		usleep_range(50, 500);
+		if (unlikely(irqs_disabled()))
+			udelay(50);
+		else
+			usleep_range(50, 500);
 	} while (1);
 
 	return readl_relaxed(pll->base) & BM_PLL_LOCK ? 0 : -ETIMEDOUT;