Bug 2009312

Hi Polina,

Thanks for reporting the issue.
Just to make sure that I am interpreting things correctly, this issue is
only reproducible on PPC and not on x86?

The patch that was causing this regression (at least on x86) was reverted
in 4.18.0-242.el8.
Later on, that patch was brought back with several other fixes in 8.5
(kernel-4.18.0-318.el8) as part of Bug 1904570. But at that time we didn't
observe any regression maybe because we only tested on x86(?).

I am wondering if there is a different patch that is causing this because
as Tamir reported he only started observing this issue from 4.18.0-305.8.el8
onwards.

Adding Vitaly and Greg to see if they have any inputs.

Looking at the changelog for 4.18.0-305.8.el8, there is a patch for context
tracking. I wonder if it has something to do with it (but this is purely
based on a quick look). 
 
 KVM: PPC: Book3S HV: Context tracking exit guest context before enabling irqs (Greg Kurz) [1945745]

But if it does make sense maybe we can try a build by reverting this patch.
Vitaly & Greg what do you guys think?

Thanks

Honestly, I don't know much about PPC but as the issue is introduced in
kernel-4.18.0-305.8.el8, I don't think it is a regression from BZ#1904570. It is indeed
very likely that the issue is introduced by 

    commit 112665286d08c87e66d699e7cba43c1497ad165f
    Author: Nicholas Piggin <npiggin>
    Date:   Sat Jan 30 23:08:12 2021 +1000
    
        KVM: PPC: Book3S HV: Context tracking exit guest context before enabling irqs

but afaict, the change is still present upstream so it's likely the problem is also
present there. I think we need something like 

    commit 160457140187c5fb127b844e5a85f87f00a01b14
    Author: Wanpeng Li <wanpengli>
    Date:   Tue May 4 17:27:30 2021 -0700
    
        KVM: x86: Defer vtime accounting 'til after IRQ handling

for PPC to fix the problem but again, I don't know much about PPC, maybe it is
a complete red herring.

(In reply to Nitesh Narayan Lal from comment #2)
> Hi Polina,
> 
> Thanks for reporting the issue.
> Just to make sure that I am interpreting things correctly, this issue is
> only reproducible on PPC and not on x86?
> 
> The patch that was causing this regression (at least on x86) was reverted
> in 4.18.0-242.el8.
> Later on, that patch was brought back with several other fixes in 8.5
> (kernel-4.18.0-318.el8) as part of Bug 1904570. But at that time we didn't
> observe any regression maybe because we only tested on x86(?).
> 
we tested it on both platforms. 
these tests are running as part of the regression automation set on both platforms.

> I am wondering if there is a different patch that is causing this because
> as Tamir reported he only started observing this issue from 4.18.0-305.8.el8
> onwards.
> 
> Adding Vitaly and Greg to see if they have any inputs.
> 
> Looking at the changelog for 4.18.0-305.8.el8, there is a patch for context
> tracking. I wonder if it has something to do with it (but this is purely
> based on a quick look). 
>  
>  KVM: PPC: Book3S HV: Context tracking exit guest context before enabling
> irqs (Greg Kurz) [1945745]
> 
> But if it does make sense maybe we can try a build by reverting this patch.
> Vitaly & Greg what do you guys think?
> 
> Thanks

(In reply to Vitaly Kuznetsov from comment #3)
> Honestly, I don't know much about PPC but as the issue is introduced in
> kernel-4.18.0-305.8.el8, I don't think it is a regression from BZ#1904570.
> It is indeed
> very likely that the issue is introduced by 
> 
>     commit 112665286d08c87e66d699e7cba43c1497ad165f
>     Author: Nicholas Piggin <npiggin>
>     Date:   Sat Jan 30 23:08:12 2021 +1000
>     
>         KVM: PPC: Book3S HV: Context tracking exit guest context before
> enabling irqs
> 
> but afaict, the change is still present upstream so it's likely the problem
> is also
> present there. I think we need something like 
> 
>     commit 160457140187c5fb127b844e5a85f87f00a01b14
>     Author: Wanpeng Li <wanpengli>
>     Date:   Tue May 4 17:27:30 2021 -0700
>     
>         KVM: x86: Defer vtime accounting 'til after IRQ handling
> 
> for PPC to fix the problem but again, I don't know much about PPC, maybe it
> is
> a complete red herring.

Yeah, possibly. Hopefully, Greg will be able to help us here.

Thanks for taking a look.

Interesting. The supposedly faulty upstream commit 112665286d08c87e66d699e7cba43c1497ad165f
kinda partially reverts a change from:

commit 61bd0f66ff92d5ce765ff9850fd3cbfec773c560 (tag: kvm-ppc-fixes-4.16-1)
Author: Laurent Vivier <lvivier>
Date:   Fri Mar 2 11:51:56 2018 +0100

    KVM: PPC: Book3S HV: Fix guest time accounting with VIRT_CPU_ACCOUNTING_GEN
    
    Since commit 8b24e69fc47e ("KVM: PPC: Book3S HV: Close race with testing
    for signals on guest entry"), if CONFIG_VIRT_CPU_ACCOUNTING_GEN is set, the
    guest time is not accounted to guest time and user time, but instead to
    system time.
    
    This is because guest_enter()/guest_exit() are called while interrupts
    are disabled and the tick counter cannot be updated between them.
    
    To fix that, move guest_exit() after local_irq_enable(), and as
    guest_enter() is called with IRQ disabled, call guest_enter_irqoff()
    instead.
    
    Fixes: 8b24e69fc47e ("KVM: PPC: Book3S HV: Close race with testing for signals on guest entry")
    Signed-off-by: Laurent Vivier <lvivier>
    Reviewed-by: Paolo Bonzini <pbonzini>
    Signed-off-by: Paul Mackerras <paulus>

The one in kvmppc_run_core() :

@@ -2893,8 +2893,6 @@ static noinline void kvmppc_run_core(struct kvmppc_vcore *vc)
 
        srcu_read_unlock(&vc->kvm->srcu, srcu_idx);
 
-       guest_exit();
-
        trace_hardirqs_off();
        set_irq_happened(trap);
 
@@ -2937,6 +2935,7 @@ static noinline void kvmppc_run_core(struct kvmppc_vcore *vc)
        kvmppc_set_host_core(pcpu);
 
        local_irq_enable();
+       guest_exit();
 
        /* Let secondaries go back to the offline loop */
        for (i = 0; i < controlled_threads; ++i) {

Cc'ing Laurent for insights.

Hi, I've installed  4.18.0-343.el8.bz2009312.ppc64le (from https://brewweb.engineering.redhat.com/brew/taskinfo?taskID=40060043) on ppc host and all cpu time tests passed successfully with this version

I agree with comment #3, we need something like 

    commit 160457140187c5fb127b844e5a85f87f00a01b14
    Author: Wanpeng Li <wanpengli>
    Date:   Tue May 4 17:27:30 2021 -0700
    
        KVM: x86: Defer vtime accounting 'til after IRQ handling

for PPC.

(In reply to Greg Kurz from comment #7)
> Interesting. The supposedly faulty upstream commit
> 112665286d08c87e66d699e7cba43c1497ad165f
> kinda partially reverts a change from:
> 
> commit 61bd0f66ff92d5ce765ff9850fd3cbfec773c560 (tag: kvm-ppc-fixes-4.16-1)
> Author: Laurent Vivier <lvivier>
> Date:   Fri Mar 2 11:51:56 2018 +0100
> 
>     KVM: PPC: Book3S HV: Fix guest time accounting with
> VIRT_CPU_ACCOUNTING_GEN
>     
>     Since commit 8b24e69fc47e ("KVM: PPC: Book3S HV: Close race with testing
>     for signals on guest entry"), if CONFIG_VIRT_CPU_ACCOUNTING_GEN is set,
> the
>     guest time is not accounted to guest time and user time, but instead to
>     system time.
>     
>     This is because guest_enter()/guest_exit() are called while interrupts
>     are disabled and the tick counter cannot be updated between them.
>     
>     To fix that, move guest_exit() after local_irq_enable(), and as
>     guest_enter() is called with IRQ disabled, call guest_enter_irqoff()
>     instead.
>     
>     Fixes: 8b24e69fc47e ("KVM: PPC: Book3S HV: Close race with testing for
> signals on guest entry")
>     Signed-off-by: Laurent Vivier <lvivier>
>     Reviewed-by: Paolo Bonzini <pbonzini>
>     Signed-off-by: Paul Mackerras <paulus>
> 


For reference: this was a fix for BZ 1541614

Created attachment 1829629 [details]
Patch to defer vtime accounting 'til after IRQ handling

Reproduced this bug with kernel-4.18.0-345.1.el8.ppc64le,got higher system time when guest is idle.

cat /sys/fs/cgroup/cpuacct/machine.slice/machine-qemu\\x2d1\\x2dvm.scope/cpuacct.stat
user 94
system 8296

Newly added the test case. Updating the polarion id to this bug. Thanks.

Reproduced the similar issue on 
kernel-4.18.0-348.6.el8.ppc64le
qemu-kvm-6.1.0-4.module+el8.6.0+13039+4b81a1dc.ppc64le

The guest is idle for about 5 minutes
[root@ibm-p9wr-05 home]# cat /sys/fs/cgroup/cpuacct/machine.slice/machine-qemu\\x2d1\\x2davocado\\x2dvt\\x2dvm1.scope/cpuacct.stat && virsh -r domstats avocado-vt-vm1|grep -w cpu
user 231
system 17019  ******
  cpu.time=158381637324
  cpu.user=2310000000
  cpu.system=170190000000
  cpu.cache.monitor.count=0
  cpu.haltpoll.success.time=38516
  cpu.haltpoll.fail.time=391206

Verified the issue on 
kernel-4.18.0-348.6.el8.mr1627_211109_0950.ppc64le (comment23)
qemu-kvm-6.1.0-4.module+el8.6.0+13039+4b81a1dc.ppc64le
[root@ibm-p9wr-05 tmp]# cat /sys/fs/cgroup/cpuacct/machine.slice/machine-qemu\\x2d1\\x2davocado\\x2dvt\\x2dvm1.scope/cpuacct.stat && virsh -r domstats avocado-vt-vm1|grep -w cpu
user 119
system 425  *****
  cpu.time=131242080472
  cpu.user=1190000000
  cpu.system=4250000000
  cpu.cache.monitor.count=0
  cpu.haltpoll.success.time=0
  cpu.haltpoll.fail.time=71692

Hi Laurent,

Could you please have a look on my test result, thanks a lot.

Best regards
Min

(In reply to Min Deng from comment #24)
> Reproduced the similar issue on 
> kernel-4.18.0-348.6.el8.ppc64le
> qemu-kvm-6.1.0-4.module+el8.6.0+13039+4b81a1dc.ppc64le
> 
> The guest is idle for about 5 minutes
> [root@ibm-p9wr-05 home]# cat
> /sys/fs/cgroup/cpuacct/machine.slice/machine-
> qemu\\x2d1\\x2davocado\\x2dvt\\x2dvm1.scope/cpuacct.stat && virsh -r
> domstats avocado-vt-vm1|grep -w cpu
> user 231
> system 17019  ******
>   cpu.time=158381637324
>   cpu.user=2310000000
>   cpu.system=170190000000
>   cpu.cache.monitor.count=0
>   cpu.haltpoll.success.time=38516
>   cpu.haltpoll.fail.time=391206
> 
> Verified the issue on 
> kernel-4.18.0-348.6.el8.mr1627_211109_0950.ppc64le (comment23)
> qemu-kvm-6.1.0-4.module+el8.6.0+13039+4b81a1dc.ppc64le
> [root@ibm-p9wr-05 tmp]# cat
> /sys/fs/cgroup/cpuacct/machine.slice/machine-
> qemu\\x2d1\\x2davocado\\x2dvt\\x2dvm1.scope/cpuacct.stat && virsh -r
> domstats avocado-vt-vm1|grep -w cpu
> user 119
> system 425  *****
>   cpu.time=131242080472
>   cpu.user=1190000000
>   cpu.system=4250000000
>   cpu.cache.monitor.count=0
>   cpu.haltpoll.success.time=0
>   cpu.haltpoll.fail.time=71692
> 
> Hi Laurent,
> 
> Could you please have a look on my test result, thanks a lot.
> 


I'm not used to libvirt stats, to check that bugfix I used "mpstat" (package sysstat) to check that guest cpu time is accounted to "%guest" columns and not to "%sys" columns.

But your result seems ok as in the first case your system time is "17019" and in second case it is only "425" so we can guess the difference has been accounted to guest time.

Verified the bug with build 
qemu-kvm-6.2.0-1.rc1.scrmod+el8.6.0+13325+d4e3491c.wrb21117.ppc64le
kernel-4.18.0-352.el8.ppc64le
The guest is idle.
[root@ibm-p9b-25 home]# cat /sys/fs/cgroup/cpuacct/machine.slice/machine-qemu\\x2d1\\x2davocado\\x2dvt\\x2dvm1.scope/cpuacct.stat && virsh -r domstats avocado-vt-vm1|grep -w cpu
user 259
system 1068
  cpu.time=164806434900
  cpu.user=2590000000
  cpu.system=10680000000
  cpu.cache.monitor.count=0
  cpu.haltpoll.success.time=25141
  cpu.haltpoll.fail.time=959580

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (Important: kernel security, bug fix, and enhancement update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHSA-2022:1988