On Fri, 13 Feb 2015, Josh Poimboeuf wrote:
> On Thu, Feb 12, 2015 at 04:22:24PM +0100, Miroslav Benes wrote:
> > On Tue, 10 Feb 2015, Jiri Slaby wrote:
> >
> > > On 02/09/2015, 06:31 PM, Josh Poimboeuf wrote:
> > > > --- a/kernel/livepatch/core.c
> > > > +++ b/kernel/livepatch/core.c
> > > ...
> > > > @@ -497,10 +500,6 @@ static struct attribute *klp_patch_attrs[] = {
> > > >
> > > > static void klp_kobj_release_patch(struct kobject *kobj)
> > > > {
> > > > - /*
> > > > - * Once we have a consistency model we'll need to module_put() the
> > > > - * patch module here. See klp_register_patch() for more details.
> > > > - */
> > >
> > > I deliberately let you write the note in there :). What happens when I
> > > leave some attribute in /sys open and you remove the module in the meantime?
> >
> > And if that attribute is <enabled> it can lead even to the deadlock. You
> > can try it yourself with the patchset applied and lockdep on. Simple
> > series of insmod, disable and rmmod of the patch.
> >
> > Just for the sake of completeness...
>
> Hm, even with Jiri Slaby's suggested fix to add the completion to the
> unregister path, I still get a lockdep warning. This looks more insidious,
> related to the locking order of a kernfs lock and the klp lock. I'll need to
> look at this some more...
Yes, I was afraid of this. Lockdep warning is a separate bug. It is caused
by taking klp_mutex in enabled_store. During rmmod klp_unregister_patch
takes klp_mutex and destroys the sysfs structure. If somebody writes to
enabled just after unregister takes the mutex and before the sysfs
removal, he would cause the deadlock, because enabled_store takes the
"sysfs lock" and then klp_mutex. That is exactly what the lockdep tells us
below.
We can look for inspiration elsewhere. Grep for s_active through git log
of the mainline offers several commits which dealt exactly with this. Will
browse through that...
> [26244.952692] ======================================================
> [26244.954469] [ INFO: possible circular locking dependency detected ]
> [26244.954469] 3.19.0-rc1+ #99 Tainted: G W E K
> [26244.954469] -------------------------------------------------------
> [26244.954469] rmmod/1270 is trying to acquire lock:
> [26244.954469] (s_active#70){++++.+}, at: [<ffffffff812fcb07>] kernfs_remove+0x27/0x40
> [26244.954469]
> [26244.954469] but task is already holding lock:
> [26244.954469] (klp_mutex){+.+.+.}, at: [<ffffffff81130503>] klp_unregister_patch+0x23/0xc0
> [26244.954469]
> [26244.954469] which lock already depends on the new lock.
> [26244.954469]
> [26244.954469]
> [26244.954469] the existing dependency chain (in reverse order) is:
> [26244.954469]
> -> #1 (klp_mutex){+.+.+.}:
> [26244.954469] [<ffffffff8110cfff>] lock_acquire+0xcf/0x2a0
> [26244.954469] [<ffffffff8184ea5d>] mutex_lock_nested+0x7d/0x430
> [26244.954469] [<ffffffff811303cf>] enabled_store+0x5f/0xf0
> [26244.954469] [<ffffffff8141b98f>] kobj_attr_store+0xf/0x20
> [26244.954469] [<ffffffff812fe759>] sysfs_kf_write+0x49/0x60
> [26244.954469] [<ffffffff812fe050>] kernfs_fop_write+0x140/0x1a0
> [26244.954469] [<ffffffff8126fb1a>] vfs_write+0xba/0x200
> [26244.954469] [<ffffffff8127080c>] SyS_write+0x5c/0xd0
> [26244.954469] [<ffffffff818541a9>] system_call_fastpath+0x12/0x17
> [26244.954469]
> -> #0 (s_active#70){++++.+}:
> [26244.954469] [<ffffffff8110c5de>] __lock_acquire+0x1c5e/0x1de0
> [26244.954469] [<ffffffff8110cfff>] lock_acquire+0xcf/0x2a0
> [26244.954469] [<ffffffff812fbacb>] __kernfs_remove+0x27b/0x390
> [26244.954469] [<ffffffff812fcb07>] kernfs_remove+0x27/0x40
> [26244.954469] [<ffffffff812ff041>] sysfs_remove_dir+0x51/0x90
> [26244.954469] [<ffffffff8141bbc8>] kobject_del+0x18/0x50
> [26244.954469] [<ffffffff8141bc5a>] kobject_release+0x5a/0x1c0
> [26244.954469] [<ffffffff8141bb25>] kobject_put+0x35/0x70
> [26244.954469] [<ffffffff8113056a>] klp_unregister_patch+0x8a/0xc0
> [26244.954469] [<ffffffffa034d0c5>] livepatch_exit+0x25/0xf60 [livepatch_sample]
> [26244.954469] [<ffffffff81155ddf>] SyS_delete_module+0x1cf/0x280
> [26244.954469] [<ffffffff818541a9>] system_call_fastpath+0x12/0x17
> [26244.954469]
> [26244.954469] other info that might help us debug this:
> [26244.954469]
> [26244.954469] Possible unsafe locking scenario:
> [26244.954469]
> [26244.954469] CPU0 CPU1
> [26244.954469] ---- ----
> [26244.954469] lock(klp_mutex);
> [26244.954469] lock(s_active#70);
> [26244.954469] lock(klp_mutex);
> [26244.954469] lock(s_active#70);
> [26244.954469]
> [26244.954469] *** DEADLOCK ***
> [26244.954469]
> [26244.954469] 1 lock held by rmmod/1270:
> [26244.954469] #0: (klp_mutex){+.+.+.}, at: [<ffffffff81130503>] klp_unregister_patch+0x23/0xc0
> [26244.954469]
> [26244.954469] stack backtrace:
> [26244.954469] CPU: 1 PID: 1270 Comm: rmmod Tainted: G W E K 3.19.0-rc1+ #99
> [26244.954469] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140709_153950- 04/01/2014
> [26244.954469] 0000000000000000 000000001f4deaad ffff880079877bf8 ffffffff81849fd2
> [26244.954469] 0000000000000000 ffffffff82aea9c0 ffff880079877c48 ffffffff8184710b
> [26244.954469] 00000000001d6640 ffff880079877ca8 ffff8800788525c0 ffff880078852e90
> [26244.954469] Call Trace:
> [26244.954469] [<ffffffff81849fd2>] dump_stack+0x4c/0x65
> [26244.954469] [<ffffffff8184710b>] print_circular_bug+0x202/0x213
> [26244.954469] [<ffffffff8110c5de>] __lock_acquire+0x1c5e/0x1de0
> [26244.954469] [<ffffffff81247b3d>] ? __slab_free+0xbd/0x390
> [26244.954469] [<ffffffff810e8765>] ? sched_clock_local+0x25/0x90
> [26244.954469] [<ffffffff8110cfff>] lock_acquire+0xcf/0x2a0
> [26244.954469] [<ffffffff812fcb07>] ? kernfs_remove+0x27/0x40
> [26244.954469] [<ffffffff812fbacb>] __kernfs_remove+0x27b/0x390
> [26244.954469] [<ffffffff812fcb07>] ? kernfs_remove+0x27/0x40
> [26244.954469] [<ffffffff811071cf>] ? lock_release_holdtime.part.29+0xf/0x200
> [26244.954469] [<ffffffff812fcb07>] kernfs_remove+0x27/0x40
> [26244.954469] [<ffffffff812ff041>] sysfs_remove_dir+0x51/0x90
> [26244.954469] [<ffffffff8141bbc8>] kobject_del+0x18/0x50
> [26244.954469] [<ffffffff8141bc5a>] kobject_release+0x5a/0x1c0
> [26244.954469] [<ffffffff8141bb25>] kobject_put+0x35/0x70
> [26244.954469] [<ffffffff8113056a>] klp_unregister_patch+0x8a/0xc0
> [26244.954469] [<ffffffffa034d0c5>] livepatch_exit+0x25/0xf60 [livepatch_sample]
> [26244.954469] [<ffffffff81155ddf>] SyS_delete_module+0x1cf/0x280
> [26244.954469] [<ffffffff81428a9b>] ? trace_hardirqs_on_thunk+0x3a/0x3f
> [26244.954469] [<ffffffff818541a9>] system_call_fastpath+0x12/0x17
>
>
> To recreate:
>
> insmod livepatch-sample.ko
>
> # wait for patching to complete
>
> ~/a.out & <-- simple program which opens the "enabled" file in the background
I didn't even need such a program. Lockdep warned me with sole insmod,
echo and rmmod. It is magically clever.
Miroslav
> echo 0 >/sys/kernel/livepatch/livepatch_sample/enabled
>
> # wait for unpatch to complete
>
> rmmod livepatch-sample.ko
--
To unsubscribe from this list: send the line "unsubscribe live-patching" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
