Function tracing support for pstore

PATCH Superseded Anton Vorontsov 5 participants 11 messages May 26, 2012 – Jun 8, 2012

Subsystems (3)

Documentation Tracing Pstore filesystem

lore

Share & tools

lore

Anton Vorontsov

author

2012-05-26 13:35 UTC #0 lore raw

cover Function tracing support for pstore

Hi all,

With this support kernel can save functions call chain log into a persistent ram buffer that can be decoded and dumped after reboot through pstore filesystem. It can be used to determine what function was last called before a hang or an unexpected reset (caused by, for example, a buggy driver that abuses HW).

Here's a "nano howto", to get the idea:

 # mount -t debugfs debugfs /sys/kernel/debug/
 # cd /sys/kernel/debug/tracing
 # echo persistent > current_tracer
 # reboot -f
 [...]
 # mount -t pstore pstore /mnt/
 # tail /mnt/ftrace-ramoops
 0 ffffffff8101ea64  ffffffff8101bcda  native_apic_mem_read <- disconnect_bsp_APIC+0x6a/0xc0
 0 ffffffff8101ea44  ffffffff8101bcf6  native_apic_mem_write <- disconnect_bsp_APIC+0x86/0xc0
 0 ffffffff81020084  ffffffff8101a4b5  hpet_disable <- native_machine_shutdown+0x75/0x90
 0 ffffffff81005f94  ffffffff8101a4bb  iommu_shutdown_noop <- native_machine_shutdown+0x7b/0x90
 0 ffffffff8101a6a1  ffffffff8101a437  native_machine_emergency_restart <- native_machine_restart+0x37/0x40
 0 ffffffff811f9876  ffffffff8101a73a  acpi_reboot <- native_machine_emergency_restart+0xaa/0x1e0
 0 ffffffff8101a514  ffffffff8101a772  mach_reboot_fixups <- native_machine_emergency_restart+0xe2/0x1e0
 0 ffffffff811d9c54  ffffffff8101a7a0  __const_udelay <- native_machine_emergency_restart+0x110/0x1e0
 0 ffffffff811d9c34  ffffffff811d9c80  __delay <- __const_udelay+0x30/0x40
 0 ffffffff811d9d14  ffffffff811d9c3f  delay_tsc <- __delay+0xf/0x20

Mostly the code comes from trace_persistent.c driver found in the Android git tree, written by Colin Cross <[email protected]> (according to sign-off history). I reworked the driver a little bit, and ported it to pstore subsystem.

The patches depend on a pile of other pstore-related work, so if anyone is willing to try the patches, they would rather grab the whole git tree:
git://git.infradead.org/users/cbou/linux-pstore.git
or gitweb:
http://git.infradead.org/users/cbou/linux-pstore.git

Note that so far I've tried to not change the original idea, but if we consider inclusion, there are some open questions:

1. Should we merge persistent tracer with normal function tracer, i.e. add some flag that makes function tracer to duplicate the events into pstore (via a callback to pstore)?

2. If we keep the two separate, should the code live in fs/pstore or kernel/trace?.. I can see valid points for both approaches.

Thanks,

---
 Documentation/ramoops.txt  |   24 +++++++++
 fs/pstore/Kconfig          |   12 +++++
 fs/pstore/Makefile         |    6 +++
 fs/pstore/ftrace.c         |  122 ++++++++++++++++++++++++++++++++++++++++++++
 fs/pstore/inode.c          |  111 ++++++++++++++++++++++++++++++++++++++--
 fs/pstore/internal.h       |   49 ++++++++++++++++++
 fs/pstore/platform.c       |   13 ++++-
 fs/pstore/ram.c            |   54 +++++++++++++++-----
 include/linux/pstore.h     |    5 ++
 include/linux/pstore_ram.h |    1 +
 kernel/trace/trace.c       |    7 +--
 11 files changed, 384 insertions(+), 20 deletions(-)

Signature · 2 lines

Anton Vorontsov
Email: [email protected]

Anton Vorontsov

author

2012-05-26 13:41 UTC #1 lore raw

PATCH 1/5 tracing: Fix initialization failure path in tracing_set_tracer()

If tracer->init() fails, current code will leave current_tracer pointing to an unusable tracer, which at best makes 'current_tracer' report inaccurate value.

Fix the issue by pointing current_tracer to nop tracer, and only update current_tracer with the new one after all the initialization succeeds.

Signed-off-by Anton Vorontsov <[email protected]>

---
 kernel/trace/trace.c |    7 ++++---
 1 file changed, 4 insertions(+), 3 deletions(-)

kernel/trace/trace.c +4 -3

index 68032c6..5cf7e67 100644
@@ -3172,10 +3172,10 @@ static int tracing_set_tracer(const char *buf)
 	}
 	destroy_trace_option_files(topts);
 
-	current_trace = t;
+	current_trace = &nop_trace;
 
-	topts = create_trace_option_files(current_trace);
-	if (current_trace->use_max_tr) {
+	topts = create_trace_option_files(t);
+	if (t->use_max_tr) {
 		int cpu;
 		/* we need to make per cpu buffer sizes equivalent */
 		for_each_tracing_cpu(cpu) {

@@ -3195,6 +3195,7 @@ static int tracing_set_tracer(const char *buf)
 			goto out;
 	}
 
+	current_trace = t;
 	trace_branch_enable(tr);
  out:
 	mutex_unlock(&trace_types_lock);

Signature · 1 line

1.7.9.2

Steven Rostedt

maintainer

2012-05-30 19:44 UTC #2 lore raw

Re: [PATCH 1/5] tracing: Fix initialization failure path in tracing_set_tracer()

Quoted 7 lines · Anton Vorontsov

If tracer->init() fails, current code will leave current_tracer pointing to an unusable tracer, which at best makes 'current_tracer' report inaccurate value.
Fix the issue by pointing current_tracer to nop tracer, and only update current_tracer with the new one after all the initialization succeeds.

Hmm, I'll look at this in more detail. This may be something I pull now. (for 3.6).

-- Steve

Quoted 31 lines

Signed-off-by Anton Vorontsov <[email protected]>

---
 kernel/trace/trace.c |    7 ++++---
 1 file changed, 4 insertions(+), 3 deletions(-)

kernel/trace/trace.c +4 -3

index 68032c6..5cf7e67 100644
@@ -3172,10 +3172,10 @@ static int tracing_set_tracer(const char *buf)
 	}
 	destroy_trace_option_files(topts);
 
-	current_trace = t;
+	current_trace = &nop_trace;
 
-	topts = create_trace_option_files(current_trace);
-	if (current_trace->use_max_tr) {
+	topts = create_trace_option_files(t);
+	if (t->use_max_tr) {
 		int cpu;
 		/* we need to make per cpu buffer sizes equivalent */
 		for_each_tracing_cpu(cpu) {

@@ -3195,6 +3195,7 @@ static int tracing_set_tracer(const char *buf)
 			goto out;
 	}
 
+	current_trace = t;
 	trace_branch_enable(tr);
  out:
 	mutex_unlock(&trace_types_lock);

Anton Vorontsov

author

2012-05-26 13:41 UTC #3 lore raw

PATCH 2/5 pstore: Introduce write_buf backend callback

In reply to Anton Vorontsov

For function tracing we need to stop using pstore.buf directly, since in a tracing callback we can't use spinlocks, and thus we can't safely use the global buffer.

With write_buf callback, backends no longer need to access pstore.buf directly, and thus we can pass any buffers (e.g. allocated on stack).

Signed-off-by Anton Vorontsov <[email protected]>

---
 fs/pstore/platform.c   |   10 ++++++++++
 include/linux/pstore.h |    4 ++++
 2 files changed, 14 insertions(+)

fs/pstore/platform.c +10 -0

index be4614f..e7c0a52 100644
@@ -198,6 +198,14 @@ static void pstore_register_console(void)
 static void pstore_register_console(void) {}
 #endif
 
+static int pstore_write_compat(enum pstore_type_id type,
+			       enum kmsg_dump_reason reason,
+			       u64 *id, unsigned int part,
+			       size_t size, struct pstore_info *psi)
+{
+	return psi->write_buf(type, reason, id, part, psinfo->buf, size, psi);
+}
+
 /*
  * platform specific persistent storage driver registers with
  * us here. If pstore is already mounted, call the platform

@@ -222,6 +230,8 @@ int pstore_register(struct pstore_info *psi)
 		return -EINVAL;
 	}
 
+	if (!psi->write)
+		psi->write = pstore_write_compat;
 	psinfo = psi;
 	mutex_init(&psinfo->read_mutex);
 	spin_unlock(&pstore_lock);

include/linux/pstore.h +4 -0

index 1bd014b..b107484 100644
@@ -48,6 +48,10 @@ struct pstore_info {
 	int		(*write)(enum pstore_type_id type,
 			enum kmsg_dump_reason reason, u64 *id,
 			unsigned int part, size_t size, struct pstore_info *psi);
+	int		(*write_buf)(enum pstore_type_id type,
+			enum kmsg_dump_reason reason, u64 *id,
+			unsigned int part, const char *buf, size_t size,
+			struct pstore_info *psi);
 	int		(*erase)(enum pstore_type_id type, u64 id,
 			struct pstore_info *psi);
 	void		*data;

Signature · 1 line

1.7.9.2

Kees Cook

2012-05-29 16:29 UTC #4 lore raw

Re: [PATCH 2/5] pstore: Introduce write_buf backend callback

Quoted 6 lines · Anton Vorontsov

For function tracing we need to stop using pstore.buf directly, since in a tracing callback we can't use spinlocks, and thus we can't safely use the global buffer.
With write_buf callback, backends no longer need to access pstore.buf directly, and thus we can pass any buffers (e.g. allocated on stack).

Hrm, I thought the point of having pstore.buf pre-mapped was to allow Oopses to be able to write directly to it without needing to hit any additional kernel code. Maybe I'm misunderstanding this change, though. I'd like to see Tony's opinion on it.

-Kees

Quoted 52 lines

Signed-off-by Anton Vorontsov <[email protected]>

---
fs/pstore/platform.c | 10 ++++++++++
include/linux/pstore.h | 4 ++++

 2 files changed, 14 insertions(+)

fs/pstore/platform.c +10 -0

index be4614f..e7c0a52 100644
@@ -198,6 +198,14 @@ static void pstore_register_console(void)
  static void pstore_register_console(void) {}
  #endif
 
+static int pstore_write_compat(enum pstore_type_id type,
+                              enum kmsg_dump_reason reason,
+                              u64 *id, unsigned int part,
+                              size_t size, struct pstore_info *psi)
+{
+       return psi->write_buf(type, reason, id, part, psinfo->buf, size, psi);
+}
+
  /*
  * platform specific persistent storage driver registers with
  * us here. If pstore is already mounted, call the platform

@@ -222,6 +230,8 @@ int pstore_register(struct pstore_info *psi)
                return -EINVAL;
        }
 
+       if (!psi->write)
+               psi->write = pstore_write_compat;
        psinfo = psi;
        mutex_init(&psinfo->read_mutex);
        spin_unlock(&pstore_lock);

include/linux/pstore.h +4 -1

index 1bd014b..b107484 100644
@@ -48,6 +48,10 @@ struct pstore_info {
        int             (*write)(enum pstore_type_id type,
                        enum kmsg_dump_reason reason, u64 *id,
                        unsigned int part, size_t size, struct pstore_info *psi);
+       int             (*write_buf)(enum pstore_type_id type,
+                       enum kmsg_dump_reason reason, u64 *id,
+                       unsigned int part, const char *buf, size_t size,
+                       struct pstore_info *psi);
        int             (*erase)(enum pstore_type_id type, u64 id,
                        struct pstore_info *psi);
        void            *data;
--

1.7.9.2

Signature · 2 lines

Kees Cook
Chrome OS Security

Luck, Tony

reviewer

2012-05-29 18:00 UTC #5 lore raw

RE: [PATCH 2/5] pstore: Introduce write_buf backend callback

Quoted 4 lines

Hrm, I thought the point of having pstore.buf pre-mapped was to allow Oopses to be able to write directly to it without needing to hit any additional kernel code. Maybe I'm misunderstanding this change, though. I'd like to see Tony's opinion on it.

Yes - the ERST backend needs to have a bunch of header ugliness (with special UUIDs) at the front of the buffer that is stored to non-volatile storage. So it allocates its own buffer with all that junk, and then passes the address of the plain data portion of the buffer on to the pstore layer.

As we add more backends, it might be that this is only applicable to ERST, and so it might make sense to have it copy the data from some other buffer into its specially crafted one. But we should not lose the "no allocations" property ... everything needed should be pre-allocated so we don't have to try to allocate any memory during a panic.

-Tony

Anton Vorontsov

2012-06-08 02:12 UTC #6 lore raw

Re: [PATCH 2/5] pstore: Introduce write_buf backend callback

Quoted 11 lines · Tony

Quoted 4 lines
Hrm, I thought the point of having pstore.buf pre-mapped was to allow Oopses to be able to write directly to it without needing to hit any additional kernel code. Maybe I'm misunderstanding this change, though. I'd like to see Tony's opinion on it.
Yes - the ERST backend needs to have a bunch of header ugliness (with special UUIDs) at the front of the buffer that is stored to non-volatile storage. So it allocates its own buffer with all that junk, and then passes the address of the plain data portion of the buffer on to the pstore layer.

Quoted 5 lines

As we add more backends, it might be that this is only applicable to ERST, and so it might make sense to have it copy the data from some other buffer into its specially crafted one. But we should not lose the "no allocations" property ... everything needed should be pre-allocated so we don't have to try to allocate any memory during a panic.

Yep, and everything is still pre-allocated.

The only change is that we can pass different buffers, and in tracing case it is allocated on the stack (we can't use pstore.buf for tracing as it would require grabbing pstore_lock, which we can't do -- the locking operations are traced too, so it would recurse).

Thanks,

Signature · 2 lines

Anton Vorontsov
Email: [email protected]

Anton Vorontsov

author

2012-05-26 13:41 UTC #7 lore raw

PATCH 3/5 pstore: Add persistent function tracing

In reply to Anton Vorontsov

With this support kernel can save function call chain log into a persistent ram buffer that can be decoded and dumped after reboot through pstore filesystem. It can be used to determine what function was last called before a reset or panic.

We store the log in a binary format and then decode it at read time.

p.s.
Mostly the code comes from trace_persistent.c driver found in the Android git tree, written by Colin Cross <[email protected]> (according to sign-off history). I reworked the driver a little bit, and ported it to pstore.

Signed-off-by Anton Vorontsov <[email protected]>

---
 fs/pstore/Kconfig      |   12 +++++
 fs/pstore/Makefile     |    6 +++
 fs/pstore/ftrace.c     |  122 ++++++++++++++++++++++++++++++++++++++++++++++++
 fs/pstore/inode.c      |  111 +++++++++++++++++++++++++++++++++++++++++--
 fs/pstore/internal.h   |   49 +++++++++++++++++++
 fs/pstore/platform.c   |    3 +-
 include/linux/pstore.h |    1 +
 7 files changed, 299 insertions(+), 5 deletions(-)
 create mode 100644 fs/pstore/ftrace.c

fs/pstore/Kconfig +12 -0

index d044de6..d39bb5c 100644
@@ -19,6 +19,18 @@ config PSTORE_CONSOLE
 	  When the option is enabled, pstore will log all kernel
 	  messages, even if no oops or panic happened.
 
+config PSTORE_FTRACE
+	bool "Persistent function tracer"
+	depends on PSTORE
+	depends on FUNCTION_TRACER
+	help
+	  With this option kernel traces function calls into a persistent
+	  ram buffer that can be decoded and dumped after reboot through
+	  pstore filesystem. It can be used to determine what function
+	  was last called before a reset or panic.
+
+	  If unsure, say N.
+
 config PSTORE_RAM
 	tristate "Log panic/oops to a RAM buffer"
 	depends on PSTORE

fs/pstore/Makefile +6 -0

index 278a44e..cc6aa3d 100644
@@ -7,4 +7,10 @@ obj-y += pstore.o
 pstore-objs += inode.o platform.o
 
 ramoops-objs += ram.o ram_core.o
+
+ifeq ($(CONFIG_PSTORE_FTRACE),y)
+ramoops-objs += ftrace.o
+CFLAGS_REMOVE_ftrace.o = -pg
+endif
+
 obj-$(CONFIG_PSTORE_RAM)	+= ramoops.o

fs/pstore/ftrace.c new file +122 -0

122 lines not on this page · raw message

fs/pstore/inode.c +107 -4

137 lines not on this page · raw message

fs/pstore/internal.h +49 -0

55 lines not on this page · raw message

fs/pstore/platform.c +2 -1

index e7c0a52..89995da 100644
@@ -61,7 +61,7 @@ static DECLARE_WORK(pstore_work, pstore_dowork);
  * calls to pstore_register()
  */
 static DEFINE_SPINLOCK(pstore_lock);
-static struct pstore_info *psinfo;
+struct pstore_info *psinfo;
 
 static char *backend;

@@ -246,6 +246,7 @@ int pstore_register(struct pstore_info *psi)
 
 	kmsg_dump_register(&pstore_dumper);
 	pstore_register_console();
+	pstore_register_ftrace();
 
 	if (pstore_update_ms >= 0) {
 		pstore_timer.expires = jiffies +

include/linux/pstore.h +1 -0

index b107484..23afffe 100644
@@ -30,6 +30,7 @@ enum pstore_type_id {
 	PSTORE_TYPE_DMESG	= 0,
 	PSTORE_TYPE_MCE		= 1,
 	PSTORE_TYPE_CONSOLE	= 2,
+	PSTORE_TYPE_FTRACE	= 3,
 	PSTORE_TYPE_UNKNOWN	= 255
 };

Signature · 1 line

1.7.9.2

Anton Vorontsov

author

2012-05-26 13:41 UTC #8 lore raw

PATCH 4/5 pstore/ram: Convert to write_buf callback

In reply to Anton Vorontsov

Don't use pstore.buf directly, instead convert the code to write_buf callback which passes a pointer to a buffer as an argument.

Signed-off-by Anton Vorontsov <[email protected]>

---
 fs/pstore/ram.c |   17 +++++++++--------
 1 file changed, 9 insertions(+), 8 deletions(-)

fs/pstore/ram.c +9 -8

index c7acf94..96dbd1e 100644
@@ -168,11 +168,12 @@ static size_t ramoops_write_kmsg_hdr(struct persistent_ram_zone *prz)
 	return len;
 }
 
-static int ramoops_pstore_write(enum pstore_type_id type,
-				enum kmsg_dump_reason reason,
-				u64 *id,
-				unsigned int part,
-				size_t size, struct pstore_info *psi)
+
+static int ramoops_pstore_write_buf(enum pstore_type_id type,
+				    enum kmsg_dump_reason reason,
+				    u64 *id, unsigned int part,
+				    const char *buf, size_t size,
+				    struct pstore_info *psi)
 {
 	struct ramoops_context *cxt = psi->data;
 	struct persistent_ram_zone *prz = cxt->przs[cxt->dump_write_cnt];

@@ -181,7 +182,7 @@ static int ramoops_pstore_write(enum pstore_type_id type,
 	if (type == PSTORE_TYPE_CONSOLE) {
 		if (!cxt->cprz)
 			return -ENOMEM;
-		persistent_ram_write(cxt->cprz, cxt->pstore.buf, size);
+		persistent_ram_write(cxt->cprz, buf, size);
 		return 0;
 	}

@@ -210,7 +211,7 @@ static int ramoops_pstore_write(enum pstore_type_id type,
 	hlen = ramoops_write_kmsg_hdr(prz);
 	if (size + hlen > prz->buffer_size)
 		size = prz->buffer_size - hlen;
-	persistent_ram_write(prz, cxt->pstore.buf, size);
+	persistent_ram_write(prz, buf, size);
 
 	cxt->dump_write_cnt = (cxt->dump_write_cnt + 1) % cxt->max_dump_cnt;

@@ -248,7 +249,7 @@ static struct ramoops_context oops_cxt = {
 		.name	= "ramoops",
 		.open	= ramoops_pstore_open,
 		.read	= ramoops_pstore_read,
-		.write	= ramoops_pstore_write,
+		.write_buf	= ramoops_pstore_write_buf,
 		.erase	= ramoops_pstore_erase,
 	},
 };

Signature · 1 line

1.7.9.2

Anton Vorontsov

author

2012-05-26 13:41 UTC #9 lore raw

PATCH 5/5 pstore/ram: Add ftrace messages handling

In reply to Anton Vorontsov

The ftrace log size is configurable via ramoops.ftrace_size module option, and the log itself is available via <pstore-mount>/ftrace-ramoops file.

Signed-off-by Anton Vorontsov <[email protected]>

---
 Documentation/ramoops.txt  |   24 ++++++++++++++++++++++++
 fs/pstore/ram.c            |   37 +++++++++++++++++++++++++++++++++----
 include/linux/pstore_ram.h |    1 +
 3 files changed, 58 insertions(+), 4 deletions(-)

Documentation/ramoops.txt +24 -0

index 59a74a8..dee307b 100644
@@ -94,3 +94,27 @@ timestamp and a new line. The dump then continues with the actual data.
 The dump data can be read from the pstore filesystem. The format for these
 files is "dmesg-ramoops-N", where N is the record number in memory. To delete
 a stored record from RAM, simply unlink the respective pstore file.
+
+5. Persistent function tracing
+
+Persistent function tracing might be useful for debugging software or hardware
+related hangs. The functions call chain log is stored in a "ftrace-ramoops"
+file. Here is an example of usage:
+
+ # mount -t debugfs debugfs /sys/kernel/debug/
+ # cd /sys/kernel/debug/tracing
+ # echo persistent > current_tracer
+ # reboot -f
+ [...]
+ # mount -t pstore pstore /mnt/
+ # tail /mnt/ftrace-ramoops
+ 0 ffffffff8101ea64  ffffffff8101bcda  native_apic_mem_read <- disconnect_bsp_APIC+0x6a/0xc0
+ 0 ffffffff8101ea44  ffffffff8101bcf6  native_apic_mem_write <- disconnect_bsp_APIC+0x86/0xc0
+ 0 ffffffff81020084  ffffffff8101a4b5  hpet_disable <- native_machine_shutdown+0x75/0x90
+ 0 ffffffff81005f94  ffffffff8101a4bb  iommu_shutdown_noop <- native_machine_shutdown+0x7b/0x90
+ 0 ffffffff8101a6a1  ffffffff8101a437  native_machine_emergency_restart <- native_machine_restart+0x37/0x40
+ 0 ffffffff811f9876  ffffffff8101a73a  acpi_reboot <- native_machine_emergency_restart+0xaa/0x1e0
+ 0 ffffffff8101a514  ffffffff8101a772  mach_reboot_fixups <- native_machine_emergency_restart+0xe2/0x1e0
+ 0 ffffffff811d9c54  ffffffff8101a7a0  __const_udelay <- native_machine_emergency_restart+0x110/0x1e0
+ 0 ffffffff811d9c34  ffffffff811d9c80  __delay <- __const_udelay+0x30/0x40
+ 0 ffffffff811d9d14  ffffffff811d9c3f  delay_tsc <- __delay+0xf/0x20

fs/pstore/ram.c +33 -4

index 96dbd1e..018d895 100644
@@ -45,6 +45,10 @@ static ulong ramoops_console_size = MIN_MEM_SIZE;
 module_param_named(console_size, ramoops_console_size, ulong, 0400);
 MODULE_PARM_DESC(console_size, "size of kernel console log");
 
+static ulong ramoops_ftrace_size = MIN_MEM_SIZE;
+module_param_named(ftrace_size, ramoops_ftrace_size, ulong, 0400);
+MODULE_PARM_DESC(ftrace_size, "size of ftrace log");
+
 static ulong mem_address;
 module_param(mem_address, ulong, 0400);
 MODULE_PARM_DESC(mem_address,

@@ -68,16 +72,19 @@ MODULE_PARM_DESC(ramoops_ecc,
 struct ramoops_context {
 	struct persistent_ram_zone **przs;
 	struct persistent_ram_zone *cprz;
+	struct persistent_ram_zone *fprz;
 	phys_addr_t phys_addr;
 	unsigned long size;
 	size_t record_size;
 	size_t console_size;
+	size_t ftrace_size;
 	int dump_oops;
 	bool ecc;
 	unsigned int max_dump_cnt;
 	unsigned int dump_write_cnt;
 	unsigned int dump_read_cnt;
 	unsigned int console_read_cnt;
+	unsigned int ftrace_read_cnt;
 	struct pstore_info pstore;
 };

@@ -136,6 +143,9 @@ static ssize_t ramoops_pstore_read(u64 *id, enum pstore_type_id *type,
 		prz = ramoops_get_next_prz(&cxt->cprz, &cxt->console_read_cnt,
 					   1, id, type, PSTORE_TYPE_CONSOLE, 0);
 	if (!prz)
+		prz = ramoops_get_next_prz(&cxt->fprz, &cxt->ftrace_read_cnt,
+					   1, id, type, PSTORE_TYPE_FTRACE, 0);
+	if (!prz)
 		return 0;
 
 	/* TODO(kees): Bogus time for the moment. */

@@ -184,6 +194,11 @@ static int ramoops_pstore_write_buf(enum pstore_type_id type,
 			return -ENOMEM;
 		persistent_ram_write(cxt->cprz, buf, size);
 		return 0;
+	} else if (type == PSTORE_TYPE_FTRACE) {
+		if (!cxt->fprz)
+			return -ENOMEM;
+		persistent_ram_write(cxt->fprz, buf, size);
+		return 0;
 	}
 
 	if (type != PSTORE_TYPE_DMESG)

@@ -233,6 +248,9 @@ static int ramoops_pstore_erase(enum pstore_type_id type, u64 id,
 	case PSTORE_TYPE_CONSOLE:
 		prz = cxt->cprz;
 		break;
+	case PSTORE_TYPE_FTRACE:
+		prz = cxt->fprz;
+		break;
 	default:
 		return -EINVAL;
 	}

@@ -346,7 +364,8 @@ static int __init ramoops_probe(struct platform_device *pdev)
 	if (cxt->max_dump_cnt)
 		goto fail_out;
 
-	if (!pdata->mem_size || (!pdata->record_size && !pdata->console_size)) {
+	if (!pdata->mem_size || (!pdata->record_size && !pdata->console_size &&
+			!pdata->ftrace_size)) {
 		pr_err("The memory size and the record/console size must be "
 			"non-zero\n");
 		goto fail_out;

@@ -355,18 +374,20 @@ static int __init ramoops_probe(struct platform_device *pdev)
 	pdata->mem_size = rounddown_pow_of_two(pdata->mem_size);
 	pdata->record_size = rounddown_pow_of_two(pdata->record_size);
 	pdata->console_size = rounddown_pow_of_two(pdata->console_size);
+	pdata->ftrace_size = rounddown_pow_of_two(pdata->ftrace_size);
 
 	cxt->dump_read_cnt = 0;
 	cxt->size = pdata->mem_size;
 	cxt->phys_addr = pdata->mem_address;
 	cxt->record_size = pdata->record_size;
 	cxt->console_size = pdata->console_size;
+	cxt->ftrace_size = pdata->ftrace_size;
 	cxt->dump_oops = pdata->dump_oops;
 	cxt->ecc = pdata->ecc;
 
 	paddr = cxt->phys_addr;
 
-	dump_mem_sz = cxt->size - cxt->console_size;
+	dump_mem_sz = cxt->size - cxt->console_size - cxt->ftrace_size;
 	err = ramoops_init_przs(dev, cxt, &paddr, dump_mem_sz);
 	if (err)
 		goto fail_out;

@@ -375,9 +396,14 @@ static int __init ramoops_probe(struct platform_device *pdev)
 	if (err)
 		goto fail_init_cprz;
 
-	if (!cxt->przs && !cxt->cprz) {
+	err = ramoops_init_prz(dev, cxt, &cxt->fprz, &paddr, cxt->ftrace_size);
+	if (err)
+		goto fail_init_fprz;
+
+	if (!cxt->przs && !cxt->cprz && !cxt->fprz) {
 		pr_err("memory size too small, minimum is %lu\n",
-			cxt->console_size + cxt->record_size);
+			cxt->console_size + cxt->record_size +
+			cxt->ftrace_size);
 		goto fail_cnt;
 	}

@@ -424,6 +450,8 @@ fail_clear:
 	cxt->pstore.bufsize = 0;
 	cxt->max_dump_cnt = 0;
 fail_cnt:
+	kfree(cxt->fprz);
+fail_init_fprz:
 	kfree(cxt->cprz);
 fail_init_cprz:
 	ramoops_free_przs(cxt);

@@ -478,6 +506,7 @@ static int __init ramoops_init(void)
 		dummy_data->mem_address = mem_address;
 		dummy_data->record_size = record_size;
 		dummy_data->console_size = ramoops_console_size;
+		dummy_data->ftrace_size = ramoops_ftrace_size;
 		dummy_data->dump_oops = dump_oops;
 		dummy_data->ecc = ramoops_ecc;
 		dummy = platform_create_bundle(&ramoops_driver, ramoops_probe,

include/linux/pstore_ram.h +1 -0

index 2470bb5..368da13 100644
@@ -75,6 +75,7 @@ struct ramoops_platform_data {
 	unsigned long	mem_address;
 	unsigned long	record_size;
 	unsigned long	console_size;
+	unsigned long	ftrace_size;
 	int		dump_oops;
 	bool		ecc;
 };

Signature · 1 line

1.7.9.2

Steven Rostedt

maintainer

2012-05-30 19:43 UTC #10 lore raw

In reply to Anton Vorontsov

Quoted 2 lines · Anton Vorontsov

Hi all,

Sorry for the late reply, Monday was US holiday, and I've been working days on finding (and fixing) a very nasty bug.

Quoted 6 lines

With this support kernel can save functions call chain log into a persistent ram buffer that can be decoded and dumped after reboot through pstore filesystem. It can be used to determine what function was last called before a hang or an unexpected reset (caused by, for example, a buggy driver that abuses HW).

Nice!

Quoted 33 lines

Here's a "nano howto", to get the idea:
 # mount -t debugfs debugfs /sys/kernel/debug/
 # cd /sys/kernel/debug/tracing
 # echo persistent > current_tracer
 # reboot -f
 [...]
 # mount -t pstore pstore /mnt/
 # tail /mnt/ftrace-ramoops
 0 ffffffff8101ea64  ffffffff8101bcda  native_apic_mem_read <- disconnect_bsp_APIC+0x6a/0xc0
 0 ffffffff8101ea44  ffffffff8101bcf6  native_apic_mem_write <- disconnect_bsp_APIC+0x86/0xc0
 0 ffffffff81020084  ffffffff8101a4b5  hpet_disable <- native_machine_shutdown+0x75/0x90
 0 ffffffff81005f94  ffffffff8101a4bb  iommu_shutdown_noop <- native_machine_shutdown+0x7b/0x90
 0 ffffffff8101a6a1  ffffffff8101a437  native_machine_emergency_restart <- native_machine_restart+0x37/0x40
 0 ffffffff811f9876  ffffffff8101a73a  acpi_reboot <- native_machine_emergency_restart+0xaa/0x1e0
 0 ffffffff8101a514  ffffffff8101a772  mach_reboot_fixups <- native_machine_emergency_restart+0xe2/0x1e0
 0 ffffffff811d9c54  ffffffff8101a7a0  __const_udelay <- native_machine_emergency_restart+0x110/0x1e0
 0 ffffffff811d9c34  ffffffff811d9c80  __delay <- __const_udelay+0x30/0x40
 0 ffffffff811d9d14  ffffffff811d9c3f  delay_tsc <- __delay+0xf/0x20
Mostly the code comes from trace_persistent.c driver found in the Android git tree, written by Colin Cross <[email protected]> (according to sign-off history). I reworked the driver a little bit, and ported it to pstore subsystem.
The patches depend on a pile of other pstore-related work, so if anyone is willing to try the patches, they would rather grab the whole git tree:
git://git.infradead.org/users/cbou/linux-pstore.git
or gitweb:
http://git.infradead.org/users/cbou/linux-pstore.git

Quoted 7 lines

Note that so far I've tried to not change the original idea, but if we consider inclusion, there are some open questions:
1. Should we merge persistent tracer with normal function tracer, i.e. add some flag that makes function tracer to duplicate the events into pstore (via a callback to pstore)?

What about making it a trace option? That is,
in .../debug/tracing/options, have 'persistent' and when that's selected, we change to using the persistent buffer. This could be for both function tracing and event tracing.

I'm currently working on getting 'multi' buffers working. I plan on presenting it at Linux Plumbers for more feedback. But it will be adding a lot of hooks that would probably make this rather trivial to implement.

-- Steve

Quoted 4 lines

2. If we keep the two separate, should the code live in fs/pstore or kernel/trace?.. I can see valid points for both approaches.
Thanks,