[PATCH 1/2] debugobjects: Warn wrong annotation outside bucket lock

[PATCH 1/2] debugobjects: Warn wrong annotation outside bucket lock

[Dmitry Safonov]

debugobjects checks during initialization where the real object resides.
Kernel must use debug_object_init() or debug_object_init_on_stack()
accordingly. I'm not sure if it's worth to check debug_object
initialization place, but it seems to be well-documented.

If initialization function finds that the debug object actually resides
in a different place than was annotated, warning is being printed.

Unfortunately, it becomes error-prone to use WARN() or printing under
debugobjects bucket lock: printk() may defer work to workqueue, and
realization of workqueues uses debugobjects. Further, console drivers
use page allocator, potentially vmalloc() or slub/slab. Which reasonably
makes lockdep to go nuts as there are debug_check_no_obj_freed() checks
in allocators.

Move printings out of debugobjets bucket lock to address the potential
lockups.

Link: lkml.kernel.org/r/20181211091154.GL23332@shao2-debian
Reported-by: kernel test robot <rong.a.chen@intel.com>
Cc: Andrew Morton <akpm@linux-foundation.org>
Cc: Ingo Molnar <mingo@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com>
Cc: Thomas Gleixner <tglx@linutronix.de>
Cc: Waiman Long <longman@redhat.com>
Signed-off-by: Dmitry Safonov <dima@arista.com>
---
 lib/debugobjects.c | 18 +++++++++++-------
 1 file changed, 11 insertions(+), 7 deletions(-)

diff --git a/lib/debugobjects.c b/lib/debugobjects.c
index 55437fd5128b..98968219405b 100644
--- a/lib/debugobjects.c
+++ b/lib/debugobjects.c
@@ -368,13 +368,14 @@ static void debug_object_is_on_stack(void *addr, int onstack)
 	WARN_ON(1);
 }
 
-static void
-__debug_object_init(void *addr, struct debug_obj_descr *descr, int onstack)
+static bool
+__debug_object_init(void *addr, struct debug_obj_descr *descr)
 {
 	enum debug_obj_state state;
 	struct debug_bucket *db;
 	struct debug_obj *obj;
 	unsigned long flags;
+	bool allocated = false;
 
 	fill_pool();
 
@@ -389,9 +390,9 @@ __debug_object_init(void *addr, struct debug_obj_descr *descr, int onstack)
 			debug_objects_enabled = 0;
 			raw_spin_unlock_irqrestore(&db->lock, flags);
 			debug_objects_oom();
-			return;
+			return false;
 		}
-		debug_object_is_on_stack(addr, onstack);
+		allocated = true;
 	}
 
 	switch (obj->state) {
@@ -406,7 +407,7 @@ __debug_object_init(void *addr, struct debug_obj_descr *descr, int onstack)
 		state = obj->state;
 		raw_spin_unlock_irqrestore(&db->lock, flags);
 		debug_object_fixup(descr->fixup_init, addr, state);
-		return;
+		return allocated;
 
 	case ODEBUG_STATE_DESTROYED:
 		debug_print_object(obj, "init");
@@ -416,6 +417,7 @@ __debug_object_init(void *addr, struct debug_obj_descr *descr, int onstack)
 	}
 
 	raw_spin_unlock_irqrestore(&db->lock, flags);
+	return allocated;
 }
 
 /**
@@ -428,7 +430,8 @@ void debug_object_init(void *addr, struct debug_obj_descr *descr)
 	if (!debug_objects_enabled)
 		return;
 
-	__debug_object_init(addr, descr, 0);
+	if (__debug_object_init(addr, descr))
+		debug_object_is_on_stack(addr, 0);
 }
 EXPORT_SYMBOL_GPL(debug_object_init);
 
@@ -443,7 +446,8 @@ void debug_object_init_on_stack(void *addr, struct debug_obj_descr *descr)
 	if (!debug_objects_enabled)
 		return;
 
-	__debug_object_init(addr, descr, 1);
+	if (__debug_object_init(addr, descr))
+		debug_object_is_on_stack(addr, 1);
 }
 EXPORT_SYMBOL_GPL(debug_object_init_on_stack);
 
-- 
2.20.0

[PATCH 2/2] debugobjects: Print warnings outside bucket lock

[Dmitry Safonov]

Whenever debugobjects finds invalid pattern during life time of a kernel
object such as:
-  Activation of uninitialized objects
-  Initialization of active objects
-  Usage of freed/destroyed objects
it prints a warning and tries to make fixup over an object.

Unfortunately, it becomes error-prone to use WARN() or printing under
debugobjects bucket lock: printk() may defer work to workqueue, and
realization of workqueues uses debugobjects. Further, console drivers
use page allocator, potentially vmalloc() or slub/slab. Which reasonably
makes lockdep to go nuts as there are debug_check_no_obj_freed() checks
in allocators.

Move printings out of debugobjets bucket lock to address the potential
lockups.

Link: lkml.kernel.org/r/20181211091154.GL23332@shao2-debian
Reported-by: kernel test robot <rong.a.chen@intel.com>
Cc: Andrew Morton <akpm@linux-foundation.org>
Cc: Ingo Molnar <mingo@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com>
Cc: Thomas Gleixner <tglx@linutronix.de>
Cc: Waiman Long <longman@redhat.com>
Signed-off-by: Dmitry Safonov <dima@arista.com>
---
 lib/debugobjects.c | 89 ++++++++++++++++++++++++----------------------
 1 file changed, 47 insertions(+), 42 deletions(-)

diff --git a/lib/debugobjects.c b/lib/debugobjects.c
index 98968219405b..0c92e46cb588 100644
--- a/lib/debugobjects.c
+++ b/lib/debugobjects.c
@@ -313,7 +313,7 @@ static struct debug_bucket *get_bucket(unsigned long addr)
 	return &obj_hash[hash];
 }
 
-static void debug_print_object(struct debug_obj *obj, char *msg)
+static void __debug_print_object(struct debug_obj *obj, char *msg)
 {
 	struct debug_obj_descr *descr = obj->descr;
 	static int limit;
@@ -330,6 +330,14 @@ static void debug_print_object(struct debug_obj *obj, char *msg)
 	debug_objects_warnings++;
 }
 
+#define debug_print_object(obj, msg, lock, flags)			\
+	do {								\
+		struct debug_obj tmp = *obj;				\
+									\
+		raw_spin_unlock_irqrestore(lock, flags);		\
+		__debug_print_object(&tmp, msg);			\
+	} while(0)
+
 /*
  * Try to repair the damage, so we have a better chance to get useful
  * debug output.
@@ -403,15 +411,14 @@ __debug_object_init(void *addr, struct debug_obj_descr *descr)
 		break;
 
 	case ODEBUG_STATE_ACTIVE:
-		debug_print_object(obj, "init");
 		state = obj->state;
-		raw_spin_unlock_irqrestore(&db->lock, flags);
+		debug_print_object(obj, "init", &db->lock, flags);
 		debug_object_fixup(descr->fixup_init, addr, state);
 		return allocated;
 
 	case ODEBUG_STATE_DESTROYED:
-		debug_print_object(obj, "init");
-		break;
+		debug_print_object(obj, "init", &db->lock, flags);
+		return allocated;
 	default:
 		break;
 	}
@@ -485,16 +492,14 @@ int debug_object_activate(void *addr, struct debug_obj_descr *descr)
 			break;
 
 		case ODEBUG_STATE_ACTIVE:
-			debug_print_object(obj, "activate");
 			state = obj->state;
-			raw_spin_unlock_irqrestore(&db->lock, flags);
+			debug_print_object(obj, "activate", &db->lock, flags);
 			ret = debug_object_fixup(descr->fixup_activate, addr, state);
 			return ret ? 0 : -EINVAL;
 
 		case ODEBUG_STATE_DESTROYED:
-			debug_print_object(obj, "activate");
-			ret = -EINVAL;
-			break;
+			debug_print_object(obj, "activate", &db->lock, flags);
+			return -EINVAL;
 		default:
 			ret = 0;
 			break;
@@ -516,7 +521,7 @@ int debug_object_activate(void *addr, struct debug_obj_descr *descr)
 		debug_object_init(addr, descr);
 		debug_object_activate(addr, descr);
 	} else {
-		debug_print_object(&o, "activate");
+		__debug_print_object(&o, "activate");
 		ret = debug_object_fixup(descr->fixup_activate, addr,
 					ODEBUG_STATE_NOTAVAILABLE);
 		return ret ? 0 : -EINVAL;
@@ -549,27 +554,27 @@ void debug_object_deactivate(void *addr, struct debug_obj_descr *descr)
 		case ODEBUG_STATE_INIT:
 		case ODEBUG_STATE_INACTIVE:
 		case ODEBUG_STATE_ACTIVE:
-			if (!obj->astate)
+			if (!obj->astate) {
 				obj->state = ODEBUG_STATE_INACTIVE;
-			else
-				debug_print_object(obj, "deactivate");
-			break;
-
+				break;
+			}
+			/* fallthrough */
 		case ODEBUG_STATE_DESTROYED:
-			debug_print_object(obj, "deactivate");
-			break;
+			debug_print_object(obj, "deactivate", &db->lock, flags);
+			return;
 		default:
 			break;
 		}
-	} else {
+	}
+	raw_spin_unlock_irqrestore(&db->lock, flags);
+
+	if (!obj) {
 		struct debug_obj o = { .object = addr,
 				       .state = ODEBUG_STATE_NOTAVAILABLE,
 				       .descr = descr };
 
-		debug_print_object(&o, "deactivate");
+		__debug_print_object(&o, "deactivate");
 	}
-
-	raw_spin_unlock_irqrestore(&db->lock, flags);
 }
 EXPORT_SYMBOL_GPL(debug_object_deactivate);
 
@@ -603,15 +608,14 @@ void debug_object_destroy(void *addr, struct debug_obj_descr *descr)
 		obj->state = ODEBUG_STATE_DESTROYED;
 		break;
 	case ODEBUG_STATE_ACTIVE:
-		debug_print_object(obj, "destroy");
 		state = obj->state;
-		raw_spin_unlock_irqrestore(&db->lock, flags);
+		debug_print_object(obj, "destroy", &db->lock, flags);
 		debug_object_fixup(descr->fixup_destroy, addr, state);
 		return;
 
 	case ODEBUG_STATE_DESTROYED:
-		debug_print_object(obj, "destroy");
-		break;
+		debug_print_object(obj, "destroy", &db->lock, flags);
+		return;
 	default:
 		break;
 	}
@@ -645,9 +649,8 @@ void debug_object_free(void *addr, struct debug_obj_descr *descr)
 
 	switch (obj->state) {
 	case ODEBUG_STATE_ACTIVE:
-		debug_print_object(obj, "free");
 		state = obj->state;
-		raw_spin_unlock_irqrestore(&db->lock, flags);
+		debug_print_object(obj, "free", &db->lock, flags);
 		debug_object_fixup(descr->fixup_free, addr, state);
 		return;
 	default:
@@ -695,7 +698,7 @@ void debug_object_assert_init(void *addr, struct debug_obj_descr *descr)
 			/* Track this static object */
 			debug_object_init(addr, descr);
 		} else {
-			debug_print_object(&o, "assert_init");
+			__debug_print_object(&o, "assert_init");
 			debug_object_fixup(descr->fixup_assert_init, addr,
 					   ODEBUG_STATE_NOTAVAILABLE);
 		}
@@ -732,25 +735,27 @@ debug_object_active_state(void *addr, struct debug_obj_descr *descr,
 	if (obj) {
 		switch (obj->state) {
 		case ODEBUG_STATE_ACTIVE:
-			if (obj->astate == expect)
+			if (obj->astate == expect) {
 				obj->astate = next;
-			else
-				debug_print_object(obj, "active_state");
-			break;
-
+				raw_spin_unlock_irqrestore(&db->lock, flags);
+				return;
+			}
+			/* fallthrough */
 		default:
-			debug_print_object(obj, "active_state");
-			break;
+			debug_print_object(obj, "active_state",
+					   &db->lock, flags);
+			return;
 		}
-	} else {
+	}
+	raw_spin_unlock_irqrestore(&db->lock, flags);
+
+	if (!obj) {
 		struct debug_obj o = { .object = addr,
 				       .state = ODEBUG_STATE_NOTAVAILABLE,
 				       .descr = descr };
 
-		debug_print_object(&o, "active_state");
+		__debug_print_object(&o, "active_state");
 	}
-
-	raw_spin_unlock_irqrestore(&db->lock, flags);
 }
 EXPORT_SYMBOL_GPL(debug_object_active_state);
 
@@ -786,10 +791,10 @@ static void __debug_check_no_obj_freed(const void *address, unsigned long size)
 
 			switch (obj->state) {
 			case ODEBUG_STATE_ACTIVE:
-				debug_print_object(obj, "free");
 				descr = obj->descr;
 				state = obj->state;
-				raw_spin_unlock_irqrestore(&db->lock, flags);
+				debug_print_object(obj, "free",
+						   &db->lock, flags);
 				debug_object_fixup(descr->fixup_free,
 						   (void *) oaddr, state);
 				goto repeat;
-- 
2.20.0

Re: [PATCH 1/2] debugobjects: Warn wrong annotation outside bucket lock

[Sergey Senozhatsky]

On (12/13/18 04:34), Dmitry Safonov wrote:
> printk() may defer work to workqueue, and realization of workqueues
> uses debugobjects.

Sorry, not following. You mean per-CPU irq_work which printk_deferred()
is using? That one should not deal with debugobjects.

	-ss

Re: [PATCH 2/2] debugobjects: Print warnings outside bucket lock

[Waiman Long]

On 12/12/2018 11:34 PM, Dmitry Safonov wrote:
> Whenever debugobjects finds invalid pattern during life time of a kernel
> object such as:
> -  Activation of uninitialized objects
> -  Initialization of active objects
> -  Usage of freed/destroyed objects
> it prints a warning and tries to make fixup over an object.
>
> Unfortunately, it becomes error-prone to use WARN() or printing under
> debugobjects bucket lock: printk() may defer work to workqueue, and
> realization of workqueues uses debugobjects. Further, console drivers
> use page allocator, potentially vmalloc() or slub/slab. Which reasonably
> makes lockdep to go nuts as there are debug_check_no_obj_freed() checks
> in allocators.
>
> Move printings out of debugobjets bucket lock to address the potential
> lockups.
>
> Link: lkml.kernel.org/r/20181211091154.GL23332@shao2-debian
> Reported-by: kernel test robot <rong.a.chen@intel.com>
> Cc: Andrew Morton <akpm@linux-foundation.org>
> Cc: Ingo Molnar <mingo@kernel.org>
> Cc: Peter Zijlstra <peterz@infradead.org>
> Cc: Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com>
> Cc: Thomas Gleixner <tglx@linutronix.de>
> Cc: Waiman Long <longman@redhat.com>
> Signed-off-by: Dmitry Safonov <dima@arista.com>
> ---
>  lib/debugobjects.c | 89 ++++++++++++++++++++++++----------------------
>  1 file changed, 47 insertions(+), 42 deletions(-)
>
> diff --git a/lib/debugobjects.c b/lib/debugobjects.c
> index 98968219405b..0c92e46cb588 100644
> --- a/lib/debugobjects.c
> +++ b/lib/debugobjects.c
> @@ -313,7 +313,7 @@ static struct debug_bucket *get_bucket(unsigned long addr)
>  	return &obj_hash[hash];
>  }
>  
> -static void debug_print_object(struct debug_obj *obj, char *msg)
> +static void __debug_print_object(struct debug_obj *obj, char *msg)
>  {
>  	struct debug_obj_descr *descr = obj->descr;
>  	static int limit;
> @@ -330,6 +330,14 @@ static void debug_print_object(struct debug_obj *obj, char *msg)
>  	debug_objects_warnings++;
>  }
>  
> +#define debug_print_object(obj, msg, lock, flags)			\
> +	do {								\
> +		struct debug_obj tmp = *obj;				\
> +									\
> +		raw_spin_unlock_irqrestore(lock, flags);		\
> +		__debug_print_object(&tmp, msg);			\
> +	} while(0)
> +

My main problem with this patch is the hiding of the unlock call in the
macro. I will prefer matching unlocks to be clearly visible in the
function bodies. Otherwise, the readers may be confused.

Cheers,
Longman