yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1692984] [NEW] VM boot fails with "TCG doesn't support requested feature: CPUID.01H:ECX.vmx"

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Ihar Hrachyshka <1692984@xxxxxxxxxxxxxxxxxx>
Date: Tue, 23 May 2017 16:44:45 -0000
Reply-to: Bug 1692984 <1692984@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

Example: http://logs.openstack.org/83/466983/1/check/gate-tempest-dsvm-
neutron-linuxbridge-ubuntu-xenial/bd69e6b/console.html

2017-05-23 03:28:58.049054 | Captured traceback-1:
2017-05-23 03:28:58.049065 | ~~~~~~~~~~~~~~~~~~~~~
2017-05-23 03:28:58.049079 |     Traceback (most recent call last):
2017-05-23 03:28:58.049103 |       File "tempest/api/compute/servers/test_server_actions.py", line 58, in tearDown
2017-05-23 03:28:58.049118 |         self.server_check_teardown()
2017-05-23 03:28:58.049141 |       File "tempest/api/compute/base.py", line 168, in server_check_teardown
2017-05-23 03:28:58.049153 |         cls.server_id, 'ACTIVE')
2017-05-23 03:28:58.049187 |       File "tempest/common/waiters.py", line 76, in wait_for_server_status
2017-05-23 03:28:58.049199 |         server_id=server_id)
2017-05-23 03:28:58.049232 |     tempest.exceptions.BuildErrorException: Server c5817b9a-a6bc-4305-9b69-0a83da64a58e failed to build and is in ERROR status
2017-05-23 03:28:58.049409 |     Details: {u'created': u'2017-05-23T03:04:30Z', u'message': u"internal error: process exited while connecting to monitor: warning: TCG doesn't support requested feature: CPUID.01H:ECX.vmx [bit 5]\n2017-05-23T03:04:29.489168Z qemu-system-x86_64: terminating on signal 15 from pid 30399 (/usr/sbin/libvirtd)", u'code': 500}

In nova-compute log, we see:

May 23 03:04:30.104411 ubuntu-xenial-osic-cloud1-s3500-8933127 nova-compute[22285]: ERROR oslo_messaging.rpc.server libvirtError: internal error: process exited while connecting to monitor: warning: TCG doesn't support requested feature: CPUID.01H:ECX.vmx [bit 5]
May 23 03:04:30.104503 ubuntu-xenial-osic-cloud1-s3500-8933127 nova-compute[22285]: ERROR oslo_messaging.rpc.server 2017-05-23T03:04:29.489168Z qemu-system-x86_64: terminating on signal 15 from pid 30399 (/usr/sbin/libvirtd)

Nothing interesting in syslog.

In libvirt log:

2017-05-23 03:04:29.489+0000: 30399: debug : qemuMonitorJSONIOProcessLine:191 : Line [{"QMP": {"version": {"qemu": {"micro": 0, "minor": 8, "major": 2}, "package": "(Debian 1:2.8+dfsg-3ubuntu2~cloud0)"}, "capabilities": []}}]
2017-05-23 03:04:29.489+0000: 30399: debug : qemuMonitorJSONIOProcess:260 : Total used 140 bytes out of 140 available in buffer
2017-05-23 03:04:29.489+0000: 30399: info : qemuMonitorIOWrite:534 : QEMU_MONITOR_IO_WRITE: mon=0x7f57f400d170 buf={"execute":"qmp_capabilities","id":"libvirt-1"}
 len=49 ret=49 errno=0
2017-05-23 03:04:29.506+0000: 30399: debug : virNetlinkEventCallback:641 : dispatching to max 0 clients, called from event watch 7
2017-05-23 03:04:29.506+0000: 30399: debug : virNetlinkEventCallback:654 : event not handled.
2017-05-23 03:04:29.507+0000: 30399: debug : virNetlinkEventCallback:641 : dispatching to max 0 clients, called from event watch 7
2017-05-23 03:04:29.507+0000: 30399: debug : virNetlinkEventCallback:654 : event not handled.
2017-05-23 03:04:29.507+0000: 30399: debug : virNetlinkEventCallback:641 : dispatching to max 0 clients, called from event watch 7
2017-05-23 03:04:29.507+0000: 30399: debug : virNetlinkEventCallback:654 : event not handled.
2017-05-23 03:04:29.530+0000: 30399: error : qemuMonitorIORead:586 : Unable to read from monitor: Connection reset by peer
2017-05-23 03:04:29.530+0000: 30399: debug : qemuDomainLogContextRead:4166 : Context read 0x7f57f4021320 manager=0x7f57f4003a60 inode=5758332 pos=4109
2017-05-23 03:04:29.530+0000: 30399: error : qemuProcessReportLogError:1802 : internal error: qemu unexpectedly closed the monitor: warning: TCG doesn't support requested feature: CPUID.01H:ECX.vmx [bit 5]
2017-05-23T03:04:29.489168Z qemu-system-x86_64: terminating on signal 15 from pid 30399 (/usr/sbin/libvirtd)
2017-05-23 03:04:29.530+0000: 30399: debug : qemuMonitorIO:743 : Error on monitor internal error: qemu unexpectedly closed the monitor: warning: TCG doesn't support requested feature: CPUID.01H:ECX.vmx [bit 5]
2017-05-23T03:04:29.489168Z qemu-system-x86_64: terminating on signal 15 from pid 30399 (/usr/sbin/libvirtd)
2017-05-23 03:04:29.530+0000: 30399: debug : qemuMonitorIO:774 : Triggering error callback
2017-05-23 03:04:29.530+0000: 30399: debug : qemuProcessHandleMonitorError:337 : Received error on 0x7f57dc00aca0 'instance-00000054'
2017-05-23 03:04:29.530+0000: 30401: debug : qemuMonitorSend:1021 : Send command resulted in error internal error: qemu unexpectedly closed the monitor: warning: TCG doesn't support requested feature: CPUID.01H:ECX.vmx [bit 5]
2017-05-23T03:04:29.489168Z qemu-system-x86_64: terminating on signal 15 from pid 30399 (/usr/sbin/libvirtd)
2017-05-23 03:04:29.530+0000: 30401: debug : qemuMonitorJSONCommandWithFd:301 : Receive command reply ret=-1 rxObject=(nil)
2017-05-23 03:04:29.685+0000: 31667: debug : qemuDomainObjBeginJobInternal:3268 : Starting job: destroy (vm=0x7f57dc00aca0 name=instance-00000054, current job=async nested async=start)
2017-05-23 03:04:29.685+0000: 31667: debug : qemuDomainObjBeginJobInternal:3291 : Waiting for job (vm=0x7f57dc00aca0 name=instance-00000054)
2017-05-23 03:04:29.685+0000: 30399: debug : virObjectEventNew:640 : obj=0x55db97ad3830
2017-05-23 03:04:29.685+0000: 30399: debug : virObjectEventDispose:134 : obj=0x55db97ad3830
2017-05-23 03:04:29.685+0000: 30399: debug : qemuMonitorIO:743 : Error on monitor internal error: qemu unexpectedly closed the monitor: warning: TCG doesn't support requested feature: CPUID.01H:ECX.vmx [bit 5]
2017-05-23T03:04:29.489168Z qemu-system-x86_64: terminating on signal 15 from pid 30399 (/usr/sbin/libvirtd)
2017-05-23 03:04:29.685+0000: 30401: debug : qemuDomainObjExitMonitorInternal:3555 : Exited monitor (mon=0x7f57f400d170 vm=0x7f57dc00aca0 name=instance-00000054)
2017-05-23 03:04:29.685+0000: 30401: debug : qemuDomainObjEndJob:3463 : Stopping job: async nested (async=start vm=0x7f57dc00aca0 name=instance-00000054)
2017-05-23 03:04:29.685+0000: 30399: debug : qemuMonitorIO:764 : Triggering EOF callback
2017-05-23 03:04:29.685+0000: 30401: debug : qemuDomainLogContextRead:4166 : Context read 0x7f57f4021320 manager=0x7f57f4003a60 inode=5758332 pos=4109
2017-05-23 03:04:29.685+0000: 30401: error : qemuProcessReportLogError:1802 : internal error: process exited while connecting to monitor: warning: TCG doesn't support requested feature: CPUID.01H:ECX.vmx [bit 5]
2017-05-23T03:04:29.489168Z qemu-system-x86_64: terminating on signal 15 from pid 30399 (/usr/sbin/libvirtd)

** Affects: neutron
     Importance: High
         Status: New

** Affects: nova
     Importance: Undecided
         Status: New


** Tags: gate-failure libvirt

** Also affects: neutron
   Importance: Undecided
       Status: New

** Changed in: neutron
   Importance: Undecided => High

** Tags added: gate-failure

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/1692984

Title:
  VM boot fails with "TCG doesn't support requested feature:
  CPUID.01H:ECX.vmx"

Status in neutron:
  New
Status in OpenStack Compute (nova):
  New

Bug description:
  Example: http://logs.openstack.org/83/466983/1/check/gate-tempest-
  dsvm-neutron-linuxbridge-ubuntu-xenial/bd69e6b/console.html

  2017-05-23 03:28:58.049054 | Captured traceback-1:
  2017-05-23 03:28:58.049065 | ~~~~~~~~~~~~~~~~~~~~~
  2017-05-23 03:28:58.049079 |     Traceback (most recent call last):
  2017-05-23 03:28:58.049103 |       File "tempest/api/compute/servers/test_server_actions.py", line 58, in tearDown
  2017-05-23 03:28:58.049118 |         self.server_check_teardown()
  2017-05-23 03:28:58.049141 |       File "tempest/api/compute/base.py", line 168, in server_check_teardown
  2017-05-23 03:28:58.049153 |         cls.server_id, 'ACTIVE')
  2017-05-23 03:28:58.049187 |       File "tempest/common/waiters.py", line 76, in wait_for_server_status
  2017-05-23 03:28:58.049199 |         server_id=server_id)
  2017-05-23 03:28:58.049232 |     tempest.exceptions.BuildErrorException: Server c5817b9a-a6bc-4305-9b69-0a83da64a58e failed to build and is in ERROR status
  2017-05-23 03:28:58.049409 |     Details: {u'created': u'2017-05-23T03:04:30Z', u'message': u"internal error: process exited while connecting to monitor: warning: TCG doesn't support requested feature: CPUID.01H:ECX.vmx [bit 5]\n2017-05-23T03:04:29.489168Z qemu-system-x86_64: terminating on signal 15 from pid 30399 (/usr/sbin/libvirtd)", u'code': 500}

  In nova-compute log, we see:

  May 23 03:04:30.104411 ubuntu-xenial-osic-cloud1-s3500-8933127 nova-compute[22285]: ERROR oslo_messaging.rpc.server libvirtError: internal error: process exited while connecting to monitor: warning: TCG doesn't support requested feature: CPUID.01H:ECX.vmx [bit 5]
  May 23 03:04:30.104503 ubuntu-xenial-osic-cloud1-s3500-8933127 nova-compute[22285]: ERROR oslo_messaging.rpc.server 2017-05-23T03:04:29.489168Z qemu-system-x86_64: terminating on signal 15 from pid 30399 (/usr/sbin/libvirtd)

  Nothing interesting in syslog.

  In libvirt log:

  2017-05-23 03:04:29.489+0000: 30399: debug : qemuMonitorJSONIOProcessLine:191 : Line [{"QMP": {"version": {"qemu": {"micro": 0, "minor": 8, "major": 2}, "package": "(Debian 1:2.8+dfsg-3ubuntu2~cloud0)"}, "capabilities": []}}]
  2017-05-23 03:04:29.489+0000: 30399: debug : qemuMonitorJSONIOProcess:260 : Total used 140 bytes out of 140 available in buffer
  2017-05-23 03:04:29.489+0000: 30399: info : qemuMonitorIOWrite:534 : QEMU_MONITOR_IO_WRITE: mon=0x7f57f400d170 buf={"execute":"qmp_capabilities","id":"libvirt-1"}
   len=49 ret=49 errno=0
  2017-05-23 03:04:29.506+0000: 30399: debug : virNetlinkEventCallback:641 : dispatching to max 0 clients, called from event watch 7
  2017-05-23 03:04:29.506+0000: 30399: debug : virNetlinkEventCallback:654 : event not handled.
  2017-05-23 03:04:29.507+0000: 30399: debug : virNetlinkEventCallback:641 : dispatching to max 0 clients, called from event watch 7
  2017-05-23 03:04:29.507+0000: 30399: debug : virNetlinkEventCallback:654 : event not handled.
  2017-05-23 03:04:29.507+0000: 30399: debug : virNetlinkEventCallback:641 : dispatching to max 0 clients, called from event watch 7
  2017-05-23 03:04:29.507+0000: 30399: debug : virNetlinkEventCallback:654 : event not handled.
  2017-05-23 03:04:29.530+0000: 30399: error : qemuMonitorIORead:586 : Unable to read from monitor: Connection reset by peer
  2017-05-23 03:04:29.530+0000: 30399: debug : qemuDomainLogContextRead:4166 : Context read 0x7f57f4021320 manager=0x7f57f4003a60 inode=5758332 pos=4109
  2017-05-23 03:04:29.530+0000: 30399: error : qemuProcessReportLogError:1802 : internal error: qemu unexpectedly closed the monitor: warning: TCG doesn't support requested feature: CPUID.01H:ECX.vmx [bit 5]
  2017-05-23T03:04:29.489168Z qemu-system-x86_64: terminating on signal 15 from pid 30399 (/usr/sbin/libvirtd)
  2017-05-23 03:04:29.530+0000: 30399: debug : qemuMonitorIO:743 : Error on monitor internal error: qemu unexpectedly closed the monitor: warning: TCG doesn't support requested feature: CPUID.01H:ECX.vmx [bit 5]
  2017-05-23T03:04:29.489168Z qemu-system-x86_64: terminating on signal 15 from pid 30399 (/usr/sbin/libvirtd)
  2017-05-23 03:04:29.530+0000: 30399: debug : qemuMonitorIO:774 : Triggering error callback
  2017-05-23 03:04:29.530+0000: 30399: debug : qemuProcessHandleMonitorError:337 : Received error on 0x7f57dc00aca0 'instance-00000054'
  2017-05-23 03:04:29.530+0000: 30401: debug : qemuMonitorSend:1021 : Send command resulted in error internal error: qemu unexpectedly closed the monitor: warning: TCG doesn't support requested feature: CPUID.01H:ECX.vmx [bit 5]
  2017-05-23T03:04:29.489168Z qemu-system-x86_64: terminating on signal 15 from pid 30399 (/usr/sbin/libvirtd)
  2017-05-23 03:04:29.530+0000: 30401: debug : qemuMonitorJSONCommandWithFd:301 : Receive command reply ret=-1 rxObject=(nil)
  2017-05-23 03:04:29.685+0000: 31667: debug : qemuDomainObjBeginJobInternal:3268 : Starting job: destroy (vm=0x7f57dc00aca0 name=instance-00000054, current job=async nested async=start)
  2017-05-23 03:04:29.685+0000: 31667: debug : qemuDomainObjBeginJobInternal:3291 : Waiting for job (vm=0x7f57dc00aca0 name=instance-00000054)
  2017-05-23 03:04:29.685+0000: 30399: debug : virObjectEventNew:640 : obj=0x55db97ad3830
  2017-05-23 03:04:29.685+0000: 30399: debug : virObjectEventDispose:134 : obj=0x55db97ad3830
  2017-05-23 03:04:29.685+0000: 30399: debug : qemuMonitorIO:743 : Error on monitor internal error: qemu unexpectedly closed the monitor: warning: TCG doesn't support requested feature: CPUID.01H:ECX.vmx [bit 5]
  2017-05-23T03:04:29.489168Z qemu-system-x86_64: terminating on signal 15 from pid 30399 (/usr/sbin/libvirtd)
  2017-05-23 03:04:29.685+0000: 30401: debug : qemuDomainObjExitMonitorInternal:3555 : Exited monitor (mon=0x7f57f400d170 vm=0x7f57dc00aca0 name=instance-00000054)
  2017-05-23 03:04:29.685+0000: 30401: debug : qemuDomainObjEndJob:3463 : Stopping job: async nested (async=start vm=0x7f57dc00aca0 name=instance-00000054)
  2017-05-23 03:04:29.685+0000: 30399: debug : qemuMonitorIO:764 : Triggering EOF callback
  2017-05-23 03:04:29.685+0000: 30401: debug : qemuDomainLogContextRead:4166 : Context read 0x7f57f4021320 manager=0x7f57f4003a60 inode=5758332 pos=4109
  2017-05-23 03:04:29.685+0000: 30401: error : qemuProcessReportLogError:1802 : internal error: process exited while connecting to monitor: warning: TCG doesn't support requested feature: CPUID.01H:ECX.vmx [bit 5]
  2017-05-23T03:04:29.489168Z qemu-system-x86_64: terminating on signal 15 from pid 30399 (/usr/sbin/libvirtd)

To manage notifications about this bug go to:
https://bugs.launchpad.net/neutron/+bug/1692984/+subscriptions
Follow ups

[Bug 1692984] Re: VM boot fails with "TCG doesn't support requested feature: CPUID.01H:ECX.vmx"
From: Launchpad Bug Tracker, 2017-12-16
[Bug 1692984] Re: VM boot fails with "TCG doesn't support requested feature: CPUID.01H:ECX.vmx"
From: Launchpad Bug Tracker, 2017-12-16