linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [ftrace] kernel panics during my attempt to use ftrace
@ 2016-06-21 12:53 Enrico Mioso
  2016-06-22 15:10 ` Steven Rostedt
  2016-06-28  3:45 ` Namhyung Kim
  0 siblings, 2 replies; 6+ messages in thread
From: Enrico Mioso @ 2016-06-21 12:53 UTC (permalink / raw)
  To: linux-kernel; +Cc: Ingo Molnar, Steven Rostedt, mattia.bonomi

Hello guys.

First of all - thank you for your great work in ftrace, and in general in the 
Linux tracing infrastructure. I am a newbie: so I am not able to use it at it's 
full power, still I find it's capabilities impressive.

I am asking for help, since I am encountering some problems in using ftrace.
I am trying to come up with a solution to trace a specific workload (a 
program): to understand what are the functions the kernel spends most of his 
time in.
To do so, I inspired myself to some code I found around (I can mention it if 
needed). I took free inspiration: so my editing may be very very wrong.
When I run this script, the kernel panics. the output is below. the kernel is 
Ubuntu 16.04 stock, running in a qemu virtual machine (using kvm).
Any help would be greatly apreciated. Thank you very much guys.
Fort any needed infos, contact me.
Enrico

Script:
#!/bin/sh
if [ `whoami` != root ]
then
     echo you need to run this script as root
     exit 1
fi

tdir=/sys/kernel/debug/tracing
start()
{
    # echo 50000 > $tdir/buffer_size_kb
    echo function_graph > $tdir/current_tracer
    echo 1000 >$tdir/tracing_thresh
    echo >$tdir/trace
    echo 1 >$tdir/tracing_on # ** this is wrong, interface changed?
}
stop()
{
    echo >set_event
    echo 0 >$tdir/tracing_on
    output=trace`date +%y-%m-%d-%H-%M-%S`.txt
    echo funcgraph-abstime >$tdir/trace_options
    echo funcgraph-proc >$tdir/trace_options
    cat $tdir/trace > $output
    echo trace written to $output
}
COMMAND="$1"
case $COMMAND in
start|stop)
 	$COMMAND
 	;;
*)
 	echo "usage: $0 [start|stop]"
;;
esac


Kernel panic output:
[  825.336708] BUG: unable to handle kernel paging request at 55501e06
[  825.340572] IP: [<c17aa9ca>] ftrace_regs_caller+0xa/0x35
[  825.340572] *pdpt = 000000001ef4c001 *pde = 0000000000000000
[  825.340572] Oops: 0000 [#1] SMP
[  825.340572] Modules linked in: isofs ppdev joydev serio_raw parport_pc parpor
t ib_iser rdma_cm iw_cm ib_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tc
p libiscsi scsi_transport_iscsi autofs4 btrfs raid10 raid456 async_raid6_recov a
sync_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multi
path linear psmouse e1000 floppy
[  825.340572] CPU: 0 PID: 7 Comm: rcu_sched Not tainted 4.4.0-24-generic #43-Ub
untu
[  825.340572] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.2
-20160422_131301-anatol 04/01/2014
[  825.340572] task: de8f3480 ti: de988000 task.ti: de988000
[  825.340572] EIP: 0060:[<c17aa9ca>] EFLAGS: 00010202 CPU: 0
[  825.340572] EIP is at ftrace_regs_caller+0xa/0x35
[  825.340572] EAX: de989e4e EBX: c10db072 ECX: 00000000 EDX: 00000268
[  825.340572] ESI: de8f3480 EDI: dee08800 EBP: de989f10 ESP: de989ec4
[  825.340572]  DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
[  825.340572] CR0: 8005003b CR2: 55501e06 CR3: 1e073e20 CR4: 000006e0
[  825.340572] Stack:
[  825.340572]  c113f017 de8f3480 d4d1dc00 de989f0c c17a5b75 de9d4ec0 de989f60 d
e989f60
[  825.340572]  c17a60e8 edf05431 00000268 f2ee631c 00000268 00000000 00000000 8
aced3dc
[  825.340572]  c1ae0490 00000000 c1ae0300 de989f60 c17aaa46 dffbbdc0 00000000 0
0000000
[  825.340572] Call Trace:
[  825.340572]  [<c113f017>] ? ftrace_return_to_handler+0x97/0x170
[  825.340572]  [<c17a5b75>] ? __schedule+0x305/0x790
[  825.340572]  [<c17a60e8>] ? yield_to+0x68/0x170
[  825.340572]  [<c17aaa46>] return_to_handler+0x9/0xf
[  825.340572]  [<c10afbd0>] ? wake_atomic_t_function+0x70/0x70
[  825.340572]  [<c10d5800>] ? force_qs_rnp+0x140/0x140
[  825.340572]  [<c108ce06>] kthread+0xa6/0xc0
[  825.340572]  [<c17a9949>] ret_from_kernel_thread+0x21/0x38
[  825.340572]  [<c108cd60>] ? kthread_create_on_node+0x170/0x170
[  825.340572] Code: 6a 00 8b 44 24 10 8b 55 04 8b 0d 94 14 b7 c1 83 e8 05 e8 08
  00 00 00 83 c4 04 5a 59 58 e9 63 00 00 00 ff 74 24 04 6a 00 0f a8 0f <a0> 06 1e
  50 55 57 56 52 51 53 8b 44 24 34 89 44 24 38 c7 44 24
[  825.340572] EIP: [<c17aa9ca>] ftrace_regs_caller+0xa/0x35 SS:ESP 0068:de989ec
4
[  825.340572] CR2: 0000000055501e06
[  825.340572] ---[ end trace 4f291f60e8d43d37 ]---
[  825.996200] invalid opcode: 0000 [#2] SMP
[  826.000050] Modules linked in: isofs ppdev joydev serio_raw parport_pc parpor
t ib_iser rdma_cm iw_cm ib_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tc
p libiscsi scsi_transport_iscsi autofs4 btrfs raid10 raid456 async_raid6_recov a
sync_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multi
path linear psmouse e1000 floppy
[  826.000050] CPU: 0 PID: 1044 Comm: iscsid Tainted: G      D         4.4.0-24-
generic #43-Ubuntu
[  826.000050] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.2
-20160422_131301-anatol 04/01/2014
[  826.000050] task: d4679180 ti: dee54000 task.ti: dee54000
[  826.000050] EIP: 0060:[<c17aa9be>] EFLAGS: 00010217 CPU: 0
[  826.000050] EIP is at ftrace_stub+0x0/0x2
[  826.000050] EAX: dee55adc EBX: c17a8d92 ECX: 00000000 EDX: 00000269
[  826.000050] ESI: d4679180 EDI: de0e9800 EBP: dee55b08 ESP: dee55abc
[  826.000050]  DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
[  826.000050] CR0: 8005003b CR2: b7362010 CR3: 1f0d3080 CR4: 000006e0
[  826.000050] Stack:
[  826.000050]  c113f017 d4679180 de29f400 dee55b04 c17a5b75 d4fe2300 dee55b88 d
ee55b88
[  826.000050]  c17a6004 edebaa8f 00000268 1a3d53a3 00000269 00000000 00000006 9
7ca1d76
[  826.000050]  dee55b34 0003d083 000000c0 dee55b88 c17aaa46 dffbbdc0 00000000 0
003d083
[  826.000050] Call Trace:
[  826.000050]  [<c113f017>] ? ftrace_return_to_handler+0x97/0x170
[  826.000050]  [<c17a5b75>] ? __schedule+0x305/0x790
[  826.000050]  [<c17a6004>] ? schedule+0x4/0x80
[  826.000050]  [<c17aaa46>] return_to_handler+0x9/0xf
[  826.000050]  [<c10dc330>] ? __hrtimer_init+0x90/0x90
[  826.000050]  [<c17aaa3d>] ? ftrace_graph_caller+0x19/0x19
[  826.000050]  [<c17a8eb7>] schedule_hrtimeout_range+0x17/0x20
[  826.000050]  [<c17aaa3d>] ftrace_graph_caller+0x19/0x19
[  826.000050]  [<c11efca6>] poll_schedule_timeout+0x36/0x60
[  826.000050]  [<c17aaa3d>] ftrace_graph_caller+0x19/0x19
[  826.000050]  [<c11f13d8>] do_sys_poll+0x4c8/0x570
[  826.000050]  [<c17aaa3d>] ftrace_graph_caller+0x19/0x19
[  826.000050]  [<c11f154e>] SyS_poll+0x5e/0x100
[  826.000050]  [<c1179368>] ? __alloc_pages_nodemask+0x128/0xa40
[  826.000050]  [<c1067736>] ? kmap_atomic_prot+0x36/0x100
[  826.000050]  [<c11efe00>] ? poll_select_copy_remaining+0x130/0x130
[  826.000050]  [<c11efe00>] ? poll_select_copy_remaining+0x130/0x130
[  826.000050]  [<c105bb07>] ? kvm_clock_read+0x17/0x20
[  826.000050]  [<c105cadb>] ? pvclock_clocksource_read+0xab/0x150
[  826.000050]  [<c105cadb>] ? pvclock_clocksource_read+0xab/0x150
[  826.000050]  [<c105bb07>] ? kvm_clock_read+0x17/0x20
[  826.000050]  [<c105cadb>] ? pvclock_clocksource_read+0xab/0x150
[  826.000050]  [<c105bb07>] ? kvm_clock_read+0x17/0x20
[  826.000050]  [<c1032918>] ? sched_clock+0x8/0x10
[  826.000050]  [<c11267a8>] ? trace_clock_local+0x8/0x10
[  826.000050]  [<c112de75>] ? rb_reserve_next_event+0x75/0x430
[  826.000050]  [<c112efc2>] ? ring_buffer_unlock_commit+0x22/0x240
[  826.000050]  [<c1135760>] ? __buffer_unlock_commit+0x10/0x20
[  826.000050]  [<c113f409>] ? __trace_graph_return+0x89/0xa0
[  826.000050]  [<c11f1542>] ? SyS_poll+0x52/0x100
[  826.000050]  [<c113f017>] ? ftrace_return_to_handler+0x97/0x170
[  826.000050]  [<c11effb8>] ? poll_select_set_timeout+0x8/0xa0
[  826.000050]  [<c17aaa3d>] ftrace_graph_caller+0x19/0x19
[  826.000050]  [<c100393d>] do_fast_syscall_32+0x8d/0x150
[  826.000050]  [<c17aaa3d>] ftrace_graph_caller+0x19/0x19
[  826.000050]  [<c17a99dc>] sysenter_past_esp+0x3d/0x61
[  826.000050]  [<c17aaa3d>] ftrace_graph_caller+0x19/0x19
[  826.000050] Code: ff ff 8d 76 00 c3 8d 76 00 50 51 52 6a 00 8b 44 24 10 8b 55
  04 8b 0d 94 14 b7 c1 83 e8 05 e8 08 00 00 00 83 c4 04 5a 59 58 e9 fd <ff> ff ff
  ff 74 24 04 6a 00 0f a8 0f a0 06 1e 50 55 57 56 52 51
[  826.000050] EIP: [<c17aa9be>] ftrace_stub+0x0/0x2 SS:ESP 0068:dee55abc
[  826.640678] ---[ end trace 4f291f60e8d43d38 ]---
[  826.649117] invalid opcode: 0000 [#3] SMP
[  826.652668] Modules linked in: isofs ppdev joydev serio_raw parport_pc parpor
t ib_iser rdma_cm iw_cm ib_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tc
p libiscsi scsi_transport_iscsi autofs4 btrfs raid10 raid456 async_raid6_recov a
sync_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multi
path linear psmouse e1000 floppy
[  826.652668] CPU: 0 PID: 4 Comm: kworker/0:0 Tainted: G      D         4.4.0-2
4-generic #43-Ubuntu
[  826.652668] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.2
-20160422_131301-anatol 04/01/2014
[  826.652668] task: de8f1a40 ti: de8fe000 task.ti: de8fe000
[  826.652668] EIP: 0060:[<c17aa9be>] EFLAGS: 00010246 CPU: 0
[  826.652668] EIP is at ftrace_stub+0x0/0x2
[  826.652668] EAX: de8fff00 EBX: c10879d2 ECX: 00000000 EDX: 00000269
[  826.652668] ESI: de8f1a40 EDI: de167800 EBP: de8fff2c ESP: de8ffee0
[  826.652668]  DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
[  826.652668] CR0: 8005003b CR2: 00000068 CR3: 1f0d3080 CR4: 000006e0
[  826.652668] Stack:
[  826.652668]  c113f017 de8f1a40 deb1a600 de8fff28 c17a5b75 d467e040 de8fff60 d
e8fff60
[  826.652668]  c17a6004 edd8153d 00000268 41282712 00000269 00000000 00000000 b
4d9c50e
[  826.652668]  dffbb8c0 de821a98 de821a80 de8fff60 c17aaa46 dffbbdc0 00000000 d
ffbba54
[  826.652668] Call Trace:
[  826.652668]  [<c113f017>] ? ftrace_return_to_handler+0x97/0x170
[  826.652668]  [<c17a5b75>] ? __schedule+0x305/0x790
[  826.652668]  [<c17a6004>] ? schedule+0x4/0x80
[  826.652668]  [<c17aaa46>] return_to_handler+0x9/0xf
[  826.652668]  [<c1087920>] ? process_one_work+0x3f0/0x3f0
[  826.652668]  [<c108ce06>] kthread+0xa6/0xc0
[  826.652668]  [<c17a9949>] ret_from_kernel_thread+0x21/0x38
[  826.652668]  [<c108cd60>] ? kthread_create_on_node+0x170/0x170
[  826.652668] Code: ff ff 8d 76 00 c3 8d 76 00 50 51 52 6a 00 8b 44 24 10 8b 55
  04 8b 0d 94 14 b7 c1 83 e8 05 e8 08 00 00 00 83 c4 04 5a 59 58 e9 fd <ff> ff ff
  ff 74 24 04 6a 00 0f a8 0f a0 06 1e 50 55 57 56 52 51
[  826.652668] EIP: [<c17aa9be>] ftrace_stub+0x0/0x2 SS:ESP 0068:de8ffee0
[  827.033592] ---[ end trace 4f291f60e8d43d39 ]---
[  827.041794] invalid opcode: 0000 [#4] SMP
[  827.045579] Modules linked in: isofs ppdev joydev serio_raw parport_pc parpor
t ib_iser rdma_cm iw_cm ib_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tc
p libiscsi scsi_transport_iscsi autofs4 btrfs raid10 raid456 async_raid6_recov a
sync_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multi
path linear psmouse e1000 floppy
[  827.045579] CPU: 0 PID: 76 Comm: kworker/u2:3 Tainted: G      D         4.4.0
-24-generic #43-Ubuntu
[  827.045579] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.2
-20160422_131301-anatol 04/01/2014
[  827.045579] task: d4fe2300 ti: d4ff0000 task.ti: d4ff0000
[  827.045579] EIP: 0060:[<c17aa9be>] EFLAGS: 00010246 CPU: 0
[  827.045579] EIP is at ftrace_stub+0x0/0x2
[  827.045579] EAX: d4ff1f00 EBX: c10879d2 ECX: 00000000 EDX: 00000269
[  827.045579] ESI: d4fe2300 EDI: de04a000 EBP: d4ff1f2c ESP: d4ff1ee0
[  827.045579]  DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
[  827.045579] CR0: 8005003b CR2: 00000068 CR3: 1f0d3080 CR4: 000006e0
[  827.045579] Stack:
[  827.045579]  c113f017 d4fe2300 deb1a600 d4ff1f28 c17a5b75 de8f3480 d4ff1f60 d
4ff1f60
[  827.045579]  c17a6004 edee6883 00000268 588ffd18 00000269 00000000 00000000 9
f590057
[  827.045579]  de8a5c00 d4f91b58 d4f91b40 d4ff1f60 c17aaa46 dffbbdc0 00000000 d
e8a5d94
[  827.045579] Call Trace:
[  827.045579]  [<c113f017>] ? ftrace_return_to_handler+0x97/0x170
[  827.045579]  [<c17a5b75>] ? __schedule+0x305/0x790
[  827.045579]  [<c17a6004>] ? schedule+0x4/0x80
[  827.045579]  [<c17aaa46>] return_to_handler+0x9/0xf
[  827.045579]  [<c1087920>] ? process_one_work+0x3f0/0x3f0
[  827.045579]  [<c108ce06>] kthread+0xa6/0xc0
[  827.045579]  [<c17a9949>] ret_from_kernel_thread+0x21/0x38
[  827.045579]  [<c108cd60>] ? kthread_create_on_node+0x170/0x170
[  827.045579] Code: ff ff 8d 76 00 c3 8d 76 00 50 51 52 6a 00 8b 44 24 10 8b 55
  04 8b 0d 94 14 b7 c1 83 e8 05 e8 08 00 00 00 83 c4 04 5a 59 58 e9 fd <ff> ff ff
  ff 74 24 04 6a 00 0f a8 0f a0 06 1e 50 55 57 56 52 51
[  827.045579] EIP: [<c17aa9be>] ftrace_stub+0x0/0x2 SS:ESP 0068:d4ff1ee0
[  827.426561] ---[ end trace 4f291f60e8d43d3a ]---
[  827.856521] BUG: unable to handle kernel paging request at ffffffec
[  827.860060] IP: [<c108d3bf>] kthread_data+0xf/0x20
[  827.860060] *pdpt = 0000000001c6b001 *pde = 0000000001c6c063 *pte = 000000000
0000000
[  827.860060] Oops: 0000 [#5] SMP
[  827.860060] Modules linked in: isofs ppdev joydev serio_raw parport_pc parpor
t ib_iser rdma_cm iw_cm ib_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tc
p libiscsi scsi_transport_iscsi autofs4 btrfs raid10 raid456 async_raid6_recov a
sync_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multi
path linear psmouse e1000 floppy
[  827.860060] CPU: 0 PID: 76 Comm: kworker/u2:3 Tainted: G      D         4.4.0
-24-generic #43-Ubuntu
[  827.860060] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.2
-20160422_131301-anatol 04/01/2014
[  827.860060] task: d4fe2300 ti: d4ff0000 task.ti: d4ff0000
[  827.860060] EIP: 0060:[<c108d3bf>] EFLAGS: 00010086 CPU: 0
[  827.860060] EIP is at kthread_data+0xf/0x20
[  827.860060] EAX: 00000000 EBX: 00000000 ECX: c17a5944 EDX: 00000000
[  827.860060] ESI: c1c62dc0 EDI: dffbbdc0 EBP: d4ff1d08 ESP: d4ff1d00
[  827.860060]  DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
[  827.860060] CR0: 8005003b CR2: 00000014 CR3: 1ee9a040 CR4: 000006e0
[  827.860060] Stack:
[  827.860060]  c17aaa3d d4fe2300 d4ff1d44 c17aaa3d c10546d2 d4ff1d9c d4ff1d9c c
17a6004
[  827.860060]  00000000 9f590057 00000000 d4ff1d84 dffbbdc0 d4fe2300 d4ff2000 d
4ff1d84
[  827.860060]  d4fe2300 d4ff1d50 c17a602d d4ff1a4c d4ff1d9c c17aaa3d d4ff1d78 c
10c7ca1
[  827.860060] Call Trace:
[  827.860060]  [<c17aaa3d>] ? ftrace_graph_caller+0x19/0x19
[  827.860060]  [<c102cea6>] print_context_stack+0xc6/0xd0
[  827.860060]  [<c17aaa3d>] ftrace_graph_caller+0x19/0x19
[  827.860060]  [<c102c445>] dump_trace+0xc5/0x1e0
[  827.860060]  [<c10546d2>] ? prepare_ftrace_return+0x92/0xc0
[  827.860060]  [<c17a6004>] ? schedule+0x4/0x80
[  827.860060]  [<c17a602d>] schedule+0x2d/0x80
[  827.860060]  [<c17aaa3d>] ftrace_graph_caller+0x19/0x19
[  827.860060]  [<c102cfe6>] show_trace_log_lvl+0x46/0x50
[  827.860060]  [<c10c7ca1>] ? vprintk_default+0x41/0x60
[  827.860060]  [<c116fb07>] ? printk+0x17/0x19
[  827.860060]  [<c102cc42>] oops_end+0x92/0xd0
[  827.860060]  [<c102d10e>] die+0x4e/0x70
[  827.860060]  [<c102a269>] do_trap+0x99/0xc0
[  827.860060]  [<c102a58a>] do_error_trap+0x8a/0x120
[  827.860060]  [<c17aa9be>] ? ftrace_graph_call+0x2/0x2
[  827.860060]  [<c112efc2>] ? ring_buffer_unlock_commit+0x22/0x240
[  827.860060]  [<c1135760>] ? __buffer_unlock_commit+0x10/0x20
[  827.860060]  [<c113f409>] ? __trace_graph_return+0x89/0xa0
[  827.860060]  [<c10879d2>] ? worker_thread+0xb2/0x490
[  827.860060]  [<c102abb0>] ? do_overflow+0x30/0x30
[  827.860060]  [<c102abd4>] do_invalid_op+0x24/0x30
[  827.860060]  [<c17aaac7>] error_code+0x67/0x6c
[  827.860060]  [<c10879d2>] ? worker_thread+0xb2/0x490
[  827.860060]  [<c10500d8>] ? assign_irq_vector+0x228/0x2c0
[  827.860060]  [<c17aa9be>] ? ftrace_graph_call+0x2/0x2
[  827.860060]  [<c113f017>] ? ftrace_return_to_handler+0x97/0x170
[  827.860060]  [<c17a5b75>] ? __schedule+0x305/0x790
[  827.860060]  [<c17a6004>] ? schedule+0x4/0x80
[  827.860060]  [<c17aaa46>] return_to_handler+0x9/0xf
[  827.860060]  [<c1087920>] ? process_one_work+0x3f0/0x3f0
[  827.860060]  [<c108ce06>] kthread+0xa6/0xc0
[  827.860060]  [<c17a9949>] ret_from_kernel_thread+0x21/0x38
[  827.860060]  [<c108cd60>] ? kthread_create_on_node+0x170/0x170
[  827.860060] Code: 00 00 00 00 ba 46 02 00 00 b8 04 6c 9b c1 e8 19 30 fe ff e9
  df fe ff ff 8d 74 26 00 55 89 e5 e8 6c d6 71 00 8b 80 74 03 00 00 5d <8b> 40 ec
  c3 8d b6 00 00 00 00 8d bc 27 00 00 00 00 55 89 e5 83
[  827.860060] EIP: [<c108d3bf>] kthread_data+0xf/0x20 SS:ESP 0068:d4ff1d00
[  827.860060] CR2: 00000000ffffffec
[  827.860060] ---[ end trace 4f291f60e8d43d3b ]---
[  827.860060] Fixing recursive fault but reboot is needed!

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: [ftrace] kernel panics during my attempt to use ftrace
  2016-06-21 12:53 [ftrace] kernel panics during my attempt to use ftrace Enrico Mioso
@ 2016-06-22 15:10 ` Steven Rostedt
  2016-06-24  8:08   ` Enrico Mioso
  2016-06-28  3:45 ` Namhyung Kim
  1 sibling, 1 reply; 6+ messages in thread
From: Steven Rostedt @ 2016-06-22 15:10 UTC (permalink / raw)
  To: Enrico Mioso; +Cc: linux-kernel, Ingo Molnar, mattia.bonomi

On Tue, 21 Jun 2016 14:53:24 +0200 (CEST)
Enrico Mioso <mrkiko.rs@gmail.com> wrote:

> Hello guys.
> 
> First of all - thank you for your great work in ftrace, and in general in the 
> Linux tracing infrastructure. I am a newbie: so I am not able to use it at it's 
> full power, still I find it's capabilities impressive.
> 
> I am asking for help, since I am encountering some problems in using ftrace.
> I am trying to come up with a solution to trace a specific workload (a 
> program): to understand what are the functions the kernel spends most of his 
> time in.
> To do so, I inspired myself to some code I found around (I can mention it if 
> needed). I took free inspiration: so my editing may be very very wrong.
> When I run this script, the kernel panics. the output is below. the kernel is 
> Ubuntu 16.04 stock, running in a qemu virtual machine (using kvm).

I see that It's also a 32bit version. Can you run a 64 bit kernel?

> Any help would be greatly apreciated. Thank you very much guys.
> Fort any needed infos, contact me.
> Enrico
> 
> Script:
> #!/bin/sh
> if [ `whoami` != root ]
> then
>      echo you need to run this script as root
>      exit 1
> fi
> 
> tdir=/sys/kernel/debug/tracing
> start()
> {
>     # echo 50000 > $tdir/buffer_size_kb
>     echo function_graph > $tdir/current_tracer
>     echo 1000 >$tdir/tracing_thresh
>     echo >$tdir/trace
>     echo 1 >$tdir/tracing_on # ** this is wrong, interface changed?
> }
> stop()
> {
>     echo >set_event
>     echo 0 >$tdir/tracing_on
>     output=trace`date +%y-%m-%d-%H-%M-%S`.txt
>     echo funcgraph-abstime >$tdir/trace_options
>     echo funcgraph-proc >$tdir/trace_options
>     cat $tdir/trace > $output
>     echo trace written to $output
> }
> COMMAND="$1"
> case $COMMAND in
> start|stop)
>  	$COMMAND
>  	;;
> *)
>  	echo "usage: $0 [start|stop]"
> ;;
> esac
> 

I ran this on bare metal for the latest kernel as well as a stock v4.4
kernel (I don't have an Ubuntu image, I work for Red Hat ;-) (although,
I do have Debian).

> 
> Kernel panic output:
> [  825.336708] BUG: unable to handle kernel paging request at 55501e06
> [  825.340572] IP: [<c17aa9ca>] ftrace_regs_caller+0xa/0x35
> [  825.340572] *pdpt = 000000001ef4c001 *pde = 0000000000000000
> [  825.340572] Oops: 0000 [#1] SMP
> [  825.340572] Modules linked in: isofs ppdev joydev serio_raw parport_pc parpor
> t ib_iser rdma_cm iw_cm ib_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tc
> p libiscsi scsi_transport_iscsi autofs4 btrfs raid10 raid456 async_raid6_recov a
> sync_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multi
> path linear psmouse e1000 floppy
> [  825.340572] CPU: 0 PID: 7 Comm: rcu_sched Not tainted 4.4.0-24-generic #43-Ub
> untu
> [  825.340572] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.2
> -20160422_131301-anatol 04/01/2014
> [  825.340572] task: de8f3480 ti: de988000 task.ti: de988000
> [  825.340572] EIP: 0060:[<c17aa9ca>] EFLAGS: 00010202 CPU: 0
> [  825.340572] EIP is at ftrace_regs_caller+0xa/0x35
> [  825.340572] EAX: de989e4e EBX: c10db072 ECX: 00000000 EDX: 00000268
> [  825.340572] ESI: de8f3480 EDI: dee08800 EBP: de989f10 ESP: de989ec4
> [  825.340572]  DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
> [  825.340572] CR0: 8005003b CR2: 55501e06 CR3: 1e073e20 CR4: 000006e0
> [  825.340572] Stack:
> [  825.340572]  c113f017 de8f3480 d4d1dc00 de989f0c c17a5b75 de9d4ec0 de989f60 d
> e989f60
> [  825.340572]  c17a60e8 edf05431 00000268 f2ee631c 00000268 00000000 00000000 8
> aced3dc
> [  825.340572]  c1ae0490 00000000 c1ae0300 de989f60 c17aaa46 dffbbdc0 00000000 0
> 0000000
> [  825.340572] Call Trace:
> [  825.340572]  [<c113f017>] ? ftrace_return_to_handler+0x97/0x170
> [  825.340572]  [<c17a5b75>] ? __schedule+0x305/0x790
> [  825.340572]  [<c17a60e8>] ? yield_to+0x68/0x170
> [  825.340572]  [<c17aaa46>] return_to_handler+0x9/0xf
> [  825.340572]  [<c10afbd0>] ? wake_atomic_t_function+0x70/0x70
> [  825.340572]  [<c10d5800>] ? force_qs_rnp+0x140/0x140
> [  825.340572]  [<c108ce06>] kthread+0xa6/0xc0

Can you run a mainline kernel (build one yourself from the kernel.org
source) and see if it still crashes. If it doesn't you may need to
contact Ubuntu to fix this.

But if not, let me know, and I can walk you through steps to figure out
where the bug is.

-- Steve

> [  825.340572]  [<c17a9949>] ret_from_kernel_thread+0x21/0x38
> [  825.340572]  [<c108cd60>] ? kthread_create_on_node+0x170/0x170
> [  825.340572] Code: 6a 00 8b 44 24 10 8b 55 04 8b 0d 94 14 b7 c1 83 e8 05 e8 08
>   00 00 00 83 c4 04 5a 59 58 e9 63 00 00 00 ff 74 24 04 6a 00 0f a8 0f <a0> 06 1e
>   50 55 57 56 52 51 53 8b 44 24 34 89 44 24 38 c7 44 24
> [  825.340572] EIP: [<c17aa9ca>] ftrace_regs_caller+0xa/0x35 SS:ESP 0068:de989ec
> 4
> [  825.340572] CR2: 0000000055501e06
> [  825.340572] ---[ end trace 4f291f60e8d43d37 ]---
> [  825.996200] invalid opcode: 0000 [#2] SMP
> [  826.000050] Modules linked in: isofs ppdev joydev serio_raw parport_pc parpor
> t ib_iser rdma_cm iw_cm ib_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tc
> p libiscsi scsi_transport_iscsi autofs4 btrfs raid10 raid456 async_raid6_recov a
> sync_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multi
> path linear psmouse e1000 floppy
> [  826.000050] CPU: 0 PID: 1044 Comm: iscsid Tainted: G      D         4.4.0-24-
> generic #43-Ubuntu
> [  826.000050] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.2
> -20160422_131301-anatol 04/01/2014
> [  826.000050] task: d4679180 ti: dee54000 task.ti: dee54000
> [  826.000050] EIP: 0060:[<c17aa9be>] EFLAGS: 00010217 CPU: 0
> [  826.000050] EIP is at ftrace_stub+0x0/0x2
> [  826.000050] EAX: dee55adc EBX: c17a8d92 ECX: 00000000 EDX: 00000269
> [  826.000050] ESI: d4679180 EDI: de0e9800 EBP: dee55b08 ESP: dee55abc
> [  826.000050]  DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
> [  826.000050] CR0: 8005003b CR2: b7362010 CR3: 1f0d3080 CR4: 000006e0
> [  826.000050] Stack:
> [  826.000050]  c113f017 d4679180 de29f400 dee55b04 c17a5b75 d4fe2300 dee55b88 d
> ee55b88
> [  826.000050]  c17a6004 edebaa8f 00000268 1a3d53a3 00000269 00000000 00000006 9
> 7ca1d76
> [  826.000050]  dee55b34 0003d083 000000c0 dee55b88 c17aaa46 dffbbdc0 00000000 0
> 003d083
> [  826.000050] Call Trace:
> [  826.000050]  [<c113f017>] ? ftrace_return_to_handler+0x97/0x170
> [  826.000050]  [<c17a5b75>] ? __schedule+0x305/0x790
> [  826.000050]  [<c17a6004>] ? schedule+0x4/0x80
> [  826.000050]  [<c17aaa46>] return_to_handler+0x9/0xf
> [  826.000050]  [<c10dc330>] ? __hrtimer_init+0x90/0x90
> [  826.000050]  [<c17aaa3d>] ? ftrace_graph_caller+0x19/0x19
> [  826.000050]  [<c17a8eb7>] schedule_hrtimeout_range+0x17/0x20
> [  826.000050]  [<c17aaa3d>] ftrace_graph_caller+0x19/0x19
> [  826.000050]  [<c11efca6>] poll_schedule_timeout+0x36/0x60
> [  826.000050]  [<c17aaa3d>] ftrace_graph_caller+0x19/0x19
> [  826.000050]  [<c11f13d8>] do_sys_poll+0x4c8/0x570
> [  826.000050]  [<c17aaa3d>] ftrace_graph_caller+0x19/0x19
> [  826.000050]  [<c11f154e>] SyS_poll+0x5e/0x100
> [  826.000050]  [<c1179368>] ? __alloc_pages_nodemask+0x128/0xa40
> [  826.000050]  [<c1067736>] ? kmap_atomic_prot+0x36/0x100
> [  826.000050]  [<c11efe00>] ? poll_select_copy_remaining+0x130/0x130
> [  826.000050]  [<c11efe00>] ? poll_select_copy_remaining+0x130/0x130
> [  826.000050]  [<c105bb07>] ? kvm_clock_read+0x17/0x20
> [  826.000050]  [<c105cadb>] ? pvclock_clocksource_read+0xab/0x150
> [  826.000050]  [<c105cadb>] ? pvclock_clocksource_read+0xab/0x150
> [  826.000050]  [<c105bb07>] ? kvm_clock_read+0x17/0x20
> [  826.000050]  [<c105cadb>] ? pvclock_clocksource_read+0xab/0x150
> [  826.000050]  [<c105bb07>] ? kvm_clock_read+0x17/0x20
> [  826.000050]  [<c1032918>] ? sched_clock+0x8/0x10
> [  826.000050]  [<c11267a8>] ? trace_clock_local+0x8/0x10
> [  826.000050]  [<c112de75>] ? rb_reserve_next_event+0x75/0x430
> [  826.000050]  [<c112efc2>] ? ring_buffer_unlock_commit+0x22/0x240
> [  826.000050]  [<c1135760>] ? __buffer_unlock_commit+0x10/0x20
> [  826.000050]  [<c113f409>] ? __trace_graph_return+0x89/0xa0
> [  826.000050]  [<c11f1542>] ? SyS_poll+0x52/0x100
> [  826.000050]  [<c113f017>] ? ftrace_return_to_handler+0x97/0x170
> [  826.000050]  [<c11effb8>] ? poll_select_set_timeout+0x8/0xa0
> [  826.000050]  [<c17aaa3d>] ftrace_graph_caller+0x19/0x19
> [  826.000050]  [<c100393d>] do_fast_syscall_32+0x8d/0x150
> [  826.000050]  [<c17aaa3d>] ftrace_graph_caller+0x19/0x19
> [  826.000050]  [<c17a99dc>] sysenter_past_esp+0x3d/0x61
> [  826.000050]  [<c17aaa3d>] ftrace_graph_caller+0x19/0x19
> [  826.000050] Code: ff ff 8d 76 00 c3 8d 76 00 50 51 52 6a 00 8b 44 24 10 8b 55
>   04 8b 0d 94 14 b7 c1 83 e8 05 e8 08 00 00 00 83 c4 04 5a 59 58 e9 fd <ff> ff ff
>   ff 74 24 04 6a 00 0f a8 0f a0 06 1e 50 55 57 56 52 51
> [  826.000050] EIP: [<c17aa9be>] ftrace_stub+0x0/0x2 SS:ESP 0068:dee55abc
> [  826.640678] ---[ end trace 4f291f60e8d43d38 ]---
> [  826.649117] invalid opcode: 0000 [#3] SMP
> [  826.652668] Modules linked in: isofs ppdev joydev serio_raw parport_pc parpor
> t ib_iser rdma_cm iw_cm ib_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tc
> p libiscsi scsi_transport_iscsi autofs4 btrfs raid10 raid456 async_raid6_recov a
> sync_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multi
> path linear psmouse e1000 floppy
> [  826.652668] CPU: 0 PID: 4 Comm: kworker/0:0 Tainted: G      D         4.4.0-2
> 4-generic #43-Ubuntu
> [  826.652668] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.2
> -20160422_131301-anatol 04/01/2014
> [  826.652668] task: de8f1a40 ti: de8fe000 task.ti: de8fe000
> [  826.652668] EIP: 0060:[<c17aa9be>] EFLAGS: 00010246 CPU: 0
> [  826.652668] EIP is at ftrace_stub+0x0/0x2
> [  826.652668] EAX: de8fff00 EBX: c10879d2 ECX: 00000000 EDX: 00000269
> [  826.652668] ESI: de8f1a40 EDI: de167800 EBP: de8fff2c ESP: de8ffee0
> [  826.652668]  DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
> [  826.652668] CR0: 8005003b CR2: 00000068 CR3: 1f0d3080 CR4: 000006e0
> [  826.652668] Stack:
> [  826.652668]  c113f017 de8f1a40 deb1a600 de8fff28 c17a5b75 d467e040 de8fff60 d
> e8fff60
> [  826.652668]  c17a6004 edd8153d 00000268 41282712 00000269 00000000 00000000 b
> 4d9c50e
> [  826.652668]  dffbb8c0 de821a98 de821a80 de8fff60 c17aaa46 dffbbdc0 00000000 d
> ffbba54
> [  826.652668] Call Trace:
> [  826.652668]  [<c113f017>] ? ftrace_return_to_handler+0x97/0x170
> [  826.652668]  [<c17a5b75>] ? __schedule+0x305/0x790
> [  826.652668]  [<c17a6004>] ? schedule+0x4/0x80
> [  826.652668]  [<c17aaa46>] return_to_handler+0x9/0xf
> [  826.652668]  [<c1087920>] ? process_one_work+0x3f0/0x3f0
> [  826.652668]  [<c108ce06>] kthread+0xa6/0xc0
> [  826.652668]  [<c17a9949>] ret_from_kernel_thread+0x21/0x38
> [  826.652668]  [<c108cd60>] ? kthread_create_on_node+0x170/0x170
> [  826.652668] Code: ff ff 8d 76 00 c3 8d 76 00 50 51 52 6a 00 8b 44 24 10 8b 55
>   04 8b 0d 94 14 b7 c1 83 e8 05 e8 08 00 00 00 83 c4 04 5a 59 58 e9 fd <ff> ff ff
>   ff 74 24 04 6a 00 0f a8 0f a0 06 1e 50 55 57 56 52 51
> [  826.652668] EIP: [<c17aa9be>] ftrace_stub+0x0/0x2 SS:ESP 0068:de8ffee0
> [  827.033592] ---[ end trace 4f291f60e8d43d39 ]---
> [  827.041794] invalid opcode: 0000 [#4] SMP
> [  827.045579] Modules linked in: isofs ppdev joydev serio_raw parport_pc parpor
> t ib_iser rdma_cm iw_cm ib_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tc
> p libiscsi scsi_transport_iscsi autofs4 btrfs raid10 raid456 async_raid6_recov a
> sync_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multi
> path linear psmouse e1000 floppy
> [  827.045579] CPU: 0 PID: 76 Comm: kworker/u2:3 Tainted: G      D         4.4.0
> -24-generic #43-Ubuntu
> [  827.045579] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.2
> -20160422_131301-anatol 04/01/2014
> [  827.045579] task: d4fe2300 ti: d4ff0000 task.ti: d4ff0000
> [  827.045579] EIP: 0060:[<c17aa9be>] EFLAGS: 00010246 CPU: 0
> [  827.045579] EIP is at ftrace_stub+0x0/0x2
> [  827.045579] EAX: d4ff1f00 EBX: c10879d2 ECX: 00000000 EDX: 00000269
> [  827.045579] ESI: d4fe2300 EDI: de04a000 EBP: d4ff1f2c ESP: d4ff1ee0
> [  827.045579]  DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
> [  827.045579] CR0: 8005003b CR2: 00000068 CR3: 1f0d3080 CR4: 000006e0
> [  827.045579] Stack:
> [  827.045579]  c113f017 d4fe2300 deb1a600 d4ff1f28 c17a5b75 de8f3480 d4ff1f60 d
> 4ff1f60
> [  827.045579]  c17a6004 edee6883 00000268 588ffd18 00000269 00000000 00000000 9
> f590057
> [  827.045579]  de8a5c00 d4f91b58 d4f91b40 d4ff1f60 c17aaa46 dffbbdc0 00000000 d
> e8a5d94
> [  827.045579] Call Trace:
> [  827.045579]  [<c113f017>] ? ftrace_return_to_handler+0x97/0x170
> [  827.045579]  [<c17a5b75>] ? __schedule+0x305/0x790
> [  827.045579]  [<c17a6004>] ? schedule+0x4/0x80
> [  827.045579]  [<c17aaa46>] return_to_handler+0x9/0xf
> [  827.045579]  [<c1087920>] ? process_one_work+0x3f0/0x3f0
> [  827.045579]  [<c108ce06>] kthread+0xa6/0xc0
> [  827.045579]  [<c17a9949>] ret_from_kernel_thread+0x21/0x38
> [  827.045579]  [<c108cd60>] ? kthread_create_on_node+0x170/0x170
> [  827.045579] Code: ff ff 8d 76 00 c3 8d 76 00 50 51 52 6a 00 8b 44 24 10 8b 55
>   04 8b 0d 94 14 b7 c1 83 e8 05 e8 08 00 00 00 83 c4 04 5a 59 58 e9 fd <ff> ff ff
>   ff 74 24 04 6a 00 0f a8 0f a0 06 1e 50 55 57 56 52 51
> [  827.045579] EIP: [<c17aa9be>] ftrace_stub+0x0/0x2 SS:ESP 0068:d4ff1ee0
> [  827.426561] ---[ end trace 4f291f60e8d43d3a ]---
> [  827.856521] BUG: unable to handle kernel paging request at ffffffec
> [  827.860060] IP: [<c108d3bf>] kthread_data+0xf/0x20
> [  827.860060] *pdpt = 0000000001c6b001 *pde = 0000000001c6c063 *pte = 000000000
> 0000000
> [  827.860060] Oops: 0000 [#5] SMP
> [  827.860060] Modules linked in: isofs ppdev joydev serio_raw parport_pc parpor
> t ib_iser rdma_cm iw_cm ib_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tc
> p libiscsi scsi_transport_iscsi autofs4 btrfs raid10 raid456 async_raid6_recov a
> sync_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multi
> path linear psmouse e1000 floppy
> [  827.860060] CPU: 0 PID: 76 Comm: kworker/u2:3 Tainted: G      D         4.4.0
> -24-generic #43-Ubuntu
> [  827.860060] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.2
> -20160422_131301-anatol 04/01/2014
> [  827.860060] task: d4fe2300 ti: d4ff0000 task.ti: d4ff0000
> [  827.860060] EIP: 0060:[<c108d3bf>] EFLAGS: 00010086 CPU: 0
> [  827.860060] EIP is at kthread_data+0xf/0x20
> [  827.860060] EAX: 00000000 EBX: 00000000 ECX: c17a5944 EDX: 00000000
> [  827.860060] ESI: c1c62dc0 EDI: dffbbdc0 EBP: d4ff1d08 ESP: d4ff1d00
> [  827.860060]  DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
> [  827.860060] CR0: 8005003b CR2: 00000014 CR3: 1ee9a040 CR4: 000006e0
> [  827.860060] Stack:
> [  827.860060]  c17aaa3d d4fe2300 d4ff1d44 c17aaa3d c10546d2 d4ff1d9c d4ff1d9c c
> 17a6004
> [  827.860060]  00000000 9f590057 00000000 d4ff1d84 dffbbdc0 d4fe2300 d4ff2000 d
> 4ff1d84
> [  827.860060]  d4fe2300 d4ff1d50 c17a602d d4ff1a4c d4ff1d9c c17aaa3d d4ff1d78 c
> 10c7ca1
> [  827.860060] Call Trace:
> [  827.860060]  [<c17aaa3d>] ? ftrace_graph_caller+0x19/0x19
> [  827.860060]  [<c102cea6>] print_context_stack+0xc6/0xd0
> [  827.860060]  [<c17aaa3d>] ftrace_graph_caller+0x19/0x19
> [  827.860060]  [<c102c445>] dump_trace+0xc5/0x1e0
> [  827.860060]  [<c10546d2>] ? prepare_ftrace_return+0x92/0xc0
> [  827.860060]  [<c17a6004>] ? schedule+0x4/0x80
> [  827.860060]  [<c17a602d>] schedule+0x2d/0x80
> [  827.860060]  [<c17aaa3d>] ftrace_graph_caller+0x19/0x19
> [  827.860060]  [<c102cfe6>] show_trace_log_lvl+0x46/0x50
> [  827.860060]  [<c10c7ca1>] ? vprintk_default+0x41/0x60
> [  827.860060]  [<c116fb07>] ? printk+0x17/0x19
> [  827.860060]  [<c102cc42>] oops_end+0x92/0xd0
> [  827.860060]  [<c102d10e>] die+0x4e/0x70
> [  827.860060]  [<c102a269>] do_trap+0x99/0xc0
> [  827.860060]  [<c102a58a>] do_error_trap+0x8a/0x120
> [  827.860060]  [<c17aa9be>] ? ftrace_graph_call+0x2/0x2
> [  827.860060]  [<c112efc2>] ? ring_buffer_unlock_commit+0x22/0x240
> [  827.860060]  [<c1135760>] ? __buffer_unlock_commit+0x10/0x20
> [  827.860060]  [<c113f409>] ? __trace_graph_return+0x89/0xa0
> [  827.860060]  [<c10879d2>] ? worker_thread+0xb2/0x490
> [  827.860060]  [<c102abb0>] ? do_overflow+0x30/0x30
> [  827.860060]  [<c102abd4>] do_invalid_op+0x24/0x30
> [  827.860060]  [<c17aaac7>] error_code+0x67/0x6c
> [  827.860060]  [<c10879d2>] ? worker_thread+0xb2/0x490
> [  827.860060]  [<c10500d8>] ? assign_irq_vector+0x228/0x2c0
> [  827.860060]  [<c17aa9be>] ? ftrace_graph_call+0x2/0x2
> [  827.860060]  [<c113f017>] ? ftrace_return_to_handler+0x97/0x170
> [  827.860060]  [<c17a5b75>] ? __schedule+0x305/0x790
> [  827.860060]  [<c17a6004>] ? schedule+0x4/0x80
> [  827.860060]  [<c17aaa46>] return_to_handler+0x9/0xf
> [  827.860060]  [<c1087920>] ? process_one_work+0x3f0/0x3f0
> [  827.860060]  [<c108ce06>] kthread+0xa6/0xc0
> [  827.860060]  [<c17a9949>] ret_from_kernel_thread+0x21/0x38
> [  827.860060]  [<c108cd60>] ? kthread_create_on_node+0x170/0x170
> [  827.860060] Code: 00 00 00 00 ba 46 02 00 00 b8 04 6c 9b c1 e8 19 30 fe ff e9
>   df fe ff ff 8d 74 26 00 55 89 e5 e8 6c d6 71 00 8b 80 74 03 00 00 5d <8b> 40 ec
>   c3 8d b6 00 00 00 00 8d bc 27 00 00 00 00 55 89 e5 83
> [  827.860060] EIP: [<c108d3bf>] kthread_data+0xf/0x20 SS:ESP 0068:d4ff1d00
> [  827.860060] CR2: 00000000ffffffec
> [  827.860060] ---[ end trace 4f291f60e8d43d3b ]---
> [  827.860060] Fixing recursive fault but reboot is needed!

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: [ftrace] kernel panics during my attempt to use ftrace
  2016-06-22 15:10 ` Steven Rostedt
@ 2016-06-24  8:08   ` Enrico Mioso
  0 siblings, 0 replies; 6+ messages in thread
From: Enrico Mioso @ 2016-06-24  8:08 UTC (permalink / raw)
  To: Steven Rostedt; +Cc: linux-kernel, Ingo Molnar, mattia.bonomi

Hi Steven.

Thank you for your very very kind response.
I can build a stock kernel (I usually did for my real hw): and I don't see problems on this.
The problem is the bitness. My only KVM-enabled machine, as far as I can tell, has a 32-bit CPU.
So This would be a different problem.
I'll let you know when I can continue: right now I am a little bit in trouble with my exams: but I hope I will be able to eventually cme back and test.

Below my cpuinfo just for the record.
Thank you very much,
Enrico

processor	: 0
vendor_id	: GenuineIntel
cpu family	: 6
model		: 28
model name	: Intel(R) Atom(TM) CPU Z520   @ 1.33GHz
stepping	: 2
microcode	: 0x211
cpu MHz		: 1333.000
cache size	: 512 KB
physical id	: 0
siblings	: 2
core id		: 0
cpu cores	: 1
apicid		: 0
initial apicid	: 0
fdiv_bug	: no
f00f_bug	: no
coma_bug	: no
fpu		: yes
fpu_exception	: yes
cpuid level	: 10
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe nx constant_tsc arch_perfmon pebs bts aperfmperf eagerfpu pni dtes64 monitor ds_cpl vmx est tm2 ssse3 xtpr pdcm movbe lahf_lm tpr_shadow vnmi flexpriority dtherm
bugs		:
bogomips	: 2662.89
clflush size	: 64
cache_alignment	: 64
address sizes	: 32 bits physical, 32 bits virtual
power management:

processor	: 1
vendor_id	: GenuineIntel
cpu family	: 6
model		: 28
model name	: Intel(R) Atom(TM) CPU Z520   @ 1.33GHz
stepping	: 2
microcode	: 0x211
cpu MHz		: 800.000
cache size	: 512 KB
physical id	: 0
siblings	: 2
core id		: 0
cpu cores	: 1
apicid		: 1
initial apicid	: 1
fdiv_bug	: no
f00f_bug	: no
coma_bug	: no
fpu		: yes
fpu_exception	: yes
cpuid level	: 10
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe nx constant_tsc arch_perfmon pebs bts aperfmperf eagerfpu pni dtes64 monitor ds_cpl vmx est tm2 ssse3 xtpr pdcm movbe lahf_lm tpr_shadow vnmi flexpriority dtherm
bugs		:
bogomips	: 2662.42
clflush size	: 64
cache_alignment	: 64
address sizes	: 32 bits physical, 32 bits virtual
power management:

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: [ftrace] kernel panics during my attempt to use ftrace
  2016-06-21 12:53 [ftrace] kernel panics during my attempt to use ftrace Enrico Mioso
  2016-06-22 15:10 ` Steven Rostedt
@ 2016-06-28  3:45 ` Namhyung Kim
  2016-06-28  7:16   ` Enrico Mioso
  2016-07-17 23:59   ` Enrico Mioso
  1 sibling, 2 replies; 6+ messages in thread
From: Namhyung Kim @ 2016-06-28  3:45 UTC (permalink / raw)
  To: Enrico Mioso; +Cc: LKML, Ingo Molnar, Steven Rostedt, mattia.bonomi

Hello,

On Tue, Jun 21, 2016 at 9:53 PM, Enrico Mioso <mrkiko.rs@gmail.com> wrote:
> Hello guys.
>
> First of all - thank you for your great work in ftrace, and in general in
> the Linux tracing infrastructure. I am a newbie: so I am not able to use it
> at it's full power, still I find it's capabilities impressive.
>
> I am asking for help, since I am encountering some problems in using ftrace.
> I am trying to come up with a solution to trace a specific workload (a
> program): to understand what are the functions the kernel spends most of his
> time in.
> To do so, I inspired myself to some code I found around (I can mention it if
> needed). I took free inspiration: so my editing may be very very wrong.
> When I run this script, the kernel panics. the output is below. the kernel
> is Ubuntu 16.04 stock, running in a qemu virtual machine (using kvm).

Please check commit 8329e818f149 ("ftrace/x86: Set ftrace_stub to weak
to prevent gcc from using short jumps to it") The ubuntu 16.04 seems to
have binutils 2.26 which is same version that caused trouble in my system.

Thanks,
Namhyung


> Any help would be greatly apreciated. Thank you very much guys.
> Fort any needed infos, contact me.
> Enrico

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: [ftrace] kernel panics during my attempt to use ftrace
  2016-06-28  3:45 ` Namhyung Kim
@ 2016-06-28  7:16   ` Enrico Mioso
  2016-07-17 23:59   ` Enrico Mioso
  1 sibling, 0 replies; 6+ messages in thread
From: Enrico Mioso @ 2016-06-28  7:16 UTC (permalink / raw)
  To: Namhyung Kim; +Cc: LKML, Ingo Molnar, Steven Rostedt, mattia.bonomi

Thank you very much for the report.
I'll let you know guys, once I am able to get to work on this again , at least I'll try.
Thank you very much anyway.

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: [ftrace] kernel panics during my attempt to use ftrace
  2016-06-28  3:45 ` Namhyung Kim
  2016-06-28  7:16   ` Enrico Mioso
@ 2016-07-17 23:59   ` Enrico Mioso
  1 sibling, 0 replies; 6+ messages in thread
From: Enrico Mioso @ 2016-07-17 23:59 UTC (permalink / raw)
  To: Namhyung Kim; +Cc: LKML, Ingo Molnar, Steven Rostedt, mattia.bonomi

Thank you guys very much for your kind answers.
I can not prove it actually: but I think it's right. It seems upgrading binutils could have solved the problem.
I am sorry for my impreciseness: but in the actual Ubuntu kernel version, 4.4.0-31** ?, the problem seems fixed.
I can enable kernel tracing without hitting a panic.
Thank you very much for your help and replies.

^ permalink raw reply	[flat|nested] 6+ messages in thread

end of thread, other threads:[~2016-07-17 23:59 UTC | newest]

Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2016-06-21 12:53 [ftrace] kernel panics during my attempt to use ftrace Enrico Mioso
2016-06-22 15:10 ` Steven Rostedt
2016-06-24  8:08   ` Enrico Mioso
2016-06-28  3:45 ` Namhyung Kim
2016-06-28  7:16   ` Enrico Mioso
2016-07-17 23:59   ` Enrico Mioso

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).