trace "exit to userspace" event

PATCH Superseded Gleb Natapov 3 participants 17 messages Oct 5, 2010 – Oct 14, 2010

Subsystems (2)

KVM Tracing

lore

Share & tools

lore

Marcelo Tosatti

2010-10-07 16:25 UTC #1 lore raw

Quoted 53 lines · Gleb Natapov

Add tracepoint for userspace exit.

Signed-off-by Gleb Natapov <[email protected]>

include/trace/events/kvm.h +25 -0

index 6dd3a51..fb44da0 100644
@@ -6,6 +6,31 @@
 #undef TRACE_SYSTEM
 #define TRACE_SYSTEM kvm
 
+#define ERSN(x) { KVM_EXIT_##x, "KVM_EXIT_" #x }
+
+#define kvm_trace_exit_reason						\
+	ERSN(UNKNOWN), ERSN(EXCEPTION), ERSN(IO), ERSN(HYPERCALL),	\
+	ERSN(DEBUG), ERSN(HLT), ERSN(MMIO), ERSN(IRQ_WINDOW_OPEN),	\
+	ERSN(SHUTDOWN), ERSN(FAIL_ENTRY), ERSN(INTR), ERSN(SET_TPR),	\
+	ERSN(TPR_ACCESS), ERSN(S390_SIEIC), ERSN(S390_RESET), ERSN(DCR),\
+	ERSN(NMI), ERSN(INTERNAL_ERROR), ERSN(OSI)
+
+TRACE_EVENT(kvm_userspace_exit,
+	    TP_PROTO(__u32 reason),
+	    TP_ARGS(reason),
+
+	TP_STRUCT__entry(
+		__field(	__u32,		reason		)
+	),
+
+	TP_fast_assign(
+		__entry->reason		= reason;
+	),
+
+	TP_printk("reason %s", __print_symbolic(__entry->reason,
+						kvm_trace_exit_reason))
+);
+
 #if defined(__KVM_HAVE_IOAPIC)
 TRACE_EVENT(kvm_set_irq,
 	TP_PROTO(unsigned int gsi, int level, int irq_source_id),

virt/kvm/kvm_main.c +2 -1

index b8499f5..8800713 100644
@@ -1458,6 +1458,8 @@ static long kvm_vcpu_ioctl(struct file *filp,
 		if (arg)
 			goto out;
 		r = kvm_arch_vcpu_ioctl_run(vcpu, vcpu->run);
+		if (r >= 0)
+			trace_kvm_userspace_exit(vcpu->run->exit_reason);
 		break;
 	case KVM_GET_REGS: {
 		struct kvm_regs *kvm_regs;
--

Quoted 1 line

Gleb.

Exit codes are also valid for r == -EINTR and -EAGAIN cases, eg EXIT_INTR. Better print it out for all cases, and let the reader decide whether exit_reason is valid.

Gleb Natapov

author

2010-10-07 17:56 UTC #2 lore raw

Quoted 51 lines · Marcelo Tosatti

Quoted 50 lines · Gleb Natapov

Add tracepoint for userspace exit.

Signed-off-by Gleb Natapov <[email protected]>

include/trace/events/kvm.h +25 -0

index 6dd3a51..fb44da0 100644
@@ -6,6 +6,31 @@
 #undef TRACE_SYSTEM
 #define TRACE_SYSTEM kvm
 
+#define ERSN(x) { KVM_EXIT_##x, "KVM_EXIT_" #x }
+
+#define kvm_trace_exit_reason						\
+	ERSN(UNKNOWN), ERSN(EXCEPTION), ERSN(IO), ERSN(HYPERCALL),	\
+	ERSN(DEBUG), ERSN(HLT), ERSN(MMIO), ERSN(IRQ_WINDOW_OPEN),	\
+	ERSN(SHUTDOWN), ERSN(FAIL_ENTRY), ERSN(INTR), ERSN(SET_TPR),	\
+	ERSN(TPR_ACCESS), ERSN(S390_SIEIC), ERSN(S390_RESET), ERSN(DCR),\
+	ERSN(NMI), ERSN(INTERNAL_ERROR), ERSN(OSI)
+
+TRACE_EVENT(kvm_userspace_exit,
+	    TP_PROTO(__u32 reason),
+	    TP_ARGS(reason),
+
+	TP_STRUCT__entry(
+		__field(	__u32,		reason		)
+	),
+
+	TP_fast_assign(
+		__entry->reason		= reason;
+	),
+
+	TP_printk("reason %s", __print_symbolic(__entry->reason,
+						kvm_trace_exit_reason))
+);
+
 #if defined(__KVM_HAVE_IOAPIC)
 TRACE_EVENT(kvm_set_irq,
 	TP_PROTO(unsigned int gsi, int level, int irq_source_id),

virt/kvm/kvm_main.c +2 -0

index b8499f5..8800713 100644
@@ -1458,6 +1458,8 @@ static long kvm_vcpu_ioctl(struct file *filp,
 		if (arg)
 			goto out;
 		r = kvm_arch_vcpu_ioctl_run(vcpu, vcpu->run);
+		if (r >= 0)
+			trace_kvm_userspace_exit(vcpu->run->exit_reason);
 		break;

Quoted 8 lines

Quoted 4 lines
virt/kvm/kvm_main.c +0 -1
 	case KVM_GET_REGS: {
 		struct kvm_regs *kvm_regs;
--
Gleb.
Exit codes are also valid for r == -EINTR and -EAGAIN cases, eg EXIT_INTR. Better print it out for all cases, and let the reader decide whether exit_reason is valid.

Are they? I see that userspace does not look into run->exit_reason in case of -EINTR and -EAGAIN.

--
Gleb.

Marcelo Tosatti

2010-10-08 16:11 UTC #3 lore raw

Quoted 19 lines · Gleb Natapov

Quoted 11 lines
Quoted 11 lines
virt/kvm/kvm_main.c +2 -0
index b8499f5..8800713 100644
@@ -1458,6 +1458,8 @@ static long kvm_vcpu_ioctl(struct file *filp,
 		if (arg)
 			goto out;
 		r = kvm_arch_vcpu_ioctl_run(vcpu, vcpu->run);
+		if (r >= 0)
+			trace_kvm_userspace_exit(vcpu->run->exit_reason);
 		break;
Quoted 8 lines
Quoted 4 lines
virt/kvm/kvm_main.c +0 -1
 	case KVM_GET_REGS: {
 		struct kvm_regs *kvm_regs;
--
Gleb.
Exit codes are also valid for r == -EINTR and -EAGAIN cases, eg EXIT_INTR. Better print it out for all cases, and let the reader decide whether exit_reason is valid.

Quoted 2 lines

Are they? I see that userspace does not look into run->exit_reason in case of -EINTR and -EAGAIN.

Not userspace, but for a human reader. Otherwise the trace information is incomplete and confusing.

Gleb Natapov

author

2010-10-08 16:44 UTC #4 lore raw

Quoted 20 lines · Marcelo Tosatti

Quoted 19 lines · Gleb Natapov
Quoted 19 lines
Quoted 14 lines
virt/kvm/kvm_main.c +2 -1
index b8499f5..8800713 100644
@@ -1458,6 +1458,8 @@ static long kvm_vcpu_ioctl(struct file *filp,
 		if (arg)
 			goto out;
 		r = kvm_arch_vcpu_ioctl_run(vcpu, vcpu->run);
+		if (r >= 0)
+			trace_kvm_userspace_exit(vcpu->run->exit_reason);
 		break;
 	case KVM_GET_REGS: {
 		struct kvm_regs *kvm_regs;
--
Quoted 1 line
Gleb.
Exit codes are also valid for r == -EINTR and -EAGAIN cases, eg EXIT_INTR. Better print it out for all cases, and let the reader decide whether exit_reason is valid.

Quoted 5 lines

Quoted 2 lines
Are they? I see that userspace does not look into run->exit_reason in case of -EINTR and -EAGAIN.
Not userspace, but for a human reader. Otherwise the trace information is incomplete and confusing.

But if we will always call trace_kvm_userspace_exit() here trace information will show erroneous info since on any error but -EINTR exit_reason contains stale info. What about changing r >= 0 to r >= 0 || r == -EINTR.

--
Gleb.

Avi Kivity

2010-10-10 08:45 UTC #5 lore raw

Quoted 24 lines · Gleb Natapov

Quoted 23 lines · Marcelo Tosatti
Quoted 21 lines · Gleb Natapov
Quoted 16 lines
Quoted 7 lines
diff --git a/virt/kvm/kvm_main.c b/virt/kvm/kvm_main.c index b8499f5..8800713 100644
--- a/virt/kvm/kvm_main.c
+++ b/virt/kvm/kvm_main.c
@@ -1458,6 +1458,8 @@ static long kvm_vcpu_ioctl(struct file *filp,
if (arg)
goto out;
Quoted 8 lines
r = kvm_arch_vcpu_ioctl_run(vcpu, vcpu->run);
+ if (r>= 0)
+ trace_kvm_userspace_exit(vcpu->run->exit_reason);
break;
case KVM_GET_REGS: {
struct kvm_regs *kvm_regs;
--
Gleb.
Quoted 3 lines
Exit codes are also valid for r == -EINTR and -EAGAIN cases, eg EXIT_INTR. Better print it out for all cases, and let the reader decide whether exit_reason is valid.
Are they? I see that userspace does not look into run->exit_reason in case of -EINTR and -EAGAIN.

Quoted 6 lines

Quoted 2 lines
Not userspace, but for a human reader. Otherwise the trace information is incomplete and confusing.
But if we will always call trace_kvm_userspace_exit() here trace information will show erroneous info since on any error but -EINTR exit_reason contains stale info. What about changing r>= 0 to r>= 0 || r == -EINTR.

We should log both errno and exit_reason. If we want to be clever, we can display strerror(errno) if it's nonzero, and exit_reason otherwise (easy to do in a trace-cmd plugin).

Signature · 1 line

error compiling committee.c: too many arguments to function

Gleb Natapov

author

2010-10-10 15:46 UTC #6 lore raw

Quoted 27 lines · Avi Kivity

Quoted 26 lines · Gleb Natapov
Quoted 25 lines · Marcelo Tosatti
Quoted 16 lines · Gleb Natapov
Quoted 16 lines
Quoted 15 lines
diff --git a/virt/kvm/kvm_main.c b/virt/kvm/kvm_main.c index b8499f5..8800713 100644
--- a/virt/kvm/kvm_main.c
+++ b/virt/kvm/kvm_main.c
@@ -1458,6 +1458,8 @@ static long kvm_vcpu_ioctl(struct file *filp,
if (arg)
goto out;
r = kvm_arch_vcpu_ioctl_run(vcpu, vcpu->run);
+ if (r>= 0)
+ trace_kvm_userspace_exit(vcpu->run->exit_reason);
break;
case KVM_GET_REGS: {
struct kvm_regs *kvm_regs;
--
Gleb.
Quoted 5 lines
Quoted 3 lines
Exit codes are also valid for r == -EINTR and -EAGAIN cases, eg EXIT_INTR. Better print it out for all cases, and let the reader decide whether exit_reason is valid.
Are they? I see that userspace does not look into run->exit_reason in case of -EINTR and -EAGAIN.
Not userspace, but for a human reader. Otherwise the trace information is incomplete and confusing.

Quoted 9 lines

Quoted 4 lines
But if we will always call trace_kvm_userspace_exit() here trace information will show erroneous info since on any error but -EINTR exit_reason contains stale info. What about changing r>= 0 to r>= 0 || r == -EINTR.
We should log both errno and exit_reason. If we want to be clever, we can display strerror(errno) if it's nonzero, and exit_reason otherwise (easy to do in a trace-cmd plugin).

For starters we should remove KVM_EXIT_INTR exit reason. Looking into qemu-kvm history it was never used and there is at least one code path that returns -EINTR and does not set KVM_EXIT_INTR, so exit_reason field contains stale info on exit.

--
Gleb.

Avi Kivity

2010-10-14 10:27 UTC #7 lore raw

Quoted 10 lines · Gleb Natapov

Quoted 5 lines
We should log both errno and exit_reason. If we want to be clever, we can display strerror(errno) if it's nonzero, and exit_reason otherwise (easy to do in a trace-cmd plugin).
For starters we should remove KVM_EXIT_INTR exit reason. Looking into qemu-kvm history it was never used and there is at least one code path that returns -EINTR and does not set KVM_EXIT_INTR, so exit_reason field contains stale info on exit.

The two issues are unrelated.

Signature · 1 line

error compiling committee.c: too many arguments to function

Gleb Natapov

author

2010-10-14 10:29 UTC #8 lore raw

Quoted 6 lines · Avi Kivity

Quoted 5 lines · Gleb Natapov
Quoted 5 lines
We should log both errno and exit_reason. If we want to be clever, we can display strerror(errno) if it's nonzero, and exit_reason otherwise (easy to do in a trace-cmd plugin).

Quoted 8 lines

Quoted 5 lines
For starters we should remove KVM_EXIT_INTR exit reason. Looking into qemu-kvm history it was never used and there is at least one code path that returns -EINTR and does not set KVM_EXIT_INTR, so exit_reason field contains stale info on exit.
The two issues are unrelated.

So what do you propose? I see no issue with my original patch.

--
Gleb.

Avi Kivity

2010-10-14 11:11 UTC #9 lore raw

Quoted 13 lines · Gleb Natapov

Quoted 12 lines · Avi Kivity
Quoted 10 lines · Gleb Natapov
Quoted 5 lines
We should log both errno and exit_reason. If we want to be clever, we can display strerror(errno) if it's nonzero, and exit_reason otherwise (easy to do in a trace-cmd plugin).
For starters we should remove KVM_EXIT_INTR exit reason. Looking into qemu-kvm history it was never used and there is at least one code path that returns -EINTR and does not set KVM_EXIT_INTR, so exit_reason field contains stale info on exit.

Quoted 3 lines

Quoted 2 lines
The two issues are unrelated.
So what do you propose? I see no issue with my original patch.

Record both errno and exit_reason. While they're never both valid at the same time, they're both necessary.

Signature · 1 line

error compiling committee.c: too many arguments to function

Gleb Natapov

author

2010-10-14 11:28 UTC #10 lore raw

Quoted 14 lines · Avi Kivity

Quoted 13 lines · Gleb Natapov
Quoted 12 lines · Avi Kivity
Quoted 10 lines · Gleb Natapov
Quoted 5 lines
We should log both errno and exit_reason. If we want to be clever, we can display strerror(errno) if it's nonzero, and exit_reason otherwise (easy to do in a trace-cmd plugin).
For starters we should remove KVM_EXIT_INTR exit reason. Looking into qemu-kvm history it was never used and there is at least one code path that returns -EINTR and does not set KVM_EXIT_INTR, so exit_reason field contains stale info on exit.

Quoted 7 lines

Quoted 3 lines
Quoted 2 lines
The two issues are unrelated.
So what do you propose? I see no issue with my original patch.
Record both errno and exit_reason. While they're never both valid at the same time, they're both necessary.

If they can't be valid at the same time, why not record one of them? The one that happened? Also any error other then -EINTR will cause qemu to stop, so it is not very interesting. And ioctl return value can be traced by strace anyway.

--
Gleb.

Avi Kivity

2010-10-14 11:32 UTC #11 lore raw

Quoted 15 lines · Gleb Natapov

Quoted 14 lines · Avi Kivity
Quoted 13 lines · Gleb Natapov
Quoted 12 lines · Avi Kivity
Quoted 10 lines · Gleb Natapov
Quoted 5 lines
We should log both errno and exit_reason. If we want to be clever, we can display strerror(errno) if it's nonzero, and exit_reason otherwise (easy to do in a trace-cmd plugin).
For starters we should remove KVM_EXIT_INTR exit reason. Looking into qemu-kvm history it was never used and there is at least one code path that returns -EINTR and does not set KVM_EXIT_INTR, so exit_reason field contains stale info on exit.

Quoted 8 lines

Quoted 7 lines
Quoted 3 lines
Quoted 2 lines
The two issues are unrelated.
So what do you propose? I see no issue with my original patch.
Record both errno and exit_reason. While they're never both valid at the same time, they're both necessary.
If they can't be valid at the same time, why not record one of them?

If you record just one, you don't know if the other one happened.

Quoted 4 lines

The
one that happened? Also any error other then -EINTR will cause qemu to stop, so it is not very interesting. And ioctl return value can be traced by strace anyway.

You can't correlate it with ftrace.

Signature · 1 line

error compiling committee.c: too many arguments to function

Gleb Natapov

author

2010-10-14 11:41 UTC #12 lore raw

Quoted 18 lines · Avi Kivity

Quoted 17 lines · Gleb Natapov
Quoted 16 lines · Avi Kivity
Quoted 15 lines · Gleb Natapov
Quoted 14 lines · Avi Kivity
Quoted 10 lines · Gleb Natapov
Quoted 5 lines
We should log both errno and exit_reason. If we want to be clever, we can display strerror(errno) if it's nonzero, and exit_reason otherwise (easy to do in a trace-cmd plugin).
For starters we should remove KVM_EXIT_INTR exit reason. Looking into qemu-kvm history it was never used and there is at least one code path that returns -EINTR and does not set KVM_EXIT_INTR, so exit_reason field contains stale info on exit.
The two issues are unrelated.

Quoted 9 lines

Quoted 6 lines
Quoted 5 lines
Quoted 1 line
So what do you propose? I see no issue with my original patch.
Record both errno and exit_reason. While they're never both valid at the same time, they're both necessary.
If they can't be valid at the same time, why not record one of them?
If you record just one, you don't know if the other one happened.

I mean to record type/value. So it can be (type error/value -EINVAL) or (type exit/value HALT). The goal is to not print non-relevant info in ftrace, but we can do the same with recording errno and exit_reason and show only exit_reason is errno>=0 or errno otherwise.

Quoted 7 lines

Quoted 4 lines
The
one that happened? Also any error other then -EINTR will cause qemu to stop, so it is not very interesting. And ioctl return value can be traced by strace anyway.
You can't correlate it with ftrace.

True. But given that the only interesting error code in -EINTR I do not know if this is useful, but potentially may generate a lot of events in ftrace. Sometimes too much info is almost as bad as not enough and if we will use the same event for both exit_reason and errno it will be impossible to enable one without the other.

--
Gleb.

Avi Kivity

2010-10-14 11:43 UTC #13 lore raw

Quoted 5 lines · Gleb Natapov

Quoted 5 lines
Quoted 5 lines
Quoted 5 lines
Quoted 1 line
So what do you propose? I see no issue with my original patch.
Record both errno and exit_reason. While they're never both valid at the same time, they're both necessary.

Quoted 8 lines

Quoted 4 lines
Quoted 1 line
If they can't be valid at the same time, why not record one of them?
If you record just one, you don't know if the other one happened.
I mean to record type/value. So it can be (type error/value -EINVAL) or (type exit/value HALT). The goal is to not print non-relevant info in ftrace, but we can do the same with recording errno and exit_reason and show only exit_reason is errno>=0 or errno otherwise.

That's fine. As long as you don't drop information.

Quoted 5 lines

Quoted 5 lines
Quoted 4 lines
The
one that happened? Also any error other then -EINTR will cause qemu to stop, so it is not very interesting. And ioctl return value can be traced by strace anyway.

Quoted 7 lines

Quoted 2 lines
You can't correlate it with ftrace.
True. But given that the only interesting error code in -EINTR I do not know if this is useful, but potentially may generate a lot of events in ftrace. Sometimes too much info is almost as bad as not enough and if we will use the same event for both exit_reason and errno it will be impossible to enable one without the other.

You can always filter excess information away. If you're looking for exits to userspace (a major performance issue) then you want to see both normal exits and signal exits.

Signature · 1 line

error compiling committee.c: too many arguments to function

Gleb Natapov

author

2010-10-14 11:47 UTC #14 lore raw

Quoted 30 lines · Avi Kivity

Quoted 5 lines · Gleb Natapov
Quoted 5 lines
Quoted 5 lines
Quoted 5 lines
Quoted 1 line
So what do you propose? I see no issue with my original patch.
Record both errno and exit_reason. While they're never both valid at the same time, they're both necessary.
Quoted 8 lines
Quoted 4 lines
Quoted 1 line
If they can't be valid at the same time, why not record one of them?
If you record just one, you don't know if the other one happened.
I mean to record type/value. So it can be (type error/value -EINVAL) or (type exit/value HALT). The goal is to not print non-relevant info in ftrace, but we can do the same with recording errno and exit_reason and show only exit_reason is errno>=0 or errno otherwise.
That's fine. As long as you don't drop information.
Quoted 5 lines
Quoted 5 lines
Quoted 4 lines
The
one that happened? Also any error other then -EINTR will cause qemu to stop, so it is not very interesting. And ioctl return value can be traced by strace anyway.
Quoted 7 lines
Quoted 2 lines
You can't correlate it with ftrace.
True. But given that the only interesting error code in -EINTR I do not know if this is useful, but potentially may generate a lot of events in ftrace. Sometimes too much info is almost as bad as not enough and if we will use the same event for both exit_reason and errno it will be impossible to enable one without the other.

Quoted 4 lines

You can always filter excess information away. If you're looking for exits to userspace (a major performance issue) then you want to see both normal exits and signal exits.

How do I do it via /debug file system? Now I just echo name of the event I am interested in set_event, how do I add filter to that?

--
Gleb.

Avi Kivity

2010-10-14 12:09 UTC #15 lore raw

Quoted 7 lines · Gleb Natapov

Quoted 5 lines
You can always filter excess information away. If you're looking for exits to userspace (a major performance issue) then you want to see both normal exits and signal exits.
How do I do it via /debug file system? Now I just echo name of the event I am interested in set_event, how do I add filter to that?

echo exit_reason==33 > /sys/kernel/debug/tracing/events/kvm/kvm_exit/filter

Signature · 1 line

error compiling committee.c: too many arguments to function

Avi Kivity

2010-10-14 12:10 UTC #16 lore raw

Quoted 11 lines · Avi Kivity

Quoted 7 lines · Gleb Natapov
Quoted 5 lines
You can always filter excess information away. If you're looking for exits to userspace (a major performance issue) then you want to see both normal exits and signal exits.
How do I do it via /debug file system? Now I just echo name of the event I am interested in set_event, how do I add filter to that?
echo exit_reason==33 > /sys/kernel/debug/tracing/events/kvm/kvm_exit/filter

Or, easier,

trace-cmd record -e kvm:kvm_exit -f exit_reason==33

Signature · 1 line

error compiling committee.c: too many arguments to function