linux-kernel - Re: Ftrace test failure on MIPS

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [day] [month] [year] [list]

Message-ID: <1357872874.5141.28.camel@gandalf.local.home>
Date:	Thu, 10 Jan 2013 21:54:34 -0500
From:	Steven Rostedt <rostedt@...dmis.org>
To:	David Daney <ddaney@...iumnetworks.com>
Cc:	Ralf Baechle <ralf@...ux-mips.org>,
	linux-mips <linux-mips@...ux-mips.org>,
	Linux Kernel Mailing List <linux-kernel@...r.kernel.org>
Subject: Re: Ftrace test failure on MIPS - Looking for insight..

On Thu, 2013-01-10 at 17:58 -0800, David Daney wrote:
> Hi Steven,
> 
> I am trying to track down the cause of:
> 
> .
> .
> .
> Brought up 32 CPUs
> Testing tracer function: PASSED
> Testing dynamic ftrace: .. filter failed count=0 ..FAILED!
> ------------[ cut here ]------------
> WARNING: at kernel/trace/trace.c:878 register_tracer+0x23c/0x300()
> Modules linked in:
> Call Trace:
> [<ffffffff815a0578>] dump_stack+0x14/0x40
> [<ffffffff8113e8fc>] warn_slowpath_common+0x84/0xb0
> [<ffffffff811bd04c>] register_tracer+0x23c/0x300
> [<ffffffff81100538>] do_one_initcall+0x110/0x178
> [<ffffffff8159234c>] kernel_init+0x174/0x318
> [<ffffffff81119de4>] ret_from_kernel_thread+0x14/0x1c
> 
> ---[ end trace 204112383c2d190e ]---
> .
> .
> .
> 
> 
> This is a MIPS64 kernel build from Linus' tree of today (commit 
> 254adaa465c40151df11fc1f88f93e6e86eb61d4)
> 
> I think the failure is long standing (since 3.4.x at least).
> 
> If you have any ideas off the top of your head as to what the cause 
> might be, I would love to hear them.
> 
> In any event, I will try to track down the root cause and fix it.  But 
> if something jumped out at you, that could speed up my search for the cause.

The failure is that it set the tracing filter to be DYN_FTRACE_TEST_NAME
(which is defined as trace_selftest_dynamic_test_func) and then it
called the function and then checked how many events were in the trace.
But there wasn't any (count=0). For some reason dynamic function tracing
didn't trace the function when it was called.

Some reasons fro this to happen:

1) tracing was some how disabled (tracing_on set to zero). But as the
function tracer passed, I don't think this would be the case.

2) the function wasn't properly set in the filter. That is, could mips
have another name for that function? Where it wouldn't add it?

3) well, just about anything :-)

I could suggest adding printks in the code, and that might help you.
Look into ftrace_set_global_filter (kernel/trace/ftrace.c) and follow
that code. Follow it all the way to __ftrace_hash_rec_update(), and make
sure the rec get's updated. You may add a printk right after the inc
(although, you may also want to set a variable to not do that printk
until the dynamic test runs).

Something like this:

	rec->flags++;
	if (ok_to_printk)
		printk("setting rec %p %pS\n", (void*)rec->ip, (void*)rec->ip);

and at the start of the dynamic test have:

	ok_to_printk = 1;
	pr_info("Testing dynamic ftarce: ");

You should see the record being set. If not, you know why it broke.

-- Steve

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/