| Message ID | f629134d-0ce2-46df-13b5-30b735f6bd3d@redhat.com (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
| Series | Failure in iotest 183 | expand |
On 05.07.22 11:35, Thomas Huth wrote: > > 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}}} Weird because query-status cannot return something with '"status": "completed"' in it. We can see the '"status": "postmigrate"' object somewhere below, so it seems to me like the silent=yes part for the query-migrate execution didn’t work as intended. (And it does seem to work below, when waiting for a “100 %” to appear on $dest.) It’s been a while since we’ve touched common.qemu, so nothing comes to my mind immediately that might have broken this. > > === 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) I’ve never hit this so far. The only things to try I can come up with would be to bisect, or to try adding `silent=$silent` to the `_timed_wait_for` calls in `send_qemu_cmd`... Hanna
On 05/07/2022 11.58, Hanna Reitz wrote: > On 05.07.22 11:35, Thomas Huth wrote: >> >> 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}}} > > Weird because query-status cannot return something with '"status": > "completed"' in it. We can see the '"status": "postmigrate"' object > somewhere below, so it seems to me like the silent=yes part for the > query-migrate execution didn’t work as intended. > > (And it does seem to work below, when waiting for a “100 %” to appear on > $dest.) > > It’s been a while since we’ve touched common.qemu, so nothing comes to my > mind immediately that might have broken this. ... > I’ve never hit this so far. > > The only things to try I can come up with would be to bisect, or to try > adding `silent=$silent` to the `_timed_wait_for` calls in `send_qemu_cmd`... Seems also like it does not reproduce that easily, though - I've just seen it once so far while running "make -j6 check SPEED=slow", so lots of other stuff was happening at the same time. I'll keep an eye on it to see whether I can reproduce it more easily somehow. Thomas
On 05/07/2022 12.20, Thomas Huth wrote: > On 05/07/2022 11.58, Hanna Reitz wrote: >> On 05.07.22 11:35, Thomas Huth wrote: >>> >>> 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}}} >> >> Weird because query-status cannot return something with '"status": >> "completed"' in it. We can see the '"status": "postmigrate"' object >> somewhere below, so it seems to me like the silent=yes part for the >> query-migrate execution didn’t work as intended. >> >> (And it does seem to work below, when waiting for a “100 %” to appear on >> $dest.) >> >> It’s been a while since we’ve touched common.qemu, so nothing comes to my >> mind immediately that might have broken this. > ... >> I’ve never hit this so far. >> >> The only things to try I can come up with would be to bisect, or to try >> adding `silent=$silent` to the `_timed_wait_for` calls in `send_qemu_cmd`... > > Seems also like it does not reproduce that easily, though - I've just seen > it once so far while running "make -j6 check SPEED=slow", so lots of other > stuff was happening at the same time. I'll keep an eye on it to see whether > I can reproduce it more easily somehow. I just reproduced it by running "./check -raw -j8" directly: --- /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": 1003, "total-time": 1537, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, "pages-per-second": 288578, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 352.48204554326611, "transferred": 497205, "precopy-bytes": 497205, "duplicate": 32849, "dirty-pages-rate": 0, "skipped": 0, "normal-bytes": 200704, "normal": 49}}} === Do some I/O on the destination === @@ -53,8 +53,16 @@ === Shut down and check image === {"execute":"quit"} +{"return": {"status": "completed", "setup-time": 0, "downtime": 1003, "total-time": 1537, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, "pages-per-second": 288578, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 352.48204554326611, "transferred": 497205, "precopy-bytes": 497205, "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": 1003, "total-time": 1537, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, "pages-per-second": 288578, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 352.48204554326611, "transferred": 497205, "precopy-bytes": 497205, "duplicate": 32849, "dirty-pages-rate": 0, "skipped": 0, "normal-bytes": 200704, "normal": 49}}} +{"return": {"status": "completed", "setup-time": 0, "downtime": 1003, "total-time": 1537, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, "pages-per-second": 288578, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 352.48204554326611, "transferred": 497205, "precopy-bytes": 497205, "duplicate": 32849, "dirty-pages-rate": 0, "skipped": 0, "normal-bytes": 200704, "normal": 49}}} +{"return": {"status": "completed", "setup-time": 0, "downtime": 1003, "total-time": 1537, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, "pages-per-second": 288578, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 352.48204554326611, "transferred": 497205, "precopy-bytes": 497205, "duplicate": 32849, "dirty-pages-rate": 0, "skipped": 0, "normal-bytes": 200704, "normal": 49}}} +{"return": {"status": "completed", "setup-time": 0, "downtime": 1003, "total-time": 1537, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, "pages-per-second": 288578, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 352.48204554326611, "transferred": 497205, "precopy-bytes": 497205, "duplicate": 32849, "dirty-pages-rate": 0, "skipped": 0, "normal-bytes": 200704, "normal": 49}}} +{"return": {"status": "completed", "setup-time": 0, "downtime": 1003, "total-time": 1537, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, "pages-per-second": 288578, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 352.48204554326611, "transferred": 497205, "precopy-bytes": 497205, "duplicate": 32849, "dirty-pages-rate": 0, "skipped": 0, "normal-bytes": 200704, "normal": 49}}} +{"return": {"status": "completed", "setup-time": 0, "downtime": 1003, "total-time": 1537, "ram": {"total": 134750208, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, "pages-per-second": 288578, "downtime-bytes": 0, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 352.48204554326611, "transferred": 497205, "precopy-bytes": 497205, "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"}} It does not seem to happen if I run with "-j1" instead. Thomas
--- /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"}}