[Skiboot] [PATCH 7/7] core/lock: Add debug options to store backtrace of where lock was taken

[Andrew Donnellan]

On 18/3/19 3:29 pm, Andrew Donnellan wrote:
> Contrary to popular belief, skiboot developers are imperfect and
> occasionally write locking bugs. When we exit skiboot, we check if we're
> still holding any locks, and if so, we print an error with a list of the
> locks currently held and the locations where they were taken.
> 
> However, this only tells us the location where lock() was called, which may
> not be enough to work out what's going on. To give us more to go on with,
> we can store backtrace data in the lock and print that out when we
> unexpectedly still hold locks.
> 
> Because the backtrace data is rather big, we only enable this if
> DEBUG_LOCKS_BACKTRACE is defined, which in turn is switched on when
> DEBUG=1.
> 
> Signed-off-by: Andrew Donnellan <andrew.donnellan at au1.ibm.com>

Apparently this causes a test failure in core/test/run-mem_region, which 
is interesting!

> 
> ---
> 
> RFC->v1:
> - Switch this on when DEBUG=1 (Stewart)
> - Rebase on top of some backtrace API changes
> ---
>   core/lock.c      | 19 +++++++++++++++++--
>   include/config.h |  7 +++++++
>   include/lock.h   | 11 +++++++++++
>   3 files changed, 35 insertions(+), 2 deletions(-)
> 
> diff --git a/core/lock.c b/core/lock.c
> index fbf0b21ed5c6..6fbb5eb9bf5e 100644
> --- a/core/lock.c
> +++ b/core/lock.c
> @@ -208,6 +208,12 @@ bool try_lock_caller(struct lock *l, const char *owner)
>   		cpu->con_suspend++;
>   	if (__try_lock(cpu, l)) {
>   		l->owner = owner;
> +
> +#ifdef DEBUG_LOCKS_BACKTRACE
> +		backtrace_create(l->bt_buf, LOCKS_BACKTRACE_MAX_ENTS,
> +				 &l->bt_metadata);
> +#endif
> +
>   		list_add(&cpu->locks_held, &l->list);
>   		return true;
>   	}
> @@ -312,8 +318,12 @@ void dump_locks_list(void)
>   	struct lock *l;
>   
>   	prlog(PR_ERR, "Locks held:\n");
> -	list_for_each(&this_cpu()->locks_held, l, list)
> +	list_for_each(&this_cpu()->locks_held, l, list) {
>   		prlog(PR_ERR, "  %s\n", l->owner);
> +#ifdef DEBUG_LOCKS_BACKTRACE
> +		backtrace_print(l->bt_buf, &l->bt_metadata, NULL, NULL, true);
> +#endif
> +	}
>   }
>   
>   void drop_my_locks(bool warn)
> @@ -322,8 +332,13 @@ void drop_my_locks(bool warn)
>   
>   	disable_fast_reboot("Lock corruption");
>   	while((l = list_top(&this_cpu()->locks_held, struct lock, list)) != NULL) {
> -		if (warn)
> +		if (warn) {
>   			prlog(PR_ERR, "  %s\n", l->owner);
> +#ifdef DEBUG_LOCKS_BACKTRACE
> +			backtrace_print(l->bt_buf, &l->bt_metadata, NULL, NULL,
> +					true);
> +#endif
> +		}
>   		unlock(l);
>   	}
>   }
> diff --git a/include/config.h b/include/config.h
> index 438f1b0f3373..7059e39ddb91 100644
> --- a/include/config.h
> +++ b/include/config.h
> @@ -39,6 +39,13 @@
>   /* Enable lock debugging */
>   #define DEBUG_LOCKS		1
>   
> +/* Enable printing of backtraces when locks not released */
> +#ifdef DEBUG
> +#define DEBUG_LOCKS_BACKTRACE  1
> +#else
> +//#define DEBUG_LOCKS_BACKTRACE	1
> +#endif
> +
>   /* Enable lock dependency checker */
>   #define DEADLOCK_CHECKER	1
>   
> diff --git a/include/lock.h b/include/lock.h
> index b18757394dbb..e08ec08fcdfb 100644
> --- a/include/lock.h
> +++ b/include/lock.h
> @@ -23,6 +23,12 @@
>   #include <ccan/list/list.h>
>   #include <ccan/str/str.h>
>   
> +#ifdef DEBUG_LOCKS_BACKTRACE
> +#include <stack.h>
> +
> +#define LOCKS_BACKTRACE_MAX_ENTS	60
> +#endif
> +
>   struct lock {
>   	/* Lock value has bit 63 as lock bit and the PIR of the owner
>   	 * in the top 32-bit
> @@ -38,6 +44,11 @@ struct lock {
>   	/* file/line of lock owner */
>   	const char *owner;
>   
> +#ifdef DEBUG_LOCKS_BACKTRACE
> +	struct bt_entry bt_buf[LOCKS_BACKTRACE_MAX_ENTS];
> +	struct bt_metadata bt_metadata;
> +#endif
> +
>   	/* linkage in per-cpu list of owned locks */
>   	struct list_node list;
>   };
> 

-- 
Andrew Donnellan              OzLabs, ADL Canberra
andrew.donnellan at au1.ibm.com  IBM Australia Limited