虚拟创建失败之Dbus调试
DBus调试命令
查询连接名
### 查询所有连接名
# dbus-send --system --print-reply --dest=org.freedesktop.DBus / org.freedesktop.DBus.ListActivatableNames
### 查询当前生效的连接名
# dbus-send --system --print-reply --dest=org.freedesktop.DBus / org.freedesktop.DBus.ListNames
查询连接对象路径
### 不断递归查找子节点,知道找到叶子节点
# dbus-send --system --print-reply --dest=<连接名> / org.freedesktop.DBus.Introspectable.Introspect
# dbus-send --system --print-reply --dest=<连接名> /<节点> org.freedesktop.DBus.Introspectable.Introspect
监控dbus消息
# dbus-monitor --system
实际应用
问题描述
### kolla部署openstack后虚拟机创建报错
2017-08-04 13:51:55.905+0000: 16256: error : virSystemdCreateMachine:383 : Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.
分析过程
首先看下出错的对应代码
查询下对应连接
# dbus-send --system --print-reply --dest=org.freedesktop.DBus / org.freedesktop.DBus.ListActivatableNames
method return sender=org.freedesktop.DBus -> dest=:1.15 reply_serial=2
array [
string "org.freedesktop.DBus"
string "org.freedesktop.login1"
string "org.freedesktop.machine1"
string "org.freedesktop.systemd1"
string "org.freedesktop.import1"
string "org.freedesktop.PolicyKit1"
string "org.freedesktop.hostname1"
string "org.freedesktop.NetworkManager"
string "fi.epitest.hostap.WPASupplicant"
string "org.freedesktop.timedate1"
string "fi.w1.wpa_supplicant1"
string "org.freedesktop.locale1"
string "org.freedesktop.nm_dispatcher"
]
连接是存在的,接着我们查询下对应方法
# dbus-send --system --print-reply --dest=org.freedesktop.machine1 / org.freedesktop.DBus.Introspectable.Introspect
method return sender=:1.17 -> dest=:1.16 reply_serial=2
string "<!DOCTYPE node PUBLIC "-//freedesktop//DTD D-BUS Object Introspection 1.0//EN"
"http://www.freedesktop.org/standards/dbus/1.0/introspect.dtd">
<node>
<interface name="org.freedesktop.DBus.Peer">
<method name="Ping"/>
<method name="GetMachineId">
<arg type="s" name="machine_uuid" direction="out"/>
</method>
</interface>
<interface name="org.freedesktop.DBus.Introspectable">
<method name="Introspect">
<arg name="data" type="s" direction="out"/>
</method>
</interface>
<interface name="org.freedesktop.DBus.Properties">
<method name="Get">
<arg name="interface" direction="in" type="s"/>
<arg name="property" direction="in" type="s"/>
<arg name="value" direction="out" type="v"/>
</method>
<method name="GetAll">
<arg name="interface" direction="in" type="s"/>
<arg name="properties" direction="out" type="a{sv}"/>
</method>
<method name="Set">
<arg name="interface" direction="in" type="s"/>
<arg name="property" direction="in" type="s"/>
<arg name="value" direction="in" type="v"/>
</method>
<signal name="PropertiesChanged">
<arg type="s" name="interface"/>
<arg type="a{sv}" name="changed_properties"/>
<arg type="as" name="invalidated_properties"/>
</signal>
</interface>
<node name="org/freedesktop/machine1"/>
<node name="org/freedesktop/machine1/image"/>
<node name="org/freedesktop/machine1/image/_2ehost"/>
<node name="org/freedesktop/machine1/machine"/>
</node>
"
### 继续查询<node name="org/freedesktop/machine1"/>
# dbus-send --system --print-reply --dest=org.freedesktop.machine1 /org/freedesktop/machine1 org.freedesktop.DBus.Introspectable.Introspect
method return sender=:1.20 -> dest=:1.19 reply_serial=2
string "<!DOCTYPE node PUBLIC "-//freedesktop//DTD D-BUS Object Introspection 1.0//EN"
"http://www.freedesktop.org/standards/dbus/1.0/introspect.dtd">
<node>
<interface name="org.freedesktop.DBus.Peer">
<method name="Ping"/>
<method name="GetMachineId">
<arg type="s" name="machine_uuid" direction="out"/>
</method>
</interface>
<interface name="org.freedesktop.DBus.Introspectable">
<method name="Introspect">
<arg name="data" type="s" direction="out"/>
</method>
</interface>
<interface name="org.freedesktop.DBus.Properties">
<method name="Get">
<arg name="interface" direction="in" type="s"/>
<arg name="property" direction="in" type="s"/>
<arg name="value" direction="out" type="v"/>
</method>
<method name="GetAll">
<arg name="interface" direction="in" type="s"/>
<arg name="properties" direction="out" type="a{sv}"/>
</method>
<method name="Set">
<arg name="interface" direction="in" type="s"/>
<arg name="property" direction="in" type="s"/>
<arg name="value" direction="in" type="v"/>
</method>
<signal name="PropertiesChanged">
<arg type="s" name="interface"/>
<arg type="a{sv}" name="changed_properties"/>
<arg type="as" name="invalidated_properties"/>
</signal>
</interface>
<interface name="org.freedesktop.machine1.Manager">
<method name="GetMachine">
<arg type="s" direction="in"/>
<arg type="o" direction="out"/>
</method>
<method name="GetImage">
<arg type="s" direction="in"/>
<arg type="o" direction="out"/>
</method>
<method name="GetMachineByPID">
<arg type="u" direction="in"/>
<arg type="o" direction="out"/>
</method>
<method name="ListMachines">
<arg type="a(ssso)" direction="out"/>
</method>
<method name="ListImages">
<arg type="a(ssbttto)" direction="out"/>
</method>
<method name="CreateMachine">
<arg type="s" direction="in"/>
<arg type="ay" direction="in"/>
<arg type="s" direction="in"/>
<arg type="s" direction="in"/>
<arg type="u" direction="in"/>
<arg type="s" direction="in"/>
<arg type="a(sv)" direction="in"/>
<arg type="o" direction="out"/>
<annotation name="org.freedesktop.systemd1.Privileged" value="true"/>
</method>
<method name="CreateMachineWithNetwork">
<arg type="s" direction="in"/>
<arg type="ay" direction="in"/>
<arg type="s" direction="in"/>
<arg type="s" direction="in"/>
<arg type="u" direction="in"/>
<arg type="s" direction="in"/>
<arg type="ai" direction="in"/>
<arg type="a(sv)" direction="in"/>
<arg type="o" direction="out"/>
<annotation name="org.freedesktop.systemd1.Privileged" value="true"/>
</method>
<method name="RegisterMachine">
<arg type="s" direction="in"/>
<arg type="ay" direction="in"/>
<arg type="s" direction="in"/>
<arg type="s" direction="in"/>
<arg type="u" direction="in"/>
<arg type="s" direction="in"/>
<arg type="o" direction="out"/>
<annotation name="org.freedesktop.systemd1.Privileged" value="true"/>
</method>
<method name="RegisterMachineWithNetwork">
<arg type="s" direction="in"/>
<arg type="ay" direction="in"/>
<arg type="s" direction="in"/>
<arg type="s" direction="in"/>
<arg type="u" direction="in"/>
<arg type="s" direction="in"/>
<arg type="ai" direction="in"/>
<arg type="o" direction="out"/>
<annotation name="org.freedesktop.systemd1.Privileged" value="true"/>
</method>
<method name="KillMachine">
<arg type="s" direction="in"/>
<arg type="s" direction="in"/>
<arg type="i" direction="in"/>
<annotation name="org.freedesktop.systemd1.Privileged" value="true"/>
</method>
<method name="TerminateMachine">
<arg type="s" direction="in"/>
<annotation name="org.freedesktop.systemd1.Privileged" value="true"/>
</method>
<method name="GetMachineAddresses">
<arg type="s" direction="in"/>
<arg type="a(iay)" direction="out"/>
</method>
<method name="GetMachineOSRelease">
<arg type="s" direction="in"/>
<arg type="a{ss}" direction="out"/>
</method>
<method name="OpenMachinePTY">
<arg type="s" direction="in"/>
<arg type="h" direction="out"/>
<arg type="s" direction="out"/>
<annotation name="org.freedesktop.systemd1.Privileged" value="true"/>
</method>
<method name="OpenMachineLogin">
<arg type="s" direction="in"/>
<arg type="h" direction="out"/>
<arg type="s" direction="out"/>
</method>
<method name="RemoveImage">
<arg type="s" direction="in"/>
<annotation name="org.freedesktop.systemd1.Privileged" value="true"/>
</method>
<method name="RenameImage">
<arg type="s" direction="in"/>
<arg type="s" direction="in"/>
<annotation name="org.freedesktop.systemd1.Privileged" value="true"/>
</method>
<method name="CloneImage">
<arg type="s" direction="in"/>
<arg type="s" direction="in"/>
<arg type="b" direction="in"/>
<annotation name="org.freedesktop.systemd1.Privileged" value="true"/>
</method>
<method name="MarkImageReadOnly">
<arg type="s" direction="in"/>
<arg type="b" direction="in"/>
<annotation name="org.freedesktop.systemd1.Privileged" value="true"/>
</method>
<signal name="MachineNew">
<arg type="s"/>
<arg type="o"/>
</signal>
<signal name="MachineRemoved">
<arg type="s"/>
<arg type="o"/>
</signal>
</interface>
</node>
"
我们接着来看下dbus收到了哪些消息
# dbus-monitor --system
signal sender=org.freedesktop.DBus -> dest=:1.25 serial=2 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameAcquired
string ":1.25"
signal sender=org.freedesktop.DBus -> dest=(null destination) serial=202 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameOwnerChanged
string ":1.26"
string ""
string ":1.26"
signal sender=org.freedesktop.DBus -> dest=(null destination) serial=208 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameOwnerChanged
string "org.freedesktop.machine1"
string ""
string ":1.26"
signal sender=:1.0 -> dest=(null destination) serial=287 path=/org/freedesktop/systemd1; interface=org.freedesktop.systemd1.Manager; member=JobRemoved
uint32 2797
object path "/org/freedesktop/systemd1/job/2797"
string "systemd-machined.service"
string "done"
signal sender=:1.0 -> dest=(null destination) serial=288 path=/org/freedesktop/systemd1/unit/systemd_2dmachined_2eservice; interface=org.freedesktop.DBus.Properties; member=PropertiesChanged
string "org.freedesktop.systemd1.Service"
array [
dict entry(
string "MainPID"
variant uint32 22125
)
dict entry(
string "ControlPID"
variant uint32 0
)
dict entry(
string "StatusText"
variant string ""
)
dict entry(
string "StatusErrno"
variant int32 0
)
dict entry(
string "Result"
variant string "success"
)
dict entry(
string "ExecMainStartTimestamp"
variant uint64 1501856600666609
)
dict entry(
string "ExecMainStartTimestampMonotonic"
variant uint64 16667635543
)
dict entry(
string "ExecMainExitTimestamp"
variant uint64 0
)
dict entry(
string "ExecMainExitTimestampMonotonic"
variant uint64 0
)
dict entry(
string "ExecMainPID"
variant uint32 22125
)
dict entry(
string "ExecMainCode"
variant int32 0
)
dict entry(
string "ExecMainStatus"
variant int32 0
)
]
array [
string "ExecStartPre"
string "ExecStart"
string "ExecStartPost"
string "ExecReload"
string "ExecStop"
string "ExecStopPost"
]
signal sender=:1.0 -> dest=(null destination) serial=289 path=/org/freedesktop/systemd1/unit/systemd_2dmachined_2eservice; interface=org.freedesktop.DBus.Properties; member=PropertiesChanged
string "org.freedesktop.systemd1.Unit"
array [
dict entry(
string "ActiveState"
variant string "active"
)
dict entry(
string "SubState"
variant string "running"
)
dict entry(
string "InactiveExitTimestamp"
variant uint64 1501856600666635
)
dict entry(
string "InactiveExitTimestampMonotonic"
variant uint64 16667635568
)
dict entry(
string "ActiveEnterTimestamp"
variant uint64 1501856600696439
)
dict entry(
string "ActiveEnterTimestampMonotonic"
variant uint64 16667665373
)
dict entry(
string "ActiveExitTimestamp"
variant uint64 0
)
dict entry(
string "ActiveExitTimestampMonotonic"
variant uint64 0
)
dict entry(
string "InactiveEnterTimestamp"
variant uint64 0
)
dict entry(
string "InactiveEnterTimestampMonotonic"
variant uint64 0
)
dict entry(
string "Job"
variant struct {
uint32 0
object path "/"
}
)
dict entry(
string "ConditionResult"
variant boolean true
)
dict entry(
string "AssertResult"
variant boolean true
)
dict entry(
string "ConditionTimestamp"
variant uint64 1501856600665536
)
dict entry(
string "ConditionTimestampMonotonic"
variant uint64 16667634470
)
dict entry(
string "AssertTimestamp"
variant uint64 1501856600665537
)
dict entry(
string "AssertTimestampMonotonic"
variant uint64 16667634470
)
]
array [
]
signal sender=:1.0 -> dest=(null destination) serial=290 path=/org/freedesktop/systemd1/unit/systemd_2dmachined_2eservice; interface=org.freedesktop.DBus.Properties; member=PropertiesChanged
string "org.freedesktop.systemd1.Service"
array [
dict entry(
string "MainPID"
variant uint32 22125
)
dict entry(
string "ControlPID"
variant uint32 0
)
dict entry(
string "StatusText"
variant string "Processing requests..."
)
dict entry(
string "StatusErrno"
variant int32 0
)
dict entry(
string "Result"
variant string "success"
)
dict entry(
string "ExecMainStartTimestamp"
variant uint64 1501856600666609
)
dict entry(
string "ExecMainStartTimestampMonotonic"
variant uint64 16667635543
)
dict entry(
string "ExecMainExitTimestamp"
variant uint64 0
)
dict entry(
string "ExecMainExitTimestampMonotonic"
variant uint64 0
)
dict entry(
string "ExecMainPID"
variant uint32 22125
)
dict entry(
string "ExecMainCode"
variant int32 0
)
dict entry(
string "ExecMainStatus"
variant int32 0
)
]
array [
string "ExecStartPre"
string "ExecStart"
string "ExecStartPost"
string "ExecReload"
string "ExecStop"
string "ExecStopPost"
]
signal sender=:1.0 -> dest=(null destination) serial=291 path=/org/freedesktop/systemd1/unit/systemd_2dmachined_2eservice; interface=org.freedesktop.DBus.Properties; member=PropertiesChanged
string "org.freedesktop.systemd1.Unit"
array [
dict entry(
string "ActiveState"
variant string "active"
)
dict entry(
string "SubState"
variant string "running"
)
dict entry(
string "InactiveExitTimestamp"
variant uint64 1501856600666635
)
dict entry(
string "InactiveExitTimestampMonotonic"
variant uint64 16667635568
)
dict entry(
string "ActiveEnterTimestamp"
variant uint64 1501856600696439
)
dict entry(
string "ActiveEnterTimestampMonotonic"
variant uint64 16667665373
)
dict entry(
string "ActiveExitTimestamp"
variant uint64 0
)
dict entry(
string "ActiveExitTimestampMonotonic"
variant uint64 0
)
dict entry(
string "InactiveEnterTimestamp"
variant uint64 0
)
dict entry(
string "InactiveEnterTimestampMonotonic"
variant uint64 0
)
dict entry(
string "Job"
variant struct {
uint32 0
object path "/"
}
)
dict entry(
string "ConditionResult"
variant boolean true
)
dict entry(
string "AssertResult"
variant boolean true
)
dict entry(
string "ConditionTimestamp"
variant uint64 1501856600665536
)
dict entry(
string "ConditionTimestampMonotonic"
variant uint64 16667634470
)
dict entry(
string "AssertTimestamp"
variant uint64 1501856600665537
)
dict entry(
string "AssertTimestampMonotonic"
variant uint64 16667634470
)
]
array [
]
signal sender=:1.0 -> dest=(null destination) serial=302 path=/org/freedesktop/systemd1; interface=org.freedesktop.systemd1.Manager; member=UnitNew
string "libvirt-guests.service"
object path "/org/freedesktop/systemd1/unit/libvirt_2dguests_2eservice"
signal sender=:1.0 -> dest=(null destination) serial=303 path=/org/freedesktop/systemd1; interface=org.freedesktop.systemd1.Manager; member=UnitNew
string "libvirtd.service"
object path "/org/freedesktop/systemd1/unit/libvirtd_2eservice"
signal sender=:1.0 -> dest=(null destination) serial=304 path=/org/freedesktop/systemd1; interface=org.freedesktop.systemd1.Manager; member=UnitNew
string "machine-qemu\x2d2\x2dinstance\x2d00000004.scope"
object path "/org/freedesktop/systemd1/unit/machine_2dqemu_5cx2d2_5cx2dinstance_5cx2d00000004_2escope"
signal sender=:1.0 -> dest=(null destination) serial=305 path=/org/freedesktop/systemd1; interface=org.freedesktop.systemd1.Manager; member=JobNew
uint32 2895
object path "/org/freedesktop/systemd1/job/2895"
string "machine-qemu\x2d2\x2dinstance\x2d00000004.scope"
signal sender=:1.26 -> dest=(null destination) serial=10 path=/org/freedesktop/machine1; interface=org.freedesktop.machine1.Manager; member=MachineNew
string "qemu-2-instance-00000004"
object path "/org/freedesktop/machine1/machine/qemu_2d2_2dinstance_2d00000004"
signal sender=:1.0 -> dest=(null destination) serial=306 path=/org/freedesktop/systemd1; interface=org.freedesktop.systemd1.Manager; member=JobRemoved
uint32 2895
object path "/org/freedesktop/systemd1/job/2895"
string "machine-qemu\x2d2\x2dinstance\x2d00000004.scope"
string "done"
signal sender=:1.0 -> dest=(null destination) serial=308 path=/org/freedesktop/systemd1/unit/machine_2dqemu_5cx2d2_5cx2dinstance_5cx2d00000004_2escope; interface=org.freedesktop.DBus.Properties; member=PropertiesChanged
string "org.freedesktop.systemd1.Scope"
array [
dict entry(
string "Result"
variant string "success"
)
]
array [
]
signal sender=:1.0 -> dest=(null destination) serial=309 path=/org/freedesktop/systemd1/unit/machine_2dqemu_5cx2d2_5cx2dinstance_5cx2d00000004_2escope; interface=org.freedesktop.DBus.Properties; member=PropertiesChanged
string "org.freedesktop.systemd1.Unit"
array [
dict entry(
string "ActiveState"
variant string "active"
)
dict entry(
string "SubState"
variant string "running"
)
dict entry(
string "InactiveExitTimestamp"
variant uint64 1501856600700114
)
dict entry(
string "InactiveExitTimestampMonotonic"
variant uint64 16667669047
)
dict entry(
string "ActiveEnterTimestamp"
variant uint64 1501856600700114
)
dict entry(
string "ActiveEnterTimestampMonotonic"
variant uint64 16667669047
)
dict entry(
string "ActiveExitTimestamp"
variant uint64 0
)
dict entry(
string "ActiveExitTimestampMonotonic"
variant uint64 0
)
dict entry(
string "InactiveEnterTimestamp"
variant uint64 0
)
dict entry(
string "InactiveEnterTimestampMonotonic"
variant uint64 0
)
dict entry(
string "Job"
variant struct {
uint32 0
object path "/"
}
)
dict entry(
string "ConditionResult"
variant boolean true
)
dict entry(
string "AssertResult"
variant boolean true
)
dict entry(
string "ConditionTimestamp"
variant uint64 1501856600699722
)
dict entry(
string "ConditionTimestampMonotonic"
variant uint64 16667668656
)
dict entry(
string "AssertTimestamp"
variant uint64 1501856600699722
)
dict entry(
string "AssertTimestampMonotonic"
variant uint64 16667668656
)
]
array [
]
我们手动测试下列举虚拟机命令
# dbus-send --system --print-reply --dest=org.freedesktop.machine1 /org/freedesktop/machine1 org.freedesktop.machine1.Manager.ListMachines
Error org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.
我们看下连接点org.freedesktop.machine1对应systemd-machined服务的状态
# cat /usr/lib/systemd/system/systemd-machined.service
# This file is part of systemd.
#
# systemd is free software; you can redistribute it and/or modify it
# under the terms of the GNU Lesser General Public License as published by
# the Free Software Foundation; either version 2.1 of the License, or
# (at your option) any later version.
[Unit]
Description=Virtual Machine and Container Registration Service
Documentation=man:systemd-machined.service(8)
Documentation=http://www.freedesktop.org/wiki/Software/systemd/machined
Wants=machine.slice
After=machine.slice
[Service]
ExecStart=/usr/lib/systemd/systemd-machined
BusName=org.freedesktop.machine1
CapabilityBoundingSet=CAP_KILL CAP_SYS_PTRACE CAP_SYS_ADMIN CAP_SETGID CAP_SYS_CHROOT CAP_DAC_READ_SEARCH
WatchdogSec=3min
PrivateTmp=yes
PrivateDevices=yes
PrivateNetwork=yes
ProtectSystem=full
ProtectHome=yes
### 发现服务挂掉了,如果我们启动服务人,然后执行上面的org.freedesktop.machine1.Manager.ListMachines方法就会出现我们创建虚拟机时的消息,而且在能正常创建虚拟机的环境下,此服务也是正常启动的(没创建虚拟机前是inactive的,创建虚拟机时被启动)
# systemctl status systemd-machined.service
● systemd-machined.service - Virtual Machine and Container Registration Service
Loaded: loaded (/usr/lib/systemd/system/systemd-machined.service; static; vendor preset: disabled)
Active: inactive (dead)
Docs: man:systemd-machined.service(8)
http://www.freedesktop.org/wiki/Software/systemd/machined
Aug 04 22:23:20 localhost.localdomain systemd-machined[22125]: New machine qemu-2-instance-00000004.
Aug 04 22:23:50 localhost.localdomain systemd-machined[22125]: Machine qemu-2-instance-00000004 terminated.
Aug 04 22:45:47 localhost.localdomain systemd[1]: Starting Virtual Machine and Container Registration Service...
Aug 04 22:45:47 localhost.localdomain systemd[1]: Started Virtual Machine and Container Registration Service.
Aug 04 22:48:00 localhost.localdomain systemd[1]: Starting Virtual Machine and Container Registration Service...
Aug 04 22:48:00 localhost.localdomain systemd[1]: Started Virtual Machine and Container Registration Service.
Aug 04 22:56:10 localhost.localdomain systemd[1]: Starting Virtual Machine and Container Registration Service...
Aug 04 22:56:10 localhost.localdomain systemd[1]: Started Virtual Machine and Container Registration Service.
Aug 04 22:56:10 localhost.localdomain systemd-machined[27779]: New machine qemu-3-instance-00000005.
Aug 04 22:56:40 localhost.localdomain systemd-machined[27779]: Machine qemu-3-instance-00000005 terminated.
我们再来看下服务日志
### 正常的
Aug 05 06:12:52 localhost.localdomain sudo[2938]: nova : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/var/lib/kolla/venv/bin/nova-rootwrap /etc/nova/rootwrap.conf touch -c /var/lib/nova/i
Aug 05 06:12:55 localhost.localdomain sudo[2955]: nova : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/var/lib/kolla/venv/bin/nova-rootwrap /etc/nova/rootwrap.conf privsep-helper --config-
Aug 05 06:12:56 localhost.localdomain kernel: warning: `privsep-helper' uses deprecated v2 capabilities in a way that may be insecure.
Aug 05 06:12:56 localhost.localdomain ovs-vsctl[2967]: ovs|00001|vsctl|INFO|Called as ovs-vsctl -- --may-exist add-br br-int -- set Bridge br-int datapath_type=system
Aug 05 06:12:56 localhost.localdomain kernel: tun: Universal TUN/TAP device driver, 1.6
Aug 05 06:12:56 localhost.localdomain kernel: tun: (C) 1999-2004 Max Krasnyansky <maxk@qualcomm.com>
Aug 05 06:12:56 localhost.localdomain NetworkManager[743]: <info> (tapc8d87b70-ed): new Tun device (carrier: OFF, driver: 'tun', ifindex: 8)
Aug 05 06:12:56 localhost.localdomain ovs-vsctl[2985]: ovs|00001|vsctl|INFO|Called as ovs-vsctl --timeout=5 -- --if-exists del-port tapc8d87b70-ed -- add-port br-int tapc8d87b70-ed -- set I
Aug 05 06:12:56 localhost.localdomain kernel: device tapc8d87b70-ed entered promiscuous mode
Aug 05 06:12:56 localhost.localdomain NetworkManager[743]: <info> (tapc8d87b70-ed): enslaved to non-master-type device ovs-system; ignoring
Aug 05 06:12:56 localhost.localdomain kernel: Netfilter messages via NETLINK v0.30.
Aug 05 06:12:56 localhost.localdomain kernel: ctnetlink v0.93: registering with nfnetlink.
Aug 05 06:12:56 localhost.localdomain NetworkManager[743]: <info> (tapc8d87b70-ed): enslaved to non-master-type device ovs-system; ignoring
Aug 05 06:12:56 localhost.localdomain NetworkManager[743]: <info> (tapc8d87b70-ed): link connected
Aug 05 06:12:56 localhost.localdomain dbus-daemon[736]: dbus[736]: [system] Activating via systemd: service name='org.freedesktop.machine1' unit='dbus-org.freedesktop.machine1.service'
Aug 05 06:12:56 localhost.localdomain dbus[736]: [system] Activating via systemd: service name='org.freedesktop.machine1' unit='dbus-org.freedesktop.machine1.service'
Aug 05 06:12:56 localhost.localdomain systemd[1]: Created slice Virtual Machine and Container Slice.
Aug 05 06:12:56 localhost.localdomain systemd[1]: Starting Virtual Machine and Container Slice.
Aug 05 06:12:56 localhost.localdomain systemd[1]: Starting Virtual Machine and Container Registration Service...
Aug 05 06:12:56 localhost.localdomain kernel: SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
Aug 05 06:12:56 localhost.localdomain dbus-daemon[736]: dbus[736]: [system] Successfully activated service 'org.freedesktop.machine1'
Aug 05 06:12:56 localhost.localdomain dbus[736]: [system] Successfully activated service 'org.freedesktop.machine1'
Aug 05 06:12:56 localhost.localdomain systemd[1]: Started Virtual Machine and Container Registration Service.
Aug 05 06:12:56 localhost.localdomain systemd-machined[3006]: New machine qemu-1-instance-00000007.
Aug 05 06:12:56 localhost.localdomain systemd[1]: Started Virtual Machine qemu-1-instance-00000007.
Aug 05 06:12:56 localhost.localdomain systemd[1]: Starting Virtual Machine qemu-1-instance-00000007.
Aug 05 06:12:57 localhost.localdomain kvm[3011]: 1 guest now active
Aug 05 06:12:57 localhost.localdomain kernel: kvm: zapping shadow pages for mmio generation wraparound
Aug 05 06:12:57 localhost.localdomain kernel: kvm: zapping shadow pages for mmio generation wraparound
### 出错的
Aug 04 23:07:34 localhost.localdomain sudo[5933]: nova : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/var/lib/kolla/venv/bin/nova-rootwrap /etc/nova/rootwrap.conf touch -c /var/lib/nova/i
Aug 04 23:07:37 localhost.localdomain sudo[5961]: nova : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/var/lib/kolla/venv/bin/nova-rootwrap /etc/nova/rootwrap.conf privsep-helper --config-
Aug 04 23:07:38 localhost.localdomain kernel: warning: `privsep-helper' uses deprecated v2 capabilities in a way that may be insecure.
Aug 04 23:07:39 localhost.localdomain ovs-vsctl[5980]: ovs|00001|vsctl|INFO|Called as ovs-vsctl -- --may-exist add-br br-int -- set Bridge br-int datapath_type=system
Aug 04 23:07:39 localhost.localdomain kernel: tun: Universal TUN/TAP device driver, 1.6
Aug 04 23:07:39 localhost.localdomain kernel: tun: (C) 1999-2004 Max Krasnyansky <maxk@qualcomm.com>
Aug 04 23:07:39 localhost.localdomain NetworkManager[745]: <info> (tap2960ed0a-bd): new Tun device (carrier: OFF, driver: 'tun', ifindex: 10)
Aug 04 23:07:39 localhost.localdomain ovs-vsctl[5992]: ovs|00001|vsctl|INFO|Called as ovs-vsctl --timeout=5 -- --if-exists del-port tap2960ed0a-bd -- add-port br-int tap2960ed0a-bd -- set I
Aug 04 23:07:39 localhost.localdomain kernel: device tap2960ed0a-bd entered promiscuous mode
Aug 04 23:07:39 localhost.localdomain NetworkManager[745]: <info> (tap2960ed0a-bd): enslaved to non-master-type device ovs-system; ignoring
Aug 04 23:07:39 localhost.localdomain kernel: Netfilter messages via NETLINK v0.30.
Aug 04 23:07:39 localhost.localdomain kernel: ctnetlink v0.93: registering with nfnetlink.
Aug 04 23:07:39 localhost.localdomain NetworkManager[745]: <info> (tap2960ed0a-bd): enslaved to non-master-type device ovs-system; ignoring
Aug 04 23:07:39 localhost.localdomain NetworkManager[745]: <info> (tap2960ed0a-bd): link connected
Aug 04 23:07:39 localhost.localdomain dbus-daemon[736]: dbus[736]: [system] Activating via systemd: service name='org.freedesktop.machine1' unit='dbus-org.freedesktop.machine1.service'
Aug 04 23:07:39 localhost.localdomain dbus[736]: [system] Activating via systemd: service name='org.freedesktop.machine1' unit='dbus-org.freedesktop.machine1.service'
Aug 04 23:07:39 localhost.localdomain systemd[1]: Created slice Virtual Machine and Container Slice.
Aug 04 23:07:39 localhost.localdomain systemd[1]: Starting Virtual Machine and Container Slice.
Aug 04 23:07:39 localhost.localdomain systemd[1]: Starting Virtual Machine and Container Registration Service...
Aug 04 23:07:39 localhost.localdomain kernel: IPVS: Creating netns size=2040 id=3
Aug 04 23:07:39 localhost.localdomain kernel: SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
Aug 04 23:07:39 localhost.localdomain dbus-daemon[736]: dbus[736]: [system] Successfully activated service 'org.freedesktop.machine1'
Aug 04 23:07:39 localhost.localdomain dbus[736]: [system] Successfully activated service 'org.freedesktop.machine1'
Aug 04 23:07:39 localhost.localdomain systemd[1]: Started Virtual Machine and Container Registration Service.
Aug 04 23:07:39 localhost.localdomain systemd-machined[6002]: New machine qemu-1-instance-00000008.
Aug 04 23:07:39 localhost.localdomain systemd[1]: Started Virtual Machine qemu-1-instance-00000008.
Aug 04 23:07:39 localhost.localdomain systemd[1]: Starting Virtual Machine qemu-1-instance-00000008.
Aug 04 23:08:09 localhost.localdomain kernel: device tap2960ed0a-bd left promiscuous mode
Aug 04 23:08:09 localhost.localdomain NetworkManager[745]: <warn> (tap2960ed0a-bd): failed to disable userspace IPv6LL address handling
Aug 04 23:08:10 localhost.localdomain systemd-machined[6002]: Machine qemu-1-instance-00000008 terminated.
Aug 04 23:08:10 localhost.localdomain ovs-vsctl[6111]: ovs|00001|vsctl|INFO|Called as ovs-vsctl --timeout=5 -- --if-exists del-port tap2960ed0a-bd
分析上面的日志可以得出是tap出了问题导致虚拟机创建失败,查看正常环境和异常环境,发现docker版本不同,正常的是1.12.0,不正常的是1.12.5(由于时间问题,只能排查到这里)
Aug 04 23:08:09 localhost.localdomain kernel: device tap2960ed0a-bd left promiscuous mode
Aug 04 23:08:09 localhost.localdomain NetworkManager[745]: <warn> (tap2960ed0a-bd): failed to disable userspace IPv6LL address handling
Aug 04 23:08:10 localhost.localdomain systemd-machined[6002]: Machine qemu-1-instance-00000008 terminated.
Aug 04 23:08:10 localhost.localdomain ovs-vsctl[6111]: ovs|00001|vsctl|INFO|Called as ovs-vsctl --timeout=5 -- --if-exists del-port tap2960ed0a-bd