nova.openstack.common.periodic_task libvirtError: Unable to decode message paylo

admin

2023-08-31 11:13:08.438 12115 INFO nova.compute.resource_tracker [req-95546975-91f8-4d85-aa63-d055e60b8cda - - - - -] Auditing locally available compute resources for node compute2.ksc
- Y) l9 e$ @. i9 J% ~" X2023-08-31 11:13:08.443 12115 ERROR nova.openstack.common.periodic_task [req-95546975-91f8-4d85-aa63-d055e60b8cda - - - - -] Error during ComputeManager.update_available_resource: Unable to decode message payload
# M. }" L; b; w- Z2023-08-31 11:13:08.443 12115 TRACE nova.openstack.common.periodic_task Traceback (most recent call last):
2023-08-31 11:13:08.443 12115 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/nova/openstack/common/periodic_task.py", line 224, in run_periodic_tasks
2023-08-31 11:13:08.443 12115 TRACE nova.openstack.common.periodic_task     task(self, context)
2023-08-31 11:13:08.443 12115 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 6895, in update_available_resource
2023-08-31 11:13:08.443 12115 TRACE nova.openstack.common.periodic_task     rt.update_available_resource(context)
- W; D+ F2 {2 m- ?: H, q% P3 P5 d2023-08-31 11:13:08.443 12115 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/nova/compute/resource_tracker.py", line 376, in update_available_resource
2023-08-31 11:13:08.443 12115 TRACE nova.openstack.common.periodic_task     resources = self.driver.get_available_resource(self.nodename)
+ }; b3 }0 ^: X2 x2023-08-31 11:13:08.443 12115 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4997, in get_available_resource
3 o' [3 I' h/ a5 U2023-08-31 11:13:08.443 12115 TRACE nova.openstack.common.periodic_task     data["memory_mb"] = self._get_memory_mb_total()
2023-08-31 11:13:08.443 12115 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4593, in _get_memory_mb_total
4 l' \* v7 M! k9 x. M3 g" t% n) ]2023-08-31 11:13:08.443 12115 TRACE nova.openstack.common.periodic_task     return self._conn.getInfo()[1]
2023-08-31 11:13:08.443 12115 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 183, in doit
2023-08-31 11:13:08.443 12115 TRACE nova.openstack.common.periodic_task     result = proxy_call(self._autowrap, f, *args, **kwargs)
/ x, w8 H: V% y# h( h) f" G: N% P2023-08-31 11:13:08.443 12115 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 141, in proxy_call
0 O, A0 r- k& N  _2023-08-31 11:13:08.443 12115 TRACE nova.openstack.common.periodic_task     rv = execute(f, *args, **kwargs)
* S$ F. w1 a3 T" [9 t2023-08-31 11:13:08.443 12115 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 122, in execute
9 s- `/ q, o" m$ Z. k, I3 X2023-08-31 11:13:08.443 12115 TRACE nova.openstack.common.periodic_task     six.reraise(c, e, tb)
/ g4 ?* f! u/ W2023-08-31 11:13:08.443 12115 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 80, in tworker
2023-08-31 11:13:08.443 12115 TRACE nova.openstack.common.periodic_task     rv = meth(*args, **kwargs)
2023-08-31 11:13:08.443 12115 TRACE nova.openstack.common.periodic_task   File "/usr/lib64/python2.7/site-packages/libvirt.py", line 3691, in getInfo
  D' q# y) B8 ?; c2023-08-31 11:13:08.443 12115 TRACE nova.openstack.common.periodic_task     if ret is None: raise libvirtError ('virNodeGetInfo() failed', conn=self)
2023-08-31 11:13:08.443 12115 TRACE nova.openstack.common.periodic_task libvirtError: Unable to decode message payload
2023-08-31 11:13:08.443 12115 TRACE nova.openstack.common.periodic_task
2 g( T% H/ l) ~- i$ q2023-08-31 11:13:11.098 12673 INFO nova.compute.resource_tracker [req-17f4b2a3-d909-4714-b1d9-772ffadcb257 - - - - -] Auditing locally available compute resources for node compute2.ksc
4 h' z1 a& t* z9 p* q& {7 o. t2 r% \2023-08-31 11:13:11.103 12673 ERROR nova.openstack.common.periodic_task [req-17f4b2a3-d909-4714-b1d9-772ffadcb257 - - - - -] Error during ComputeManager.update_available_resource: Unable to decode message payload
4 j3 s5 n+ a0 ?2 f2 b2023-08-31 11:13:11.103 12673 TRACE nova.openstack.common.periodic_task Traceback (most recent call last):
. g* t5 J: M0 T  ^, y% a2023-08-31 11:13:11.103 12673 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/nova/openstack/common/periodic_task.py", line 224, in run_periodic_tasks
2023-08-31 11:13:11.103 12673 TRACE nova.openstack.common.periodic_task     task(self, context)
2023-08-31 11:13:11.103 12673 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 6895, in update_available_resource
/ q; M/ P/ i: V* U! b9 p# c2023-08-31 11:13:11.103 12673 TRACE nova.openstack.common.periodic_task     rt.update_available_resource(context)
2023-08-31 11:13:11.103 12673 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/nova/compute/resource_tracker.py", line 376, in update_available_resource
2023-08-31 11:13:11.103 12673 TRACE nova.openstack.common.periodic_task     resources = self.driver.get_available_resource(self.nodename)
2023-08-31 11:13:11.103 12673 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4997, in get_available_resource
8 \) r" P$ ?! N( }2023-08-31 11:13:11.103 12673 TRACE nova.openstack.common.periodic_task     data["memory_mb"] = self._get_memory_mb_total()
1 n$ C( A" Z( ?) U. l* l( U, n2023-08-31 11:13:11.103 12673 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4593, in _get_memory_mb_total
2023-08-31 11:13:11.103 12673 TRACE nova.openstack.common.periodic_task     return self._conn.getInfo()[1]
2023-08-31 11:13:11.103 12673 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 183, in doit
2023-08-31 11:13:11.103 12673 TRACE nova.openstack.common.periodic_task     result = proxy_call(self._autowrap, f, *args, **kwargs)
! h$ t+ c7 Y) S" V2023-08-31 11:13:11.103 12673 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 141, in proxy_call
2023-08-31 11:13:11.103 12673 TRACE nova.openstack.common.periodic_task     rv = execute(f, *args, **kwargs)
5 D( o1 p7 ^( w/ l2 V- @2023-08-31 11:13:11.103 12673 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 122, in execute
6 l  |/ T3 S# _! \0 v5 Y2023-08-31 11:13:11.103 12673 TRACE nova.openstack.common.periodic_task     six.reraise(c, e, tb)
/ I; P6 t' G- }2023-08-31 11:13:11.103 12673 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 80, in tworker
) {% b3 H( Z, i) [. O# R& Z2023-08-31 11:13:11.103 12673 TRACE nova.openstack.common.periodic_task     rv = meth(*args, **kwargs)
2023-08-31 11:13:11.103 12673 TRACE nova.openstack.common.periodic_task   File "/usr/lib64/python2.7/site-packages/libvirt.py", line 3691, in getInfo
+ n7 V: ^5 s0 ~7 l2023-08-31 11:13:11.103 12673 TRACE nova.openstack.common.periodic_task     if ret is None: raise libvirtError ('virNodeGetInfo() failed', conn=self)
% \% _) x( S- O  L2023-08-31 11:13:11.103 12673 TRACE nova.openstack.common.periodic_task libvirtError: Unable to decode message payload
2023-08-31 11:13:11.103 12673 TRACE nova.openstack.common.periodic_task
2023-08-31 11:13:36.174 11634 INFO nova.compute.resource_tracker [req-0e6b83fd-a801-4922-a225-c84f11014d4f - - - - -] Auditing locally available compute resources for node compute2.ksc
0 a2 u; @$ Q8 `* G0 R9 N0 [+ w( G2023-08-31 11:13:36.179 11634 ERROR nova.openstack.common.periodic_task [req-0e6b83fd-a801-4922-a225-c84f11014d4f - - - - -] Error during ComputeManager.update_available_resource: Unable to decode message payload
2023-08-31 11:13:36.179 11634 TRACE nova.openstack.common.periodic_task Traceback (most recent call last):
2023-08-31 11:13:36.179 11634 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/nova/openstack/common/periodic_task.py", line 224, in run_periodic_tasks
# z: z' _  r$ a; @9 }+ R8 {2023-08-31 11:13:36.179 11634 TRACE nova.openstack.common.periodic_task     task(self, context)
2023-08-31 11:13:36.179 11634 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 6895, in update_available_resource
2023-08-31 11:13:36.179 11634 TRACE nova.openstack.common.periodic_task     rt.update_available_resource(context)
+ s8 L: \6 ~! G- a+ V) ~2 `; f2023-08-31 11:13:36.179 11634 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/nova/compute/resource_tracker.py", line 376, in update_available_resource
- ^& @4 L5 [4 I2023-08-31 11:13:36.179 11634 TRACE nova.openstack.common.periodic_task     resources = self.driver.get_available_resource(self.nodename)
( J" p) q& F) b  |. S2 L2023-08-31 11:13:36.179 11634 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4997, in get_available_resource
2 J9 Q8 I( Y" t# R+ j: @7 x% `' L2023-08-31 11:13:36.179 11634 TRACE nova.openstack.common.periodic_task     data["memory_mb"] = self._get_memory_mb_total()
4 z* d4 {! `  z" d2023-08-31 11:13:36.179 11634 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4593, in _get_memory_mb_total
3 ^- T: @# }  B% m2023-08-31 11:13:36.179 11634 TRACE nova.openstack.common.periodic_task     return self._conn.getInfo()[1]
* L' }# S. k) G# |2023-08-31 11:13:36.179 11634 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 183, in doit
2023-08-31 11:13:36.179 11634 TRACE nova.openstack.common.periodic_task     result = proxy_call(self._autowrap, f, *args, **kwargs)
2023-08-31 11:13:36.179 11634 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 141, in proxy_call
/ L( K. W5 w; U3 d) T9 d9 _4 q6 T2023-08-31 11:13:36.179 11634 TRACE nova.openstack.common.periodic_task     rv = execute(f, *args, **kwargs)
2023-08-31 11:13:36.179 11634 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 122, in execute
2023-08-31 11:13:36.179 11634 TRACE nova.openstack.common.periodic_task     six.reraise(c, e, tb)
2023-08-31 11:13:36.179 11634 TRACE nova.openstack.common.periodic_task   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 80, in tworker
2023-08-31 11:13:36.179 11634 TRACE nova.openstack.common.periodic_task     rv = meth(*args, **kwargs)
2023-08-31 11:13:36.179 11634 TRACE nova.openstack.common.periodic_task   File "/usr/lib64/python2.7/site-packages/libvirt.py", line 3691, in getInfo
$ q* Q8 `0 x& {! d/ N0 h8 L/ s2023-08-31 11:13:36.179 11634 TRACE nova.openstack.common.periodic_task     if ret is None: raise libvirtError ('virNodeGetInfo() failed', conn=self)
2023-08-31 11:13:36.179 11634 TRACE nova.openstack.common.periodic_task libvirtError: Unable to decode message payload
2023-08-31 11:13:36.179 11634 TRACE nova.openstack.common.periodic_task
& N- ~1 a+ \0 ?( Q( b
3 d: t. y  k: G* ^
3 x8 O  ?& g; p* \! E6 D  N* n; m

admin

检查服务状态正常：
systemctl status libvirtd.service
/ \9 H- `$ C! `0 T● libvirtd.service - Virtualization daemon
6 q' z0 i5 y. G$ K. S   Loaded: loaded (/usr/lib/systemd/system/libvirtd.service; enabled; vendor preset: enabled)
* u0 @' V, S; X4 R. ?% M1 e   Active: active (running) since Mon 2021-10-18 19:35:52 CST; 1 years 10 months ago
Main PID: 3615 (libvirtd)
' ]7 |8 r1 [5 ?! p) k$ r   CGroup: /system.slice/libvirtd.service
           └─3615 /usr/sbin/libvirtd --listen
% O6 W. ?0 m2 S: Q. Y1 b
Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable.
" R& p' ]% D$ s

admin

经过排查是因为compute2节点存在 内存cpu不足导致不能迁移。
* r# P8 a  B! K9 e2 z
正常测试节点3可以正常迁移。日志如下：
9 t: O; h# ]1 O  ?7 J2023-08-31 11:20:29.879 23276 INFO nova.compute.resource_tracker [req-52674467-955d-4fd4-b4ea-845c1cd523f6 - - - - -] Auditing locally available compute resources for node compute3.ksc
3 k+ K; H# Q$ ]& R! G. y2023-08-31 11:20:30.742 23276 INFO nova.compute.resource_tracker [req-52674467-955d-4fd4-b4ea-845c1cd523f6 - - - - -] Total usable vcpus: 36, total allocated vcpus: 68
4 B+ w; q/ F9 X! h$ c, d+ W2023-08-31 11:20:30.743 23276 INFO nova.compute.resource_tracker [req-52674467-955d-4fd4-b4ea-845c1cd523f6 - - - - -] Final resource view: name=compute3.ksc phys_ram=386407MB used_ram=196608MB phys_disk=95GB used_disk=750GB total_vcpus=36 used_vcpus=68 pci_stats=<nova.pci.stats.PciDeviceStats object at 0x5770390>
$ a" I; E! x5 P- }6 |0 E+ g) }2023-08-31 11:20:30.762 23276 INFO nova.scheduler.client.report [req-52674467-955d-4fd4-b4ea-845c1cd523f6 - - - - -] Compute_service record updated for ('compute3.ksc', 'compute3.ksc')
2023-08-31 11:20:30.763 23276 INFO nova.compute.resource_tracker [req-52674467-955d-4fd4-b4ea-845c1cd523f6 - - - - -] Compute_service record updated for compute3.ksc:compute3.ksc
2023-08-31 11:21:30.879 23276 INFO nova.compute.resource_tracker [req-52674467-955d-4fd4-b4ea-845c1cd523f6 - - - - -] Auditing locally available compute resources for node compute3.ksc
2023-08-31 11:21:31.725 23276 INFO nova.compute.resource_tracker [req-52674467-955d-4fd4-b4ea-845c1cd523f6 - - - - -] Total usable vcpus: 36, total allocated vcpus: 68
% |/ I7 i1 d; A% D4 M2023-08-31 11:21:31.726 23276 INFO nova.compute.resource_tracker [req-52674467-955d-4fd4-b4ea-845c1cd523f6 - - - - -] Final resource view: name=compute3.ksc phys_ram=386407MB used_ram=196608MB phys_disk=95GB used_disk=750GB total_vcpus=36 used_vcpus=68 pci_stats=<nova.pci.stats.PciDeviceStats object at 0x5770390>
. s; L$ v- I* K! Z2 a2023-08-31 11:21:31.746 23276 INFO nova.scheduler.client.report [req-52674467-955d-4fd4-b4ea-845c1cd523f6 - - - - -] Compute_service record updated for ('compute3.ksc', 'compute3.ksc')
0 P: E4 Y/ k4 k/ G4 k2023-08-31 11:21:31.746 23276 INFO nova.compute.resource_tracker [req-52674467-955d-4fd4-b4ea-845c1cd523f6 - - - - -] Compute_service record updated for compute3.ksc:compute3.ksc
8 a& l  V+ P/ z2023-08-31 11:22:31.879 23276 INFO nova.compute.resource_tracker [req-52674467-955d-4fd4-b4ea-845c1cd523f6 - - - - -] Auditing locally available compute resources for node compute3.ksc
2023-08-31 11:22:32.752 23276 INFO nova.compute.resource_tracker [req-52674467-955d-4fd4-b4ea-845c1cd523f6 - - - - -] Total usable vcpus: 36, total allocated vcpus: 68
! J$ o+ x9 x% G2023-08-31 11:22:32.752 23276 INFO nova.compute.resource_tracker [req-52674467-955d-4fd4-b4ea-845c1cd523f6 - - - - -] Final resource view: name=compute3.ksc phys_ram=386407MB used_ram=196608MB phys_disk=95GB used_disk=750GB total_vcpus=36 used_vcpus=68 pci_stats=<nova.pci.stats.PciDeviceStats object at 0x5770390>
2023-08-31 11:22:32.771 23276 INFO nova.scheduler.client.report [req-52674467-955d-4fd4-b4ea-845c1cd523f6 - - - - -] Compute_service record updated for ('compute3.ksc', 'compute3.ksc')
2023-08-31 11:22:32.772 23276 INFO nova.compute.resource_tracker [req-52674467-955d-4fd4-b4ea-845c1cd523f6 - - - - -] Compute_service record updated for compute3.ksc:compute3.ksc
2023-08-31 11:22:43.575 23276 INFO nova.compute.manager [req-27049fc1-fc8b-496e-a034-686d594e1dc5 - - - - -] [instance: 603ae7b4-f644-4a82-929c-b698cafecbe0] VM Started (Lifecycle Event)
2023-08-31 11:22:43.668 23276 INFO nova.compute.manager [req-27049fc1-fc8b-496e-a034-686d594e1dc5 - - - - -] [instance: 603ae7b4-f644-4a82-929c-b698cafecbe0] During the sync_power process the instance has moved from host compute12.ksc to host compute3.ksc

$ m, i$ g: ]+ k2 s9 F2023-08-31 11:23:21.267 23276 INFO nova.compute.manager [req-27049fc1-fc8b-496e-a034-686d594e1dc5 - - - - -] [instance: 603ae7b4-f644-4a82-929c-b698cafecbe0] VM Resumed (Lifecycle Event)
3 c5 e# y* y" b1 x( Q: A2023-08-31 11:23:21.467 23276 INFO nova.compute.manager [req-27049fc1-fc8b-496e-a034-686d594e1dc5 - - - - -] [instance: 603ae7b4-f644-4a82-929c-b698cafecbe0] During the sync_power process the instance has moved from host compute12.ksc to host compute3.ksc
; f9 t  r9 e  D" a# C' s2023-08-31 11:23:21.468 23276 INFO nova.compute.manager [req-27049fc1-fc8b-496e-a034-686d594e1dc5 - - - - -] [instance: 603ae7b4-f644-4a82-929c-b698cafecbe0] VM Resumed (Lifecycle Event)
' }& Q: `! z3 x3 |2 q2023-08-31 11:23:21.566 23276 INFO nova.compute.manager [req-27049fc1-fc8b-496e-a034-686d594e1dc5 - - - - -] [instance: 603ae7b4-f644-4a82-929c-b698cafecbe0] During the sync_power process the instance has moved from host compute12.ksc to host compute3.ksc
0 E4 G4 O& i$ P# d! f0 p2023-08-31 11:23:22.584 23276 INFO nova.compute.manager [req-e068b830-a351-4340-924a-c53e01c6ff63 8c4ddcc3e636480bab36ba528221d326 dbacf480939b4ac1b89d3819750729df - - -] [instance: 603ae7b4-f644-4a82-929c-b698cafecbe0] Post operation of migration started
2023-08-31 11:23:32.879 23276 INFO nova.compute.resource_tracker [req-52674467-955d-4fd4-b4ea-845c1cd523f6 - - - - -] Auditing locally available compute resources for node compute3.ksc
2023-08-31 11:23:33.782 23276 INFO nova.compute.resource_tracker [req-52674467-955d-4fd4-b4ea-845c1cd523f6 - - - - -] Total usable vcpus: 36, total allocated vcpus: 70
, L) b( \. u  d6 w" J2023-08-31 11:23:33.783 23276 INFO nova.compute.resource_tracker [req-52674467-955d-4fd4-b4ea-845c1cd523f6 - - - - -] Final resource view: name=compute3.ksc phys_ram=386407MB used_ram=204800MB phys_disk=95GB used_disk=800GB total_vcpus=36 used_vcpus=70 pci_stats=<nova.pci.stats.PciDeviceStats object at 0x5770390>
. |3 H* S* X( H% j3 _) x2023-08-31 11:23:33.802 23276 INFO nova.scheduler.client.report [req-52674467-955d-4fd4-b4ea-845c1cd523f6 - - - - -] Compute_service record updated for ('compute3.ksc', 'compute3.ksc')
2023-08-31 11:23:33.802 23276 INFO nova.compute.resource_tracker [req-52674467-955d-4fd4-b4ea-845c1cd523f6 - - - - -] Compute_service record updated for compute3.ksc:compute3.ksc
2023-08-31 11:24:32.878 23276 INFO nova.compute.resource_tracker [req-52674467-955d-4fd4-b4ea-845c1cd523f6 - - - - -] Auditing locally available compute resources for node compute3.ksc
2023-08-31 11:24:33.800 23276 INFO nova.compute.resource_tracker [req-52674467-955d-4fd4-b4ea-845c1cd523f6 - - - - -] Total usable vcpus: 36, total allocated vcpus: 70
2023-08-31 11:24:33.801 23276 INFO nova.compute.resource_tracker [req-52674467-955d-4fd4-b4ea-845c1cd523f6 - - - - -] Final resource view: name=compute3.ksc phys_ram=386407MB used_ram=204800MB phys_disk=95GB used_disk=800GB total_vcpus=36 used_vcpus=70 pci_stats=<nova.pci.stats.PciDeviceStats object at 0x5770390>
) t/ q! Q* t# I2023-08-31 11:24:33.825 23276 INFO nova.scheduler.client.report [req-52674467-955d-4fd4-b4ea-845c1cd523f6 - - - - -] Compute_service record updated for ('compute3.ksc', 'compute3.ksc')
. P/ c. B5 A( n9 A2 V9 H2023-08-31 11:24:33.825 23276 INFO nova.compute.resource_tracker [req-52674467-955d-4fd4-b4ea-845c1cd523f6 - - - - -] Compute_service record updated for compute3.ksc:compute3.ksc