| 2021-02-18 13:02:41 |
Belmiro Moreira |
description |
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. |
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. |
|
