changeset 3647:76d3d42bd153

5073041 enhancing Ftrace to get the caller information 6457723 DR causes memory leak of ftrace buffers
author bs21162
date Wed, 14 Feb 2007 07:03:29 -0800
parents 7de0c1c360da
children 9058c29beed0
files usr/src/uts/common/os/ftrace.c usr/src/uts/common/sys/cpuvar.h usr/src/uts/common/sys/ftrace.h usr/src/uts/intel/ia32/ml/i86_subr.s usr/src/uts/sparc/v9/ml/sparcv9_subr.s usr/src/uts/sun4/ml/interrupt.s
diffstat 6 files changed, 315 insertions(+), 90 deletions(-) [+]
line wrap: on
line diff
--- a/usr/src/uts/common/os/ftrace.c	Tue Feb 13 20:13:34 2007 -0800
+++ b/usr/src/uts/common/os/ftrace.c	Wed Feb 14 07:03:29 2007 -0800
@@ -2,9 +2,8 @@
  * CDDL HEADER START
  *
  * The contents of this file are subject to the terms of the
- * Common Development and Distribution License, Version 1.0 only
- * (the "License").  You may not use this file except in compliance
- * with the License.
+ * Common Development and Distribution License (the "License").
+ * You may not use this file except in compliance with the License.
  *
  * You can obtain a copy of the license at usr/src/OPENSOLARIS.LICENSE
  * or http://www.opensolaris.org/os/licensing.
@@ -20,7 +19,7 @@
  * CDDL HEADER END
  */
 /*
- * Copyright 1998-2003 Sun Microsystems, Inc.  All rights reserved.
+ * Copyright 2007 Sun Microsystems, Inc.  All rights reserved.
  * Use is subject to license terms.
  */
 
@@ -49,7 +48,24 @@
 int ftrace_nent = FTRACE_NENT;
 
 /*
- * The current overall state of the ftrace subsystem.
+ * Global Tracing State:
+ *
+ *                NOTREADY(=0)
+ *                  |
+ *            ftrace_init()
+ *                  |
+ *                  |
+ *                  v
+ *      +-------->READY-------+
+ *      |                     |
+ *  ftrace_stop()         ftrace_start()
+ *      |                     |
+ *      +---(ENABLED|READY)<--+
+ *
+ * During boot, ftrace_init() is called and the state becomes
+ * READY. If ftrace_atboot is set, ftrace_start() is called at
+ * this time.
+ *
  * If FTRACE_READY is set, then tracing can be enabled.
  * If FTRACE_ENABLED is set, tracing is enabled on the set of CPUs
  *   which are currently FTRACE_READY.
@@ -57,16 +73,53 @@
 static int ftrace_state = 0;
 
 /*
- * Protects assignments to:
+ * Per-CPU Tracing State:
+ *
+ *     +-----------------READY<--------------+
+ *     |                 ^   |               |
+ *     |                 | ftrace_cpu_fini() |
+ *     |                 |   |               |
+ *     |   ftrace_cpu_init() |               |
+ *     |                 |   v     ftrace_cpu_stop()
+ *     |              NOTREADY(=0)           |
+ *     |                   ^                 |
+ * ftrace_cpu_start()      |                 |
+ *     |              ftrace_cpu_fini()      |
+ *     |                   |                 |
+ *     +----------->(ENABLED|READY)----------+
+ *
+ */
+
+/*
+ * Locking :
+ *
+ * Trace context code does not use any lock. There is a per-cpu circular trace
+ * buffer that has a head, a tail and a current pointer. Each record of this
+ * buffer is of equal length. Before doing anything, trace context code checks
+ * the per-cpu ENABLED bit. Trace buffer is allocated in non-trace context and
+ * it sets this bit only after allocating and setting up the buffer. So trace
+ * context code can't access the buffer till it is set up completely. The
+ * buffer is freed also in non-trace context. The code that frees the buffer is
+ * executed only after the corresponding cpu is powered off. So when this
+ * happens, no trace context code can be running on it. We only need to make
+ * sure that trace context code is not preempted from the cpu in the middle of
+ * accessing the trace buffer. This can be achieved simply by disabling
+ * interrupts temporarily. This approach makes the least assumption about the
+ * state of the callers of tracing functions.
+ *
+ * A single global lock, ftrace_lock protects assignments to all global and
+ * per-cpu trace variables. It does not protect reading of those in some cases.
+ *
+ * More specifically, it protects assignments to:
+ *
  *   ftrace_state
  *   cpu[N]->cpu_ftrace.ftd_state
- *   cpu[N]->cpu_ftrace.ftd_cur
  *   cpu[N]->cpu_ftrace.ftd_first
  *   cpu[N]->cpu_ftrace.ftd_last
- * Does _not_ protect readers of cpu[N]->cpu_ftrace.ftd_state.
- * Does not protect reading the FTRACE_READY bit in ftrace_state,
- *   since non-READY to READY is a stable transition.  This is used
- *   to ensure ftrace_init() has been called.
+ *
+ * Does _not_ protect reading of cpu[N]->cpu_ftrace.ftd_state
+ * Does _not_ protect cpu[N]->cpu_ftrace.ftd_cur
+ * Does _not_ protect reading of ftrace_state
  */
 static kmutex_t ftrace_lock;
 
@@ -119,11 +172,18 @@
 		return;
 
 	/*
-	 * Do not free mutex and the the trace buffer once they are
-	 * allocated. A thread, preempted from the now powered-off CPU
-	 * may be holding the mutex and in the middle of adding a trace
-	 * record.
+	 * This cpu is powered off and no code can be executing on it. So
+	 * we can simply finish our cleanup. There is no need for a xcall
+	 * to make sure that this cpu is out of trace context.
+	 *
+	 * The cpu structure will be cleared soon. But, for the sake of
+	 * debugging, clear our pointers and state.
 	 */
+	if (ftd->ftd_first != NULL) {
+		kmem_free(ftd->ftd_first,
+		    ftrace_nent * sizeof (ftrace_record_t));
+	}
+	bzero(ftd, sizeof (ftrace_data_t));
 }
 
 static void
@@ -140,11 +200,19 @@
 		if (ftd->ftd_first == NULL) {
 			ftrace_record_t *ptrs;
 
-			mutex_init(&ftd->ftd_mutex, NULL, MUTEX_DEFAULT, NULL);
 			mutex_exit(&ftrace_lock);
 			ptrs = kmem_zalloc(ftrace_nent *
 			    sizeof (ftrace_record_t), KM_SLEEP);
 			mutex_enter(&ftrace_lock);
+			if (ftd->ftd_first != NULL) {
+				/*
+				 * Someone else beat us to it. The winner will
+				 * set up the pointers and the state.
+				 */
+				kmem_free(ptrs,
+				    ftrace_nent * sizeof (ftrace_record_t));
+				return;
+			}
 
 			ftd->ftd_first = ptrs;
 			ftd->ftd_last = ptrs + (ftrace_nent - 1);
@@ -232,6 +300,9 @@
 		(void) ftrace_start();
 }
 
+/*
+ * Called from uadmin ioctl, or via mp_init_table[] during boot.
+ */
 int
 ftrace_start(void)
 {
@@ -250,6 +321,9 @@
 	return (was_enabled);
 }
 
+/*
+ * Called from uadmin ioctl, to stop tracing.
+ */
 int
 ftrace_stop(void)
 {
@@ -269,102 +343,146 @@
 	return (was_enabled);
 }
 
+/*
+ * ftrace_X() functions are called from trace context. All callers of ftrace_X()
+ * tests FTRACE_ENABLED first. Although this is not very accurate, it keeps the
+ * overhead very low when tracing is not enabled.
+ *
+ * gethrtime_unscaled() appears to be safe to be called in trace context. As an
+ * added precaution, we call these before we disable interrupts on this cpu.
+ */
+
 void
-ftrace_0(char *str)
+ftrace_0(char *str, caddr_t caller)
 {
 	ftrace_record_t *r;
-	struct cpu *cp = CPU;
-	ftrace_data_t *ftd = &cp->cpu_ftrace;
+	struct cpu *cp;
+	ftrace_data_t *ftd;
+	ftrace_icookie_t cookie;
+	hrtime_t  timestamp;
+
+	timestamp = gethrtime_unscaled();
+
+	cookie = ftrace_interrupt_disable();
 
-	if (mutex_tryenter(&ftd->ftd_mutex) == 0) {
-		if (CPU_ON_INTR(cp))
-			return;
-		else
-			mutex_enter(&ftd->ftd_mutex);
+	cp = CPU;
+	ftd = &cp->cpu_ftrace;
+
+	if (!(ftd->ftd_state & FTRACE_ENABLED)) {
+		ftrace_interrupt_enable(cookie);
+		return;
 	}
+
 	r = ftd->ftd_cur;
 	r->ftr_event = str;
 	r->ftr_thread = curthread;
-	r->ftr_tick = gethrtime_unscaled();
-	r->ftr_caller = caller();
+	r->ftr_tick = timestamp;
+	r->ftr_caller = caller;
 
 	if (r++ == ftd->ftd_last)
 		r = ftd->ftd_first;
 	ftd->ftd_cur = r;
-	mutex_exit(&ftd->ftd_mutex);
+
+	ftrace_interrupt_enable(cookie);
 }
 
 void
-ftrace_1(char *str, ulong_t arg1)
+ftrace_1(char *str, ulong_t arg1, caddr_t caller)
 {
 	ftrace_record_t *r;
-	struct cpu *cp = CPU;
-	ftrace_data_t *ftd = &cp->cpu_ftrace;
+	struct cpu *cp;
+	ftrace_data_t *ftd;
+	ftrace_icookie_t cookie;
+	hrtime_t  timestamp;
+
+	timestamp = gethrtime_unscaled();
+
+	cookie = ftrace_interrupt_disable();
 
-	if (mutex_tryenter(&ftd->ftd_mutex) == 0) {
-		if (CPU_ON_INTR(cp))
-			return;
-		else
-			mutex_enter(&ftd->ftd_mutex);
+	cp = CPU;
+	ftd = &cp->cpu_ftrace;
+
+	if (!(ftd->ftd_state & FTRACE_ENABLED)) {
+		ftrace_interrupt_enable(cookie);
+		return;
 	}
+
 	r = ftd->ftd_cur;
 	r->ftr_event = str;
 	r->ftr_thread = curthread;
-	r->ftr_tick = gethrtime_unscaled();
-	r->ftr_caller = caller();
+	r->ftr_tick = timestamp;
+	r->ftr_caller = caller;
 	r->ftr_data1 = arg1;
 
 	if (r++ == ftd->ftd_last)
 		r = ftd->ftd_first;
 	ftd->ftd_cur = r;
-	mutex_exit(&ftd->ftd_mutex);
+
+	ftrace_interrupt_enable(cookie);
 }
 
 void
-ftrace_2(char *str, ulong_t arg1, ulong_t arg2)
+ftrace_2(char *str, ulong_t arg1, ulong_t arg2, caddr_t caller)
 {
 	ftrace_record_t *r;
-	struct cpu *cp = CPU;
-	ftrace_data_t *ftd = &cp->cpu_ftrace;
+	struct cpu *cp;
+	ftrace_data_t *ftd;
+	ftrace_icookie_t cookie;
+	hrtime_t  timestamp;
+
+	timestamp = gethrtime_unscaled();
+
+	cookie = ftrace_interrupt_disable();
 
-	if (mutex_tryenter(&ftd->ftd_mutex) == 0) {
-		if (CPU_ON_INTR(cp))
-			return;
-		else
-			mutex_enter(&ftd->ftd_mutex);
+	cp = CPU;
+	ftd = &cp->cpu_ftrace;
+
+	if (!(ftd->ftd_state & FTRACE_ENABLED)) {
+		ftrace_interrupt_enable(cookie);
+		return;
 	}
+
 	r = ftd->ftd_cur;
 	r->ftr_event = str;
 	r->ftr_thread = curthread;
-	r->ftr_tick = gethrtime_unscaled();
-	r->ftr_caller = caller();
+	r->ftr_tick = timestamp;
+	r->ftr_caller = caller;
 	r->ftr_data1 = arg1;
 	r->ftr_data2 = arg2;
 
 	if (r++ == ftd->ftd_last)
 		r = ftd->ftd_first;
 	ftd->ftd_cur = r;
-	mutex_exit(&ftd->ftd_mutex);
+
+	ftrace_interrupt_enable(cookie);
 }
 
 void
-ftrace_3(char *str, ulong_t arg1, ulong_t arg2, ulong_t arg3)
+ftrace_3(char *str, ulong_t arg1, ulong_t arg2, ulong_t arg3, caddr_t caller)
 {
 	ftrace_record_t *r;
-	struct cpu *cp = CPU;
-	ftrace_data_t *ftd = &cp->cpu_ftrace;
+	struct cpu *cp;
+	ftrace_data_t *ftd;
+	ftrace_icookie_t cookie;
+	hrtime_t  timestamp;
+
+	timestamp = gethrtime_unscaled();
+
+	cookie = ftrace_interrupt_disable();
 
-	if (mutex_tryenter(&ftd->ftd_mutex) == 0) {
-		if (CPU_ON_INTR(cp))
-			return;
-		else
-			mutex_enter(&ftd->ftd_mutex);
+	cp = CPU;
+	ftd = &cp->cpu_ftrace;
+
+	if (!(ftd->ftd_state & FTRACE_ENABLED)) {
+		ftrace_interrupt_enable(cookie);
+		return;
 	}
+
 	r = ftd->ftd_cur;
 	r->ftr_event = str;
 	r->ftr_thread = curthread;
-	r->ftr_tick = gethrtime_unscaled();
-	r->ftr_caller = caller();
+	r->ftr_tick = timestamp;
+	r->ftr_caller = caller;
 	r->ftr_data1 = arg1;
 	r->ftr_data2 = arg2;
 	r->ftr_data3 = arg3;
@@ -372,27 +490,34 @@
 	if (r++ == ftd->ftd_last)
 		r = ftd->ftd_first;
 	ftd->ftd_cur = r;
-	mutex_exit(&ftd->ftd_mutex);
+
+	ftrace_interrupt_enable(cookie);
 }
 
 void
-ftrace_3_notick(char *str, ulong_t arg1, ulong_t arg2, ulong_t arg3)
+ftrace_3_notick(char *str, ulong_t arg1, ulong_t arg2,
+    ulong_t arg3, caddr_t caller)
 {
 	ftrace_record_t *r;
-	struct cpu *cp = CPU;
-	ftrace_data_t *ftd = &cp->cpu_ftrace;
+	struct cpu *cp;
+	ftrace_data_t *ftd;
+	ftrace_icookie_t cookie;
+
+	cookie = ftrace_interrupt_disable();
 
-	if (mutex_tryenter(&ftd->ftd_mutex) == 0) {
-		if (CPU_ON_INTR(cp))
-			return;
-		else
-			mutex_enter(&ftd->ftd_mutex);
+	cp = CPU;
+	ftd = &cp->cpu_ftrace;
+
+	if (!(ftd->ftd_state & FTRACE_ENABLED)) {
+		ftrace_interrupt_enable(cookie);
+		return;
 	}
+
 	r = ftd->ftd_cur;
 	r->ftr_event = str;
 	r->ftr_thread = curthread;
 	r->ftr_tick = 0;
-	r->ftr_caller = caller();
+	r->ftr_caller = caller;
 	r->ftr_data1 = arg1;
 	r->ftr_data2 = arg2;
 	r->ftr_data3 = arg3;
@@ -400,5 +525,6 @@
 	if (r++ == ftd->ftd_last)
 		r = ftd->ftd_first;
 	ftd->ftd_cur = r;
-	mutex_exit(&ftd->ftd_mutex);
+
+	ftrace_interrupt_enable(cookie);
 }
--- a/usr/src/uts/common/sys/cpuvar.h	Tue Feb 13 20:13:34 2007 -0800
+++ b/usr/src/uts/common/sys/cpuvar.h	Wed Feb 14 07:03:29 2007 -0800
@@ -71,7 +71,7 @@
 struct ftrace_record;
 typedef struct ftrace_data {
 	int			ftd_state;	/* ftrace flags */
-	kmutex_t		ftd_mutex;	/* ftrace buffer lock */
+	kmutex_t		ftd_unused;	/* ftrace buffer lock, unused */
 	struct ftrace_record	*ftd_cur;	/* current record */
 	struct ftrace_record	*ftd_first;	/* first record */
 	struct ftrace_record	*ftd_last;	/* last record */
--- a/usr/src/uts/common/sys/ftrace.h	Tue Feb 13 20:13:34 2007 -0800
+++ b/usr/src/uts/common/sys/ftrace.h	Wed Feb 14 07:03:29 2007 -0800
@@ -2,9 +2,8 @@
  * CDDL HEADER START
  *
  * The contents of this file are subject to the terms of the
- * Common Development and Distribution License, Version 1.0 only
- * (the "License").  You may not use this file except in compliance
- * with the License.
+ * Common Development and Distribution License (the "License").
+ * You may not use this file except in compliance with the License.
  *
  * You can obtain a copy of the license at usr/src/OPENSOLARIS.LICENSE
  * or http://www.opensolaris.org/os/licensing.
@@ -20,8 +19,8 @@
  * CDDL HEADER END
  */
 /*
- * Copyright (c) 1998 by Sun Microsystems, Inc.
- * All rights reserved.
+ * Copyright 2007 Sun Microsystems, Inc.  All rights reserved.
+ * Use is subject to license terms.
  */
 
 #ifndef	_SYS_FTRACE_H
@@ -87,30 +86,37 @@
 extern void		ftrace_init(void);
 extern int		ftrace_start(void);
 extern int		ftrace_stop(void);
-extern void		ftrace_0(char *);
-extern void		ftrace_1(char *, ulong_t);
-extern void		ftrace_2(char *, ulong_t, ulong_t);
-extern void		ftrace_3(char *, ulong_t, ulong_t, ulong_t);
+extern void		ftrace_0(char *, caddr_t);
+extern void		ftrace_1(char *, ulong_t, caddr_t);
+extern void		ftrace_2(char *, ulong_t, ulong_t, caddr_t);
+extern void		ftrace_3(char *, ulong_t, ulong_t, ulong_t, caddr_t);
+extern void		ftrace_3_notick(char *, ulong_t, ulong_t, ulong_t,
+    caddr_t);
+
+typedef	uintptr_t	ftrace_icookie_t;
+extern ftrace_icookie_t ftrace_interrupt_disable(void);
+extern void ftrace_interrupt_enable(ftrace_icookie_t);
+extern caddr_t caller(void);
 
 #define	FTRACE_0(fmt)						\
 	{							\
 		if (CPU->cpu_ftrace.ftd_state & FTRACE_ENABLED)	\
-			ftrace_0(fmt);				\
+			ftrace_0(fmt, caller());		\
 	}
 #define	FTRACE_1(fmt, d1) 					\
 	{							\
 		if (CPU->cpu_ftrace.ftd_state & FTRACE_ENABLED)	\
-			ftrace_1(fmt, d1);			\
+			ftrace_1(fmt, d1, caller());		\
 	}
 #define	FTRACE_2(fmt, d1, d2) 					\
 	{							\
 		if (CPU->cpu_ftrace.ftd_state & FTRACE_ENABLED)	\
-			ftrace_2(fmt, d1, d2);			\
+			ftrace_2(fmt, d1, d2, caller());	\
 	}
 #define	FTRACE_3(fmt, d1, d2, d3) 				\
 	{							\
 		if (CPU->cpu_ftrace.ftd_state & FTRACE_ENABLED)	\
-			ftrace_3(fmt, d1, d2, d3);		\
+			ftrace_3(fmt, d1, d2, d3, caller());	\
 	}
 #define	FTRACE_START()	ftrace_start()
 #define	FTRACE_STOP()	ftrace_stop()
--- a/usr/src/uts/intel/ia32/ml/i86_subr.s	Tue Feb 13 20:13:34 2007 -0800
+++ b/usr/src/uts/intel/ia32/ml/i86_subr.s	Wed Feb 14 07:03:29 2007 -0800
@@ -59,6 +59,7 @@
 #include <sys/archsystm.h>
 #include <sys/byteorder.h>
 #include <sys/dtrace.h>
+#include <sys/ftrace.h>
 #else	/* __lint */
 #include "assym.h"
 #endif	/* __lint */
@@ -3708,3 +3709,61 @@
 #endif	/* __i386 */
 
 #endif	/* __lint */
+
+#if defined(__lint)
+
+ftrace_icookie_t
+ftrace_interrupt_disable(void)
+{ return (0); }
+
+#else   /* __lint */
+
+#if defined(__amd64)
+
+	ENTRY(ftrace_interrupt_disable)
+	pushfq
+	popq	%rax
+	CLI(%rdx)
+	ret
+	SET_SIZE(ftrace_interrupt_disable)
+
+#elif defined(__i386)
+		
+	ENTRY(ftrace_interrupt_disable)
+	pushfl
+	popl	%eax
+	CLI(%edx)
+	ret
+	SET_SIZE(ftrace_interrupt_disable)
+
+#endif	/* __i386 */	
+#endif	/* __lint */
+
+#if defined(__lint)
+
+/*ARGSUSED*/
+void
+ftrace_interrupt_enable(ftrace_icookie_t cookie)
+{}
+
+#else	/* __lint */
+
+#if defined(__amd64)
+
+	ENTRY(ftrace_interrupt_enable)
+	pushq	%rdi
+	popfq
+	ret
+	SET_SIZE(ftrace_interrupt_enable)
+
+#elif defined(__i386)
+		
+	ENTRY(ftrace_interrupt_enable)
+	movl	4(%esp), %eax
+	pushl	%eax
+	popfl
+	ret
+	SET_SIZE(ftrace_interrupt_enable)
+
+#endif	/* __i386 */	
+#endif	/* __lint */
--- a/usr/src/uts/sparc/v9/ml/sparcv9_subr.s	Tue Feb 13 20:13:34 2007 -0800
+++ b/usr/src/uts/sparc/v9/ml/sparcv9_subr.s	Wed Feb 14 07:03:29 2007 -0800
@@ -2,9 +2,8 @@
  * CDDL HEADER START
  *
  * The contents of this file are subject to the terms of the
- * Common Development and Distribution License, Version 1.0 only
- * (the "License").  You may not use this file except in compliance
- * with the License.
+ * Common Development and Distribution License (the "License").
+ * You may not use this file except in compliance with the License.
  *
  * You can obtain a copy of the license at usr/src/OPENSOLARIS.LICENSE
  * or http://www.opensolaris.org/os/licensing.
@@ -20,7 +19,7 @@
  * CDDL HEADER END
  */
 /*
- * Copyright 2006 Sun Microsystems, Inc.  All rights reserved.
+ * Copyright 2007 Sun Microsystems, Inc.  All rights reserved.
  * Use is subject to license terms.
  */
 
@@ -46,6 +45,7 @@
 #include <sys/sunddi.h>
 #include <sys/lockstat.h>
 #include <sys/dtrace.h>
+#include <sys/ftrace.h>
 #endif	/* lint */
 
 #include <sys/asm_linkage.h>
@@ -1772,3 +1772,36 @@
 	SET_SIZE(get_subcc_ccr)
 
 #endif  /* lint */
+
+#if defined(lint) || defined(__lint)
+
+ftrace_icookie_t
+ftrace_interrupt_disable(void)
+{ return (0); }
+
+#else	/* lint */
+
+	ENTRY_NP(ftrace_interrupt_disable)
+	rdpr	%pstate, %o0
+	andn	%o0, PSTATE_IE, %o1
+	retl
+	wrpr	%g0, %o1, %pstate
+	SET_SIZE(ftrace_interrupt_disable)
+
+#endif	/* lint */
+
+#if defined(lint) || defined(__lint)
+
+/*ARGSUSED*/
+void
+ftrace_interrupt_enable(ftrace_icookie_t cookie)
+{}
+
+#else
+
+	ENTRY_NP(ftrace_interrupt_enable)
+	retl
+	wrpr	%g0, %o0, %pstate 
+	SET_SIZE(ftrace_interrupt_enable)
+
+#endif /* lint*/
--- a/usr/src/uts/sun4/ml/interrupt.s	Tue Feb 13 20:13:34 2007 -0800
+++ b/usr/src/uts/sun4/ml/interrupt.s	Wed Feb 14 07:03:29 2007 -0800
@@ -19,7 +19,7 @@
  * CDDL HEADER END
  */
 /*
- * Copyright 2006 Sun Microsystems, Inc.  All rights reserved.
+ * Copyright 2007 Sun Microsystems, Inc.  All rights reserved.
  * Use is subject to license terms.
  */
 
@@ -547,8 +547,9 @@
 	set	ftrace_intr_thread_format_str, %o0
 	mov	%i0, %o1
 	mov	%i1, %o2
+	mov	%i5, %o3
 	call	ftrace_3
-	mov	%i5, %o3
+	ldn	[%i0 + PC_OFF], %o4
 	restore
 1:
 	!