虚拟创建失败之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-qemux2d2x2dinstancex2d00000004.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-qemux2d2x2dinstancex2d00000004.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-qemux2d2x2dinstancex2d00000004.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

参考文档

DBus学习笔记
machined

原文地址:https://www.cnblogs.com/silvermagic/p/7666194.html