Dramatic lockdep slowdown in 4.14

Dramatic lockdep slowdown in 4.14

[Johan Hovold]

Hi,

I had noticed that the BeagleBone Black boot time appeared to have
increased significantly with 4.14 and yesterday I finally had time to
investigate it.

Boot time (from "Linux version" to login prompt) had in fact doubled
since 4.13 where it took 17 seconds (with my current config) compared to
the 35 seconds I now see with 4.14-rc4.

I quick bisect pointed to lockdep and specifically the following commit:

	28a903f63ec0 ("locking/lockdep: Handle non(or multi)-acquisition
	               of a crosslock")

which I've verified is the commit which doubled the boot time (compared
to 28a903f63ec0^) (added by lockdep crossrelease series [1]).

I also verified that simply disabling CONFIG_PROVE_LOCKING on 4.14-rc4
brought boot time down to about 14 seconds.

Now since it's lockdep I guess this can't really be considered a
regression if these changes did improve lockdep correctness, but still,
this dramatic slow down essentially forces me to disable PROVE_LOCKING
by default on this system.

Is this lockdep slowdown expected and desirable?

Johan

[1] https://lkml.kernel.org/r/1502089981-21272-1-git-send-email-byungchul.park@lge.com

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to majordomo@kvack.org.  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"dont@kvack.org"> email@kvack.org </a>

Re: Dramatic lockdep slowdown in 4.14

[Peter Zijlstra]

On Fri, Oct 13, 2017 at 11:03:33AM +0200, Johan Hovold wrote:
> Hi,
> 
> I had noticed that the BeagleBone Black boot time appeared to have
> increased significantly with 4.14 and yesterday I finally had time to
> investigate it.
> 
> Boot time (from "Linux version" to login prompt) had in fact doubled
> since 4.13 where it took 17 seconds (with my current config) compared to
> the 35 seconds I now see with 4.14-rc4.
> 
> I quick bisect pointed to lockdep and specifically the following commit:
> 
> 	28a903f63ec0 ("locking/lockdep: Handle non(or multi)-acquisition
> 	               of a crosslock")
> 
> which I've verified is the commit which doubled the boot time (compared
> to 28a903f63ec0^) (added by lockdep crossrelease series [1]).
> 
> I also verified that simply disabling CONFIG_PROVE_LOCKING on 4.14-rc4
> brought boot time down to about 14 seconds.
> 
> Now since it's lockdep I guess this can't really be considered a
> regression if these changes did improve lockdep correctness, but still,
> this dramatic slow down essentially forces me to disable PROVE_LOCKING
> by default on this system.
> 
> Is this lockdep slowdown expected and desirable?

Expected yes, desirable not so much. Its the save_stack_trace() in
add_xhlock() (IIRC).

I've not yet had time to figure out what to do about that.

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to majordomo@kvack.org.  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"dont@kvack.org"> email@kvack.org </a>

Re: Dramatic lockdep slowdown in 4.14

[Johan Hovold]

On Fri, Oct 13, 2017 at 11:07:44AM +0200, Peter Zijlstra wrote:
> On Fri, Oct 13, 2017 at 11:03:33AM +0200, Johan Hovold wrote:
> > Hi,
> > 
> > I had noticed that the BeagleBone Black boot time appeared to have
> > increased significantly with 4.14 and yesterday I finally had time to
> > investigate it.
> > 
> > Boot time (from "Linux version" to login prompt) had in fact doubled
> > since 4.13 where it took 17 seconds (with my current config) compared to
> > the 35 seconds I now see with 4.14-rc4.
> > 
> > I quick bisect pointed to lockdep and specifically the following commit:
> > 
> > 	28a903f63ec0 ("locking/lockdep: Handle non(or multi)-acquisition
> > 	               of a crosslock")
> > 
> > which I've verified is the commit which doubled the boot time (compared
> > to 28a903f63ec0^) (added by lockdep crossrelease series [1]).
> > 
> > I also verified that simply disabling CONFIG_PROVE_LOCKING on 4.14-rc4
> > brought boot time down to about 14 seconds.
> > 
> > Now since it's lockdep I guess this can't really be considered a
> > regression if these changes did improve lockdep correctness, but still,
> > this dramatic slow down essentially forces me to disable PROVE_LOCKING
> > by default on this system.
> > 
> > Is this lockdep slowdown expected and desirable?
> 
> Expected yes, desirable not so much. Its the save_stack_trace() in
> add_xhlock() (IIRC).
> 
> I've not yet had time to figure out what to do about that.

Thanks for confirming. Do you think it makes sense to track this as a
4.14 regression to avoid having others spend time on tracking this down
meanwhile? (Adding Thorsten on CC.)

Johan

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to majordomo@kvack.org.  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"dont@kvack.org"> email@kvack.org </a>

Re: Dramatic lockdep slowdown in 4.14

[Ingo Molnar]

* Johan Hovold <johan@kernel.org> wrote:

> Hi,
> 
> I had noticed that the BeagleBone Black boot time appeared to have
> increased significantly with 4.14 and yesterday I finally had time to
> investigate it.
> 
> Boot time (from "Linux version" to login prompt) had in fact doubled
> since 4.13 where it took 17 seconds (with my current config) compared to
> the 35 seconds I now see with 4.14-rc4.
> 
> I quick bisect pointed to lockdep and specifically the following commit:
> 
> 	28a903f63ec0 ("locking/lockdep: Handle non(or multi)-acquisition
> 	               of a crosslock")
> 
> which I've verified is the commit which doubled the boot time (compared
> to 28a903f63ec0^) (added by lockdep crossrelease series [1]).
> 
> I also verified that simply disabling CONFIG_PROVE_LOCKING on 4.14-rc4
> brought boot time down to about 14 seconds.
> 
> Now since it's lockdep I guess this can't really be considered a
> regression if these changes did improve lockdep correctness, but still,
> this dramatic slow down essentially forces me to disable PROVE_LOCKING
> by default on this system.
> 
> Is this lockdep slowdown expected and desirable?

It's not desirable at all.

Does the patch below fix the regression for you - or does the introduction and 
handling of ->nr_acquire hurt as well?

Thanks,

	Ingo

====================>
 lib/Kconfig.debug | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug
index c6401d325b0e..f5b40c1668ea 100644
--- a/lib/Kconfig.debug
+++ b/lib/Kconfig.debug
@@ -1138,8 +1138,8 @@ config PROVE_LOCKING
 	select DEBUG_MUTEXES
 	select DEBUG_RT_MUTEXES if RT_MUTEXES
 	select DEBUG_LOCK_ALLOC
-	select LOCKDEP_CROSSRELEASE
-	select LOCKDEP_COMPLETIONS
+#	select LOCKDEP_CROSSRELEASE
+#	select LOCKDEP_COMPLETIONS
 	select TRACE_IRQFLAGS
 	default n
 	help

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to majordomo@kvack.org.  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"dont@kvack.org"> email@kvack.org </a>

Re: Dramatic lockdep slowdown in 4.14

[Johan Hovold]

On Sat, Oct 14, 2017 at 09:26:59AM +0200, Ingo Molnar wrote:
> 
> * Johan Hovold <johan@kernel.org> wrote:
> 
> > Hi,
> > 
> > I had noticed that the BeagleBone Black boot time appeared to have
> > increased significantly with 4.14 and yesterday I finally had time to
> > investigate it.
> > 
> > Boot time (from "Linux version" to login prompt) had in fact doubled
> > since 4.13 where it took 17 seconds (with my current config) compared to
> > the 35 seconds I now see with 4.14-rc4.
> > 
> > I quick bisect pointed to lockdep and specifically the following commit:
> > 
> > 	28a903f63ec0 ("locking/lockdep: Handle non(or multi)-acquisition
> > 	               of a crosslock")
> > 
> > which I've verified is the commit which doubled the boot time (compared
> > to 28a903f63ec0^) (added by lockdep crossrelease series [1]).
> > 
> > I also verified that simply disabling CONFIG_PROVE_LOCKING on 4.14-rc4
> > brought boot time down to about 14 seconds.
> > 
> > Now since it's lockdep I guess this can't really be considered a
> > regression if these changes did improve lockdep correctness, but still,
> > this dramatic slow down essentially forces me to disable PROVE_LOCKING
> > by default on this system.
> > 
> > Is this lockdep slowdown expected and desirable?
> 
> It's not desirable at all.
> 
> Does the patch below fix the regression for you - or does the introduction and 
> handling of ->nr_acquire hurt as well?

> -	select LOCKDEP_CROSSRELEASE
> -	select LOCKDEP_COMPLETIONS
> +#	select LOCKDEP_CROSSRELEASE
> +#	select LOCKDEP_COMPLETIONS

Disabling these options this way gives me a about boot time of 17
seconds again, so yes, that fixes the problem.

Thanks,
Johan

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to majordomo@kvack.org.  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"dont@kvack.org"> email@kvack.org </a>