Re: [PATCH RFC 00/15] KVM: Dirty ring interface

From: Peter Xu
Date: Thu Dec 05 2019 - 14:31:04 EST

On Tue, Dec 03, 2019 at 02:59:14PM +0100, Paolo Bonzini wrote:
> On 02/12/19 03:13, Peter Xu wrote:
> >> This is not needed, it will just be a false negative (dirty page that
> >> actually isn't dirty). The dirty bit will be cleared when userspace
> >> resets the ring buffer; then the instruction will be executed again and
> >> mark the page dirty again. Since ring full is not a common condition,
> >> it's not a big deal.
> >
> > Actually I added this only because it failed one of the unit tests
> > when verifying the dirty bits.. But now after a second thought, I
> > probably agree with you that we can change the userspace too to fix
> > this.
>
> I think there is already a similar case in dirty_log_test when a page is
> dirty but we called KVM_GET_DIRTY_LOG just before it got written to.

If you mean the host_bmap_track (in dirty_log_test.c), that should be
a reversed version of this race (that's where the data is written,
while we didn't see the dirty bit set). But yes I think I can
probably use the same bitmap to fix the test case, because in both
cases what we want to do is to make sure "the dirty bit of this page
should be set in next round".

>
> > I think the steps of the failed test case could be simplified into
> > something like this (assuming the QEMU migration context, might be
> > easier to understand):
> >
> > 1. page P has data P1
> > 2. vcpu writes to page P, with date P2
> > 3. vmexit (P is still with data P1)
> > 4. mark P as dirty, ring full, user exit
> > 5. collect dirty bit P, migrate P with data P1
> > 6. vcpu run due to some reason, P was written with P2, user exit again
> > (because ring is already reaching soft limit)
> > 7. do KVM_RESET_DIRTY_RINGS
>
> Migration should only be done after KVM_RESET_DIRTY_RINGS (think of
> KVM_RESET_DIRTY_RINGS as the equivalent of KVM_CLEAR_DIRTY_LOG).

Totally agree for migration. It's probably just that the test case
needs fixing.

>
> > dirty_log_test-29003 [001] 184503.384328: kvm_entry: vcpu 1
> > dirty_log_test-29003 [001] 184503.384329: kvm_exit: reason EPT_VIOLATION rip 0x40359f info 582 0
> > dirty_log_test-29003 [001] 184503.384329: kvm_page_fault: address 7fc036d000 error_code 582
> > dirty_log_test-29003 [001] 184503.384331: kvm_entry: vcpu 1
> > dirty_log_test-29003 [001] 184503.384332: kvm_exit: reason EPT_VIOLATION rip 0x40359f info 582 0
> > dirty_log_test-29003 [001] 184503.384332: kvm_page_fault: address 7fc036d000 error_code 582
> > dirty_log_test-29003 [001] 184503.384332: kvm_dirty_ring_push: ring 1: dirty 0x37f reset 0x1c0 slot 1 offset 0x37e ret 0 (used 447)
> > dirty_log_test-29003 [001] 184503.384333: kvm_entry: vcpu 1
> > dirty_log_test-29003 [001] 184503.384334: kvm_exit: reason EPT_VIOLATION rip 0x40359f info 582 0
> > dirty_log_test-29003 [001] 184503.384334: kvm_page_fault: address 7fc036e000 error_code 582
> > dirty_log_test-29003 [001] 184503.384336: kvm_entry: vcpu 1
> > dirty_log_test-29003 [001] 184503.384336: kvm_exit: reason EPT_VIOLATION rip 0x40359f info 582 0
> > dirty_log_test-29003 [001] 184503.384336: kvm_page_fault: address 7fc036e000 error_code 582
> > dirty_log_test-29003 [001] 184503.384337: kvm_dirty_ring_push: ring 1: dirty 0x380 reset 0x1c0 slot 1 offset 0x37f ret 1 (used 448)
> > dirty_log_test-29003 [001] 184503.384337: kvm_dirty_ring_exit: vcpu 1
> > dirty_log_test-29003 [001] 184503.384338: kvm_fpu: unload
> > dirty_log_test-29003 [001] 184503.384340: kvm_userspace_exit: reason 0x1d (29)
> > dirty_log_test-29000 [006] 184503.505103: kvm_dirty_ring_reset: ring 1: dirty 0x380 reset 0x380 (used 0)
> > dirty_log_test-29003 [001] 184503.505184: kvm_fpu: load
> > dirty_log_test-29003 [001] 184503.505187: kvm_entry: vcpu 1
> > dirty_log_test-29003 [001] 184503.505193: kvm_exit: reason EPT_VIOLATION rip 0x40359f info 582 0
> > dirty_log_test-29003 [001] 184503.505194: kvm_page_fault: address 7fc036f000 error_code 582 <-------- [1]
> > dirty_log_test-29003 [001] 184503.505206: kvm_entry: vcpu 1
> > dirty_log_test-29003 [001] 184503.505207: kvm_exit: reason EPT_VIOLATION rip 0x40359f info 582 0
> > dirty_log_test-29003 [001] 184503.505207: kvm_page_fault: address 7fc036f000 error_code 582
> > dirty_log_test-29003 [001] 184503.505226: kvm_dirty_ring_push: ring 1: dirty 0x381 reset 0x380 slot 1 offset 0x380 ret 0 (used 1)
> > dirty_log_test-29003 [001] 184503.505226: kvm_entry: vcpu 1
> > dirty_log_test-29003 [001] 184503.505227: kvm_exit: reason EPT_VIOLATION rip 0x40359f info 582 0
> > dirty_log_test-29003 [001] 184503.505228: kvm_page_fault: address 7fc0370000 error_code 582
> > dirty_log_test-29003 [001] 184503.505231: kvm_entry: vcpu 1
> > ...
> >
> > The test was trying to continuously write to pages, from above log
> > starting from 7fc036d000. The reason 0x1d (29) is the new dirty ring
> > full exit reason.
> >
> > So far I'm still unsure of two things:
> >
> > 1. Why for each page we faulted twice rather than once. Take the
> > example of page at 7fc036e000 above, the first fault didn't
> > trigger the marking dirty path, while only until the 2nd ept
> > violation did we trigger kvm_dirty_ring_push.
>
> Not sure about that. Try enabling kvmmmu tracepoints too, it will tell
> you more of the path that was taken while processing the EPT violation.

These new tracepoints are extremely useful (which I didn't notice
before).

So here's the final culprit...

void kvm_reset_dirty_gfn(struct kvm *kvm, u32 slot, u64 offset, u64 mask)
{
...
spin_lock(&kvm->mmu_lock);
/* FIXME: we should use a single AND operation, but there is no
* applicable atomic API.
*/
while (mask) {
clear_bit_le(offset + __ffs(mask), memslot->dirty_bitmap);
mask &= mask - 1;
}

kvm_arch_mmu_enable_log_dirty_pt_masked(kvm, memslot, offset, mask);
spin_unlock(&kvm->mmu_lock);
}

The mask is cleared before reaching
kvm_arch_mmu_enable_log_dirty_pt_masked()..

The funny thing is that I did have a few more patches to even skip
allocate the dirty_bitmap when dirty ring is enabled (hence in that
tree I removed this while loop too, so that has no such problem).
However I dropped those patches when I posted the RFC because I don't
think it's mature, and the selftest didn't complain about that
either.. Though, I do plan to redo that in v2 if you don't disagree.
The major question would be whether the dirty_bitmap could still be
for any use if dirty ring is enabled.

>
> If your machine has PML, what you're seeing is likely not-present
> violation, not dirty-protect violation. Try disabling pml and see if
> the trace changes.
>
> > 2. Why we didn't get the last page written again after
> > kvm_userspace_exit (last page was 7fc036e000, and the test failed
> > because 7fc036e000 detected change however dirty bit unset). In
> > this case the first write after KVM_RESET_DIRTY_RINGS is the line
> > pointed by [1], I thought it should be a rewritten of page
> > 7fc036e000 because when the user exit happens logically the write
> > should not happen yet and eip should keep. However at [1] it's
> > already writting to a new page.
>
> IIUC you should get, with PML enabled:
>
> - guest writes to page
> - PML marks dirty bit, causes vmexit
> - host copies PML log to ring, causes userspace exit
> - userspace calls KVM_RESET_DIRTY_RINGS
> - host marks page as clean
> - userspace calls KVM_RUN
> - guest writes again to page
>
> but the page won't be in the ring until after another vmexit happens.
> Therefore, it's okay to reap the pages in the ring asynchronously, but
> there must be a synchronization point in the testcase sooner or later,
> where all CPUs are kicked out of KVM_RUN. This synchronization point
> corresponds to the migration downtime.

Yep, currently in the test case I used the same signal trick to kick
the vcpu out to make sure PML buffers are flushed during the vmexit,
before the main thread starts to collect dirty bits.

Thanks,

--
Peter Xu