lkml.org 
[lkml]   [2014]   [Sep]   [22]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: itrace: An interrupts tracing tool
On Mon, 22 Sep 2014 11:35:43 +0800
duzhiping <duzhiping.du@huawei.com> wrote:

> Many functions depends on interrupts in Linux system, when the interrupts occur an error, it may cause fatal problem.
>
> Then, we should record their trace when interrupts in and out. The recorded information could help us analyze interrupts errors.
>
> Itrace is such an interrupts trace tool we have developed, it provides config interface and trace information through "procfs".
>
> Do you think it has the value to upstream?
>

You mean like:

# trace-cmd record -p function_graph -l do_IRQ -e irq_handler_entry sleep 10
# trace-cmd report
trace-cmd-3165 [002] 53.201912: funcgraph_entry: | do_IRQ() {
trace-cmd-3165 [002] 53.201920: irq_handler_entry: irq=21 name=uhci_hcd:usb4
trace-cmd-3165 [002] 53.201924: irq_handler_entry: irq=21 name=eth0
trace-cmd-3165 [002] 53.201927: funcgraph_exit: + 12.738 us | }
<idle>-0 [003] 53.202140: funcgraph_entry: | do_IRQ() {
<idle>-0 [003] 53.202146: irq_handler_entry: irq=21 name=uhci_hcd:usb4
<idle>-0 [003] 53.202148: irq_handler_entry: irq=21 name=eth0
<idle>-0 [003] 53.202151: funcgraph_exit: + 10.172 us | }
<idle>-0 [000] 58.679619: funcgraph_entry: | do_IRQ() {
<idle>-0 [000] 58.679625: irq_handler_entry: irq=14 name=ata_piix
<idle>-0 [000] 58.679630: funcgraph_exit: 8.040 us | }
<idle>-0 [001] 58.680176: funcgraph_entry: | do_IRQ() {
<idle>-0 [001] 58.680178: irq_handler_entry: irq=14 name=ata_piix
<idle>-0 [001] 58.680181: funcgraph_exit: 4.160 us | }
<idle>-0 [002] 58.680633: funcgraph_entry: | do_IRQ() {
<idle>-0 [002] 58.680635: irq_handler_entry: irq=14 name=ata_piix
<idle>-0 [002] 58.680637: funcgraph_exit: 3.489 us | }
<idle>-0 [003] 58.680913: funcgraph_entry: | do_IRQ() {
<idle>-0 [003] 58.680915: irq_handler_entry: irq=14 name=ata_piix
<idle>-0 [003] 58.680917: funcgraph_exit: 3.368 us | }
kworker/u8:1-40 [000] 58.681191: funcgraph_entry: | do_IRQ() {
kworker/u8:1-40 [000] 58.681192: irq_handler_entry: irq=14 name=ata_piix
kworker/u8:1-40 [000] 58.681196: funcgraph_exit: 4.551 us | }
<idle>-0 [001] 58.681415: funcgraph_entry: | do_IRQ() {
<idle>-0 [001] 58.681417: irq_handler_entry: irq=14 name=ata_piix
<idle>-0 [001] 58.681420: funcgraph_exit: 3.991 us | }
<idle>-0 [002] 58.681632: funcgraph_entry: | do_IRQ() {
<idle>-0 [002] 58.681633: irq_handler_entry: irq=14 name=ata_piix
<idle>-0 [002] 58.681635: funcgraph_exit: 2.183 us | }


Or just use the irq events only?

# trace-cmd record -e irq_handler_entry -e irq_handler_exit sleep 10
# trace-cmd report
<idle>-0 [003] 198.853342: irq_handler_entry: irq=14 name=ata_piix
<idle>-0 [003] 198.853344: irq_handler_exit: irq=14 ret=handled
<idle>-0 [000] 198.862038: irq_handler_entry: irq=14 name=ata_piix
<idle>-0 [000] 198.862040: irq_handler_exit: irq=14 ret=handled
<idle>-0 [001] 198.862227: irq_handler_entry: irq=14 name=ata_piix
<idle>-0 [001] 198.862228: irq_handler_exit: irq=14 ret=handled
<idle>-0 [002] 198.870423: irq_handler_entry: irq=14 name=ata_piix
<idle>-0 [002] 198.870424: irq_handler_exit: irq=14 ret=handled


It's a bit cleaner, but the function_graph gives the times nicely. But
I do plan on updating trace-cmd to give times between different events.

-- Steve


\
 
 \ /
  Last update: 2014-09-22 15:01    [W:0.045 / U:1.356 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site