Comment 0 for bug 1916031

Revision history for this message
Belmiro Moreira (moreira-belmiro-email-lists) wrote :

In a recent VM live migration I noticed that the migration time reported in
the logs was not consistent with the actual time that it was taking:

```
2021-01-15 09:51:07.41 43553 INFO nova.virt.libvirt.driver [ ] Migration running for 0 secs, memory 100% remaining; (bytes processed=0, remaining=0, total=0)
2021-01-15 09:52:37.740 43553 DEBUG nova.virt.libvirt.driver [ ] Migration running for 5 secs, memory 100% remaining; (bytes processed=0, remaining=0, total=0)
2021-01-15 09:53:34.574 43553 DEBUG nova.virt.libvirt.driver [ ] Migration running for 10 secs, memory 100% remaining; (bytes processed=0, remaining=0, total=0)
2021-01-15 09:54:21.186 43553 DEBUG nova.virt.libvirt.driver [ ] Migration running for 15 secs, memory 100% remaining; (bytes processed=0, remaining=0, total=0)
(...)
```

This is because Nova doesn’t log the actual time that is taking. It cycles
to check the migration job status every 500ms and it logs the number of cycles/2.

Nova assumes that libvirt calls will report immediately, which was not the case.
(In this particular example the compute node had issues and libvirt calls were
taking a few seconds).

This behavior can cause some confusion when operators are debugging issues.
In my opinion Nova should log the real migration time.