Failure in iotest 183

[Thomas Huth]

 Hi!

I've just hit a failure in iotest 183:

--- /home/thuth/devel/qemu/tests/qemu-iotests/183.out
+++ /home/thuth/tmp/qemu-build/tests/qemu-iotests/scratch/183/183.out.bad
@@ -30,7 +30,7 @@
        'arguments': { 'uri': 'unix:SOCK_DIR/migrate', 'blk': true } }
 {"return": {}}
 { 'execute': 'query-status' }
-{"return": {"status": "postmigrate", "singlestep": false, "running": false}}
+{"return": {"status": "completed", "setup-time": 0, "downtime": 2448, "total-time": 2872, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, 
"pages-per-second": 0, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 188.63209192200557, "transferred": 496829, "precopy-bytes": 496829, "duplicate": 32849, "dirty-pages-rate": 0, 
"skipped": 0, "normal-bytes": 200704, "normal": 49}}}

 === Do some I/O on the destination ===

@@ -53,8 +53,31 @@
 === Shut down and check image ===

 {"execute":"quit"}
+{"return": {"status": "completed", "setup-time": 0, "downtime": 2448, "total-time": 2872, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, 
"pages-per-second": 0, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 188.63209192200557, "transferred": 496829, "precopy-bytes": 496829, "duplicate": 32849, "dirty-pages-rate": 0, 
"skipped": 0, "normal-bytes": 200704, "normal": 49}}}
+{"execute":"quit"}
 {"return": {}}
-{"execute":"quit"}
+{"return": {"status": "completed", "setup-time": 0, "downtime": 2448, "total-time": 2872, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, 
"pages-per-second": 0, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 188.63209192200557, "transferred": 496829, "precopy-bytes": 496829, "duplicate": 32849, "dirty-pages-rate": 0, 
"skipped": 0, "normal-bytes": 200704, "normal": 49}}}
+{"return": {"status": "completed", "setup-time": 0, "downtime": 2448, "total-time": 2872, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, 
"pages-per-second": 0, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 188.63209192200557, "transferred": 496829, "precopy-bytes": 496829, "duplicate": 32849, "dirty-pages-rate": 0, 
"skipped": 0, "normal-bytes": 200704, "normal": 49}}}
+{"return": {"status": "completed", "setup-time": 0, "downtime": 2448, "total-time": 2872, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, 
"pages-per-second": 0, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 188.63209192200557, "transferred": 496829, "precopy-bytes": 496829, "duplicate": 32849, "dirty-pages-rate": 0, 
"skipped": 0, "normal-bytes": 200704, "normal": 49}}}
+{"return": {"status": "completed", "setup-time": 0, "downtime": 2448, "total-time": 2872, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, 
"pages-per-second": 0, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 188.63209192200557, "transferred": 496829, "precopy-bytes": 496829, "duplicate": 32849, "dirty-pages-rate": 0, 
"skipped": 0, "normal-bytes": 200704, "normal": 49}}}
+{"return": {"status": "completed", "setup-time": 0, "downtime": 2448, "total-time": 2872, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, 
"pages-per-second": 0, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 188.63209192200557, "transferred": 496829, "precopy-bytes": 496829, "duplicate": 32849, "dirty-pages-rate": 0, 
"skipped": 0, "normal-bytes": 200704, "normal": 49}}}
+{"return": {"status": "completed", "setup-time": 0, "downtime": 2448, "total-time": 2872, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, 
"pages-per-second": 0, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 188.63209192200557, "transferred": 496829, "precopy-bytes": 496829, "duplicate": 32849, "dirty-pages-rate": 0, 
"skipped": 0, "normal-bytes": 200704, "normal": 49}}}
+{"return": {"status": "completed", "setup-time": 0, "downtime": 2448, "total-time": 2872, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, 
"pages-per-second": 0, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 188.63209192200557, "transferred": 496829, "precopy-bytes": 496829, "duplicate": 32849, "dirty-pages-rate": 0, 
"skipped": 0, "normal-bytes": 200704, "normal": 49}}}
+{"return": {"status": "completed", "setup-time": 0, "downtime": 2448, "total-time": 2872, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, 
"pages-per-second": 0, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 188.63209192200557, "transferred": 496829, "precopy-bytes": 496829, "duplicate": 32849, "dirty-pages-rate": 0, 
"skipped": 0, "normal-bytes": 200704, "normal": 49}}}
+{"return": {"status": "completed", "setup-time": 0, "downtime": 2448, "total-time": 2872, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, 
"pages-per-second": 0, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 188.63209192200557, "transferred": 496829, "precopy-bytes": 496829, "duplicate": 32849, "dirty-pages-rate": 0, 
"skipped": 0, "normal-bytes": 200704, "normal": 49}}}
+{"return": {"status": "completed", "setup-time": 0, "downtime": 2448, "total-time": 2872, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, 
"pages-per-second": 0, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 188.63209192200557, "transferred": 496829, "precopy-bytes": 496829, "duplicate": 32849, "dirty-pages-rate": 0, 
"skipped": 0, "normal-bytes": 200704, "normal": 49}}}
+{"return": {"status": "completed", "setup-time": 0, "downtime": 2448, "total-time": 2872, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, 
"pages-per-second": 0, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 188.63209192200557, "transferred": 496829, "precopy-bytes": 496829, "duplicate": 32849, "dirty-pages-rate": 0, 
"skipped": 0, "normal-bytes": 200704, "normal": 49}}}
+{"return": {"status": "completed", "setup-time": 0, "downtime": 2448, "total-time": 2872, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, 
"pages-per-second": 0, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 188.63209192200557, "transferred": 496829, "precopy-bytes": 496829, "duplicate": 32849, "dirty-pages-rate": 0, 
"skipped": 0, "normal-bytes": 200704, "normal": 49}}}
+{"return": {"status": "completed", "setup-time": 0, "downtime": 2448, "total-time": 2872, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, 
"pages-per-second": 0, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 188.63209192200557, "transferred": 496829, "precopy-bytes": 496829, "duplicate": 32849, "dirty-pages-rate": 0, 
"skipped": 0, "normal-bytes": 200704, "normal": 49}}}
+{"return": {"status": "completed", "setup-time": 0, "downtime": 2448, "total-time": 2872, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, 
"pages-per-second": 0, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 188.63209192200557, "transferred": 496829, "precopy-bytes": 496829, "duplicate": 32849, "dirty-pages-rate": 0, 
"skipped": 0, "normal-bytes": 200704, "normal": 49}}}
+{"return": {"status": "completed", "setup-time": 0, "downtime": 2448, "total-time": 2872, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, 
"pages-per-second": 0, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 188.63209192200557, "transferred": 496829, "precopy-bytes": 496829, "duplicate": 32849, "dirty-pages-rate": 0, 
"skipped": 0, "normal-bytes": 200704, "normal": 49}}}
+{"return": {"status": "completed", "setup-time": 0, "downtime": 2448, "total-time": 2872, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, 
"pages-per-second": 0, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 188.63209192200557, "transferred": 496829, "precopy-bytes": 496829, "duplicate": 32849, "dirty-pages-rate": 0, 
"skipped": 0, "normal-bytes": 200704, "normal": 49}}}
+{"return": {"status": "completed", "setup-time": 0, "downtime": 2448, "total-time": 2872, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, 
"pages-per-second": 0, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 188.63209192200557, "transferred": 496829, "precopy-bytes": 496829, "duplicate": 32849, "dirty-pages-rate": 0, 
"skipped": 0, "normal-bytes": 200704, "normal": 49}}}
+{"return": {"status": "completed", "setup-time": 0, "downtime": 2448, "total-time": 2872, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, 
"pages-per-second": 0, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 188.63209192200557, "transferred": 496829, "precopy-bytes": 496829, "duplicate": 32849, "dirty-pages-rate": 0, 
"skipped": 0, "normal-bytes": 200704, "normal": 49}}}
+{"return": {"status": "completed", "setup-time": 0, "downtime": 2448, "total-time": 2872, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, 
"pages-per-second": 0, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 188.63209192200557, "transferred": 496829, "precopy-bytes": 496829, "duplicate": 32849, "dirty-pages-rate": 0, 
"skipped": 0, "normal-bytes": 200704, "normal": 49}}}
+{"return": {"status": "completed", "setup-time": 0, "downtime": 2448, "total-time": 2872, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, 
"pages-per-second": 0, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 188.63209192200557, "transferred": 496829, "precopy-bytes": 496829, "duplicate": 32849, "dirty-pages-rate": 0, 
"skipped": 0, "normal-bytes": 200704, "normal": 49}}}
+{"return": {"status": "completed", "setup-time": 0, "downtime": 2448, "total-time": 2872, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, 
"pages-per-second": 0, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 188.63209192200557, "transferred": 496829, "precopy-bytes": 496829, "duplicate": 32849, "dirty-pages-rate": 0, 
"skipped": 0, "normal-bytes": 200704, "normal": 49}}}
+{"return": {"status": "postmigrate", "singlestep": false, "running": false}}
 {"return": {}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "SHUTDOWN", "data": 
{"guest": false, "reason": "host-qmp-quit"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "SHUTDOWN", "data": 
{"guest": false, "reason": "host-qmp-quit"}}

Is that a known problem already? (I haven't seen anything
related on the list)

 Thomas