[PATCH 1/3] Documention for trace records (trec).

[PATCH 1/3] Documention for trace records (trec).

[Wink Saville]

Trec is a light weight tracing mechanism that places
trace information into a buffer. The contents of the
buffer is dumped when errors occurs or when enabled
via SYSRQ commands.

Signed-off-by: Wink Saville <wink@saville.com>
---
 Documentation/trec.txt |   87 ++++++++++++++++++++++++++++++++++++++++++++++++
 1 files changed, 87 insertions(+), 0 deletions(-)
 create mode 100644 Documentation/trec.txt

diff --git a/Documentation/trec.txt b/Documentation/trec.txt
new file mode 100644
index 0000000..2275edd
--- /dev/null
+++ b/Documentation/trec.txt
@@ -0,0 +1,87 @@
+Title	: Trace Records
+Authors	: Wink Saville <wink@saville.com>
+
+CONTENTS
+
+1. Concepts
+2. Architectures Supported
+3. Configuring
+4. API Reference
+5. Overhead
+6. TODO
+
+
+1. Concepts
+
+Trace records are a light weight tracing technique that time stamps
+small amounts of information and stores them in a buffer. TREC's are
+light enough that they may be sprinkled most anywhere in the kernel
+and have very little performance impact.
+
+For instance they can be placed in the scheduler and ISR's to watch
+the interaction between ISR's and the scheduler. They can be placed
+in memory handling routines to determine how and when memory is
+allocated and freed.
+
+In the current default configuration the trec's are dumped by calling
+trec_print_snapshot when die() or panic() are called as well as when
+the kernel itself page faults in do_page_fault.
+
+If CONFIG_MAGIC_SYSRQ is the 'y' command will execute trec_snapshot
+and the 'z' command will print the current snapshot.
+
+A general macro TREC allows trec_write to be invoked as a macro and
+TRECC allows it to be invoked conditionally. See include/linux/trec.h
+for the current set of macros.
+
+2. Architectures Supported
+
+Should support all architectures has been tested only on:
+
+- X86_64
+
+
+3. Configuring
+
+Since trec's are implemented as a device driver they are configured
+by enabling support in the "Device Drivers" section of as they could
+be used early being a module is not supported.
+
+
+4. API Reference
+
+Trec supports the following API:
+
+void trec_init(void):
+
+  Initialize the module, this may be called before the driver is loaded
+  if it is desired to use trec's early.
+
+void trec_write(unsigned long pc, int pid, unsigned long v1, unsigned long v2);
+
+  This is the routine used to write into the buffer. pc is the program counter
+  pid is the process id and v1 and v2 are two parameters.
+
+void trec_snapshot(void);
+
+  Calling this function takes a snapshot of the current trec buffer so that it
+  will not be modified. This is called prior to printing the snapshot via
+  trec_print_snapshot.
+
+void trec_print_snapshot(void);
+
+  Print the snapshot.
+
+5. Overhead
+
+Measured on a 2.4GHZ Core 2 Duo the readings between two TREC's is
+270 tics of the rdtsc or about 0.1us. No attempt has been made to
+optimize and less information can be collected if the overhead
+is still to high.
+
+
+6. TODO
+
+a. Add code to dump trec to user space
+b. Enhance to allow runtime registration and runtime enable disable.
+
-- 
1.5.0.rc2

[PATCH 2/3] Trec driver.

[Wink Saville]

This is the Trec driver, Makefile, header files.
Enable trec in Kernel hacking configuration menu.

Signed-off-by: Wink Saville <wink@saville.com>
---
 drivers/Makefile           |    1 +
 drivers/trec/Makefile      |    5 +
 drivers/trec/trec.c        |  404 ++++++++++++++++++++++++++++++++++++++++++++
 include/asm-generic/trec.h |   17 ++
 include/asm-i386/trec.h    |   33 ++++
 include/asm-x86_64/trec.h  |   13 ++
 include/linux/trec.h       |   75 ++++++++
 lib/Kconfig.debug          |    7 +
 8 files changed, 555 insertions(+), 0 deletions(-)
 create mode 100644 drivers/trec/Makefile
 create mode 100644 drivers/trec/trec.c
 create mode 100644 include/asm-generic/trec.h
 create mode 100644 include/asm-i386/trec.h
 create mode 100644 include/asm-x86_64/trec.h
 create mode 100644 include/linux/trec.h

diff --git a/drivers/Makefile b/drivers/Makefile
index 3a718f5..01724c0 100644
--- a/drivers/Makefile
+++ b/drivers/Makefile
@@ -81,3 +81,4 @@ obj-$(CONFIG_GENERIC_TIME)	+= clocksource/
 obj-$(CONFIG_DMA_ENGINE)	+= dma/
 obj-$(CONFIG_HID)		+= hid/
 obj-$(CONFIG_PPC_PS3)		+= ps3/
+obj-$(CONFIG_TREC)		+= trec/
diff --git a/drivers/trec/Makefile b/drivers/trec/Makefile
new file mode 100644
index 0000000..d930b4d
--- /dev/null
+++ b/drivers/trec/Makefile
@@ -0,0 +1,5 @@
+#
+# Makefile for Trace records.
+#
+
+obj-$(CONFIG_TREC)	+= trec.o
diff --git a/drivers/trec/trec.c b/drivers/trec/trec.c
new file mode 100644
index 0000000..0b04b71
--- /dev/null
+++ b/drivers/trec/trec.c
@@ -0,0 +1,404 @@
+/*
+ * Copyright (C) 2007 Saville Software, Inc.
+ *
+ * This code may be used for any purpose whatsoever,
+ * but no warranty of any kind is provided.
+ */
+
+#include <linux/device.h>
+#include <linux/fs.h>
+#include <linux/cdev.h>
+#include <linux/smp.h>
+#include <linux/kallsyms.h>
+#include <linux/sysrq.h>
+#include <linux/trec.h>
+
+#include <asm/trec.h>
+
+#define TREC_DEBUG
+#ifdef TREC_DEBUG
+#define DPK(fmt, args...) printk(KERN_ERR "trec " fmt, ## args)
+#else
+#define DPK(fmt, args...)
+#endif
+
+struct trec_dev_struct
+{
+	struct	cdev		cdev;			/* Character device structure */
+};
+
+MODULE_AUTHOR("Wink Saville");
+MODULE_LICENSE("Dual BSD/GPL");
+
+/*
+ * Module parameters
+ */
+int major = 240;	/* 240 a "local/expermental" device number for the moment */
+int minor = 1;
+
+module_param(major, int, S_IRUGO);
+module_param(minor, int, S_IRUGO);
+
+/*
+ * Forward declarations
+ */
+static int trec_open(struct inode *inode, struct file *file);
+static int trec_release(struct inode *inode, struct file *file);
+
+/*
+ * File operations
+ */
+struct file_operations trec_f_ops = {
+	.owner		=	THIS_MODULE,
+	.open		=	trec_open,
+	.release	=	trec_release,
+};
+
+struct trec_struct {
+	uint64_t	tsc;
+	unsigned long	pc;
+	unsigned long	tsk;
+	unsigned int	pid;
+	unsigned long	v1;
+	unsigned long	v2;
+};
+
+/*
+ * Change trec_buffer_struct.data to be a pointer to a PAGE in the future
+ */
+#define TREC_DATA_SIZE 0x200
+struct trec_buffer_struct {
+	struct trec_buffer_struct *	next;
+	struct trec_struct *		cur;
+	struct trec_struct *		end;
+	struct trec_struct		data[TREC_DATA_SIZE];
+};
+
+/*
+ * Number of buffers must be a multiple of two so we can
+ * snapshot the buffers and the minimum should be 4.
+ */
+#define	TREC_COUNT 2
+struct trec_buffer_struct 	trec_buffers[2][TREC_COUNT];
+int				trec_idx = 0;
+spinlock_t 			trec_lock = SPIN_LOCK_UNLOCKED;
+
+struct trec_buffer_struct *	trec_buffer_cur = NULL;
+struct trec_buffer_struct *	trec_buffer_snapshot = NULL;
+
+struct trec_dev_struct 		trec_dev;
+
+/**
+ * Print an address symbol if available to the buffer
+ * this is from traps.c
+ */
+static int snprint_address(char *b, int bsize, unsigned long address)
+{
+#ifdef CONFIG_KALLSYMS
+	unsigned long offset = 0, symsize;
+	const char *symname;
+	char *modname;
+	char *delim = ":";
+	int n;
+	char namebuf[128];
+
+	symname = kallsyms_lookup(address, &symsize, &offset, &modname, namebuf);
+	if (!symname) {
+		n = 0;
+	} else {
+		if (!modname)
+			modname = delim = ""; 		
+		n = snprintf(b, bsize, "0x%016lx %s%s%s%s+0x%lx/0x%lx",
+			address, delim, modname, delim, symname, offset, symsize);
+	}
+	return n;
+#else
+	return snprintf(b, bsize, "0x%016lx", address);
+#endif
+}
+
+/*
+ * Initialize the trec buffers
+ */
+void trec_init(void)
+{
+	int i;
+	int j;
+
+	DPK("trec: trec_init E\n");
+
+	for (i = 0; i < 2; i++) {
+		for (j = 0; j < TREC_COUNT; j++) {
+			struct trec_buffer_struct *trec = &trec_buffers[i][j];
+
+			trec->next = &trec_buffers[i][(j+1) % TREC_COUNT];
+			trec->cur = &trec->data[0];
+			trec->end = &trec->data[TREC_DATA_SIZE];
+			memset(trec->cur, 0, sizeof(trec->data));
+		}
+	}
+
+	trec_idx = 0;
+	trec_buffer_cur = &trec_buffers[trec_idx][0];
+	trec_buffer_snapshot = NULL;
+
+	DPK("trec: trec_init X\n");
+}
+EXPORT_SYMBOL(trec_init);
+
+/*
+ * Write a trec entry
+ */
+void trec_write(unsigned long pc, int pid, unsigned long v1, unsigned long v2)
+{
+	struct trec_struct *trec;
+	int flags;
+
+	spin_lock_irqsave(&trec_lock, flags);
+	trec = trec_buffer_cur->cur;
+	trec_buffer_cur->cur += 1;
+	if (trec_buffer_cur->cur >= trec_buffer_cur->end) {
+		trec_buffer_cur = trec_buffer_cur->next;
+		trec_buffer_cur->cur = &trec_buffer_cur->data[0];
+	}
+	spin_unlock_irqrestore(&trec_lock, flags);
+
+	trec->tsc = rd_tsc();	
+	trec->pc = pc;
+	trec->pid = pid;
+	trec->tsk = (unsigned long)current;
+	trec->v1 = v1;
+	trec->v2 = v2;
+}
+EXPORT_SYMBOL(trec_write);
+
+/*
+ * Snapshot the current trecs
+ */
+void trec_snapshot(void)
+{
+	int flags;
+
+	spin_lock_irqsave(&trec_lock, flags);
+	trec_buffer_snapshot = trec_buffer_cur;
+	trec_idx = trec_idx ^ 1;
+	trec_buffer_cur = &trec_buffers[trec_idx][0];
+	spin_unlock_irqrestore(&trec_lock, flags);
+}
+EXPORT_SYMBOL(trec_snapshot);
+
+/*
+ * trec_print
+ */
+void trec_print_snapshot(void)
+{
+	int i;
+	struct trec_buffer_struct *cur_buffer;
+
+	if (!trec_buffer_snapshot)
+		trec_snapshot();
+
+	cur_buffer = trec_buffer_snapshot->next;
+	for (i = 0; i < TREC_COUNT; i++) {
+		struct trec_struct *cur;
+
+		for (cur = &cur_buffer->data[0];
+			cur < cur_buffer->cur;
+			cur += 1) {
+			char b[256];
+			int n;
+			
+			n = snprintf(b, sizeof(b), KERN_ERR "t=%20llu pid=%5u tsk=%p v1=%p v2=%p ",
+				cur->tsc, cur->pid, (void *)cur->tsk, (void *)cur->v1, (void *)cur->v2);
+			n += snprint_address(b+n, sizeof(b)-n, cur->pc);
+			printk("%s\n", b);
+		}
+		cur_buffer = cur_buffer->next;
+	}
+}
+EXPORT_SYMBOL(trec_print_snapshot);
+
+/*
+ * Sysrq support for trec's
+ */
+#ifdef CONFIG_MAGIC_SYSRQ
+/*
+ * trec print snapshot handler for sysrq
+ */
+static void sysrq_handle_trec_print_snapshot(int key, struct tty_struct *tty) 
+{
+	trec_print_snapshot();
+}
+
+/*
+ * trec snapshot handler for sysrq
+ */
+static void sysrq_handle_trec_snapshot(int key, struct tty_struct *tty) 
+{
+	trec_snapshot();
+}
+
+static struct sysrq_key_op sysrq_trec_snapshot_op = 
+{
+	.handler =	sysrq_handle_trec_snapshot,
+	.help_msg =	"Trec snapshot(Y)",
+	.action_msg =	"Trec snapshot",
+};
+
+static struct sysrq_key_op sysrq_trec_print_snapshot_op = 
+{
+	.handler =	sysrq_handle_trec_print_snapshot,
+	.help_msg =	"Print current trec snapshot",
+	.action_msg =	"Trec print snapshot(Z)",
+};
+
+/*
+ * Initilize trec sysrq support
+ */
+static int __init setup_trec_sysrq(void)
+{
+	DPK("setup_trec_sysrq y=trec_snapshot z=trec_print_snapshot\n");
+	register_sysrq_key('y', &sysrq_trec_snapshot_op);
+	register_sysrq_key('z', &sysrq_trec_print_snapshot_op);
+	return 0;
+}
+__initcall(setup_trec_sysrq);
+#endif /* CONFIG_MAGIC_SYSRQ */
+
+/*
+ * Open
+ */
+static int trec_open(struct inode *inode, struct file *file)
+{
+	int result = 0;
+	struct trec_dev_struct *dev;
+       
+	DPK("trec_open: E\n");
+
+	dev = container_of(inode->i_cdev, struct trec_dev_struct, cdev);
+	file->private_data = (void *)dev;
+
+	DPK("trec_open: X result=%d\n", result);
+	return result;
+}
+
+/*
+ * Release/Close
+ */
+static int trec_release(struct inode *inode, struct file *file)
+{
+	int	result = 0; 
+
+	DPK("trec_release: E\n");
+	
+	DPK("trec_release: X result=%d\n", result);
+	return result;
+}
+
+/*
+ * Init routine for the trec device
+ */
+static int __init trec_device_init(void)
+{
+	int 		result;
+	dev_t 		dev_number = 0;
+	static struct 	class *trec_class;
+
+	DPK("trec_device_init: E\n");
+
+	if (major) {
+		dev_number = MKDEV(major, minor);
+		result = register_chrdev_region(dev_number, 1, "trec");
+		DPK("trec_device_init: static major result=%d\n", result);
+	} else {
+		result = alloc_chrdev_region(&dev_number, minor, 1, "trec");
+		major = MAJOR(dev_number);
+		DPK("trec_device_init: dynamic major result=%d\n", result);
+	}	
+
+	if (result < 0) {
+		printk(KERN_WARNING "trec: can't get major %d\n", major);
+		goto err;
+	}
+
+	cdev_init(&trec_dev.cdev, &trec_f_ops);
+	trec_dev.cdev.owner = THIS_MODULE;
+	trec_dev.cdev.ops = &trec_f_ops;
+	
+	result = cdev_add(&trec_dev.cdev, dev_number, 1);
+	if (result)
+	{
+		DPK("trec_device_init: cdev_add failed\n");
+		goto err;
+	}
+
+	/*
+	 * Make a trec class and create the device
+	 */
+	trec_class = class_create(THIS_MODULE, "trec");
+	class_device_create(trec_class, NULL, dev_number, NULL, "trec");
+
+	/*
+	 * If the trec buffers have not been initialized do so
+	 */
+	if (trec_buffer_cur == NULL) {
+		trec_init();
+	}
+
+	/*
+	 * Test macros
+	 */
+	TREC(1, 2);
+	TRECC(1, 3, 4);
+	TRECC0(1);
+	TRECC1(1, 5);
+	TRECC2(1, 6, 7);
+
+	TREC0();
+	TREC1(8);
+	TREC2(9, 10);
+
+#undef TREC_ENABLED
+#define TREC_ENABLED 0
+	/*
+	 * Should not be in the trec buffer
+	 */
+	TREC(1, 11);
+	TRECC(1, 12, 13);
+	TRECC0(1);
+	TRECC1(1, 14);
+	TRECC2(1, 15, 16);
+
+	TREC0();
+	TREC1(17);
+	TREC2(18, 19);
+#undef TREC_ENABLED
+#define TREC_ENABLED 1
+
+	result = 0;
+	goto out;
+
+err:
+	unregister_chrdev_region(dev_number, 1);
+out:
+	DPK("trec_device_init: X result=%d major=%d minor=%d\n", result, major, minor);
+	TREC_RETV(result);
+}
+
+/*
+ * Exit routine for trec device
+ */
+static void __exit trec_device_exit(void)
+{
+	dev_t dev_number = MKDEV(major, minor);
+
+	DPK("trec_device_exit: E\n");
+
+	unregister_chrdev_region(dev_number, 1);
+
+	DPK("trec_device_exit: X\n");
+}
+
+module_init(trec_device_init);
+module_exit(trec_device_exit);
+
diff --git a/include/asm-generic/trec.h b/include/asm-generic/trec.h
new file mode 100644
index 0000000..4d8dffb
--- /dev/null
+++ b/include/asm-generic/trec.h
@@ -0,0 +1,17 @@
+/*
+ * Copyright (C) 2007 Saville Software, Inc.
+ *
+ * This code may be used for any purpose whatsoever, but
+ * no warranty of any kind is provided.
+ */
+
+#ifndef _ASM_GENERIC_TREC_H
+#define _ASM_GENERIC_TREC_H
+
+#ifndef __ASSEMBLY__
+
+#define rd_tsc() (0)
+
+#endif /* !__ASSEMBLY__ */
+
+#endif /* _ASM_GENERIC_TREC_H */
diff --git a/include/asm-i386/trec.h b/include/asm-i386/trec.h
new file mode 100644
index 0000000..1de4dc6
--- /dev/null
+++ b/include/asm-i386/trec.h
@@ -0,0 +1,33 @@
+/*
+ * Copyright (C) 2007 Saville Software, Inc.
+ *
+ * This code may be used for any purpose whatsoever, but
+ * no warranty of any kind is provided.
+ */
+
+#ifndef _ASM_I386_TREC_H
+#define _ASM_I386_TREC_H
+
+#ifndef __ASSEMBLY__
+
+#if CONFIG_X86_TSC 
+#include <asm/msr.h>
+
+/*
+ * read x86 time stamp counter.
+ */
+static uint64_t inline rd_tsc(void)
+{
+	volatile uint64_t value;
+
+	rdtscll(value);
+
+	return value;
+}
+#else
+	#define rd_tsc() (0)
+#endif /* CONFIG_X86_TSC */
+
+#endif /* !__ASSEMBLY__ */
+
+#endif /* _ASM_I386_TREC_H */
diff --git a/include/asm-x86_64/trec.h b/include/asm-x86_64/trec.h
new file mode 100644
index 0000000..ba2a852
--- /dev/null
+++ b/include/asm-x86_64/trec.h
@@ -0,0 +1,13 @@
+/*
+ * Copyright (C) 2007 Saville Software, Inc.
+ *
+ * This code may be used for any purpose whatsoever, but
+ * no warranty of any kind is provided.
+ */
+
+#ifndef _ASM_X86_64_TREC_H
+#define _ASM_X86_64_TREC_H
+
+#include <asm-i386/trec.h>
+
+#endif /* _ASM_X86_64_TREC_H */
diff --git a/include/linux/trec.h b/include/linux/trec.h
new file mode 100644
index 0000000..d5d8e74
--- /dev/null
+++ b/include/linux/trec.h
@@ -0,0 +1,75 @@
+/*
+ * Copyright (C) 2007 Saville Software, Inc.
+ *
+ * This code may be used for any purpose whatsoever, but
+ * no warranty of any kind is provided.
+ */
+
+#ifndef _TREC_H
+#define _TREC_H
+
+#if defined(CONFIG_TREC)
+
+#include <linux/sched.h>	/* For current->pid */
+#include <asm/processor.h>	/* For current_text_addr */
+
+#define TREC_PC_ADDR		((unsigned long)(current_text_addr()))
+#define TREC_PID		(current->pid)
+
+#ifndef TREC_ENABLED
+#define TREC_ENABLED 		1
+#endif
+
+#define TREC(__v1, __v2) \
+	do { \
+		if (TREC_ENABLED) \
+			trec_write(TREC_PC_ADDR, TREC_PID, (unsigned long)(__v1), (unsigned long)(__v2)); \
+       	} while (0)
+
+
+#define TRECC(__c, __v1, __v2)	do { if ((__c)) TREC(__v1, __v2); } while (0)
+#define TRECC0(__c) 		TRECC(__c, 0, 0)
+#define TRECC1(__c, __v1)	TRECC(__c, __v1, 0)
+#define TRECC2(__c, __v1, __v2) TRECC(__c, __v1, __v2)
+#define TRECC0_RETV(__c,__retv) do { TRECC0(__c); return(__retv); } while (0)
+#define TRECC0_RET(__c) 	do { TRECC0(__c); return; } while (0)
+
+#define TREC0() 		TRECC0(1)
+#define TREC1(__v) 		TRECC1(1, (__v)) 
+#define TREC2(__v1, __v2)	TRECC2(1, (__v1), (__v2)) 
+#define TREC_RETV(__retv) 	TRECC0_RETV(1, __retv)
+#define TREC_RET() 		TRECC0_RET(1)
+
+extern void trec_init(void);
+extern void trec_write(unsigned long pc, int pid, unsigned long v1, unsigned long v2);
+extern void trec_snapshot(void);
+extern void trec_print_snapshot(void);
+
+#else
+
+/*
+ * All TREC's are disabled
+ */
+#define TREC_ENABLED 		0
+
+#define TREC(__v1, __v2)	do { } while (0)
+
+#define TRECC(__c,__v1, __v2)	do { } while (0)
+#define TRECC0(__c)		do { } while (0)
+#define TRECC1(__c, __v)	do { } while (0)
+#define TRECC2(__c, __v1, __v2)	do { } while (0)
+
+#define TREC0()			do { } while (0)
+#define TREC1(__v)		do { } while (0)
+#define TREC2(__v1, __v2)	do { } while (0)
+#define TREC_RETV(__retv) 	do { return(__retv); } while (0)
+#define TREC_RET() 		do { return; } while (0)
+
+static inline void trec_init(void) {}
+static inline void trec_write(unsigned long pc, int pid, unsigned long v1, unsigned long v2) {}
+static inline void trec_snapshot(void) {}
+static inline void trec_print_snapshot(void) {}
+
+#endif /* CONFIG_TREC && !TREC_DISABLED */
+
+#endif /* _TREC_H */
diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug
index 3f3e740..db53fdb 100644
--- a/lib/Kconfig.debug
+++ b/lib/Kconfig.debug
@@ -303,6 +303,13 @@ config STACKTRACE
 	depends on DEBUG_KERNEL
 	depends on STACKTRACE_SUPPORT
 
+config TREC
+ 	def_bool n
+ 	bool "Trace record support"
+ 	depends on DEBUG_KERNEL
+ 	help
+ 	  Trace records are a light weight tracing facility
+
 config DEBUG_KOBJECT
 	bool "kobject debugging"
 	depends on DEBUG_KERNEL
-- 
1.5.0.rc2

[PATCH 3/3] Initialize and use trec_snapshot and trec_print_snapshot.

[Wink Saville]

Trec's are initialized early in main.c and then dump
trec's in die(), panic() and do_page_fault().

Signed-off-by: Wink Saville <wink@saville.com>
---
 arch/x86_64/kernel/traps.c |    5 +++++
 arch/x86_64/mm/fault.c     |    6 ++++++
 init/main.c                |    4 ++++
 kernel/panic.c             |    5 +++++
 4 files changed, 20 insertions(+), 0 deletions(-)

diff --git a/arch/x86_64/kernel/traps.c b/arch/x86_64/kernel/traps.c
index 09d2e8a..b4f1a36 100644
--- a/arch/x86_64/kernel/traps.c
+++ b/arch/x86_64/kernel/traps.c
@@ -32,6 +32,7 @@
 #include <linux/unwind.h>
 #include <linux/uaccess.h>
 #include <linux/bug.h>
+#include <linux/trec.h>
 
 #include <asm/system.h>
 #include <asm/io.h>
@@ -547,9 +548,13 @@ void die(const char * str, struct pt_regs * regs, long err)
 {
 	unsigned long flags = oops_begin();
 
+	trec_snapshot();
+
 	if (!user_mode(regs))
 		report_bug(regs->rip);
 
+	trec_print_snapshot();
+
 	__die(str, regs, err);
 	oops_end(flags);
 	do_exit(SIGSEGV); 
diff --git a/arch/x86_64/mm/fault.c b/arch/x86_64/mm/fault.c
index 6ada723..e92f6bc 100644
--- a/arch/x86_64/mm/fault.c
+++ b/arch/x86_64/mm/fault.c
@@ -24,6 +24,7 @@
 #include <linux/module.h>
 #include <linux/kprobes.h>
 #include <linux/uaccess.h>
+#include <linux/trec.h>
 
 #include <asm/system.h>
 #include <asm/pgalloc.h>
@@ -535,6 +536,8 @@ no_context:
 
 	flags = oops_begin();
 
+	trec_snapshot();
+
 	if (address < PAGE_SIZE)
 		printk(KERN_ALERT "Unable to handle kernel NULL pointer dereference");
 	else
@@ -548,6 +551,9 @@ no_context:
 	__die("Oops", regs, error_code);
 	/* Executive summary in case the body of the oops scrolled away */
 	printk(KERN_EMERG "CR2: %016lx\n", address);
+	
+	trec_print_snapshot();
+
 	oops_end(flags);
 	do_exit(SIGKILL);
 
diff --git a/init/main.c b/init/main.c
index a92989e..46bc440 100644
--- a/init/main.c
+++ b/init/main.c
@@ -54,6 +54,7 @@
 #include <linux/lockdep.h>
 #include <linux/pid_namespace.h>
 #include <linux/device.h>
+#include <linux/trec.h>
 
 #include <asm/io.h>
 #include <asm/bugs.h>
@@ -517,6 +518,9 @@ asmlinkage void __init start_kernel(void)
 	early_boot_irqs_off();
 	early_init_irq_lock_class();
 
+	trec_init();
+	TREC0();
+
 /*
  * Interrupts are still disabled. Do necessary setups, then
  * enable them
diff --git a/kernel/panic.c b/kernel/panic.c
index 623d182..52812f2 100644
--- a/kernel/panic.c
+++ b/kernel/panic.c
@@ -19,6 +19,7 @@
 #include <linux/nmi.h>
 #include <linux/kexec.h>
 #include <linux/debug_locks.h>
+#include <linux/trec.h>
 
 int panic_on_oops;
 int tainted;
@@ -66,6 +67,8 @@ NORET_TYPE void panic(const char * fmt, ...)
         unsigned long caller = (unsigned long) __builtin_return_address(0);
 #endif
 
+	trec_snapshot();
+
 	/*
 	 * It's possible to come here directly from a panic-assertion and not
 	 * have preempt disabled. Some functions called from here want
@@ -96,6 +99,8 @@ NORET_TYPE void panic(const char * fmt, ...)
 	smp_send_stop();
 #endif
 
+	trec_print_snapshot();
+
 	atomic_notifier_call_chain(&panic_notifier_list, 0, buf);
 
 	if (!panic_blink)
-- 
1.5.0.rc2

Re: [PATCH 2/3] Trec driver.

[Randy Dunlap]

On Sat, 24 Mar 2007 16:51:38 -0700 Wink Saville wrote:

> This is the Trec driver, Makefile, header files.
> Enable trec in Kernel hacking configuration menu.
> 
> Signed-off-by: Wink Saville <wink@saville.com>
> ---

> diff --git a/drivers/trec/trec.c b/drivers/trec/trec.c
> new file mode 100644
> index 0000000..0b04b71
> --- /dev/null
> +++ b/drivers/trec/trec.c
> @@ -0,0 +1,404 @@
...
> +
> +struct trec_dev_struct
> +{
> +	struct	cdev		cdev;			/* Character device structure */

Fit in 80 columns, please.

> +};
> +
> +MODULE_AUTHOR("Wink Saville");
> +MODULE_LICENSE("Dual BSD/GPL");
> +
> +/*
> + * Module parameters
> + */
> +int major = 240;	/* 240 a "local/expermental" device number for the moment */
> +int minor = 1;
> +
> +module_param(major, int, S_IRUGO);
> +module_param(minor, int, S_IRUGO);
> +
> +/*
> + * Forward declarations
> + */
> +static int trec_open(struct inode *inode, struct file *file);
> +static int trec_release(struct inode *inode, struct file *file);
> +
> +/*
> + * File operations
> + */
> +struct file_operations trec_f_ops = {
> +	.owner		=	THIS_MODULE,
> +	.open		=	trec_open,
> +	.release	=	trec_release,
> +};
> +
> +struct trec_struct {
> +	uint64_t	tsc;
> +	unsigned long	pc;
> +	unsigned long	tsk;
> +	unsigned int	pid;
> +	unsigned long	v1;
> +	unsigned long	v2;
> +};
> +
> +/*
> + * Change trec_buffer_struct.data to be a pointer to a PAGE in the future
> + */
> +#define TREC_DATA_SIZE 0x200
> +struct trec_buffer_struct {
> +	struct trec_buffer_struct *	next;
> +	struct trec_struct *		cur;
> +	struct trec_struct *		end;
> +	struct trec_struct		data[TREC_DATA_SIZE];

Kernel style is:
	sturct trec_struct		*cur;

> +};
> +
> +/*
> + * Number of buffers must be a multiple of two so we can
> + * snapshot the buffers and the minimum should be 4.
> + */
> +#define	TREC_COUNT 2
> +struct trec_buffer_struct 	trec_buffers[2][TREC_COUNT];
> +int				trec_idx = 0;
> +spinlock_t 			trec_lock = SPIN_LOCK_UNLOCKED;
> +
> +struct trec_buffer_struct *	trec_buffer_cur = NULL;
> +struct trec_buffer_struct *	trec_buffer_snapshot = NULL;

Pointer style.  + don't init to NULL.

> +
> +struct trec_dev_struct 		trec_dev;
> +
> +/**
> + * Print an address symbol if available to the buffer
> + * this is from traps.c
> + */

Don't use kernel-doc indicator ("/**") unless the function block
comment is actually in kernel-doc syntax (see
Documentation/kernel-doc-nano-HOWTO.txt).

> +static int snprint_address(char *b, int bsize, unsigned long address)
> +{
> +#ifdef CONFIG_KALLSYMS
> +	unsigned long offset = 0, symsize;
> +	const char *symname;
> +	char *modname;
> +	char *delim = ":";
> +	int n;
> +	char namebuf[128];
> +
> +	symname = kallsyms_lookup(address, &symsize, &offset, &modname, namebuf);
> +	if (!symname) {
> +		n = 0;
> +	} else {
> +		if (!modname)
> +			modname = delim = ""; 		
> +		n = snprintf(b, bsize, "0x%016lx %s%s%s%s+0x%lx/0x%lx",
> +			address, delim, modname, delim, symname, offset, symsize);
> +	}
> +	return n;
> +#else
> +	return snprintf(b, bsize, "0x%016lx", address);
> +#endif
> +}

> +/*
> + * Snapshot the current trecs
> + */
> +void trec_snapshot(void)
> +{
> +	int flags;
> +
> +	spin_lock_irqsave(&trec_lock, flags);
> +	trec_buffer_snapshot = trec_buffer_cur;
> +	trec_idx = trec_idx ^ 1;
> +	trec_buffer_cur = &trec_buffers[trec_idx][0];
> +	spin_unlock_irqrestore(&trec_lock, flags);
> +}
> +EXPORT_SYMBOL(trec_snapshot);

What (if anything) prevents multiple snapshots from overwriting
each other, or from being overwritten while one is printing?

> +/*
> + * trec_print
> + */
> +void trec_print_snapshot(void)
> +{
> +	int i;
> +	struct trec_buffer_struct *cur_buffer;
> +
> +	if (!trec_buffer_snapshot)
> +		trec_snapshot();
> +
> +	cur_buffer = trec_buffer_snapshot->next;
> +	for (i = 0; i < TREC_COUNT; i++) {
> +		struct trec_struct *cur;
> +
> +		for (cur = &cur_buffer->data[0];
> +			cur < cur_buffer->cur;
> +			cur += 1) {
> +			char b[256];
> +			int n;
> +			
> +			n = snprintf(b, sizeof(b), KERN_ERR "t=%20llu pid=%5u tsk=%p v1=%p v2=%p ",
> +				cur->tsc, cur->pid, (void *)cur->tsk, (void *)cur->v1, (void *)cur->v2);
> +			n += snprint_address(b+n, sizeof(b)-n, cur->pc);
> +			printk("%s\n", b);
> +		}
> +		cur_buffer = cur_buffer->next;
> +	}
> +}
> +EXPORT_SYMBOL(trec_print_snapshot);
> +
> +/*
> + * Sysrq support for trec's
> + */
> +#ifdef CONFIG_MAGIC_SYSRQ
> +/*
> + * trec print snapshot handler for sysrq
> + */
> +static void sysrq_handle_trec_print_snapshot(int key, struct tty_struct *tty) 
> +{
> +	trec_print_snapshot();
> +}
> +
> +/*
> + * trec snapshot handler for sysrq
> + */
> +static void sysrq_handle_trec_snapshot(int key, struct tty_struct *tty) 
> +{
> +	trec_snapshot();
> +}
> +
> +static struct sysrq_key_op sysrq_trec_snapshot_op = 
> +{
> +	.handler =	sysrq_handle_trec_snapshot,
> +	.help_msg =	"Trec snapshot(Y)",
> +	.action_msg =	"Trec snapshot",
> +};
> +
> +static struct sysrq_key_op sysrq_trec_print_snapshot_op = 
> +{
> +	.handler =	sysrq_handle_trec_print_snapshot,
> +	.help_msg =	"Print current trec snapshot",

(Z) should be on the help_msg, not on the action_msg.

> +	.action_msg =	"Trec print snapshot(Z)",
> +};
> +
> +/*
> + * Initilize trec sysrq support

      Initialize

> + */
> +static int __init setup_trec_sysrq(void)
> +{
> +	DPK("setup_trec_sysrq y=trec_snapshot z=trec_print_snapshot\n");
> +	register_sysrq_key('y', &sysrq_trec_snapshot_op);
> +	register_sysrq_key('z', &sysrq_trec_print_snapshot_op);
> +	return 0;
> +}
> +__initcall(setup_trec_sysrq);
> +#endif /* CONFIG_MAGIC_SYSRQ */

> +/*
> + * Init routine for the trec device
> + */
> +static int __init trec_device_init(void)
> +{
> +	int 		result;
> +	dev_t 		dev_number = 0;
> +	static struct 	class *trec_class;
> +
> +	DPK("trec_device_init: E\n");
> +
> +	if (major) {
> +		dev_number = MKDEV(major, minor);
> +		result = register_chrdev_region(dev_number, 1, "trec");
> +		DPK("trec_device_init: static major result=%d\n", result);
> +	} else {
> +		result = alloc_chrdev_region(&dev_number, minor, 1, "trec");
> +		major = MAJOR(dev_number);
> +		DPK("trec_device_init: dynamic major result=%d\n", result);
> +	}	
> +
> +	if (result < 0) {
> +		printk(KERN_WARNING "trec: can't get major %d\n", major);
> +		goto err;
> +	}
> +
> +	cdev_init(&trec_dev.cdev, &trec_f_ops);
> +	trec_dev.cdev.owner = THIS_MODULE;
> +	trec_dev.cdev.ops = &trec_f_ops;
> +	
> +	result = cdev_add(&trec_dev.cdev, dev_number, 1);
> +	if (result)
> +	{
> +		DPK("trec_device_init: cdev_add failed\n");
> +		goto err;
> +	}
> +
> +	/*
> +	 * Make a trec class and create the device
> +	 */
> +	trec_class = class_create(THIS_MODULE, "trec");
> +	class_device_create(trec_class, NULL, dev_number, NULL, "trec");
> +
> +	/*
> +	 * If the trec buffers have not been initialized do so
> +	 */
> +	if (trec_buffer_cur == NULL) {
> +		trec_init();
> +	}

Style: no braces on one-statement "blocks".

> +}

> diff --git a/include/asm-i386/trec.h b/include/asm-i386/trec.h
> new file mode 100644
> index 0000000..1de4dc6
> --- /dev/null
> +++ b/include/asm-i386/trec.h
> @@ -0,0 +1,33 @@
> +/*
> + * Copyright (C) 2007 Saville Software, Inc.
> + *
> + * This code may be used for any purpose whatsoever, but
> + * no warranty of any kind is provided.
> + */
> +
> +#ifndef _ASM_I386_TREC_H
> +#define _ASM_I386_TREC_H
> +
> +#ifndef __ASSEMBLY__
> +
> +#if CONFIG_X86_TSC 
> +#include <asm/msr.h>
> +
> +/*
> + * read x86 time stamp counter.
> + */
> +static uint64_t inline rd_tsc(void)
> +{
> +	volatile uint64_t value;
> +
> +	rdtscll(value);
> +
> +	return value;
> +}
> +#else
> +	#define rd_tsc() (0)

We don't typically indent (#if/) #else block contents like this.

> +#endif /* CONFIG_X86_TSC */
> +
> +#endif /* !__ASSEMBLY__ */
> +
> +#endif /* _ASM_I386_TREC_H */

> diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug
> index 3f3e740..db53fdb 100644
> --- a/lib/Kconfig.debug
> +++ b/lib/Kconfig.debug
> @@ -303,6 +303,13 @@ config STACKTRACE
>  	depends on DEBUG_KERNEL
>  	depends on STACKTRACE_SUPPORT
>  
> +config TREC
> + 	def_bool n
> + 	bool "Trace record support"
> + 	depends on DEBUG_KERNEL
> + 	help
> + 	  Trace records are a light weight tracing facility

                              lightweight   ...    facility.

> +
>  config DEBUG_KOBJECT
>  	bool "kobject debugging"
>  	depends on DEBUG_KERNEL


---
~Randy
*** Remember to use Documentation/SubmitChecklist when testing your code ***

Re: [PATCH 1/3] Documention for trace records (trec).

[Randy Dunlap]

On Sat, 24 Mar 2007 16:51:37 -0700 Wink Saville wrote:

> Trec is a light weight tracing mechanism that places
> trace information into a buffer. The contents of the
> buffer is dumped when errors occurs or when enabled
> via SYSRQ commands.
> 
> Signed-off-by: Wink Saville <wink@saville.com>
> ---
>  Documentation/trec.txt |   87 ++++++++++++++++++++++++++++++++++++++++++++++++
>  1 files changed, 87 insertions(+), 0 deletions(-)
>  create mode 100644 Documentation/trec.txt
> 
> diff --git a/Documentation/trec.txt b/Documentation/trec.txt
> new file mode 100644
> index 0000000..2275edd
> --- /dev/null
> +++ b/Documentation/trec.txt
> @@ -0,0 +1,87 @@
> +Title	: Trace Records
> +Authors	: Wink Saville <wink@saville.com>
> +
> +CONTENTS
> +
> +1. Concepts
> +2. Architectures Supported
> +3. Configuring
> +4. API Reference
> +5. Overhead
> +6. TODO
> +
> +
> +1. Concepts
> +
> +Trace records are a light weight tracing technique that time stamps

                       lightweight                 ...     timestamps

> +small amounts of information and stores them in a buffer. TREC's are
> +light enough that they may be sprinkled most anywhere in the kernel
> +and have very little performance impact.
> +
> +For instance they can be placed in the scheduler and ISR's to watch
> +the interaction between ISR's and the scheduler. They can be placed
> +in memory handling routines to determine how and when memory is
> +allocated and freed.
> +
> +In the current default configuration the trec's are dumped by calling
> +trec_print_snapshot when die() or panic() are called as well as when

                                             is

> +the kernel itself page faults in do_page_fault.
> +
> +If CONFIG_MAGIC_SYSRQ is the 'y' command will execute trec_snapshot
                           ^
                           enabled,

> +and the 'z' command will print the current snapshot.
> +
> +A general macro TREC allows trec_write to be invoked as a macro and
> +TRECC allows it to be invoked conditionally. See include/linux/trec.h
> +for the current set of macros.
> +
> +2. Architectures Supported
> +
> +Should support all architectures has been tested only on:
                                   ^
                                   ;
> +
> +- X86_64
> +
> +
> +3. Configuring
> +
> +Since trec's are implemented as a device driver they are configured
> +by enabling support in the "Device Drivers" section of as they could
                                                         ^
                                                         ??

> +be used early being a module is not supported.
> +
> +
> +4. API Reference
> +
> +Trec supports the following API:
> +
> +void trec_init(void):
> +
> +  Initialize the module, this may be called before the driver is loaded
                          ^
                          ; (or maybe :)

> +  if it is desired to use trec's early.
> +
> +void trec_write(unsigned long pc, int pid, unsigned long v1, unsigned long v2);
> +
> +  This is the routine used to write into the buffer. pc is the program counter

end above line with ,

> +  pid is the process id and v1 and v2 are two parameters.
> +
> +void trec_snapshot(void);
> +
> +  Calling this function takes a snapshot of the current trec buffer so that it
> +  will not be modified. This is called prior to printing the snapshot via
> +  trec_print_snapshot.
> +
> +void trec_print_snapshot(void);
> +
> +  Print the snapshot.
> +
> +5. Overhead
> +
> +Measured on a 2.4GHZ Core 2 Duo the readings between two TREC's is
> +270 tics of the rdtsc or about 0.1us. No attempt has been made to
> +optimize and less information can be collected if the overhead
> +is still to high.

            too

> +
> +
> +6. TODO
> +
> +a. Add code to dump trec to user space
> +b. Enhance to allow runtime registration and runtime enable disable.
> +


---
~Randy
*** Remember to use Documentation/SubmitChecklist when testing your code ***

Re: [PATCH 1/3] Documention for trace records (trec).

[Andi Kleen]

Wink Saville <wink@saville.com> writes:

> Trec is a light weight tracing mechanism that places
> trace information into a buffer. The contents of the
> buffer is dumped when errors occurs or when enabled
> via SYSRQ commands.

relayfs was supposed to fill this purpose. Why do you want
another one?

It doesn't work for sysrq dumping on fatal errors, but in my 
experience on such cases custom tracing is best.

-Andi