On Tue, Apr 7, 2020 at 2:25 AM Naresh Kamboju naresh.kamboju@linaro.org wrote:
On Wed, 11 Mar 2020 at 02:16, Brendan Higgins brendanhiggins@google.com wrote:
> > > > > Steps reproduce by using kselftests, > > > > > > > > > > - lsmod || true > > > > > - cd /opt/kselftests/default-in-kernel/lib/ > > > > > - export PATH=/opt/kselftests/default-in-kernel/kselftest:$PATH > > > > > - ./printf.sh || true > > > > > - ./bitmap.sh || true > > > > > - ./prime_numbers.sh || true > > > > > - ./strscpy.sh || true > > > > > > > > > > x86_64 kernel BUG dump. > > > > > + ./printf.sh > > > > > > Oops, I am wondering if I broke this with my change "Revert "software > > > node: Simplify software_node_release() function"": > > > > > > https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git/commit/?... > > > > > > I am still investigating, will update later. > > > > Okay, yeah, I am pretty sure I caused the breakage. I got an email > > from kernel test robot a couple days ago that I didn't see: > > > > https://lists.01.org/hyperkitty/list/lkp@lists.01.org/thread/N3ZN5XH7HK24JVE... > > > > It shows the same breakage after applying this change. > > > > I am still investigating how my change broke it, nevertheless. > > As nodes in the tree are being removed, the code before the patch that > "simplified" the software_node_release() function accessed the node's parent > in its release function. > > And if CONFIG_DEBUG_KOBJECT_RELEASE is defined, the release functions are no > longer necessarily called in order, leading to referencing released memory. > Oops! > > So Heikki's patch actually fixed a bug. :-)
Well, I think it just hid the problem. It looks like the core (lib/kobject.c) allows the parent kobject to be released before the last child kobject is released. To be honest, that does not sound right to me...
I think we can workaround this problem by taking reference to the parent when the child is added, and then releasing it when the child is released, and in that way be guaranteed that the parent will not disappear before the child is fully released, but that still does not feel right. It feels more like the core is not doing it's job to me. The parent just should not be released before its children.
Either I'm wrong about that, and we still should take the reference on the parent, or we revert my patch like Brendan proposed and then fix
Either way, isn't it wrong to release the node ID before deleting the sysfs entry? I am not sure that my fix was the correct one, but I believe the bug that Heidi and I found is actually a bug.
I agree.
the core with something like this (warning, I did not even try to compile that):
I will try it out.
diff --git a/lib/kobject.c b/lib/kobject.c index 83198cb37d8d..ec5774992337 100644 --- a/lib/kobject.c +++ b/lib/kobject.c @@ -680,6 +680,12 @@ static void kobject_cleanup(struct kobject *kobj) kobject_uevent(kobj, KOBJ_REMOVE); }
if (t && t->release) {pr_debug("kobject: '%s' (%p): calling ktype release\n",kobject_name(kobj), kobj);t->release(kobj);}/* remove from sysfs if the caller did not do it */ if (kobj->state_in_sysfs) { pr_debug("kobject: '%s' (%p): auto cleanup kobject_del\n",@@ -687,12 +693,6 @@ static void kobject_cleanup(struct kobject *kobj) kobject_del(kobj); }
if (t && t->release) {pr_debug("kobject: '%s' (%p): calling ktype release\n",kobject_name(kobj), kobj);t->release(kobj);}/* free name if we allocated it */ if (name) { pr_debug("kobject: '%s': free name\n", name);Alright, so I tried it and it looks like Heikki's suggestion worked.
Is everyone comfortable going this route?
Hold on. Another way to fix the problem is to increment the parent's reference count before that kobject_del(kobj) is called, and then decrementing it after t->release(kobj) is called. It may be safer to fix the problem like that.
Right, this was your first suggestion above, right? That actually made more sense to me, but you seemed skeptical of it due to it being messier, which makes sense.
Nevertheless, having children take a reference seems like the right thing to do because the children need to degregister themselves from the parent. Calling t->release() ahead of kobject_del() seems to reintroduce the problem that I pointed out, albeit *much* more briefly. If I understand correctly, it is always wrong to have a sysfs entry that points to a partially deallocated kobject. Please correct me if I am wrong.
So I think there are two solutions: Either we have to ensure that each child is deallocated first so we can preserve the kobject_del() and then t->release() ordering, or we have to add some sort of "locking" mechanism to prevent the kobject from being accessed by anything other than the deallocation code until it is fully deallocated; well, it would have to prevent any access at all :-). I think it goes without saying that this "locking" idea is pretty flawed.
The problem with just having children take a reference is that the kobject children already take a reference to their parent, so it seems like the kobject should be smart enough to deallocate children rather than having swnode have to keep a separate tally of children, no?
Sorry if this all seems obvious, I am not an expert on this part of the kernel.
My example above proofs that there is the problem, but it changes the order of execution which I think can always have other consequences.
Also, should I send this fix as a separate patch? Or do people want me to send an updated revision of my revert patch with the fix?
This needs to be send in its own separate patch. Ideally it could be send together with the revert in the same series, but I'm not sure that's possible anymore. Didn't Greg pick the revert already?
Sounds good.
I did already let Greg know when he emailed us on backporting the patch to stable, and he acked saying he removed them. So as long as these are not in the queue for 5.6 (it is not in Linus' tree yet), we should be good.
The reported bug is still noticed on Linux mainline master branch The Kernel BUG noticed on x86_64 and i386 running selftest on Linux mainline kernel 5.6.0.
Oh sorry, I thought that this patch was dropped from the maintainer's for-next branch.
Heikki, what do you think about my suggestion of having kobject deallocate its children?
In the meantime, are people cool with the patch that Heikki proposed as a temporary mitigation? I think my solution might be a bit more involved. If I don't hear anything back, I will send out Heikki's suggestion as a patch.
Linux version 5.6.0 (oe-user@oe-host) (gcc version 7.3.0 (GCC)) #1 SMP Mon Apr 6 17:25:26 UTC 2020 <> [ 270.580905] BUG: kernel NULL pointer dereference, address: 0000000000000000 [ 270.588978] #PF: supervisor read access in kernel mode [ 270.594114] #PF: error_code(0x0000) - not-present page [ 270.599247] PGD 800000026b340067 P4D 800000026b340067 PUD 26b34e067 PMD 0 [ 270.606119] Oops: 0000 [#1] SMP PTI [ 270.609604] CPU: 1 PID: 4688 Comm: modprobe Tainted: G W 5.6.0 #1 [ 270.616996] Hardware name: Supermicro SYS-5019S-ML/X11SSH-F, BIOS 2.2 05/23/2018 [ 270.624381] RIP: 0010:ida_free+0x76/0x140 [ 270.628391] Code: 45 d0 00 00 00 00 48 89 45 b0 0f 88 c4 00 00 00 89 f3 e8 0d 51 02 00 48 8d 7d a8 49 89 c6 e8 e1 04 01 00 a8 01 49 89 c5 75 42 <4c> 0f a3 20 72 76 48 8b 7d a8 4c 89 f6 e8 18 53 02 00 89 de 48 c7 [ 270.647128] RSP: 0018:ffffbd8841d07a50 EFLAGS: 00010046 [ 270.652346] RAX: 0000000000000000 RBX: 0000000000000000 RCX: ffff978be6ac48c0 [ 270.659468] RDX: 0000000000000000 RSI: ffff978beb346780 RDI: ffff978be6ac5138 [ 270.666595] RBP: ffffbd8841d07aa8 R08: 0000000000000001 R09: 0000000000000000 [ 270.673725] R10: 0000000000000001 R11: 0000000000000000 R12: 0000000000000000 [ 270.680850] R13: 0000000000000000 R14: 0000000000000246 R15: ffffffffc0383b3c [ 270.687973] FS: 00007fc8e92c2740(0000) GS:ffff978befa80000(0000) knlGS:0000000000000000 [ 270.696052] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 270.701790] CR2: 0000000000000000 CR3: 000000021f2b0003 CR4: 00000000003606e0 [ 270.708920] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [ 270.716043] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [ 270.723169] Call Trace: [ 270.725618] software_node_release+0x2b/0xb0 [ 270.729886] kobject_put+0xad/0x1c0 [ 270.733378] kobject_del+0x4a/0x60 [ 270.736776] kobject_put+0x92/0x1c0 [ 270.740270] fwnode_remove_software_node+0x32/0x40 [ 270.745061] software_node_unregister_nodes+0x2a/0x50 [ 270.750114] test_printf_init+0xf30/0x1c16 [test_printf] [ 270.755422] ? test_hashed+0x75/0x75 [test_printf] [ 270.760211] ? test_hashed+0x75/0x75 [test_printf] [ 270.765003] do_one_initcall+0x61/0x2f0 [ 270.768842] ? rcu_read_lock_sched_held+0x4f/0x80 [ 270.773541] ? kmem_cache_alloc_trace+0x282/0x2b0 [ 270.778247] do_init_module+0x5f/0x22b [ 270.781999] load_module+0x24e6/0x2ac0 [ 270.785754] ? security_kernel_post_read_file+0x3f/0x60 [ 270.790979] __do_sys_finit_module+0xfc/0x120 [ 270.795334] ? __do_sys_finit_module+0xfc/0x120 [ 270.799862] __x64_sys_finit_module+0x1a/0x20 [ 270.804219] do_syscall_64+0x55/0x200 [ 270.807885] entry_SYSCALL_64_after_hwframe+0x49/0xb3 [ 270.812938] RIP: 0033:0x7fc8e8bcaf59 [ 270.816516] Code: 00 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 0f ff 2b 00 f7 d8 64 89 01 48 [ 270.835253] RSP: 002b:00007ffe9a4fb6f8 EFLAGS: 00000202 ORIG_RAX: 0000000000000139 [ 270.842810] RAX: ffffffffffffffda RBX: 0000000000cdfaf0 RCX: 00007fc8e8bcaf59 [ 270.849934] RDX: 0000000000000000 RSI: 0000000000418cce RDI: 0000000000000005 [ 270.857057] RBP: 0000000000418cce R08: 0000000000000000 R09: 0000000000000000 [ 270.864180] R10: 0000000000000005 R11: 0000000000000202 R12: 0000000000000000 [ 270.871306] R13: 0000000000040000 R14: 0000000000000000 R15: 0000000000000000 [ 270.878433] Modules linked in: test_printf(+) cls_bpf sch_fq 8021q sch_ingress veth algif_hash x86_pkg_temp_thermal fuse [last unloaded: gpio_mockup] [ 270.891812] CR2: 0000000000000000 [ 270.895130] ---[ end trace 151cfe414205f0bc ]--- [ 270.899742] RIP: 0010:ida_free+0x76/0x140 [ 270.903752] Code: 45 d0 00 00 00 00 48 89 45 b0 0f 88 c4 00 00 00 89 f3 e8 0d 51 02 00 48 8d 7d a8 49 89 c6 e8 e1 04 01 00 a8 01 49 89 c5 75 42 <4c> 0f a3 20 72 76 48 8b 7d a8 4c 89 f6 e8 18 53 02 00 89 de 48 c7 [ 270.922489] RSP: 0018:ffffbd8841d07a50 EFLAGS: 00010046 [ 270.927706] RAX: 0000000000000000 RBX: 0000000000000000 RCX: ffff978be6ac48c0 [ 270.934831] RDX: 0000000000000000 RSI: ffff978beb346780 RDI: ffff978be6ac5138 [ 270.941954] RBP: ffffbd8841d07aa8 R08: 0000000000000001 R09: 0000000000000000 [ 270.949078] R10: 0000000000000001 R11: 0000000000000000 R12: 0000000000000000 [ 270.956204] R13: 0000000000000000 R14: 0000000000000246 R15: ffffffffc0383b3c [ 270.963328] FS: 00007fc8e92c2740(0000) GS:ffff978befa80000(0000) knlGS:0000000000000000 [ 270.971414] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 270.977158] CR2: 0000000000000000 CR3: 000000021f2b0003 CR4: 00000000003606e0 [ 270.984281] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [ 270.991407] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [ 270.998540] BUG: sleeping function called from invalid context at /usr/src/kernel/include/linux/percpu-rwsem.h:49 [ 271.008782] in_atomic(): 1, irqs_disabled(): 1, non_block: 0, pid: 4688, name: modprobe [ 271.016771] INFO: lockdep is turned off. [ 271.020691] irq event stamp: 4812 [ 271.024011] hardirqs last enabled at (4811): [<ffffffffb5be42f1>] kfree+0x181/0x2e0 [ 271.031748] hardirqs last disabled at (4812): [<ffffffffb67d2b68>] _raw_spin_lock_irqsave+0x18/0x50 [ 271.040778] softirqs last enabled at (4496): [<ffffffffb6a00348>] __do_softirq+0x348/0x459 [ 271.049117] softirqs last disabled at (4487): [<ffffffffb59be298>] irq_exit+0xb8/0xc0 [ 271.056933] CPU: 1 PID: 4688 Comm: modprobe Tainted: G D W 5.6.0 #1 [ 271.064317] Hardware name: Supermicro SYS-5019S-ML/X11SSH-F, BIOS 2.2 05/23/2018 [ 271.071702] Call Trace: [ 271.074147] dump_stack+0x7a/0xa5 [ 271.077465] ___might_sleep+0x163/0x250 [ 271.081296] __might_sleep+0x4a/0x80 [ 271.084868] exit_signals+0x33/0x2f0 [ 271.088446] do_exit+0xb6/0xcd0 [ 271.091586] rewind_stack_do_exit+0x17/0x20 [ 271.095770] RIP: 0033:0x7fc8e8bcaf59 [ 271.099349] Code: 00 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 0f ff 2b 00 f7 d8 64 89 01 48 [ 271.118093] RSP: 002b:00007ffe9a4fb6f8 EFLAGS: 00000202 ORIG_RAX: 0000000000000139 [ 271.125649] RAX: ffffffffffffffda RBX: 0000000000cdfaf0 RCX: 00007fc8e8bcaf59 [ 271.132775] RDX: 0000000000000000 RSI: 0000000000418cce RDI: 0000000000000005 [ 271.139897] RBP: 0000000000418cce R08: 0000000000000000 R09: 0000000000000000 [ 271.147022] R10: 0000000000000005 R11: 0000000000000202 R12: 0000000000000000 [ 271.154146] R13: 0000000000040000 R14: 0000000000000000 R15: 0000000000000000 [ 271.161274] note: modprobe[4688] exited with preempt_count 1
Full test log: https://lkft.validation.linaro.org/scheduler/job/1341945#L8386 https://lkft.validation.linaro.org/scheduler/job/1341969#L8023
- Naresh