Return-Path: <linux-kernel-owner@vger.kernel.org>
Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand
	id S1753675AbbBMQRT (ORCPT <rfc822;w@1wt.eu>);
	Fri, 13 Feb 2015 11:17:19 -0500
Received: from cantor2.suse.de ([195.135.220.15]:35113 "EHLO mx2.suse.de"
	rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP
	id S1752848AbbBMQRP (ORCPT <rfc822;linux-kernel@vger.kernel.org>);
	Fri, 13 Feb 2015 11:17:15 -0500
Date: Fri, 13 Feb 2015 17:17:10 +0100 (CET)
From: Miroslav Benes <mbenes@suse.cz>
To: Josh Poimboeuf <jpoimboe@redhat.com>
cc: Jiri Slaby <jslaby@suse.cz>, Seth Jennings <sjenning@redhat.com>,
        Jiri Kosina <jkosina@suse.cz>, Vojtech Pavlik <vojtech@suse.cz>,
        Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com>,
        live-patching@vger.kernel.org, linux-kernel@vger.kernel.org
Subject: Re: [RFC PATCH 8/9] livepatch: allow patch modules to be removed
In-Reply-To: <20150213160441.GG27180@treble.redhat.com>
Message-ID: <alpine.LNX.2.00.1502131709520.14133@pobox.suse.cz>
References: <cover.1423499826.git.jpoimboe@redhat.com> <5a1f98566264a40895704d553e9acf8cfda0659c.1423499826.git.jpoimboe@redhat.com> <54DA55CA.3080408@suse.cz> <alpine.LNX.2.00.1502121618160.16826@pobox.suse.cz> <20150213160441.GG27180@treble.redhat.com>
User-Agent: Alpine 2.00 (LNX 1167 2008-08-23)
MIME-Version: 1.0
Content-Type: TEXT/PLAIN; charset=US-ASCII
Sender: linux-kernel-owner@vger.kernel.org
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org
Content-Length: 7580
Lines: 153

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 linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/