| Message ID | 20160622005208.GB25106@js1304-P5Q-DELUXE (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
On Wed, Jun 22, 2016 at 09:52:08AM +0900, Joonsoo Kim wrote: > On Tue, Jun 21, 2016 at 05:54:06AM -0700, Paul E. McKenney wrote: > > On Tue, Jun 21, 2016 at 03:43:02PM +0900, Joonsoo Kim wrote: > > > On Mon, Jun 20, 2016 at 06:12:54AM -0700, Paul E. McKenney wrote: > > > > On Mon, Jun 20, 2016 at 03:39:43PM +0900, Joonsoo Kim wrote: > > > > > CCing Paul to ask some question. > > > > > > > > > > On Wed, Jun 15, 2016 at 10:39:47AM +0200, Geert Uytterhoeven wrote: > > > > > > Hi Joonsoo, > > > > > > > > > > > > On Wed, Jun 15, 2016 at 4:23 AM, Joonsoo Kim <iamjoonsoo.kim@lge.com> wrote: > > > > > > > On Tue, Jun 14, 2016 at 12:45:14PM +0200, Geert Uytterhoeven wrote: > > > > > > >> On Tue, Jun 14, 2016 at 10:11 AM, Joonsoo Kim <iamjoonsoo.kim@lge.com> wrote: > > > > > > >> > On Tue, Jun 14, 2016 at 09:31:23AM +0200, Geert Uytterhoeven wrote: > > > > > > >> >> On Tue, Jun 14, 2016 at 8:24 AM, Joonsoo Kim <iamjoonsoo.kim@lge.com> wrote: > > > > > > >> >> > On Mon, Jun 13, 2016 at 09:43:13PM +0200, Geert Uytterhoeven wrote: > > > > > > >> >> >> On Tue, Apr 12, 2016 at 6:51 AM, <js1304@gmail.com> wrote: > > > > > > >> >> >> > From: Joonsoo Kim <iamjoonsoo.kim@lge.com> > > > > > > >> >> >> > To check whther free objects exist or not precisely, we need to grab a > > > > > > >> >> >> > lock. But, accuracy isn't that important because race window would be > > > > > > >> >> >> > even small and if there is too much free object, cache reaper would reap > > > > > > >> >> >> > it. So, this patch makes the check for free object exisistence not to > > > > > > >> >> >> > hold a lock. This will reduce lock contention in heavily allocation case. > > > > > > > > > > > > >> >> >> I've bisected a boot failure (no output at all) in v4.7-rc2 on emev2/kzm9d > > > > > > >> >> >> (Renesas dual Cortex A9) to this patch, which is upstream commit > > > > > > >> >> >> 801faf0db8947e01877920e848a4d338dd7a99e7. > > > > > > > > > > > > > It's curious that synchronize_sched() has some effect in this early > > > > > > > phase. In synchronize_sched(), rcu_blocking_is_gp() is called and > > > > > > > it checks num_online_cpus <= 1. If so, synchronize_sched() does nothing. > > > > > > > > > > > > > > It would be related to might_sleep() in rcu_blocking_is_gp() but I'm not sure now. > > > > > > > > > > > > > > First, I'd like to confirm that num_online_cpus() is correct. > > > > > > > Could you try following patch and give me a dmesg? > > > > > > > > > > > > > > Thanks. > > > > > > > > > > > > > > ------->8---------- > > > > > > > diff --git a/mm/slab.c b/mm/slab.c > > > > > > > index 763096a..5b7300a 100644 > > > > > > > --- a/mm/slab.c > > > > > > > +++ b/mm/slab.c > > > > > > > @@ -964,8 +964,10 @@ static int setup_kmem_cache_node(struct kmem_cache *cachep, > > > > > > > * guaranteed to be valid until irq is re-enabled, because it will be > > > > > > > * freed after synchronize_sched(). > > > > > > > */ > > > > > > > - if (force_change) > > > > > > > - synchronize_sched(); > > > > > > > + if (force_change) { > > > > > > > + WARN_ON_ONCE(num_online_cpus() <= 1); > > > > > > > + WARN_ON_ONCE(num_online_cpus() > 1); > > > > > > > + } > > > > > > > > > > > > Full dmesg output below. > > > > > > > > > > > > I also tested whether it's the call to synchronize_sched() before or after > > > > > > secondary CPU bringup that hangs. > > > > > > > > > > > > if (force_change && num_online_cpus() <= 1) > > > > > > synchronize_sched(); > > > > > > > > > > > > boots. > > > > > > > > > > > > if (force_change && num_online_cpus() > 1) > > > > > > synchronize_sched(); > > > > > > > > > > > > hangs. > > > > > > > > > > Hello, Paul. > > > > > > > > > > I changed slab.c to use synchronize_sched() for full memory barrier. First > > > > > call happens on kmem_cache_init_late() and it would not be a problem > > > > > because, at this time, num_online_cpus() <= 1 and synchronize_sched() > > > > > would return immediately. Second call site would be shmem_init() > > > > > and it seems that system hangs on it. Since smp is already initialized > > > > > at that time, there would be some effect of synchronize_sched() but I > > > > > can't imagine what's wrong here. Is it invalid moment to call > > > > > synchronize_sched()? > > > > > > > > > > Note that my x86 virtual machine works fine even if > > > > > synchronize_sched() is called in shmem_init() but Geert's some ARM > > > > > machines (not all ARM machine) don't work well with it. > > > > > > > > Color me confused. > > > > > > > > Is Geert's ARM system somehow adding the second CPU before > > > > rcu_spawn_gp_kthread() is called, that is, before or during > > > > early_initcall() time? > > > > > > Hang would happen on shmem_init() which is called in do_basic_setup(). > > > do_basic_setup() is called after early_initcall(). > > > > Thank you for the info! > > > > That should be lat enough that the RCU kthreads are alive and well. > > > > Can you get sysalt-t output? > > > > > Hmm... Is it okay to call synchronize_sched() by kernel thread? > > > > Yes, it can, in fact, rcutorture does this all the time. As do any > > number of other kthreads. > > Paul, thanks for confirmation. > > Geert, we need to try more debugging. > > Could you try below patch to check who causes the hang? Nice! That might be quite valuable! > And, if sysalt-t works when hang, could you get sysalt-t output? I haven't > used it before but Paul could find some culprit on it. :) And the other thing to do is to read the last portion of Documentation/RCU/stallwarn.txt, the part starting with "What Causes RCU CPU Stall Warnings?". I would expect any of these things to also result in an RCU CPU stall warning, but perhaps something is preventing them from being printed. Short summary: If a CPU gets stuck badly enough, RCU grace periods won't end and therefore synchronize_sched() won't ever return. Thanx, Paul > Thanks. > > > ----->8----- > diff --git a/mm/slab.c b/mm/slab.c > index 763096a..9652d38 100644 > --- a/mm/slab.c > +++ b/mm/slab.c > @@ -964,8 +964,13 @@ static int setup_kmem_cache_node(struct kmem_cache *cachep, > * guaranteed to be valid until irq is re-enabled, because it will be > * freed after synchronize_sched(). > */ > - if (force_change) > + if (force_change) { > + if (num_online_cpus() > 1) > + dump_stack(); > synchronize_sched(); > + if (num_online_cpus() > 1) > + dump_stack(); > + } > > fail: > kfree(old_shared); >
On Wed, Jun 22, 2016 at 2:52 AM, Joonsoo Kim <iamjoonsoo.kim@lge.com> wrote: > Could you try below patch to check who causes the hang? > > And, if sysalt-t works when hang, could you get sysalt-t output? I haven't > used it before but Paul could find some culprit on it. :) > > Thanks. > > > ----->8----- > diff --git a/mm/slab.c b/mm/slab.c > index 763096a..9652d38 100644 > --- a/mm/slab.c > +++ b/mm/slab.c > @@ -964,8 +964,13 @@ static int setup_kmem_cache_node(struct kmem_cache *cachep, > * guaranteed to be valid until irq is re-enabled, because it will be > * freed after synchronize_sched(). > */ > - if (force_change) > + if (force_change) { > + if (num_online_cpus() > 1) > + dump_stack(); > synchronize_sched(); > + if (num_online_cpus() > 1) > + dump_stack(); > + } I've only added the first one, as I would never see the second one. All of this happens before the serial console is activated, earlycon is not supported, and I only have remote access. Brought up 2 CPUs SMP: Total of 2 processors activated (2132.00 BogoMIPS). CPU: All CPU(s) started in SVC mode. CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.7.0-rc4-kzm9d-00404-g4a235e6dde4404dd-dirty #89 Hardware name: Generic Emma Mobile EV2 (Flattened Device Tree) [<c010de68>] (unwind_backtrace) from [<c010a658>] (show_stack+0x10/0x14) [<c010a658>] (show_stack) from [<c02b5cf8>] (dump_stack+0x7c/0x9c) [<c02b5cf8>] (dump_stack) from [<c01cfa4c>] (setup_kmem_cache_node+0x140/0x170) [<c01cfa4c>] (setup_kmem_cache_node) from [<c01cfe3c>] (__do_tune_cpucache+0xf4/0x114) [<c01cfe3c>] (__do_tune_cpucache) from [<c01cff54>] (enable_cpucache+0xf8/0x148) [<c01cff54>] (enable_cpucache) from [<c01d0190>] (__kmem_cache_create+0x1a8/0x1d0) [<c01d0190>] (__kmem_cache_create) from [<c01b32d0>] (kmem_cache_create+0xbc/0x190) [<c01b32d0>] (kmem_cache_create) from [<c070d968>] (shmem_init+0x34/0xb0) [<c070d968>] (shmem_init) from [<c0700cc8>] (kernel_init_freeable+0x98/0x1ec) [<c0700cc8>] (kernel_init_freeable) from [<c049fdbc>] (kernel_init+0x8/0x110) [<c049fdbc>] (kernel_init) from [<c0106cb8>] (ret_from_fork+0x14/0x3c) devtmpfs: initialized Gr{oetje,eeting}s, Geert -- Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- geert@linux-m68k.org In personal conversations with technical people, I call myself a hacker. But when I'm talking to journalists I just say "programmer" or something like that. -- Linus Torvalds
On Wed, Jun 22, 2016 at 05:01:35PM +0200, Geert Uytterhoeven wrote: > On Wed, Jun 22, 2016 at 2:52 AM, Joonsoo Kim <iamjoonsoo.kim@lge.com> wrote: > > Could you try below patch to check who causes the hang? > > > > And, if sysalt-t works when hang, could you get sysalt-t output? I haven't > > used it before but Paul could find some culprit on it. :) > > > > Thanks. > > > > > > ----->8----- > > diff --git a/mm/slab.c b/mm/slab.c > > index 763096a..9652d38 100644 > > --- a/mm/slab.c > > +++ b/mm/slab.c > > @@ -964,8 +964,13 @@ static int setup_kmem_cache_node(struct kmem_cache *cachep, > > * guaranteed to be valid until irq is re-enabled, because it will be > > * freed after synchronize_sched(). > > */ > > - if (force_change) > > + if (force_change) { > > + if (num_online_cpus() > 1) > > + dump_stack(); > > synchronize_sched(); > > + if (num_online_cpus() > 1) > > + dump_stack(); > > + } > > I've only added the first one, as I would never see the second one. All of > this happens before the serial console is activated, earlycon is not supported, > and I only have remote access. > > Brought up 2 CPUs > SMP: Total of 2 processors activated (2132.00 BogoMIPS). > CPU: All CPU(s) started in SVC mode. > CPU: 0 PID: 1 Comm: swapper/0 Not tainted > 4.7.0-rc4-kzm9d-00404-g4a235e6dde4404dd-dirty #89 > Hardware name: Generic Emma Mobile EV2 (Flattened Device Tree) > [<c010de68>] (unwind_backtrace) from [<c010a658>] (show_stack+0x10/0x14) > [<c010a658>] (show_stack) from [<c02b5cf8>] (dump_stack+0x7c/0x9c) > [<c02b5cf8>] (dump_stack) from [<c01cfa4c>] (setup_kmem_cache_node+0x140/0x170) > [<c01cfa4c>] (setup_kmem_cache_node) from [<c01cfe3c>] > (__do_tune_cpucache+0xf4/0x114) > [<c01cfe3c>] (__do_tune_cpucache) from [<c01cff54>] (enable_cpucache+0xf8/0x148) > [<c01cff54>] (enable_cpucache) from [<c01d0190>] > (__kmem_cache_create+0x1a8/0x1d0) > [<c01d0190>] (__kmem_cache_create) from [<c01b32d0>] > (kmem_cache_create+0xbc/0x190) > [<c01b32d0>] (kmem_cache_create) from [<c070d968>] (shmem_init+0x34/0xb0) > [<c070d968>] (shmem_init) from [<c0700cc8>] (kernel_init_freeable+0x98/0x1ec) > [<c0700cc8>] (kernel_init_freeable) from [<c049fdbc>] (kernel_init+0x8/0x110) > [<c049fdbc>] (kernel_init) from [<c0106cb8>] (ret_from_fork+0x14/0x3c) > devtmpfs: initialized I don't see anything here that would prevent grace periods from completing. The CPUs are using the normal hotplug sequence to come online, correct? Thanx, Paul
On Wed, Jun 22, 2016 at 12:08:59PM -0700, Paul E. McKenney wrote: > On Wed, Jun 22, 2016 at 05:01:35PM +0200, Geert Uytterhoeven wrote: > > On Wed, Jun 22, 2016 at 2:52 AM, Joonsoo Kim <iamjoonsoo.kim@lge.com> wrote: > > > Could you try below patch to check who causes the hang? > > > > > > And, if sysalt-t works when hang, could you get sysalt-t output? I haven't > > > used it before but Paul could find some culprit on it. :) > > > > > > Thanks. > > > > > > > > > ----->8----- > > > diff --git a/mm/slab.c b/mm/slab.c > > > index 763096a..9652d38 100644 > > > --- a/mm/slab.c > > > +++ b/mm/slab.c > > > @@ -964,8 +964,13 @@ static int setup_kmem_cache_node(struct kmem_cache *cachep, > > > * guaranteed to be valid until irq is re-enabled, because it will be > > > * freed after synchronize_sched(). > > > */ > > > - if (force_change) > > > + if (force_change) { > > > + if (num_online_cpus() > 1) > > > + dump_stack(); > > > synchronize_sched(); > > > + if (num_online_cpus() > 1) > > > + dump_stack(); > > > + } > > > > I've only added the first one, as I would never see the second one. All of > > this happens before the serial console is activated, earlycon is not supported, > > and I only have remote access. > > > > Brought up 2 CPUs > > SMP: Total of 2 processors activated (2132.00 BogoMIPS). > > CPU: All CPU(s) started in SVC mode. > > CPU: 0 PID: 1 Comm: swapper/0 Not tainted > > 4.7.0-rc4-kzm9d-00404-g4a235e6dde4404dd-dirty #89 > > Hardware name: Generic Emma Mobile EV2 (Flattened Device Tree) > > [<c010de68>] (unwind_backtrace) from [<c010a658>] (show_stack+0x10/0x14) > > [<c010a658>] (show_stack) from [<c02b5cf8>] (dump_stack+0x7c/0x9c) > > [<c02b5cf8>] (dump_stack) from [<c01cfa4c>] (setup_kmem_cache_node+0x140/0x170) > > [<c01cfa4c>] (setup_kmem_cache_node) from [<c01cfe3c>] > > (__do_tune_cpucache+0xf4/0x114) > > [<c01cfe3c>] (__do_tune_cpucache) from [<c01cff54>] (enable_cpucache+0xf8/0x148) > > [<c01cff54>] (enable_cpucache) from [<c01d0190>] > > (__kmem_cache_create+0x1a8/0x1d0) > > [<c01d0190>] (__kmem_cache_create) from [<c01b32d0>] > > (kmem_cache_create+0xbc/0x190) > > [<c01b32d0>] (kmem_cache_create) from [<c070d968>] (shmem_init+0x34/0xb0) > > [<c070d968>] (shmem_init) from [<c0700cc8>] (kernel_init_freeable+0x98/0x1ec) > > [<c0700cc8>] (kernel_init_freeable) from [<c049fdbc>] (kernel_init+0x8/0x110) > > [<c049fdbc>] (kernel_init) from [<c0106cb8>] (ret_from_fork+0x14/0x3c) > > devtmpfs: initialized > > I don't see anything here that would prevent grace periods from completing. > > The CPUs are using the normal hotplug sequence to come online, correct? And either way, could you please apply the patch below and then invoke rcu_dump_rcu_sched_tree() just before the offending call to synchronize_sched()? That will tell me what CPUs RCU believes exist, and perhaps also which CPU is holding it up. Thanx, Paul
diff --git a/mm/slab.c b/mm/slab.c index 763096a..9652d38 100644 --- a/mm/slab.c +++ b/mm/slab.c @@ -964,8 +964,13 @@ static int setup_kmem_cache_node(struct kmem_cache *cachep, * guaranteed to be valid until irq is re-enabled, because it will be * freed after synchronize_sched(). */ - if (force_change) + if (force_change) { + if (num_online_cpus() > 1) + dump_stack(); synchronize_sched(); + if (num_online_cpus() > 1) + dump_stack(); + } fail: kfree(old_shared);