Re: ftrace - graph tracer for Microblaze

From: Michal Simek
Date: Mon Nov 09 2009 - 03:12:43 EST


Steven Rostedt wrote:
On Fri, 2009-11-06 at 12:03 +0100, Michal Simek wrote:
Hi Steven,


I am getting some problem is irqsoff tracing. Is there any special things which needs to be implemented/changed?

It is dependent on TRACE_IRQFLAGS_SUPPORT, which is kind of nasty. This
is what LOCKDEP uses. If you can successfully implement LOCKDEP you get
irqsoff tracing for free.

That's crucial information. Would it be possible to add this dependency to trace/Kconfig?


The biggest issue with lockdep implementation is that you need to have a
hook at every irq disable and enable location. This includes assembly.
That's what all those TRACE_IRQS_OFF and TRACE_IRQS_ON are in x86's
entry_*.S.

I have there some issues - I am debugging it.



I would like to implement ftrace graph support and stack save support.

I believe that for stack_trace I need just to implement save_stack_trace.
If I understand correctly that feature should look at current process
and trace that process back to zero stack size.
It is just for current task right?

Yes, just current task is needed.

Then output shows which functions are called and size of stack. I found your post which is at http://lkml.org/lkml/2009/8/21/319 but you don't have any zero size stack size. Here is my log which seems to me weird because of zero size values. Is it correct or not?

# echo 1 > /proc/sys/kernel/stack_tracer_enabled
# cat /debug/tracing/stack_trace
Depth Size Location (63 entries)
----- ---- --------
0) 2100 0 stack_trace_call+0x12c/0x1d8
1) 2100 0 stack_trace_call+0x12c/0x1d8
2) 2100 0 _spin_unlock+0x2c/0x3c
3) 2100 180 __rcu_process_callbacks+0x3e0/0x460
4) 1920 568 end_graph_tracer+0x24/0x2c
5) 1352 0 end_graph_tracer+0x24/0x2c
6) 1352 0 microblaze_read+0x14/0x4c
7) 1352 184 microblaze_read+0x0/0x4c
...
63) 156 156 ktime_add_ns+0x88/0x124

Here is my function -> it is the same as we use for dump stack.
I look at mips implementation and is the same

void save_stack_trace(struct stack_trace *trace)
{
unsigned int sp;
asm("addik %0, r1, 0" : "=r" (sp));

while (!kstack_end(sp)) {
addr = *sp++;
if (__kernel_text_address(addr)) {

Hmm, this does not look too reliable. That is, anytime there's a text
address in the code you report it, although it may not be a real return
address.

Does Microblaze have any kind of frame pointer? Or a way to detect the
next frame? If so, that would be really helpful here.

if (trace->skip > 0)
trace->skip--;
else
trace->entries[trace->nr_entries++] = addr;

if (trace->nr_entries >= trace->max_entries)
break;
}
}
}

The stack tracer is very simple. If you look at the check_stack code in
kernel/trace/trace_stack.c it shows the implementation.

Basically what it does is to look at the address local variable in the
function itself (this_size). It masks it with THREAD_SIZE-1 to get the
top of the stack.

It then starts up the stack looking at the contents to match the
contents of the report from save_stack_trace(). If it finds a return
value, it reports the address off of that. If it does not find that
return value, you will see zero. This is strange since it should have
found all those that were reported. But perhaps those values were in the
stack when calling the save_stack_trace function, but not at the level
of check_stack's stack.


will look.

...





This is third topic - maybe I should send three separate emails :-(

I found some incompatibility which IMHO could be synchronize.
There is C implementation for ftrace_graph_entry_stub and ftrace_stub
is implemented in asm. The purpose of that two functions should be the same that's I think implementation should be too.

The two take different arguments. Sure the stubs don't care, but it this
topic came up in the design. We found issues (I don't remember exactly
what they were) by having the two the same. That was the original
design.

ok.


Because of my unresolved issue around irqsoff I traced it in code and there is too many tracing_reset_online_cpus() functions. I found one calling in __irqsoff_tracer_init and then in tracer_init function. Is that correct or one calling is enough?

Hmm, It may be enough to call it just in tracer_init, but it does seem
that irqsoff tracer wants it reset it again after it zeros out the
numbers. I'll look into that. But it should not affect anything, since
this is only at startup of the tracer.

ok


Then I think that there is some things in Kconfig which should be cleared. I found link to /sys/kernel/debug/tracing/profile_branch which I don't have in tracing folder. Is it correct?

You enabled TRACE_BRANCH_PROFILING and you don't have that?

maybe it is related with registration.

microblaze_timer_set_mode: oneshot
Warning: could not register all branches stats
Warning: could not register annotated branches stats
msgmni has been set to 488
84000000.serial: ttyUL0 at MMIO 0x84000003 (irq = 8) is a uartlite
console [ttyUL0] enabled
...

uclinux login: root
Password:
login[45]: root login on 'ttyUL0'
# cd ; mkdir /debug; mount -t debugfs none /debug; cat /debug/tracing/available_tracers
function_graph function sched_switch nop
# ls /debug/tracing/
README options trace tracing_cpumask
available_events per_cpu trace_clock tracing_enabled
available_tracers printk_formats trace_marker tracing_on
buffer_size_kb saved_cmdlines trace_options
current_tracer set_event trace_pipe
events set_ftrace_pid trace_stat
#
#
# gunzip < /proc/config.gz | grep BRANCH
CONFIG_TRACE_BRANCH_PROFILING=y
# CONFIG_BRANCH_PROFILE_NONE is not set
# CONFIG_PROFILE_ANNOTATED_BRANCHES is not set
CONFIG_PROFILE_ALL_BRANCHES=y
# CONFIG_BRANCH_TRACER is not set
#

Thanks,
Michal



-- Steve



--
Michal Simek, Ing. (M.Eng)
w: www.monstr.eu p: +42-0-721842854
Maintainer of Linux kernel 2.6 Microblaze Linux - http://www.monstr.eu/fdt/
Microblaze U-BOOT custodian
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/