debugobject: Prevent init race with static objects

Message ID 87zg7dzgao.ffs@tglx
State New
Headers
Series debugobject: Prevent init race with static objects |

Commit Message

Thomas Gleixner April 12, 2023, 7:54 a.m. UTC
  Statically initialized objects are usually not initialized via the init()
function of the subsystem. They are special cased and the subsystem
provides a function to validate whether an object which is not yet tracked
by debugobjects is statically initialized. This means the object is started
to be tracked on first use, e.g. activation.

This works perfectly fine, unless there are two concurrent operations on
that object. Schspa decoded the problem:

T0 	          	    	    T1

debug_object_assert_init(addr)
  lock_hash_bucket()
  obj = lookup_object(addr);
  if (!obj) {
  	unlock_hash_bucket();
	- > preemption
			            lock_subsytem_object(addr);
				      activate_object(addr)
				      lock_hash_bucket();
				      obj = lookup_object(addr);
				      if (!obj) {
				    	unlock_hash_bucket();
					if (is_static_object(addr))
					   init_and_track(addr);
				      lock_hash_bucket();
				      obj = lookup_object(addr);
				      obj->state = ACTIVATED;
				      unlock_hash_bucket();

				    subsys function modifies content of addr,
				    so static object detection does
				    not longer work.

				    unlock_subsytem_object(addr);
				    
        if (is_static_object(addr)) <- Fails

	  debugobject emits a warning and invokes the fixup function which
	  reinitializes the already active object in the worst case.

This race exists forever, but was never observed until mod_timer() got a
debug_object_assert_init() added which is outside of the timer base lock
held section right at the beginning of the function to cover the lockless
early exit points too.

Rework the code so that the lookup, the static object check and the
tracking object association happens atomically under the hash bucket
lock. This prevents the issue completely as all callers are serialized on
the hash bucket lock and therefore cannot observe inconsistent state.

Fixes: 3ac7fe5a4aab ("infrastructure to debug (dynamic) objects")
Reported-by: syzbot+5093ba19745994288b53@syzkaller.appspotmail.com
Debugged-by: Schspa Shi <schspa@gmail.com>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Link: https://syzkaller.appspot.com/bug?id=22c8a5938eab640d1c6bcc0e3dc7be519d878462
Link: https://lore.kernel.org/lkml/20230303161906.831686-1-schspa@gmail.com
---
 lib/debugobjects.c |  125 +++++++++++++++++++++++++++--------------------------
 1 file changed, 66 insertions(+), 59 deletions(-)
  

Comments

Stephen Boyd April 13, 2023, 12:17 a.m. UTC | #1
Quoting Thomas Gleixner (2023-04-12 00:54:39)
> Statically initialized objects are usually not initialized via the init()
> function of the subsystem. They are special cased and the subsystem
[...]
>
> Rework the code so that the lookup, the static object check and the
> tracking object association happens atomically under the hash bucket
> lock. This prevents the issue completely as all callers are serialized on
> the hash bucket lock and therefore cannot observe inconsistent state.
>
> Fixes: 3ac7fe5a4aab ("infrastructure to debug (dynamic) objects")
> Reported-by: syzbot+5093ba19745994288b53@syzkaller.appspotmail.com
> Debugged-by: Schspa Shi <schspa@gmail.com>
> Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
> Link: https://syzkaller.appspot.com/bug?id=22c8a5938eab640d1c6bcc0e3dc7be519d878462
> Link: https://lore.kernel.org/lkml/20230303161906.831686-1-schspa@gmail.com
> ---

Reviewed-by: Stephen Boyd <swboyd@chromium.org>

Tiny nitpick below

>
> --- a/lib/debugobjects.c
> +++ b/lib/debugobjects.c
> @@ -698,24 +723,16 @@ int debug_object_activate(void *addr, co
>
>         raw_spin_unlock_irqrestore(&db->lock, flags);
>
> -       /*
> -        * We are here when a static object is activated. We
> -        * let the type specific code confirm whether this is
> -        * true or not. if true, we just make sure that the
> -        * static object is tracked in the object tracker. If
> -        * not, this must be a bug, so we try to fix it up.
> -        */
> -       if (descr->is_static_object && descr->is_static_object(addr)) {
> -               /* track this static object */
> -               debug_object_init(addr, descr);
> -               debug_object_activate(addr, descr);
> -       } else {
> -               debug_print_object(&o, "activate");
> -               ret = debug_object_fixup(descr->fixup_activate, addr,
> -                                       ODEBUG_STATE_NOTAVAILABLE);
> -               return ret ? 0 : -EINVAL;
> +       /* If NULL the allocaction has hit OOM */

s/allocaction/allocation/

Or is this "alloc action"? Or should it be "lookup_object_or_alloc() has
hit OOM"?

> +       if (!obj) {
> +               debug_objects_oom();
> +               return 0;
>         }
> -       return 0;
> +
> +       /* Object is neither static nor tracked. It's not initialized */
> +       debug_print_object(&o, "activate");
> +       ret = debug_object_fixup(descr->fixup_activate, addr, ODEBUG_STATE_NOTAVAILABLE);
> +       return ret ? 0 : -EINVAL;
>  }
>  EXPORT_SYMBOL_GPL(debug_object_activate);
>
> @@ -879,31 +897,20 @@ void debug_object_assert_init(void *addr
>         db = get_bucket((unsigned long) addr);
>
>         raw_spin_lock_irqsave(&db->lock, flags);
> +       obj = lookup_object_or_alloc(addr, db, descr, false, true);
> +       raw_spin_unlock_irqrestore(&db->lock, flags);
> +       if (likely(!IS_ERR_OR_NULL(obj)))
> +               return;
>
> -       obj = lookup_object(addr, db);
> +       /* If NULL the allocaction has hit OOM */

Same comment.
  
Thomas Gleixner April 13, 2023, 12:14 p.m. UTC | #2
On Wed, Apr 12 2023 at 17:17, Stephen Boyd wrote:
> Quoting Thomas Gleixner (2023-04-12 00:54:39)
>> +       /* If NULL the allocaction has hit OOM */
>
> s/allocaction/allocation/

That's what I probably wanted to type.

>> -       obj = lookup_object(addr, db);
>> +       /* If NULL the allocaction has hit OOM */
>
> Same comment.

The wonders of copy & pasta!

Thanks for the review!

       tglx
  
Ido Schimmel May 1, 2023, 1:40 p.m. UTC | #3
On Wed, Apr 12, 2023 at 09:54:39AM +0200, Thomas Gleixner wrote:
> Statically initialized objects are usually not initialized via the init()
> function of the subsystem. They are special cased and the subsystem
> provides a function to validate whether an object which is not yet tracked
> by debugobjects is statically initialized. This means the object is started
> to be tracked on first use, e.g. activation.
> 
> This works perfectly fine, unless there are two concurrent operations on
> that object. Schspa decoded the problem:

[...]

> This race exists forever, but was never observed until mod_timer() got a
> debug_object_assert_init() added which is outside of the timer base lock
> held section right at the beginning of the function to cover the lockless
> early exit points too.
> 
> Rework the code so that the lookup, the static object check and the
> tracking object association happens atomically under the hash bucket
> lock. This prevents the issue completely as all callers are serialized on
> the hash bucket lock and therefore cannot observe inconsistent state.
> 
> Fixes: 3ac7fe5a4aab ("infrastructure to debug (dynamic) objects")
> Reported-by: syzbot+5093ba19745994288b53@syzkaller.appspotmail.com
> Debugged-by: Schspa Shi <schspa@gmail.com>
> Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
> Link: https://syzkaller.appspot.com/bug?id=22c8a5938eab640d1c6bcc0e3dc7be519d878462
> Link: https://lore.kernel.org/lkml/20230303161906.831686-1-schspa@gmail.com

Thomas,

With this patch we see the following warning in the kernel log during
boot:

"ODEBUG: Out of memory. ODEBUG disabled"

In which case, the stats are:

# cat /sys/kernel/debug/debug_objects/stats
max_chain     :24
max_checked   :37
warnings      :0
fixups        :0
pool_free     :4297
pool_pcp_free :84
pool_min_free :0
pool_used     :0
pool_max_used :6615
on_free_list  :0
objs_allocated:15616
objs_freed    :11319


If I revert this patch, the warning disappears and I see the following
stats:

# cat /sys/kernel/debug/debug_objects/stats
max_chain     :25
max_checked   :40
warnings      :0
fixups        :0
pool_free     :1219
pool_pcp_free :209
pool_min_free :289
pool_used     :1578
pool_max_used :8026
on_free_list  :0
objs_allocated:32304
objs_freed    :29507

The following diff seems to solve the problem for me:

diff --git a/lib/debugobjects.c b/lib/debugobjects.c
index b796799fadb2..af4bd66c571c 100644
--- a/lib/debugobjects.c
+++ b/lib/debugobjects.c
@@ -21,7 +21,7 @@
 #define ODEBUG_HASH_BITS       14
 #define ODEBUG_HASH_SIZE       (1 << ODEBUG_HASH_BITS)
 
-#define ODEBUG_POOL_SIZE       1024
+#define ODEBUG_POOL_SIZE       (16 * 1024)
 #define ODEBUG_POOL_MIN_LEVEL  256
 #define ODEBUG_POOL_PERCPU_SIZE        64
 #define ODEBUG_BATCH_SIZE      16

In which case, the stats are:

# cat /sys/kernel/debug/debug_objects/stats 
max_chain     :28
max_checked   :64
warnings      :0
fixups        :0
pool_free     :14789
pool_pcp_free :192
pool_min_free :8120
pool_used     :1595
pool_max_used :8264
on_free_list  :0
objs_allocated:16384
objs_freed    :0

I'm not familiar with the debugobjects code, but maybe it makes sense to
make "ODEBUG_POOL_SIZE" configurable via Kconfig in a similar fashion to
"CONFIG_DEBUG_KMEMLEAK_MEM_POOL_SIZE"?

Please let me know if more information is required or if you want me to
test a patch.

Thanks
  
Thomas Gleixner May 1, 2023, 3:42 p.m. UTC | #4
Ido!

On Mon, May 01 2023 at 16:40, Ido Schimmel wrote:
> On Wed, Apr 12, 2023 at 09:54:39AM +0200, Thomas Gleixner wrote:
> With this patch we see the following warning in the kernel log during
> boot:
>
> "ODEBUG: Out of memory. ODEBUG disabled"
...

> The following diff seems to solve the problem for me:
>
> diff --git a/lib/debugobjects.c b/lib/debugobjects.c
> index b796799fadb2..af4bd66c571c 100644
> --- a/lib/debugobjects.c
> +++ b/lib/debugobjects.c
> @@ -21,7 +21,7 @@
>  #define ODEBUG_HASH_BITS       14
>  #define ODEBUG_HASH_SIZE       (1 << ODEBUG_HASH_BITS)
>  
> -#define ODEBUG_POOL_SIZE       1024
> +#define ODEBUG_POOL_SIZE       (16 * 1024)

That's a big hammer :)

> I'm not familiar with the debugobjects code, but maybe it makes sense to
> make "ODEBUG_POOL_SIZE" configurable via Kconfig in a similar fashion to
> "CONFIG_DEBUG_KMEMLEAK_MEM_POOL_SIZE"?

I don't think so.

The change in that patch is neither debug_objects_activate() nor
debug_objecs_assert_init() no longer invoke debug_object_init() which is
now the only place doing pool refills. So depending on the number of
statically allocated objects this might deplete the pool quick enough.

Does the patch below restore the old behaviour?

Thanks,

        tglx
---
diff --git a/lib/debugobjects.c b/lib/debugobjects.c
index b796799fadb2..003edc5ebd67 100644
--- a/lib/debugobjects.c
+++ b/lib/debugobjects.c
@@ -587,6 +587,16 @@ static struct debug_obj *lookup_object_or_alloc(void *addr, struct debug_bucket
 	return NULL;
 }
 
+static void debug_objects_fill_pool(void)
+{
+	/*
+	 * On RT enabled kernels the pool refill must happen in preemptible
+	 * context:
+	 */
+	if (!IS_ENABLED(CONFIG_PREEMPT_RT) || preemptible())
+		fill_pool();
+}
+
 static void
 __debug_object_init(void *addr, const struct debug_obj_descr *descr, int onstack)
 {
@@ -595,12 +605,7 @@ __debug_object_init(void *addr, const struct debug_obj_descr *descr, int onstack
 	struct debug_obj *obj;
 	unsigned long flags;
 
-	/*
-	 * On RT enabled kernels the pool refill must happen in preemptible
-	 * context:
-	 */
-	if (!IS_ENABLED(CONFIG_PREEMPT_RT) || preemptible())
-		fill_pool();
+	debug_objects_fill_pool();
 
 	db = get_bucket((unsigned long) addr);
 
@@ -685,6 +690,8 @@ int debug_object_activate(void *addr, const struct debug_obj_descr *descr)
 	if (!debug_objects_enabled)
 		return 0;
 
+	debug_objects_fill_pool();
+
 	db = get_bucket((unsigned long) addr);
 
 	raw_spin_lock_irqsave(&db->lock, flags);
@@ -894,6 +901,8 @@ void debug_object_assert_init(void *addr, const struct debug_obj_descr *descr)
 	if (!debug_objects_enabled)
 		return;
 
+	debug_objects_fill_pool();
+
 	db = get_bucket((unsigned long) addr);
 
 	raw_spin_lock_irqsave(&db->lock, flags);
  
Ido Schimmel May 2, 2023, 5:53 a.m. UTC | #5
On Mon, May 01, 2023 at 05:42:06PM +0200, Thomas Gleixner wrote:
> The change in that patch is neither debug_objects_activate() nor
> debug_objecs_assert_init() no longer invoke debug_object_init() which is
> now the only place doing pool refills. So depending on the number of
> statically allocated objects this might deplete the pool quick enough.
> 
> Does the patch below restore the old behaviour?

Yes. Couldn't reproduce the issue with the proposed fix. Feel free to
add:

Tested-by: Ido Schimmel <idosch@nvidia.com>

Thanks for the quick fix!
  

Patch

--- a/lib/debugobjects.c
+++ b/lib/debugobjects.c
@@ -216,10 +216,6 @@  static struct debug_obj *__alloc_object(
 	return obj;
 }
 
-/*
- * Allocate a new object. If the pool is empty, switch off the debugger.
- * Must be called with interrupts disabled.
- */
 static struct debug_obj *
 alloc_object(void *addr, struct debug_bucket *b, const struct debug_obj_descr *descr)
 {
@@ -552,11 +548,49 @@  static void debug_object_is_on_stack(voi
 	WARN_ON(1);
 }
 
+static struct debug_obj *lookup_object_or_alloc(void *addr, struct debug_bucket *b,
+						const struct debug_obj_descr *descr,
+						bool onstack, bool alloc_ifstatic)
+{
+	struct debug_obj *obj = lookup_object(addr, b);
+	enum debug_obj_state state = ODEBUG_STATE_NONE;
+
+	if (likely(obj))
+		return obj;
+
+	/*
+	 * debug_object_init() unconditionally allocates untracked
+	 * objects. It does not matter whether it is a static object or
+	 * not.
+	 *
+	 * debug_object_assert_init() and debug_object_activate() allow
+	 * allocation only if the descriptor callback confirms that the
+	 * object is static and considered initialized. For non-static
+	 * objects the allocation needs to be done from the fixup callback.
+	 */
+	if (unlikely(alloc_ifstatic)) {
+		if (!descr->is_static_object || !descr->is_static_object(addr))
+			return ERR_PTR(-ENOENT);
+		/* Statically allocated objects are considered initialized */
+		state = ODEBUG_STATE_INIT;
+	}
+
+	obj = alloc_object(addr, b, descr);
+	if (likely(obj)) {
+		obj->state = state;
+		debug_object_is_on_stack(addr, onstack);
+		return obj;
+	}
+
+	/* Out of memory. Do the cleanup outside of the locked region */
+	debug_objects_enabled = 0;
+	return NULL;
+}
+
 static void
 __debug_object_init(void *addr, const struct debug_obj_descr *descr, int onstack)
 {
 	enum debug_obj_state state;
-	bool check_stack = false;
 	struct debug_bucket *db;
 	struct debug_obj *obj;
 	unsigned long flags;
@@ -572,16 +606,11 @@  static void
 
 	raw_spin_lock_irqsave(&db->lock, flags);
 
-	obj = lookup_object(addr, db);
-	if (!obj) {
-		obj = alloc_object(addr, db, descr);
-		if (!obj) {
-			debug_objects_enabled = 0;
-			raw_spin_unlock_irqrestore(&db->lock, flags);
-			debug_objects_oom();
-			return;
-		}
-		check_stack = true;
+	obj = lookup_object_or_alloc(addr, db, descr, onstack, false);
+	if (unlikely(!obj)) {
+		raw_spin_unlock_irqrestore(&db->lock, flags);
+		debug_objects_oom();
+		return;
 	}
 
 	switch (obj->state) {
@@ -607,8 +636,6 @@  static void
 	}
 
 	raw_spin_unlock_irqrestore(&db->lock, flags);
-	if (check_stack)
-		debug_object_is_on_stack(addr, onstack);
 }
 
 /**
@@ -648,14 +675,12 @@  EXPORT_SYMBOL_GPL(debug_object_init_on_s
  */
 int debug_object_activate(void *addr, const struct debug_obj_descr *descr)
 {
+	struct debug_obj o = { .object = addr, .state = ODEBUG_STATE_NOTAVAILABLE, .descr = descr };
 	enum debug_obj_state state;
 	struct debug_bucket *db;
 	struct debug_obj *obj;
 	unsigned long flags;
 	int ret;
-	struct debug_obj o = { .object = addr,
-			       .state = ODEBUG_STATE_NOTAVAILABLE,
-			       .descr = descr };
 
 	if (!debug_objects_enabled)
 		return 0;
@@ -664,8 +689,8 @@  int debug_object_activate(void *addr, co
 
 	raw_spin_lock_irqsave(&db->lock, flags);
 
-	obj = lookup_object(addr, db);
-	if (obj) {
+	obj = lookup_object_or_alloc(addr, db, descr, false, true);
+	if (likely(!IS_ERR_OR_NULL(obj))) {
 		bool print_object = false;
 
 		switch (obj->state) {
@@ -698,24 +723,16 @@  int debug_object_activate(void *addr, co
 
 	raw_spin_unlock_irqrestore(&db->lock, flags);
 
-	/*
-	 * We are here when a static object is activated. We
-	 * let the type specific code confirm whether this is
-	 * true or not. if true, we just make sure that the
-	 * static object is tracked in the object tracker. If
-	 * not, this must be a bug, so we try to fix it up.
-	 */
-	if (descr->is_static_object && descr->is_static_object(addr)) {
-		/* track this static object */
-		debug_object_init(addr, descr);
-		debug_object_activate(addr, descr);
-	} else {
-		debug_print_object(&o, "activate");
-		ret = debug_object_fixup(descr->fixup_activate, addr,
-					ODEBUG_STATE_NOTAVAILABLE);
-		return ret ? 0 : -EINVAL;
+	/* If NULL the allocaction has hit OOM */
+	if (!obj) {
+		debug_objects_oom();
+		return 0;
 	}
-	return 0;
+
+	/* Object is neither static nor tracked. It's not initialized */
+	debug_print_object(&o, "activate");
+	ret = debug_object_fixup(descr->fixup_activate, addr, ODEBUG_STATE_NOTAVAILABLE);
+	return ret ? 0 : -EINVAL;
 }
 EXPORT_SYMBOL_GPL(debug_object_activate);
 
@@ -869,6 +886,7 @@  EXPORT_SYMBOL_GPL(debug_object_free);
  */
 void debug_object_assert_init(void *addr, const struct debug_obj_descr *descr)
 {
+	struct debug_obj o = { .object = addr, .state = ODEBUG_STATE_NOTAVAILABLE, .descr = descr };
 	struct debug_bucket *db;
 	struct debug_obj *obj;
 	unsigned long flags;
@@ -879,31 +897,20 @@  void debug_object_assert_init(void *addr
 	db = get_bucket((unsigned long) addr);
 
 	raw_spin_lock_irqsave(&db->lock, flags);
+	obj = lookup_object_or_alloc(addr, db, descr, false, true);
+	raw_spin_unlock_irqrestore(&db->lock, flags);
+	if (likely(!IS_ERR_OR_NULL(obj)))
+		return;
 
-	obj = lookup_object(addr, db);
+	/* If NULL the allocaction has hit OOM */
 	if (!obj) {
-		struct debug_obj o = { .object = addr,
-				       .state = ODEBUG_STATE_NOTAVAILABLE,
-				       .descr = descr };
-
-		raw_spin_unlock_irqrestore(&db->lock, flags);
-		/*
-		 * Maybe the object is static, and we let the type specific
-		 * code confirm. Track this static object if true, else invoke
-		 * fixup.
-		 */
-		if (descr->is_static_object && descr->is_static_object(addr)) {
-			/* Track this static object */
-			debug_object_init(addr, descr);
-		} else {
-			debug_print_object(&o, "assert_init");
-			debug_object_fixup(descr->fixup_assert_init, addr,
-					   ODEBUG_STATE_NOTAVAILABLE);
-		}
+		debug_objects_oom();
 		return;
 	}
 
-	raw_spin_unlock_irqrestore(&db->lock, flags);
+	/* Object is neither tracked nor static. It's not initialized. */
+	debug_print_object(&o, "assert_init");
+	debug_object_fixup(descr->fixup_assert_init, addr, ODEBUG_STATE_NOTAVAILABLE);
 }
 EXPORT_SYMBOL_GPL(debug_object_assert_init);