2.6.38.2 kernel with trace-cmd git pulled this morning:
trace-cmd record -e kvm
trace-cmd report 2>&1 | less
trace-cmd: No such file or directory
function ftrace_print_symbols_seq not defined
failed to read event print fmt for kvm_nested_vmexit_inject
function ftrace_print_symbols_seq not defined
failed to read event print fmt for kvm_nested_vmexit
function ftrace_print_symbols_seq not defined
failed to read event print fmt for kvm_exit
bad op token {
failed to read event print fmt for kvm_emulate_insn
qemu-kvm-1864 [002] 2253.714134: kvm_entry: vcpu 1
qemu-kvm-1863 [008] 2253.714136: kvm_exit: [FAILED
TO PARSE] exit_reason=44 guest_rip=0xc01185ed isa=1 info1=4272 info2=0
qemu-kvm-1864 [002] 2253.714138: kvm_exit: [FAILED
TO PARSE] exit_reason=44 guest_rip=0xc01185ed isa=1 info1=4272 info2=0
qemu-kvm-1863 [008] 2253.714145: kvm_emulate_insn: [FAILED
TO PARSE] rip=3222373869 csbase=0 len=2 insn=<89>^H]<C3><8B>^U<EC><95>K<C0>U
<89><E5>]<8D>^E flags=5 failed=0
I have not used trace-cmd much, so I am not familiar with the code. Is
this a known issue? Suggestions on how to debug?
Thanks,
David
On Fri, Apr 8, 2011 at 7:53 PM, David Ahern <[email protected]> wrote:
> 2.6.38.2 kernel with trace-cmd git pulled this morning:
>
> trace-cmd record -e kvm
>
> trace-cmd report 2>&1 | less
>
> trace-cmd: No such file or directory
> ?function ftrace_print_symbols_seq not defined
> ?failed to read event print fmt for kvm_nested_vmexit_inject
> ?function ftrace_print_symbols_seq not defined
> ?failed to read event print fmt for kvm_nested_vmexit
> ?function ftrace_print_symbols_seq not defined
> ?failed to read event print fmt for kvm_exit
> ?bad op token {
> ?failed to read event print fmt for kvm_emulate_insn
>
> ? ? ? ?qemu-kvm-1864 ?[002] ?2253.714134: kvm_entry: ? ? ? ? ? ?vcpu 1
> ? ? ? ?qemu-kvm-1863 ?[008] ?2253.714136: kvm_exit: ? ? ? ? ? ? [FAILED
> TO PARSE] exit_reason=44 guest_rip=0xc01185ed isa=1 info1=4272 info2=0
> ? ? ? ?qemu-kvm-1864 ?[002] ?2253.714138: kvm_exit: ? ? ? ? ? ? [FAILED
> TO PARSE] exit_reason=44 guest_rip=0xc01185ed isa=1 info1=4272 info2=0
> ? ? ? ?qemu-kvm-1863 ?[008] ?2253.714145: kvm_emulate_insn: ? ? [FAILED
> TO PARSE] rip=3222373869 csbase=0 len=2 insn=<89>^H]<C3><8B>^U<EC><95>K<C0>U
> <89><E5>]<8D>^E flags=5 failed=0
>
> I have not used trace-cmd much, so I am not familiar with the code. Is
> this a known issue? Suggestions on how to debug?
I think there have been issues for a long time. I've never gotten
perf or trace-cmd to be happy with kvm:* events. Here is a related
thread from a while back:
https://lkml.org/lkml/2010/5/26/194
When I looked a while back the problem was due to how there is some
preprocessor magic in Linux that ends up exporting C expressions as
strings to userspace and neither perf nor trace-cmd have the parsing
smarts to evaluate the C expressions at runtime.
I ended up using ftrace instead which handles everything inside the
kernel and compiles in those C expressions.
Stefan
On 04/08/11 14:50, Stefan Hajnoczi wrote:
> On Fri, Apr 8, 2011 at 7:53 PM, David Ahern <[email protected]> wrote:
>> 2.6.38.2 kernel with trace-cmd git pulled this morning:
>>
>> trace-cmd record -e kvm
>>
>> trace-cmd report 2>&1 | less
>>
>> trace-cmd: No such file or directory
>> function ftrace_print_symbols_seq not defined
>> failed to read event print fmt for kvm_nested_vmexit_inject
>> function ftrace_print_symbols_seq not defined
>> failed to read event print fmt for kvm_nested_vmexit
>> function ftrace_print_symbols_seq not defined
>> failed to read event print fmt for kvm_exit
>> bad op token {
>> failed to read event print fmt for kvm_emulate_insn
>>
>> qemu-kvm-1864 [002] 2253.714134: kvm_entry: vcpu 1
>> qemu-kvm-1863 [008] 2253.714136: kvm_exit: [FAILED
>> TO PARSE] exit_reason=44 guest_rip=0xc01185ed isa=1 info1=4272 info2=0
>> qemu-kvm-1864 [002] 2253.714138: kvm_exit: [FAILED
>> TO PARSE] exit_reason=44 guest_rip=0xc01185ed isa=1 info1=4272 info2=0
>> qemu-kvm-1863 [008] 2253.714145: kvm_emulate_insn: [FAILED
>> TO PARSE] rip=3222373869 csbase=0 len=2 insn=<89>^H]<C3><8B>^U<EC><95>K<C0>U
>> <89><E5>]<8D>^E flags=5 failed=0
>>
>> I have not used trace-cmd much, so I am not familiar with the code. Is
>> this a known issue? Suggestions on how to debug?
>
> I think there have been issues for a long time. I've never gotten
> perf or trace-cmd to be happy with kvm:* events. Here is a related
> thread from a while back:
>
> https://lkml.org/lkml/2010/5/26/194
>
> When I looked a while back the problem was due to how there is some
> preprocessor magic in Linux that ends up exporting C expressions as
> strings to userspace and neither perf nor trace-cmd have the parsing
> smarts to evaluate the C expressions at runtime.
Hmm.. ok. I thought it had been added - to trace-cmd at least. And I
recall Avi recently sending a patch to trace-cmd folks - I took that to
mean it works. Evidently, not.
David
>
> I ended up using ftrace instead which handles everything inside the
> kernel and compiles in those C expressions.
>
> Stefan
On 2011-04-08 20:53, David Ahern wrote:
> 2.6.38.2 kernel with trace-cmd git pulled this morning:
>
> trace-cmd record -e kvm
>
> trace-cmd report 2>&1 | less
>
> trace-cmd: No such file or directory
Does this error come from trace-cmd failing to find its kvm plugin?
Check what strace -e open says.
Jan
On 04/08/11 15:07, Jan Kiszka wrote:
> On 2011-04-08 20:53, David Ahern wrote:
>> 2.6.38.2 kernel with trace-cmd git pulled this morning:
>>
>> trace-cmd record -e kvm
>>
>> trace-cmd report 2>&1 | less
>>
>> trace-cmd: No such file or directory
>
> Does this error come from trace-cmd failing to find its kvm plugin?
> Check what strace -e open says.
>
> Jan
>
Tried that before - it was not enlightening.
strace -e trace=open trace-cmd report 2>&1 | less
open("/etc/ld.so.cache", O_RDONLY) = 3
open("/lib64/libdl.so.2", O_RDONLY) = 3
open("/lib64/libc.so.6", O_RDONLY) = 3
open("/root/trace.dat", O_RDONLY) = 3
trace-cmd: No such file or directory
function ftrace_print_symbols_seq not defined
failed to read event print fmt for kvm_nested_vmexit_inject
function ftrace_print_symbols_seq not defined
failed to read event print fmt for kvm_nested_vmexit
function ftrace_print_symbols_seq not defined
failed to read event print fmt for kvm_exit
bad op token {
failed to read event print fmt for kvm_emulate_insn
open("/proc/meminfo", O_RDONLY) = 4
David
On 2011-04-08 23:12, David Ahern wrote:
>
>
> On 04/08/11 15:07, Jan Kiszka wrote:
>> On 2011-04-08 20:53, David Ahern wrote:
>>> 2.6.38.2 kernel with trace-cmd git pulled this morning:
>>>
>>> trace-cmd record -e kvm
>>>
>>> trace-cmd report 2>&1 | less
>>>
>>> trace-cmd: No such file or directory
>>
>> Does this error come from trace-cmd failing to find its kvm plugin?
>> Check what strace -e open says.
>>
>> Jan
>>
>
> Tried that before - it was not enlightening.
> strace -e trace=open trace-cmd report 2>&1 | less
>
> open("/etc/ld.so.cache", O_RDONLY) = 3
> open("/lib64/libdl.so.2", O_RDONLY) = 3
> open("/lib64/libc.so.6", O_RDONLY) = 3
> open("/root/trace.dat", O_RDONLY) = 3
> trace-cmd: No such file or directory
> function ftrace_print_symbols_seq not defined
> failed to read event print fmt for kvm_nested_vmexit_inject
> function ftrace_print_symbols_seq not defined
> failed to read event print fmt for kvm_nested_vmexit
> function ftrace_print_symbols_seq not defined
> failed to read event print fmt for kvm_exit
> bad op token {
> failed to read event print fmt for kvm_emulate_insn
> open("/proc/meminfo", O_RDONLY) = 4
Let me check... indeed, I'm getting the same file-not-found here with
trace-cmd.git 9cce1c9b5b when starting it directly from its build directory.
But maybe your trace-cmd or kernel versions are too old / incompatible.
I'm not getting complaints about unparseable events with the above
snapshot and 2.6.38.
Jan
On 04/08/11 15:18, Jan Kiszka wrote:
> Let me check... indeed, I'm getting the same file-not-found here with
> trace-cmd.git 9cce1c9b5b when starting it directly from its build directory.
>
> But maybe your trace-cmd or kernel versions are too old / incompatible.
> I'm not getting complaints about unparseable events with the above
> snapshot and 2.6.38.
2.6.38.2 kernel, trace-cmd 3e8b5b8 which is March 18 (though git pull
done this morning).
For grins I checked-out 9cce1c9b5b and same error:
trace-cmd record -e kvm -- sleep 1
trace-cmd report 2>&1 | less
You do have to put stderr onto stdout to see the messages I reported
earlier. Or look for [FAILED TO PARSE] on the kvm_exit and
kvm_emulate_insn lines.
David
On 2011-04-09 01:26, David Ahern wrote:
> On 04/08/11 15:18, Jan Kiszka wrote:
>> Let me check... indeed, I'm getting the same file-not-found here with
>> trace-cmd.git 9cce1c9b5b when starting it directly from its build directory.
>>
>> But maybe your trace-cmd or kernel versions are too old / incompatible.
>> I'm not getting complaints about unparseable events with the above
>> snapshot and 2.6.38.
>
> 2.6.38.2 kernel, trace-cmd 3e8b5b8 which is March 18 (though git pull
> done this morning).
>
> For grins I checked-out 9cce1c9b5b and same error:
> trace-cmd record -e kvm -- sleep 1
> trace-cmd report 2>&1 | less
>
> You do have to put stderr onto stdout to see the messages I reported
> earlier. Or look for [FAILED TO PARSE] on the kvm_exit and
> kvm_emulate_insn lines.
I did that.
What I also did is updating trace-cmd git and then reinstalling the
latest plugins: make install_plugins prefix=$HOME. They then end up in
$HOME/.trace-cmd/plugins. Now I do not have a single error message
anymore, including that file not found.
Jan
On 04/08/11 17:42, Jan Kiszka wrote:
> What I also did is updating trace-cmd git and then reinstalling the
> latest plugins: make install_plugins prefix=$HOME. They then end up in
> $HOME/.trace-cmd/plugins. Now I do not have a single error message
> anymore, including that file not found.
Indeed. That did the trick. I was just running out of the build
directory -- without doing an install of any kind.
On Fri, Apr 08, 2011 at 11:07:23PM +0200, Jan Kiszka wrote:
> On 2011-04-08 20:53, David Ahern wrote:
> > 2.6.38.2 kernel with trace-cmd git pulled this morning:
> >
> > trace-cmd record -e kvm
> >
> > trace-cmd report 2>&1 | less
> >
> > trace-cmd: No such file or directory
>
> Does this error come from trace-cmd failing to find its kvm plugin?
> Check what strace -e open says.
>
I need to spend some time and fix it. That "No such file or directory"
is from the way trace-cmd does error handling. It checks if errno is set
and if so, it prints out perror(). What usually happens is I do a stat()
on a file which sets errno, and forget about it. Then if trace-cmd finds
some internal error, it calls the warning() message, which then prints
out the stale errno.
-- Steve