Messages in this thread Patch in this message | | | From | Bruce Duncan <> | Subject | Re: [git pull] ftrace for v2.6.27 | Date | Wed, 13 Aug 2008 02:48:51 +0100 |
| |
Hi Ingo, Steven, everyone,
[ Please CC me in replies ]
I have just tracked down a regression in 2.6.27-rc2 wrt 2.6.26. Commit 77a2b37d227483fe52aead242652aee406c25bf0 (ftrace: startup tester on dynamic tracing.) causes my laptop to fail to resume from S3 (it simply reboots about a second after the resume starts and the display never shows anything).
The patch doesn't revert with patch -R (I don't know if there's a cleverer way to ask git to revert it), but the problem goes away if I turn off CONFIG_DYNAMIC_FTRACE.
The commit and bisect log are attached. Please can you help me to debug this?
Cheers, Bruce commit 77a2b37d227483fe52aead242652aee406c25bf0 Author: Steven Rostedt <srostedt@redhat.com> Date: Mon May 12 21:20:45 2008 +0200
ftrace: startup tester on dynamic tracing.
This patch adds a startup self test on dynamic code modification and filters. The test filters on a specific function, makes sure that no other function is traced, exectutes the function, then makes sure that the function is traced.
This patch also fixes a slight bug with the ftrace selftest, where tracer_enabled was not being set.
Signed-off-by: Steven Rostedt <srostedt@redhat.com> Signed-off-by: Ingo Molnar <mingo@elte.hu> Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
diff --git a/include/linux/ftrace.h b/include/linux/ftrace.h index 953a36d..a842d96 100644 --- a/include/linux/ftrace.h +++ b/include/linux/ftrace.h @@ -55,6 +55,7 @@ struct dyn_ftrace { }; int ftrace_force_update(void); +void ftrace_set_filter(unsigned char *buf, int len, int reset); /* defined in arch */ extern int ftrace_ip_converted(unsigned long ip); @@ -70,6 +71,7 @@ extern void ftrace_call(void); extern void mcount_call(void); #else # define ftrace_force_update() ({ 0; }) +# define ftrace_set_filter(buf, len, reset) do { } while (0) #endif static inline void tracer_disable(void) diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c index 6d4d2e8..5e9389f 100644 --- a/kernel/trace/ftrace.c +++ b/kernel/trace/ftrace.c @@ -1010,6 +1010,25 @@ ftrace_filter_write(struct file *file, const char __user *ubuf, return ret; } +/** + * ftrace_set_filter - set a function to filter on in ftrace + * @buf - the string that holds the function filter text. + * @len - the length of the string. + * @reset - non zero to reset all filters before applying this filter. + * + * Filters denote which functions should be enabled when tracing is enabled. + * If @buf is NULL and reset is set, all functions will be enabled for tracing. + */ +notrace void ftrace_set_filter(unsigned char *buf, int len, int reset) +{ + mutex_lock(&ftrace_filter_lock); + if (reset) + ftrace_filter_reset(); + if (buf) + ftrace_match(buf, len); + mutex_unlock(&ftrace_filter_lock); +} + static int notrace ftrace_filter_release(struct inode *inode, struct file *file) { diff --git a/kernel/trace/trace_selftest.c b/kernel/trace/trace_selftest.c index c01874c..4c8a1b2 100644 --- a/kernel/trace/trace_selftest.c +++ b/kernel/trace/trace_selftest.c @@ -99,6 +99,100 @@ static int trace_test_buffer(struct trace_array *tr, unsigned long *count) } #ifdef CONFIG_FTRACE + +#ifdef CONFIG_DYNAMIC_FTRACE + +#define DYN_FTRACE_TEST_NAME trace_selftest_dynamic_test_func +#define __STR(x) #x +#define STR(x) __STR(x) +static int DYN_FTRACE_TEST_NAME(void) +{ + /* used to call mcount */ + return 0; +} + +/* Test dynamic code modification and ftrace filters */ +int trace_selftest_startup_dynamic_tracing(struct tracer *trace, + struct trace_array *tr, + int (*func)(void)) +{ + unsigned long count; + int ret; + int save_ftrace_enabled = ftrace_enabled; + int save_tracer_enabled = tracer_enabled; + + /* The ftrace test PASSED */ + printk(KERN_CONT "PASSED\n"); + pr_info("Testing dynamic ftrace: "); + + /* enable tracing, and record the filter function */ + ftrace_enabled = 1; + tracer_enabled = 1; + + /* passed in by parameter to fool gcc from optimizing */ + func(); + + /* update the records */ + ret = ftrace_force_update(); + if (ret) { + printk(KERN_CONT ".. ftraced failed .. "); + return ret; + } + + /* filter only on our function */ + ftrace_set_filter(STR(DYN_FTRACE_TEST_NAME), + sizeof(STR(DYN_FTRACE_TEST_NAME)), 1); + + /* enable tracing */ + tr->ctrl = 1; + trace->init(tr); + /* Sleep for a 1/10 of a second */ + msleep(100); + + /* we should have nothing in the buffer */ + ret = trace_test_buffer(tr, &count); + if (ret) + goto out; + + if (count) { + ret = -1; + printk(KERN_CONT ".. filter did not filter .. "); + goto out; + } + + /* call our function again */ + func(); + + /* sleep again */ + msleep(100); + + /* stop the tracing. */ + tr->ctrl = 0; + trace->ctrl_update(tr); + ftrace_enabled = 0; + + /* check the trace buffer */ + ret = trace_test_buffer(tr, &count); + trace->reset(tr); + + /* we should only have one item */ + if (!ret && count != 1) { + printk(KERN_CONT ".. filter failed .."); + ret = -1; + goto out; + } + out: + ftrace_enabled = save_ftrace_enabled; + tracer_enabled = save_tracer_enabled; + + /* Enable tracing on all functions again */ + ftrace_set_filter(NULL, 0, 1); + + return ret; +} +#else +# define trace_selftest_startup_dynamic_tracing(trace, tr, func) ({ 0; }) +#endif /* CONFIG_DYNAMIC_FTRACE */ /* * Simple verification test of ftrace function tracer. * Enable ftrace, sleep 1/10 second, and then read the trace @@ -109,8 +203,13 @@ trace_selftest_startup_function(struct tracer *trace, struct trace_array *tr) { unsigned long count; int ret; + int save_ftrace_enabled = ftrace_enabled; + int save_tracer_enabled = tracer_enabled; - /* make sure functions have been recorded */ + /* make sure msleep has been recorded */ + msleep(1); + + /* force the recorded functions to be traced */ ret = ftrace_force_update(); if (ret) { printk(KERN_CONT ".. ftraced failed .. "); @@ -119,6 +218,7 @@ trace_selftest_startup_function(struct tracer *trace, struct trace_array *tr) /* start the tracing */ ftrace_enabled = 1; + tracer_enabled = 1; tr->ctrl = 1; trace->init(tr); @@ -136,8 +236,16 @@ trace_selftest_startup_function(struct tracer *trace, struct trace_array *tr) if (!ret && !count) { printk(KERN_CONT ".. no entries found .."); ret = -1; + goto out; } + ret = trace_selftest_startup_dynamic_tracing(trace, tr, + DYN_FTRACE_TEST_NAME); + + out: + ftrace_enabled = save_ftrace_enabled; + tracer_enabled = save_tracer_enabled; + return ret; } #endif /* CONFIG_FTRACE */ @@ -415,6 +523,3 @@ trace_selftest_startup_sched_switch(struct tracer *trace, struct trace_array *tr return ret; } #endif /* CONFIG_CONTEXT_SWITCH_TRACER */ - -#ifdef CONFIG_DYNAMIC_FTRACE -#endif /* CONFIG_DYNAMIC_FTRACE */# bad: [6e86841d05f371b5b9b86ce76c02aaee83352298] Linux 2.6.27-rc1 # good: [bce7f793daec3e65ec5c5705d2457b81fe7b5725] Linux 2.6.26 git-bisect start 'v2.6.27-rc1' 'v2.6.26' # bad: [d20b27478d6ccf7c4c8de4f09db2bdbaec82a6c0] V4L/DVB (8415): gspca: Infinite loop in i2c_w() of etoms. git-bisect bad d20b27478d6ccf7c4c8de4f09db2bdbaec82a6c0 # bad: [666484f0250db2e016948d63b3ef33e202e3b8d0] Merge branch 'core/softirq' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip git-bisect bad 666484f0250db2e016948d63b3ef33e202e3b8d0 # good: [d59fdcf2ac501de99c3dfb452af5e254d4342886] Merge commit 'v2.6.26' into x86/core git-bisect good d59fdcf2ac501de99c3dfb452af5e254d4342886 # good: [a3da5bf84a97d48cfaf66c6842470fc403da5121] Merge branch 'x86/for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip git-bisect good a3da5bf84a97d48cfaf66c6842470fc403da5121 # bad: [6712e299b7dc78aa4971b85e803435ee6d49a9dd] Merge branch 'tracing/ftrace' into auto-ftrace-next git-bisect bad 6712e299b7dc78aa4971b85e803435ee6d49a9dd # bad: [4823ed7eadf35e4b57ce581327e21d39585f1f32] ftrace: fix setting of pos in read_pipe git-bisect bad 4823ed7eadf35e4b57ce581327e21d39585f1f32 # bad: [9ff9cdb2d3b0971f89e899b3420aadd91bddc215] ftrace: cleanups git-bisect bad 9ff9cdb2d3b0971f89e899b3420aadd91bddc215 # good: [c7aafc549766b87819285d3480648fc652a47bc4] ftrace: cleanups git-bisect good c7aafc549766b87819285d3480648fc652a47bc4 # skip: [f9896bf30928922a3913a3810a4ab7908da6cfe7] ftrace: add raw output git-bisect skip f9896bf30928922a3913a3810a4ab7908da6cfe7 # skip: [8c523a9d82dbc4f3f7d972df8c0f1eacd83d0d55] ftrace: clean-up-pipe-iteration git-bisect skip 8c523a9d82dbc4f3f7d972df8c0f1eacd83d0d55 # skip: [cb0f12aae8d085140d37ada351aa5a8e76c3f9b0] ftrace: bin-output git-bisect skip cb0f12aae8d085140d37ada351aa5a8e76c3f9b0 # skip: [cdd31cd2d7a0dcbec2cce3974f7129dd4fc8c879] ftrace: remove-idx-sync git-bisect skip cdd31cd2d7a0dcbec2cce3974f7129dd4fc8c879 # skip: [f0a920d5752e1788c0cba2add103076bcc0f7a49] ftrace: add trace_special() git-bisect skip f0a920d5752e1788c0cba2add103076bcc0f7a49 # skip: [53c37c17aafcf50f7c6fddaf01dda8f9d7e31ddf] ftrace: fast, scalable, synchronized timestamps git-bisect skip 53c37c17aafcf50f7c6fddaf01dda8f9d7e31ddf # skip: [dcb6308f2b56720599f6b9d5a01c33e67e69bde4] ftrace, locking fix git-bisect skip dcb6308f2b56720599f6b9d5a01c33e67e69bde4 # skip: [088b1e427dbba2af93cb6a7d39258c10ff58dd27] ftrace: pipe fixes git-bisect skip 088b1e427dbba2af93cb6a7d39258c10ff58dd27 # bad: [750ed1a40783432d0dcb0e6c2e813a12615d7664] ftrace: timestamp syncing, prepare git-bisect bad 750ed1a40783432d0dcb0e6c2e813a12615d7664 # bad: [1d4db00a5e30c7b8f8dc2a1b19e886fd942be143] ftrace: reset selftests git-bisect bad 1d4db00a5e30c7b8f8dc2a1b19e886fd942be143 # bad: [4e3c3333f3bd7eedfd21b1155b3c7cd24fc7f754] ftrace: fix time offset git-bisect bad 4e3c3333f3bd7eedfd21b1155b3c7cd24fc7f754 # bad: [77a2b37d227483fe52aead242652aee406c25bf0] ftrace: startup tester on dynamic tracing. git-bisect bad 77a2b37d227483fe52aead242652aee406c25bf0 # good: [7bd2f24c2f769e3f8f1d4fc8b9fddf689825f6a7] ftrace: add README git-bisect good 7bd2f24c2f769e3f8f1d4fc8b9fddf689825f6a7 [unhandled content-type:application/pkcs7-signature] | |