Re: [PATCH v2 14/22] qemu-iotests/199: better catch postcopy time
19.02.2020 16:16, Andrey Shinkevich wrote:
On 17/02/2020 18:02, Vladimir Sementsov-Ogievskiy wrote:
The test aims to test _postcopy_ migration, and wants to do some write
operations during postcopy time.
Test considers migrate status=complete event on source as start of
postcopy. This is completely wrong, completion is completion of the
whole migration process. Let's instead consider destination start as
start of postcopy, and use RESUME event for it.
Next, as migration finish, let's use migration status=complete event on
target, as such method is closer to what libvirt or another user will
do, than tracking number of dirty-bitmaps.
Finally, add a possibility to dump events for debug. And if
set debug to True, we see, that actual postcopy period is very small
relatively to the whole test duration time (~0.2 seconds to >40 seconds
for me). This means, that test is very inefficient in what it supposed
to do. Let's improve it in following commits.
Signed-off-by: Vladimir Sementsov-Ogievskiy
---
tests/qemu-iotests/199 | 72 +-
1 file changed, 57 insertions(+), 15 deletions(-)
diff --git a/tests/qemu-iotests/199 b/tests/qemu-iotests/199
index dda918450a..6599fc6fb4 100755
--- a/tests/qemu-iotests/199
+++ b/tests/qemu-iotests/199
@@ -20,17 +20,43 @@
import os
import iotests
-import time
from iotests import qemu_img
+debug = False
+
disk_a = os.path.join(iotests.test_dir, 'disk_a')
disk_b = os.path.join(iotests.test_dir, 'disk_b')
size = '256G'
fifo = os.path.join(iotests.test_dir, 'mig_fifo')
+def event_seconds(event):
+ return event['timestamp']['seconds'] + \
+ event['timestamp']['microseconds'] / 100.0
+
+
+def event_dist(e1, e2):
+ return event_seconds(e2) - event_seconds(e1)
+
+
class TestDirtyBitmapPostcopyMigration(iotests.QMPTestCase):
def tearDown(self):
It's common to put the definition of setUp() ahead
Preexisting, I don't want to update it in this patch
+ if debug:
+ self.vm_a_events += self.vm_a.get_qmp_events()
+ self.vm_b_events += self.vm_b.get_qmp_events()
+ for e in self.vm_a_events:
+ e['vm'] = 'SRC'
+ for e in self.vm_b_events:
+ e['vm'] = 'DST'
+ events = (self.vm_a_events + self.vm_b_events)
+ events = [(e['timestamp']['seconds'],
+ e['timestamp']['microseconds'],
+ e['vm'],
+ e['event'],
+ e.get('data', '')) for e in events]
+ for e in sorted(events):
+ print('{}.{:06} {} {} {}'.format(*e))
+
self.vm_a.shutdown()
self.vm_b.shutdown()
os.remove(disk_a)
@@ -47,6 +73,10 @@ class TestDirtyBitmapPostcopyMigration(iotests.QMPTestCase):
self.vm_a.launch()
self.vm_b.launch()
+ # collect received events for debug
+ self.vm_a_events = []
+ self.vm_b_events = []
+
def test_postcopy(self):
write_size = 0x4000
granularity = 512
@@ -77,15 +107,13 @@ class
TestDirtyBitmapPostcopyMigration(iotests.QMPTestCase):
self.vm_a.hmp_qemu_io('drive0', 'write %d %d' % (s, chunk))
s += 0x1
- bitmaps_cap = {'capability': 'dirty-bitmaps', 'state': True}
- events_cap = {'capability': 'events', 'state': True}
+ caps = [{'capability': 'dirty-bitmaps', 'state': True},
The name "capabilities" would be an appropriate identifier.
This will result in following lines growing and not fit into one line. I'll
leave
"caps". Also, they are called "caps" in iotest 169 and in migration.c. And here
in the
context always used together with full word ('capability': or capabilities=).
+ {'capability': 'events', 'state': True}]
- result = self.vm_a.qmp('migrate-set-capabilities',
- capabilities=[bitmaps_cap, events_cap])
+ result = self.vm_a.qmp('migrate-set-capabilities', capabilities=caps)
self.assert_qmp(result, 'return', {})
- result = self.vm_b.qmp('migrate-set-capabilities',
- capabilities=[bitmaps_cap])
+ result = self.vm_b.qmp('migrate-set-capabilities', capabilities=caps)
self.assert_qmp(result, 'return', {})
result = self.vm_a.qmp('migrate', uri='exec:cat>' + fifo)
@@ -94,24 +122,38 @@ class
TestDirtyBitmapPostcopyMigration(iotests.QMPTestCase):
result = self.vm_a.qmp('migrate-start-postcopy')
self.assert_qmp(result, 'return', {})
- while True:
- event = self.vm_a.event_wait('MIGRATION')
- if event['data']['status'] == 'completed':
- break
+ e_resume = self.vm_b.event_wait('RESUME')
"event_resume" gives a faster understanding
OK, no problem
+ self.vm_b_events.append(e_resume)
s = 0x8000
while s < write_size:
Re: [PATCH v2 14/22] qemu-iotests/199: better catch postcopy time
19.02.2020 16:16, Andrey Shinkevich wrote:
On 17/02/2020 18:02, Vladimir Sementsov-Ogievskiy wrote:
The test aims to test _postcopy_ migration, and wants to do some write
operations during postcopy time.
Test considers migrate status=complete event on source as start of
postcopy. This is completely wrong, completion is completion of the
whole migration process. Let's instead consider destination start as
start of postcopy, and use RESUME event for it.
Next, as migration finish, let's use migration status=complete event on
target, as such method is closer to what libvirt or another user will
do, than tracking number of dirty-bitmaps.
Finally, add a possibility to dump events for debug. And if
set debug to True, we see, that actual postcopy period is very small
relatively to the whole test duration time (~0.2 seconds to >40 seconds
for me). This means, that test is very inefficient in what it supposed
to do. Let's improve it in following commits.
Signed-off-by: Vladimir Sementsov-Ogievskiy
---
tests/qemu-iotests/199 | 72 +-
1 file changed, 57 insertions(+), 15 deletions(-)
diff --git a/tests/qemu-iotests/199 b/tests/qemu-iotests/199
index dda918450a..6599fc6fb4 100755
--- a/tests/qemu-iotests/199
+++ b/tests/qemu-iotests/199
@@ -20,17 +20,43 @@
import os
import iotests
-import time
from iotests import qemu_img
+debug = False
+
disk_a = os.path.join(iotests.test_dir, 'disk_a')
disk_b = os.path.join(iotests.test_dir, 'disk_b')
size = '256G'
fifo = os.path.join(iotests.test_dir, 'mig_fifo')
+def event_seconds(event):
+ return event['timestamp']['seconds'] + \
+ event['timestamp']['microseconds'] / 100.0
+
+
+def event_dist(e1, e2):
+ return event_seconds(e2) - event_seconds(e1)
+
+
class TestDirtyBitmapPostcopyMigration(iotests.QMPTestCase):
def tearDown(self):
It's common to put the definition of setUp() ahead
+ if debug:
+ self.vm_a_events += self.vm_a.get_qmp_events()
+ self.vm_b_events += self.vm_b.get_qmp_events()
+ for e in self.vm_a_events:
+ e['vm'] = 'SRC'
+ for e in self.vm_b_events:
+ e['vm'] = 'DST'
+ events = (self.vm_a_events + self.vm_b_events)
+ events = [(e['timestamp']['seconds'],
+ e['timestamp']['microseconds'],
+ e['vm'],
+ e['event'],
+ e.get('data', '')) for e in events]
+ for e in sorted(events):
+ print('{}.{:06} {} {} {}'.format(*e))
+
self.vm_a.shutdown()
self.vm_b.shutdown()
os.remove(disk_a)
@@ -47,6 +73,10 @@ class TestDirtyBitmapPostcopyMigration(iotests.QMPTestCase):
self.vm_a.launch()
self.vm_b.launch()
+ # collect received events for debug
+ self.vm_a_events = []
+ self.vm_b_events = []
+
def test_postcopy(self):
write_size = 0x4000
granularity = 512
@@ -77,15 +107,13 @@ class
TestDirtyBitmapPostcopyMigration(iotests.QMPTestCase):
self.vm_a.hmp_qemu_io('drive0', 'write %d %d' % (s, chunk))
s += 0x1
- bitmaps_cap = {'capability': 'dirty-bitmaps', 'state': True}
- events_cap = {'capability': 'events', 'state': True}
+ caps = [{'capability': 'dirty-bitmaps', 'state': True},
The name "capabilities" would be an appropriate identifier.
+ {'capability': 'events', 'state': True}]
- result = self.vm_a.qmp('migrate-set-capabilities',
- capabilities=[bitmaps_cap, events_cap])
+ result = self.vm_a.qmp('migrate-set-capabilities', capabilities=caps)
self.assert_qmp(result, 'return', {})
- result = self.vm_b.qmp('migrate-set-capabilities',
- capabilities=[bitmaps_cap])
+ result = self.vm_b.qmp('migrate-set-capabilities', capabilities=caps)
self.assert_qmp(result, 'return', {})
result = self.vm_a.qmp('migrate', uri='exec:cat>' + fifo)
@@ -94,24 +122,38 @@ class
TestDirtyBitmapPostcopyMigration(iotests.QMPTestCase):
result = self.vm_a.qmp('migrate-start-postcopy')
self.assert_qmp(result, 'return', {})
- while True:
- event = self.vm_a.event_wait('MIGRATION')
- if event['data']['status'] == 'completed':
- break
+ e_resume = self.vm_b.event_wait('RESUME')
"event_resume" gives a faster understanding
+ self.vm_b_events.append(e_resume)
s = 0x8000
while s < write_size:
self.vm_b.hmp_qemu_io('drive0', 'write %d %d' % (s, chunk))
s += 0x1
+ match = {'data': {'status': 'completed'}}
+ e_complete = self.vm_b.event_wait('MIGRATION', match=match)
"event_complete" also
+ self.vm_b_events.append(e_complete)
+
+ # take queued event, should already been
Re: [PATCH v2 14/22] qemu-iotests/199: better catch postcopy time
On 17/02/2020 18:02, Vladimir Sementsov-Ogievskiy wrote:
The test aims to test _postcopy_ migration, and wants to do some write
operations during postcopy time.
Test considers migrate status=complete event on source as start of
postcopy. This is completely wrong, completion is completion of the
whole migration process. Let's instead consider destination start as
start of postcopy, and use RESUME event for it.
Next, as migration finish, let's use migration status=complete event on
target, as such method is closer to what libvirt or another user will
do, than tracking number of dirty-bitmaps.
Finally, add a possibility to dump events for debug. And if
set debug to True, we see, that actual postcopy period is very small
relatively to the whole test duration time (~0.2 seconds to >40 seconds
for me). This means, that test is very inefficient in what it supposed
to do. Let's improve it in following commits.
Signed-off-by: Vladimir Sementsov-Ogievskiy
---
tests/qemu-iotests/199 | 72 +-
1 file changed, 57 insertions(+), 15 deletions(-)
diff --git a/tests/qemu-iotests/199 b/tests/qemu-iotests/199
index dda918450a..6599fc6fb4 100755
--- a/tests/qemu-iotests/199
+++ b/tests/qemu-iotests/199
@@ -20,17 +20,43 @@
import os
import iotests
-import time
from iotests import qemu_img
+debug = False
+
disk_a = os.path.join(iotests.test_dir, 'disk_a')
disk_b = os.path.join(iotests.test_dir, 'disk_b')
size = '256G'
fifo = os.path.join(iotests.test_dir, 'mig_fifo')
+def event_seconds(event):
+return event['timestamp']['seconds'] + \
+event['timestamp']['microseconds'] / 100.0
+
+
+def event_dist(e1, e2):
+return event_seconds(e2) - event_seconds(e1)
+
+
class TestDirtyBitmapPostcopyMigration(iotests.QMPTestCase):
def tearDown(self):
It's common to put the definition of setUp() ahead
+if debug:
+self.vm_a_events += self.vm_a.get_qmp_events()
+self.vm_b_events += self.vm_b.get_qmp_events()
+for e in self.vm_a_events:
+e['vm'] = 'SRC'
+for e in self.vm_b_events:
+e['vm'] = 'DST'
+events = (self.vm_a_events + self.vm_b_events)
+events = [(e['timestamp']['seconds'],
+ e['timestamp']['microseconds'],
+ e['vm'],
+ e['event'],
+ e.get('data', '')) for e in events]
+for e in sorted(events):
+print('{}.{:06} {} {} {}'.format(*e))
+
self.vm_a.shutdown()
self.vm_b.shutdown()
os.remove(disk_a)
@@ -47,6 +73,10 @@ class TestDirtyBitmapPostcopyMigration(iotests.QMPTestCase):
self.vm_a.launch()
self.vm_b.launch()
+# collect received events for debug
+self.vm_a_events = []
+self.vm_b_events = []
+
def test_postcopy(self):
write_size = 0x4000
granularity = 512
@@ -77,15 +107,13 @@ class
TestDirtyBitmapPostcopyMigration(iotests.QMPTestCase):
self.vm_a.hmp_qemu_io('drive0', 'write %d %d' % (s, chunk))
s += 0x1
-bitmaps_cap = {'capability': 'dirty-bitmaps', 'state': True}
-events_cap = {'capability': 'events', 'state': True}
+caps = [{'capability': 'dirty-bitmaps', 'state': True},
The name "capabilities" would be an appropriate identifier.
+{'capability': 'events', 'state': True}]
-result = self.vm_a.qmp('migrate-set-capabilities',
- capabilities=[bitmaps_cap, events_cap])
+result = self.vm_a.qmp('migrate-set-capabilities', capabilities=caps)
self.assert_qmp(result, 'return', {})
-result = self.vm_b.qmp('migrate-set-capabilities',
- capabilities=[bitmaps_cap])
+result = self.vm_b.qmp('migrate-set-capabilities', capabilities=caps)
self.assert_qmp(result, 'return', {})
result = self.vm_a.qmp('migrate', uri='exec:cat>' + fifo)
@@ -94,24 +122,38 @@ class
TestDirtyBitmapPostcopyMigration(iotests.QMPTestCase):
result = self.vm_a.qmp('migrate-start-postcopy')
self.assert_qmp(result, 'return', {})
-while True:
-event = self.vm_a.event_wait('MIGRATION')
-if event['data']['status'] == 'completed':
-break
+e_resume = self.vm_b.event_wait('RESUME')
"event_resume" gives a faster understanding
+self.vm_b_events.append(e_resume)
s = 0x8000
while s < write_size:
self.vm_b.hmp_qemu_io('drive0', 'write %d %d' % (s, chunk))
s += 0x1
+match = {'data': {'status': 'completed'}}
+e_complete = self.vm_b.event_wait('MIGRATION', match=match)
"event_complete" also
+self.vm_b_events.append(e_complete)
+
+# take queued event, should already
[PATCH v2 14/22] qemu-iotests/199: better catch postcopy time
The test aims to test _postcopy_ migration, and wants to do some write
operations during postcopy time.
Test considers migrate status=complete event on source as start of
postcopy. This is completely wrong, completion is completion of the
whole migration process. Let's instead consider destination start as
start of postcopy, and use RESUME event for it.
Next, as migration finish, let's use migration status=complete event on
target, as such method is closer to what libvirt or another user will
do, than tracking number of dirty-bitmaps.
Finally, add a possibility to dump events for debug. And if
set debug to True, we see, that actual postcopy period is very small
relatively to the whole test duration time (~0.2 seconds to >40 seconds
for me). This means, that test is very inefficient in what it supposed
to do. Let's improve it in following commits.
Signed-off-by: Vladimir Sementsov-Ogievskiy
---
tests/qemu-iotests/199 | 72 +-
1 file changed, 57 insertions(+), 15 deletions(-)
diff --git a/tests/qemu-iotests/199 b/tests/qemu-iotests/199
index dda918450a..6599fc6fb4 100755
--- a/tests/qemu-iotests/199
+++ b/tests/qemu-iotests/199
@@ -20,17 +20,43 @@
import os
import iotests
-import time
from iotests import qemu_img
+debug = False
+
disk_a = os.path.join(iotests.test_dir, 'disk_a')
disk_b = os.path.join(iotests.test_dir, 'disk_b')
size = '256G'
fifo = os.path.join(iotests.test_dir, 'mig_fifo')
+def event_seconds(event):
+return event['timestamp']['seconds'] + \
+event['timestamp']['microseconds'] / 100.0
+
+
+def event_dist(e1, e2):
+return event_seconds(e2) - event_seconds(e1)
+
+
class TestDirtyBitmapPostcopyMigration(iotests.QMPTestCase):
def tearDown(self):
+if debug:
+self.vm_a_events += self.vm_a.get_qmp_events()
+self.vm_b_events += self.vm_b.get_qmp_events()
+for e in self.vm_a_events:
+e['vm'] = 'SRC'
+for e in self.vm_b_events:
+e['vm'] = 'DST'
+events = (self.vm_a_events + self.vm_b_events)
+events = [(e['timestamp']['seconds'],
+ e['timestamp']['microseconds'],
+ e['vm'],
+ e['event'],
+ e.get('data', '')) for e in events]
+for e in sorted(events):
+print('{}.{:06} {} {} {}'.format(*e))
+
self.vm_a.shutdown()
self.vm_b.shutdown()
os.remove(disk_a)
@@ -47,6 +73,10 @@ class TestDirtyBitmapPostcopyMigration(iotests.QMPTestCase):
self.vm_a.launch()
self.vm_b.launch()
+# collect received events for debug
+self.vm_a_events = []
+self.vm_b_events = []
+
def test_postcopy(self):
write_size = 0x4000
granularity = 512
@@ -77,15 +107,13 @@ class
TestDirtyBitmapPostcopyMigration(iotests.QMPTestCase):
self.vm_a.hmp_qemu_io('drive0', 'write %d %d' % (s, chunk))
s += 0x1
-bitmaps_cap = {'capability': 'dirty-bitmaps', 'state': True}
-events_cap = {'capability': 'events', 'state': True}
+caps = [{'capability': 'dirty-bitmaps', 'state': True},
+{'capability': 'events', 'state': True}]
-result = self.vm_a.qmp('migrate-set-capabilities',
- capabilities=[bitmaps_cap, events_cap])
+result = self.vm_a.qmp('migrate-set-capabilities', capabilities=caps)
self.assert_qmp(result, 'return', {})
-result = self.vm_b.qmp('migrate-set-capabilities',
- capabilities=[bitmaps_cap])
+result = self.vm_b.qmp('migrate-set-capabilities', capabilities=caps)
self.assert_qmp(result, 'return', {})
result = self.vm_a.qmp('migrate', uri='exec:cat>' + fifo)
@@ -94,24 +122,38 @@ class
TestDirtyBitmapPostcopyMigration(iotests.QMPTestCase):
result = self.vm_a.qmp('migrate-start-postcopy')
self.assert_qmp(result, 'return', {})
-while True:
-event = self.vm_a.event_wait('MIGRATION')
-if event['data']['status'] == 'completed':
-break
+e_resume = self.vm_b.event_wait('RESUME')
+self.vm_b_events.append(e_resume)
s = 0x8000
while s < write_size:
self.vm_b.hmp_qemu_io('drive0', 'write %d %d' % (s, chunk))
s += 0x1
+match = {'data': {'status': 'completed'}}
+e_complete = self.vm_b.event_wait('MIGRATION', match=match)
+self.vm_b_events.append(e_complete)
+
+# take queued event, should already been happened
+e_stop = self.vm_a.event_wait('STOP')
+self.vm_a_events.append(e_stop)
+
+downtime = event_dist(e_stop, e_resume)
+postcopy_time = event_dist(e_resume, e_complete)
+
+# TODO: assert downtime * 10 < postcopy_time
+if debug:
+
