Home » Mailing list archives » linux-kernel » 2008 » August » 1

Re: [PATCH v2 2/2] ftrace: printk formatting infrastructure

Previous thread: [PATCH v2 0/2] ftrace: printk formatted recording by Steven Rostedt on Friday, August 1, 2008 - 12:26 pm. (3 messages)

Next thread: [PATCH v2 1/2] ftrace: new continue entry - separate out from trace_entry by Steven Rostedt on Friday, August 1, 2008 - 12:26 pm. (1 message)
[view original message]
From: Steven Rostedt <rostedt@...>
To: <linux-kernel@...>
Cc: Ingo Molnar <mingo@...>, Peter Zijlstra <peterz@...>, Thomas Gleixner <tglx@...>, Andrew Morton <akpm@...>, Steven Rostedt <srostedt@...>
Subject: [PATCH v2 2/2] ftrace: printk formatting infrastructure
Date: Friday, August 1, 2008 - 12:26 pm

This patch adds a feature that can help kernel developers debug their

code using ftrace.


  int ftrace_printk(const char *fmt, ...);


This records into the ftrace buffer using printf formatting. The entry

size in the buffers are still a fixed length. A new type has been added

that allows for more entries to be used for a single recording.


The start of the print is still the same as the other entries.


It returns the number of characters written to the ftrace buffer.


For example:


Having a module with the following code:


static int __init ftrace_print_test(void)

{

        ftrace_printk("jiffies are %ld\n", jiffies);

        return 0;

}


Gives me:


  insmod-5441  3...1 7569us : ftrace_print_test: jiffies are 4296626666


for the latency_trace file and:


          insmod-5441  [03]  1959.370498: ftrace_print_test jiffies are 4296626666


for the trace file.


Note: Only the infrastructure should go into the kernel. It is to help

facilitate debugging for other kernel developers. Calls to ftrace_printk

is not intended to be left in the kernel, and should be frowned upon just

like scattering printks around in the code.


But having this easily at your fingertips helps the debugging go faster

and bugs be solved quicker.


Maybe later on, we can hook this with markers and have their printf format

be sucked into ftrace output.


Signed-off-by: Steven Rostedt <srostedt@redhat.com>

---

 include/linux/ftrace.h        |   10 +

 kernel/trace/trace.c          |  273 +++++++++++++++++++++++++++++++++++++-----

 kernel/trace/trace.h          |   11 +

 kernel/trace/trace_selftest.c |   11 +

 4 files changed, 272 insertions(+), 33 deletions(-)


Index: linux-tip.git/include/linux/ftrace.h

===================================================================

--- linux-tip.git.orig/include/linux/ftrace.h	2008-08-01 11:55:08.000000000 -0400

+++ linux-tip.git/include/linux/ftrace.h	2008-08-01 12:09:11.000000000 -0400

@@ -137,10 +137,20 @@ static inline void tracer_disable(vo...
[ message continues ]
[view original message]
From: Randy Dunlap <randy.dunlap@...>
To: Steven Rostedt <rostedt@...>
Cc: <linux-kernel@...>, Ingo Molnar <mingo@...>, Peter Zijlstra <peterz@...>, Thomas Gleixner <tglx@...>, Andrew Morton <akpm@...>, Steven Rostedt <srostedt@...>
Subject: Re: [PATCH v2 2/2] ftrace: printk formatting infrastructure
Date: Friday, August 1, 2008 - 12:43 pm

* @fmt: the printf format for printing


---

~Randy

Linux Plumbers Conference, 17-19 September 2008, Portland, Oregon USA

http://linuxplumbersconf.org/

--
[view original message]
From: Steven Rostedt <rostedt@...>
To: Randy Dunlap <randy.dunlap@...>
Cc: <linux-kernel@...>, Ingo Molnar <mingo@...>, Peter Zijlstra <peterz@...>, Thomas Gleixner <tglx@...>, Andrew Morton <akpm@...>, Steven Rostedt <srostedt@...>
Subject: Re: [PATCH v2 2/2] ftrace: printk formatting infrastructure
Date: Friday, August 1, 2008 - 12:53 pm

The above note actually explains this ;-)


Should I move the description to the ftrace_printk macro?


In include/linux/ftrace.h you see:


#ifdef CONFIG_TRACING

[...]

# define ftrace_printk(x...) __ftrace_printk(_THIS_IP_, x)

extern int

__ftrace_printk(unsigned long ip, const char *fmt, ...)

        __attribute__ ((format (printf, 2, 3)));

#else

[...]

static inline int

ftrace_printk(const char *fmt, ...) __attribute__ ((format (printf, 1,

0)))

{

        return 0;

}

#endif


The true API is ftrace_printk(const char *fmt) and the __ftrace_printk

version should not be used.


Do you still think I should document the @ip?


I could also just remove the passing of _THIS_IP_ and use _RET_IP_

inside of ftrace_printk but the _THIS_IP_ seems to be more accurate

especially when we have stack unwinding returns.


--
[view original message]
From: Randy Dunlap <randy.dunlap@...>
To: Steven Rostedt <rostedt@...>
Cc: <linux-kernel@...>, Ingo Molnar <mingo@...>, Peter Zijlstra <peterz@...>, Thomas Gleixner <tglx@...>, Andrew Morton <akpm@...>, Steven Rostedt <srostedt@...>
Subject: Re: [PATCH v2 2/2] ftrace: printk formatting infrastructure
Date: Friday, August 1, 2008 - 1:52 pm

---

~Randy

Linux Plumbers Conference, 17-19 September 2008, Portland, Oregon USA

http://linuxplumbersconf.org/

--
[view original message]
From: Steven Rostedt <rostedt@...>
To: Randy Dunlap <randy.dunlap@...>
Cc: <linux-kernel@...>, Ingo Molnar <mingo@...>, Peter Zijlstra <peterz@...>, Thomas Gleixner <tglx@...>, Andrew Morton <akpm@...>, Steven Rostedt <srostedt@...>
Subject: [PATCH v2 3/2] ftrace: ftrace_printk doc moved
Date: Friday, August 1, 2008 - 2:17 pm

Based on Randy Dunlap's suggestion, the ftrace_printk kernel-doc belongs

with the ftrace_printk macro that should be used. Not with the

__ftrace_printk internal function.


Signed-off-by: Steven Rostedt <srostedt@redhat.com>

---

 include/linux/ftrace.h |   19 ++++++++++++++++++-

 kernel/trace/trace.c   |   16 ----------------

 2 files changed, 18 insertions(+), 17 deletions(-)


Index: linux-tip.git/include/linux/ftrace.h

===================================================================

--- linux-tip.git.orig/include/linux/ftrace.h	2008-08-01 12:20:56.000000000 -0400

+++ linux-tip.git/include/linux/ftrace.h	2008-08-01 14:11:13.000000000 -0400

@@ -137,7 +137,24 @@ static inline void tracer_disable(void)

 extern void

 ftrace_special(unsigned long arg1, unsigned long arg2, unsigned long arg3);

 extern void ftrace_dump(void);

-# define ftrace_printk(x...) __ftrace_printk(_THIS_IP_, x)

+

+/**

+ * ftrace_printk - printf formatting in the ftrace buffer

+ * @fmt - the printf format for printing.

+ *

+ * Note: __ftrace_printk is an internal function for ftrace_printk and

+ *       the @ip is passed in via the ftrace_printk macro.

+ *

+ * This function allows a kernel developer to debug fast path sections

+ * that printk is not appropriate for. By scattering in various

+ * printk like tracing in the code, a developer can quickly see

+ * where problems are occurring.

+ *

+ * This is intended as a debugging tool for the developer only.

+ * Please reframe from leaving ftrace_printks scattered around in

+ * your code.

+ */

+# define ftrace_printk(fmt...) __ftrace_printk(_THIS_IP_, fmt)

 extern int

 __ftrace_printk(unsigned long ip, const char *fmt, ...)

 	__attribute__ ((format (printf, 2, 3)));

Index: linux-tip.git/kernel/trace/trace.c

===================================================================

--- linux-tip.git.orig/kernel/trace/trace.c	2008-08-01 12:20:56.000000000 -0400

+++ linux-tip.git/kernel/trace/trace.c	2008-08-01 14:10:36.000000000 -0400

@@ -3243,22 +3243,6 ...
[ message continues ]
[view original message]
From: Randy Dunlap <randy.dunlap@...>
To: Steven Rostedt <rostedt@...>
Cc: <linux-kernel@...>, Ingo Molnar <mingo@...>, Peter Zijlstra <peterz@...>, Thomas Gleixner <tglx@...>, Andrew Morton <akpm@...>, Steven Rostedt <srostedt@...>
Subject: Re: [PATCH v2 3/2] ftrace: ftrace_printk doc moved
Date: Friday, August 1, 2008 - 4:34 pm

---

~Randy

Linux Plumbers Conference, 17-19 September 2008, Portland, Oregon USA

http://linuxplumbersconf.org/

--
[view original message]
From: Steven Rostedt <rostedt@...>
To: Randy Dunlap <randy.dunlap@...>
Cc: <linux-kernel@...>, Ingo Molnar <mingo@...>, Peter Zijlstra <peterz@...>, Thomas Gleixner <tglx@...>, Andrew Morton <akpm@...>, Steven Rostedt <srostedt@...>
Subject: [PATCH v3 3/2] ftrace: ftrace_printk doc moved
Date: Friday, August 1, 2008 - 4:45 pm

Based on Randy Dunlap's suggestion, the ftrace_printk kernel-doc belongs

with the ftrace_printk macro that should be used. Not with the

__ftrace_printk internal function.


Signed-off-by: Steven Rostedt <srostedt@redhat.com>

---

 include/linux/ftrace.h |   19 ++++++++++++++++++-

 kernel/trace/trace.c   |   16 ----------------

 2 files changed, 18 insertions(+), 17 deletions(-)


Index: linux-tip.git/include/linux/ftrace.h

===================================================================

--- linux-tip.git.orig/include/linux/ftrace.h	2008-08-01 12:20:56.000000000 -0400

+++ linux-tip.git/include/linux/ftrace.h	2008-08-01 16:43:56.000000000 -0400

@@ -137,7 +137,24 @@ static inline void tracer_disable(void)

 extern void

 ftrace_special(unsigned long arg1, unsigned long arg2, unsigned long arg3);

 extern void ftrace_dump(void);

-# define ftrace_printk(x...) __ftrace_printk(_THIS_IP_, x)

+

+/**

+ * ftrace_printk - printf formatting in the ftrace buffer

+ * @fmt: the printf format for printing

+ *

+ * Note: __ftrace_printk is an internal function for ftrace_printk and

+ *       the @ip is passed in via the ftrace_printk macro.

+ *

+ * This function allows a kernel developer to debug fast path sections

+ * that printk is not appropriate for. By scattering in various

+ * printk like tracing in the code, a developer can quickly see

+ * where problems are occurring.

+ *

+ * This is intended as a debugging tool for the developer only.

+ * Please refrain from leaving ftrace_printks scattered around in

+ * your code.

+ */

+# define ftrace_printk(fmt...) __ftrace_printk(_THIS_IP_, fmt)

 extern int

 __ftrace_printk(unsigned long ip, const char *fmt, ...)

 	__attribute__ ((format (printf, 2, 3)));

Index: linux-tip.git/kernel/trace/trace.c

===================================================================

--- linux-tip.git.orig/kernel/trace/trace.c	2008-08-01 12:20:56.000000000 -0400

+++ linux-tip.git/kernel/trace/trace.c	2008-08-01 14:10:36.000000000 -0400

@@ -3243,22 +3243,6 @@...
[ message continues ]
[view original message]
From: Randy Dunlap <randy.dunlap@...>
To: Steven Rostedt <rostedt@...>
Cc: <linux-kernel@...>, Ingo Molnar <mingo@...>, Peter Zijlstra <peterz@...>, Thomas Gleixner <tglx@...>, Andrew Morton <akpm@...>, Steven Rostedt <srostedt@...>
Subject: Re: [PATCH v3 3/2] ftrace: ftrace_printk doc moved
Date: Friday, August 1, 2008 - 4:49 pm

---

~Randy

Linux Plumbers Conference, 17-19 September 2008, Portland, Oregon USA

http://linuxplumbersconf.org/

--
[view original message]
From: Steven Rostedt <rostedt@...>
To: Randy Dunlap <randy.dunlap@...>
Cc: <linux-kernel@...>, Ingo Molnar <mingo@...>, Peter Zijlstra <peterz@...>, Thomas Gleixner <tglx@...>, Andrew Morton <akpm@...>, Steven Rostedt <srostedt@...>
Subject: Re: [PATCH v2 3/2] ftrace: ftrace_printk doc moved
Date: Friday, August 1, 2008 - 4:42 pm

Heh,  I manually fixed that before sending out the original. I never fixed

it in the quilt queue. Darn!


--
Previous thread: [PATCH v2 0/2] ftrace: printk formatted recording by Steven Rostedt on Friday, August 1, 2008 - 12:26 pm. (3 messages)

Next thread: [PATCH v2 1/2] ftrace: new continue entry - separate out from trace_entry by Steven Rostedt on Friday, August 1, 2008 - 12:26 pm. (1 message)