[PATCH] KVM:PPC Issue in exit timing clearance

[PATCH] KVM:PPC Issue in exit timing clearance

[Bharat Bhushan]

Following dump is observed on host when clearing the exit timing counters

[root@p1021mds kvm]# echo -n 'c' > vm1200_vcpu0_timing
INFO: task echo:1276 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
echo          D 0ff5bf94     0  1276   1190 0x00000000
Call Trace:
[c2157e40] [c0007908] __switch_to+0x9c/0xc4
[c2157e50] [c040293c] schedule+0x1b4/0x3bc
[c2157e90] [c04032dc] __mutex_lock_slowpath+0x74/0xc0
[c2157ec0] [c00369e4] kvmppc_init_timing_stats+0x20/0xb8
[c2157ed0] [c0036b00] kvmppc_exit_timing_write+0x84/0x98
[c2157ef0] [c00b9f90] vfs_write+0xc0/0x16c
[c2157f10] [c00ba284] sys_write+0x4c/0x90
[c2157f40] [c000e320] ret_from_syscall+0x0/0x3c

	The vcpu->mutex is used by kvm_ioctl_* (KVM_RUN etc) and same was used when clearing the stats (in kvmppc_init_timing_stats()).
What happens is that when the guest is idle then it held the vcpu->mutx. While the exiting timing process waits for guest to release the vcpu->mutex and a hang state is reached.

	Now using seprate lock for exit timing stats.

Signed-off-by: Bharat Bhushan <Bharat.Bhushan@freescale.com>
Acked-by: Alexander Graf <agraf@suse.de>
---
 arch/powerpc/include/asm/kvm_host.h |    1 +
 arch/powerpc/kvm/powerpc.c          |    4 ++++
 arch/powerpc/kvm/timing.c           |    8 +++++---
 3 files changed, 10 insertions(+), 3 deletions(-)

diff --git a/arch/powerpc/include/asm/kvm_host.h b/arch/powerpc/include/asm/kvm_host.h
index 2d8cc32..afcc030 100644
--- a/arch/powerpc/include/asm/kvm_host.h
+++ b/arch/powerpc/include/asm/kvm_host.h
@@ -311,6 +311,7 @@ struct kvm_vcpu_arch {
 	struct kvmppc_debug_reg host_dbg_reg;	/* host debug regiters*/
 
 #ifdef CONFIG_KVM_EXIT_TIMING
+	struct mutex exit_timing_lock;
 	struct kvmppc_exit_timing timing_exit;
 	struct kvmppc_exit_timing timing_last_enter;
 	u32 last_exit_type;
diff --git a/arch/powerpc/kvm/powerpc.c b/arch/powerpc/kvm/powerpc.c
index 434eb4e..72a7100 100644
--- a/arch/powerpc/kvm/powerpc.c
+++ b/arch/powerpc/kvm/powerpc.c
@@ -338,6 +338,10 @@ int kvm_arch_vcpu_init(struct kvm_vcpu *vcpu)
 	tasklet_init(&vcpu->arch.tasklet, kvmppc_decrementer_func, (ulong)vcpu);
 	vcpu->arch.dec_timer.function = kvmppc_decrementer_wakeup;
 
+#ifdef CONFIG_KVM_EXIT_TIMING
+	mutex_init(&vcpu->arch.exit_timing_lock);
+#endif
+
 	return 0;
 }
 
diff --git a/arch/powerpc/kvm/timing.c b/arch/powerpc/kvm/timing.c
index e71eed9..c3e40a1 100644
--- a/arch/powerpc/kvm/timing.c
+++ b/arch/powerpc/kvm/timing.c
@@ -35,8 +35,8 @@ void kvmppc_init_timing_stats(struct kvm_vcpu *vcpu)
 {
 	int i;
 
-	/* pause guest execution to avoid concurrent updates */
-	mutex_lock(&vcpu->mutex);
+	/* Take a lock to avoid concurrent updates */
+	mutex_lock(&vcpu->arch.exit_timing_lock);
 
 	vcpu->arch.last_exit_type = 0xDEAD;
 	for (i = 0; i < __NUMBER_OF_KVM_EXIT_TYPES; i++) {
@@ -51,13 +51,14 @@ void kvmppc_init_timing_stats(struct kvm_vcpu *vcpu)
 	vcpu->arch.timing_last_enter.tv64 = 0;
 	vcpu->arch.timing_start = 0;
 
-	mutex_unlock(&vcpu->mutex);
+	mutex_unlock(&vcpu->arch.exit_timing_lock);
 }
 
 static void add_exit_timing(struct kvm_vcpu *vcpu, u64 duration, int type)
 {
 	u64 old;
 
+	mutex_lock(&vcpu->arch.exit_timing_lock);
 	vcpu->arch.timing_count_type[type]++;
 
 	/* sum */
@@ -86,6 +87,7 @@ static void add_exit_timing(struct kvm_vcpu *vcpu, u64 duration, int type)
 		vcpu->arch.timing_min_duration[type] = duration;
 	if (unlikely(duration > vcpu->arch.timing_max_duration[type]))
 		vcpu->arch.timing_max_duration[type] = duration;
+	mutex_unlock(&vcpu->arch.exit_timing_lock);
 }
 
 void kvmppc_update_timing_stats(struct kvm_vcpu *vcpu)
-- 
1.7.0.4

Re: [PATCH] KVM:PPC Issue in exit timing clearance

[Avi Kivity]

On 03/16/2011 06:37 PM, Bharat Bhushan wrote:
> Following dump is observed on host when clearing the exit timing counters
>
> [root@p1021mds kvm]# echo -n 'c'>  vm1200_vcpu0_timing
> INFO: task echo:1276 blocked for more than 120 seconds.
> "echo 0>  /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> echo          D 0ff5bf94     0  1276   1190 0x00000000
> Call Trace:
> [c2157e40] [c0007908] __switch_to+0x9c/0xc4
> [c2157e50] [c040293c] schedule+0x1b4/0x3bc
> [c2157e90] [c04032dc] __mutex_lock_slowpath+0x74/0xc0
> [c2157ec0] [c00369e4] kvmppc_init_timing_stats+0x20/0xb8
> [c2157ed0] [c0036b00] kvmppc_exit_timing_write+0x84/0x98
> [c2157ef0] [c00b9f90] vfs_write+0xc0/0x16c
> [c2157f10] [c00ba284] sys_write+0x4c/0x90
> [c2157f40] [c000e320] ret_from_syscall+0x0/0x3c
>
> 	The vcpu->mutex is used by kvm_ioctl_* (KVM_RUN etc) and same was used when clearing the stats (in kvmppc_init_timing_stats()).
> What happens is that when the guest is idle then it held the vcpu->mutx. While the exiting timing process waits for guest to release the vcpu->mutex and a hang state is reached.
>
> 	Now using seprate lock for exit timing stats.
>

Seems excessive to have a new lock just for timing.

What about using vcpu->requests to have the statistics cleared in vcpu 
context?

What about dropping the whole thing and replacing it with tracepoints?

-- 
error compiling committee.c: too many arguments to function

Re: [PATCH] KVM:PPC Issue in exit timing clearance

[Alexander Graf]

On 03/22/2011 01:43 PM, Avi Kivity wrote:
> On 03/16/2011 06:37 PM, Bharat Bhushan wrote:
>> Following dump is observed on host when clearing the exit timing 
>> counters
>>
>> [root@p1021mds kvm]# echo -n 'c'>  vm1200_vcpu0_timing
>> INFO: task echo:1276 blocked for more than 120 seconds.
>> "echo 0>  /proc/sys/kernel/hung_task_timeout_secs" disables this 
>> message.
>> echo          D 0ff5bf94     0  1276   1190 0x00000000
>> Call Trace:
>> [c2157e40] [c0007908] __switch_to+0x9c/0xc4
>> [c2157e50] [c040293c] schedule+0x1b4/0x3bc
>> [c2157e90] [c04032dc] __mutex_lock_slowpath+0x74/0xc0
>> [c2157ec0] [c00369e4] kvmppc_init_timing_stats+0x20/0xb8
>> [c2157ed0] [c0036b00] kvmppc_exit_timing_write+0x84/0x98
>> [c2157ef0] [c00b9f90] vfs_write+0xc0/0x16c
>> [c2157f10] [c00ba284] sys_write+0x4c/0x90
>> [c2157f40] [c000e320] ret_from_syscall+0x0/0x3c
>>
>>     The vcpu->mutex is used by kvm_ioctl_* (KVM_RUN etc) and same was 
>> used when clearing the stats (in kvmppc_init_timing_stats()).
>> What happens is that when the guest is idle then it held the 
>> vcpu->mutx. While the exiting timing process waits for guest to 
>> release the vcpu->mutex and a hang state is reached.
>>
>>     Now using seprate lock for exit timing stats.
>>
>
> Seems excessive to have a new lock just for timing.

The whole thing is only used for debugging, so being excessive doesn't 
hurt too much here. In normal configurations, it's #ifdef'ed out.

>
> What about using vcpu->requests to have the statistics cleared in vcpu 
> context?
>
> What about dropping the whole thing and replacing it with tracepoints?

That should work. The question is if it's worth the effort. The current 
code is there after all :).


Alex

Re: [PATCH] KVM:PPC Issue in exit timing clearance

[Avi Kivity]

On 03/22/2011 04:27 PM, Alexander Graf wrote:
>
>>
>> What about using vcpu->requests to have the statistics cleared in 
>> vcpu context?
>>
>> What about dropping the whole thing and replacing it with tracepoints?
>
> That should work. The question is if it's worth the effort. The 
> current code is there after all :).
>

Tracepoints are wonderful for debugging problems in the field, from my 
experience.  Removing the special timing code (or rather, moving it to 
userspace) is just a bonus.

-- 
error compiling committee.c: too many arguments to function

RE: [PATCH] KVM:PPC Issue in exit timing clearance

[Bhushan Bharat-R65777]

> -----Original Message-----
> From: Avi Kivity [mailto:avi@redhat.com]
> Sent: Wednesday, March 23, 2011 2:50 PM
> To: Alexander Graf
> Cc: Bhushan Bharat-R65777; kvm@vger.kernel.org; bharatb.yadav@gmail.com;
> Bhushan Bharat-R65777
> Subject: Re: [PATCH] KVM:PPC Issue in exit timing clearance
> 
> On 03/22/2011 04:27 PM, Alexander Graf wrote:
> >
> >>
> >> What about using vcpu->requests to have the statistics cleared in
> >> vcpu context?
> >>
> >> What about dropping the whole thing and replacing it with tracepoints?
> >
> > That should work. The question is if it's worth the effort. The
> > current code is there after all :).
> >
> 
> Tracepoints are wonderful for debugging problems in the field, from my
> experience.  Removing the special timing code (or rather, moving it to
> userspace) is just a bonus.
> 

I think that we can always switch to tracepoints mechanism sometime in future if it really worth. But at least to remove the issue in current mechanism we can move with this patch.

Thanks
-Bharat

Re: [PATCH] KVM:PPC Issue in exit timing clearance

[Avi Kivity]

On 03/24/2011 04:21 AM, Bhushan Bharat-R65777 wrote:
> >  Tracepoints are wonderful for debugging problems in the field, from my
> >  experience.  Removing the special timing code (or rather, moving it to
> >  userspace) is just a bonus.
> >
>
> I think that we can always switch to tracepoints mechanism sometime in future if it really worth. But at least to remove the issue in current mechanism we can move with this patch.
>

Fair enough; but the patch doesn't apply.

-- 
error compiling committee.c: too many arguments to function

RE: [PATCH] KVM:PPC Issue in exit timing clearance

[Bhushan Bharat-R65777]

> -----Original Message-----
> From: Avi Kivity [mailto:avi@redhat.com]
> Sent: Thursday, March 24, 2011 3:51 PM
> To: Bhushan Bharat-R65777
> Cc: Alexander Graf; kvm@vger.kernel.org; bharatb.yadav@gmail.com
> Subject: Re: [PATCH] KVM:PPC Issue in exit timing clearance
> 
> On 03/24/2011 04:21 AM, Bhushan Bharat-R65777 wrote:
> > >  Tracepoints are wonderful for debugging problems in the field, from
> > > my  experience.  Removing the special timing code (or rather, moving
> > > it to
> > >  userspace) is just a bonus.
> > >
> >
> > I think that we can always switch to tracepoints mechanism sometime in
> future if it really worth. But at least to remove the issue in current
> mechanism we can move with this patch.
> >
> 
> Fair enough; but the patch doesn't apply.
> 

I am not sure why it does not apply,

This patch in on origin/master of http://git.kernel.org/pub/scm/linux/kernel/git/avi/kvm.git

I will send up updated on head again.

Thanks
-Bharat