Since this is not hitting on tempest anymore, moving to Fix Released
** Changed in: tempest
Status: Fix Committed => Fix Released
--
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/1251920
Title:
Tempest failures due to failure to return console logs from an
instance
Status in OpenStack Compute (Nova):
Invalid
Status in OpenStack Compute (nova) havana series:
Fix Committed
Status in Tempest:
Fix Released
Bug description:
Logstash search:
http://logstash.openstack.org/#eyJzZWFyY2giOiJmaWxlbmFtZTpjb25zb2xlLmh0bWwgQU5EIG1lc3NhZ2U6XCJhc3NlcnRpb25lcnJvcjogY29uc29sZSBvdXRwdXQgd2FzIGVtcHR5XCIiLCJmaWVsZHMiOltdLCJvZmZzZXQiOjAsInRpbWVmcmFtZSI6IjYwNDgwMCIsImdyYXBobW9kZSI6ImNvdW50IiwidGltZSI6eyJ1c2VyX2ludGVydmFsIjowfSwic3RhbXAiOjEzODQ2NDEwNzIxODl9
An example failure is http://logs.openstack.org/92/55492/8/check
/check-tempest-devstack-vm-full/ef3a4a4/console.html
console.html
===========
2013-11-16 21:54:27.998 | 2013-11-16 21:41:20,775 Request: POST
http://127.0.0.1:8774/v2/3f6934d9aabf467aa8bc51397ccfa782/servers/10aace14-23c1-4cec-9bfd-2c873df1fbee/action
2013-11-16 21:54:27.998 | 2013-11-16 21:41:20,776 Request Headers:
{'Content-Type': 'application/json', 'Accept': 'application/json',
'X-Auth-Token': '<Token omitted>'}
2013-11-16 21:54:27.998 | 2013-11-16 21:41:20,776 Request Body:
{"os-getConsoleOutput": {"length": 10}}
2013-11-16 21:54:27.998 | 2013-11-16 21:41:21,000 Response Status: 200
2013-11-16 21:54:27.999 | 2013-11-16 21:41:21,001 Nova request id:
req-7a2ee0ab-c977-4957-abb5-1d84191bf30c
2013-11-16 21:54:27.999 | 2013-11-16 21:41:21,001 Response Headers:
{'content-length': '14', 'date': 'Sat, 16 Nov 2013 21:41:20 GMT',
'content-type': 'application/json', 'connection': 'close'}
2013-11-16 21:54:27.999 | 2013-11-16 21:41:21,001 Response Body: {"output":
""}
2013-11-16 21:54:27.999 | }}}
2013-11-16 21:54:27.999 |
2013-11-16 21:54:27.999 | Traceback (most recent call last):
2013-11-16 21:54:27.999 | File
"tempest/api/compute/servers/test_server_actions.py", line 281, in
test_get_console_output
2013-11-16 21:54:28.000 | self.wait_for(get_output)
2013-11-16 21:54:28.000 | File "tempest/api/compute/base.py", line 133, in
wait_for
2013-11-16 21:54:28.000 | condition()
2013-11-16 21:54:28.000 | File
"tempest/api/compute/servers/test_server_actions.py", line 278, in get_output
2013-11-16 21:54:28.000 | self.assertTrue(output, "Console output was
empty.")
2013-11-16 21:54:28.000 | File "/usr/lib/python2.7/unittest/case.py", line
420, in assertTrue
2013-11-16 21:54:28.000 | raise self.failureException(msg)
2013-11-16 21:54:28.001 | AssertionError: Console output was empty.
n-api
====
2013-11-16 21:41:20.782 DEBUG nova.api.openstack.wsgi
[req-7a2ee0ab-c977-4957-abb5-1d84191bf30c
ServerActionsTestJSON-tempest-2102529866-user
ServerActionsTestJSON-tempest-2102529866-tenant] Action: 'action', body:
{"os-getConsoleOutput": {"length": 10}} _process_stack
/opt/stack/new/nova/nova/api/openstack/wsgi.py:963
2013-11-16 21:41:20.782 DEBUG nova.api.openstack.wsgi
[req-7a2ee0ab-c977-4957-abb5-1d84191bf30c
ServerActionsTestJSON-tempest-2102529866-user
ServerActionsTestJSON-tempest-2102529866-tenant] Calling method <bound method
ConsoleOutputController.get_console_output of
<nova.api.openstack.compute.contrib.console_output.ConsoleOutputController
object at 0x3c1f990>> _process_stack
/opt/stack/new/nova/nova/api/openstack/wsgi.py:964
2013-11-16 21:41:20.865 DEBUG nova.openstack.common.rpc.amqp
[req-7a2ee0ab-c977-4957-abb5-1d84191bf30c
ServerActionsTestJSON-tempest-2102529866-user
ServerActionsTestJSON-tempest-2102529866-tenant] Making synchronous call on
compute.devstack-precise-hpcloud-az2-663635 ... multicall
/opt/stack/new/nova/nova/openstack/common/rpc/amqp.py:553
2013-11-16 21:41:20.866 DEBUG nova.openstack.common.rpc.amqp
[req-7a2ee0ab-c977-4957-abb5-1d84191bf30c
ServerActionsTestJSON-tempest-2102529866-user
ServerActionsTestJSON-tempest-2102529866-tenant] MSG_ID is
a93dceabf6a441eb850b5fbb012d661f multicall
/opt/stack/new/nova/nova/openstack/common/rpc/amqp.py:556
2013-11-16 21:41:20.866 DEBUG nova.openstack.common.rpc.amqp
[req-7a2ee0ab-c977-4957-abb5-1d84191bf30c
ServerActionsTestJSON-tempest-2102529866-user
ServerActionsTestJSON-tempest-2102529866-tenant] UNIQUE_ID is
706ab69dc066440fbe1bd7766b73d953. _add_unique_id
/opt/stack/new/nova/nova/openstack/common/rpc/amqp.py:341
2013-11-16 21:41:20.869 22679 DEBUG amqp [-] Closed channel #1 _do_close
/usr/local/lib/python2.7/dist-packages/amqp/channel.py:95
2013-11-16 21:41:20.869 22679 DEBUG amqp [-] using channel_id: 1 __init__
/usr/local/lib/python2.7/dist-packages/amqp/channel.py:71
2013-11-16 21:41:20.870 22679 DEBUG amqp [-] Channel open _open_ok
/usr/local/lib/python2.7/dist-packages/amqp/channel.py:429
2013-11-16 21:41:20.999 INFO nova.osapi_compute.wsgi.server
[req-7a2ee0ab-c977-4957-abb5-1d84191bf30c
ServerActionsTestJSON-tempest-2102529866-user
ServerActionsTestJSON-tempest-2102529866-tenant] 127.0.0.1 "POST
/v2/3f6934d9aabf467aa8bc51397ccfa782/servers/10aace14-23c1-4cec-9bfd-2c873df1fbee/action
HTTP/1.1" status: 200 len: 205 time: 0.2208662
n-cpu
=====
2013-11-16 21:41:20.878 23086 DEBUG nova.openstack.common.rpc.amqp [-]
received {u'_msg_id': u'a93dceabf6a441eb850b5fbb012d661f',
u'_context_quota_class': None, u'_context_request_id':
u'req-7a2ee0ab-c977-4957-abb5-1d84191bf30c', u'_context_service_catalog':
[{u'endpoints_links': [], u'endpoints': [{u'adminURL':
u'http://127.0.0.1:8776/v1/3f6934d9aabf467aa8bc51397ccfa782', u'region':
u'RegionOne', u'publicURL':
u'http://127.0.0.1:8776/v1/3f6934d9aabf467aa8bc51397ccfa782', u'internalURL':
u'http://127.0.0.1:8776/v1/3f6934d9aabf467aa8bc51397ccfa782', u'id':
u'5725cc234a8346408dfe343aea62d3aa'}], u'type': u'volume', u'name':
u'cinder'}], u'_context_auth_token': '<SANITIZED>', u'_context_user_id':
u'eae9401ba3794296ae8248748ef8e26e', u'_reply_q':
u'reply_546cb0ef381e4ff29c76ee96eba21c22', u'namespace': None,
u'_context_is_admin': False, u'version': u'2.0', u'_context_timestamp':
u'2013-11-16T21:41:20.781052', u'_context_user':
u'eae9401ba3794296ae8248748ef8e26e', u'method': u'get_conso
le_output', u'_context_remote_address': u'127.0.0.1', u'_context_roles':
[u'_member_'], u'args': {u'instance': {u'vm_state': u'active',
u'availability_zone': None, u'terminated_at': None, u'ephemeral_gb': 0,
u'instance_type_id': 6, u'user_data': None, u'cleaned': False, u'vm_mode':
None, u'deleted_at': None, u'reservation_id': u'r-dnps4t4l', u'id': 40,
u'security_groups': [{u'deleted_at': None, u'user_id':
u'eae9401ba3794296ae8248748ef8e26e', u'description': u'default', u'deleted':
False, u'created_at': u'2013-11-16T21:37:03.000000', u'updated_at': None,
u'project_id': u'3f6934d9aabf467aa8bc51397ccfa782', u'id': 47, u'name':
u'default'}], u'disable_terminate': False, u'root_device_name': u'/dev/vda',
u'display_name': u'ServerActionsTestJSON-instance-tempest-308881308', u'uuid':
u'10aace14-23c1-4cec-9bfd-2c873df1fbee', u'default_swap_device': None,
u'info_cache': {u'instance_uuid': u'10aace14-23c1-4cec-9bfd-2c873df1fbee',
u'deleted': False, u'created_at': u'2013-11-16T21:37:03.000000
', u'updated_at': u'2013-11-16T21:37:08.000000', u'network_info':
[{u'ovs_interfaceid': None, u'network': {u'bridge': u'br100', u'label':
u'private', u'meta': {u'tenant_id': None, u'should_create_bridge': True,
u'bridge_interface': u'eth0'}, u'id': u'44a93331-6869-4e8a-8742-f92bb9cea7b5',
u'subnets': [{u'ips': [{u'meta': {}, u'type': u'fixed', u'floating_ips': [],
u'version': 4, u'address': u'10.1.0.6'}], u'version': 4, u'meta':
{u'dhcp_server': u'10.1.0.1'}, u'dns': [{u'meta': {}, u'type': u'dns',
u'version': 4, u'address': u'8.8.4.4'}], u'routes': [], u'cidr':
u'10.1.0.0/24', u'gateway': {u'meta': {}, u'type': u'gateway', u'version': 4,
u'address': u'10.1.0.1'}}, {u'ips': [], u'version': None, u'meta':
{u'dhcp_server': None}, u'dns': [], u'routes': [], u'cidr': None, u'gateway':
{u'meta': {}, u'type': u'gateway', u'version': None, u'address': None}}]},
u'devname': None, u'qbh_params': None, u'meta': {}, u'address':
u'fa:16:3e:38:6d:dd', u'type': u'bridge', u'id': u'2bd53919-68f4-4
fdb-bd51-dfc3238c6cbb', u'qbg_params': None}], u'deleted_at': None},
u'hostname': u'serveractionstestjson-instance-tempest-308881308',
u'launched_on': u'devstack-precise-hpcloud-az2-663635', u'display_description':
u'ServerActionsTestJSON-instance-tempest-308881308', u'key_data': None,
u'deleted': False, u'config_drive': u'', u'power_state': 1,
u'default_ephemeral_device': None, u'progress': 0, u'project_id':
u'3f6934d9aabf467aa8bc51397ccfa782', u'launched_at':
u'2013-11-16T21:37:18.000000', u'scheduled_at': u'2013-11-16T21:37:04.000000',
u'node': u'devstack-precise-hpcloud-az2-663635', u'ramdisk_id':
u'cd16eea0-986d-443f-a345-3b82c8f4fce6', u'access_ip_v6': None,
u'access_ip_v4': None, u'kernel_id': u'b1803c3b-8f66-408b-9105-73568c7181ca',
u'key_name': None, u'updated_at': u'2013-11-16T21:38:00.000000', u'host':
u'devstack-precise-hpcloud-az2-663635', u'user_id':
u'eae9401ba3794296ae8248748ef8e26e', u'system_metadata': {u'image_kernel_id':
u'b1803c3b-8f66-408b-9105-73568c7181ca', u
'instance_type_memory_mb': u'64', u'instance_type_swap': u'0',
u'instance_type_vcpu_weight': None, u'instance_type_root_gb': u'0',
u'instance_type_id': u'6', u'image_ramdisk_id':
u'cd16eea0-986d-443f-a345-3b82c8f4fce6', u'instance_type_name': u'm1.nano',
u'instance_type_ephemeral_gb': u'0', u'instance_type_rxtx_factor': u'1.0',
u'image_disk_format': u'ami', u'instance_type_flavorid': u'42',
u'image_container_format': u'ami', u'instance_type_vcpus': u'1',
u'image_min_ram': u'0', u'image_min_disk': u'0', u'image_base_image_ref':
u'11f4317b-d294-4d21-b2c4-2d7198aa32b8'}, u'task_state': None,
u'shutdown_terminate': False, u'cell_name': None, u'root_gb': 0, u'locked':
False, u'name': u'instance-00000028', u'created_at':
u'2013-11-16T21:37:03.000000', u'locked_by': None, u'launch_index': 0,
u'memory_mb': 64, u'vcpus': 1, u'image_ref':
u'11f4317b-d294-4d21-b2c4-2d7198aa32b8', u'architecture': None,
u'auto_disk_config': False, u'os_type': None, u'metadata': {}}, u'tail_length':
10}, u'_uniq
ue_id': u'706ab69dc066440fbe1bd7766b73d953', u'_context_project_name':
u'ServerActionsTestJSON-tempest-2102529866-tenant', u'_context_read_deleted':
u'no', u'_context_tenant': u'3f6934d9aabf467aa8bc51397ccfa782',
u'_context_instance_lock_checked': False, u'_context_project_id':
u'3f6934d9aabf467aa8bc51397ccfa782', u'_context_user_name':
u'ServerActionsTestJSON-tempest-2102529866-user'} _safe_log
/opt/stack/new/nova/nova/openstack/common/rpc/common.py:277
2013-11-16 21:41:20.879 23086 DEBUG nova.openstack.common.rpc.amqp [-]
unpacked context: {'tenant': u'3f6934d9aabf467aa8bc51397ccfa782',
'project_name': u'ServerActionsTestJSON-tempest-2102529866-tenant', 'user_id':
u'eae9401ba3794296ae8248748ef8e26e', 'roles': [u'_member_'], 'timestamp':
u'2013-11-16T21:41:20.781052', 'auth_token': '<SANITIZED>', 'remote_address':
u'127.0.0.1', 'quota_class': None, 'is_admin': False, 'user':
u'eae9401ba3794296ae8248748ef8e26e', 'service_catalog': [{u'endpoints':
[{u'adminURL': u'http://127.0.0.1:8776/v1/3f6934d9aabf467aa8bc51397ccfa782',
u'region': u'RegionOne', u'id': u'5725cc234a8346408dfe343aea62d3aa',
u'internalURL': u'http://127.0.0.1:8776/v1/3f6934d9aabf467aa8bc51397ccfa782',
u'publicURL': u'http://127.0.0.1:8776/v1/3f6934d9aabf467aa8bc51397ccfa782'}],
u'endpoints_links': [], u'type': u'volume', u'name': u'cinder'}], 'request_id':
u'req-7a2ee0ab-c977-4957-abb5-1d84191bf30c', 'instance_lock_checked': False,
'project_id': u'3f6934d9aabf467aa8b
c51397ccfa782', 'user_name': u'ServerActionsTestJSON-tempest-2102529866-user',
'read_deleted': u'no'} _safe_log
/opt/stack/new/nova/nova/openstack/common/rpc/common.py:277
2013-11-16 21:41:20.880 AUDIT nova.compute.manager
[req-7a2ee0ab-c977-4957-abb5-1d84191bf30c
ServerActionsTestJSON-tempest-2102529866-user
ServerActionsTestJSON-tempest-2102529866-tenant] [instance:
10aace14-23c1-4cec-9bfd-2c873df1fbee] Get console output
2013-11-16 21:41:20.894 DEBUG nova.openstack.common.processutils
[req-7a2ee0ab-c977-4957-abb5-1d84191bf30c
ServerActionsTestJSON-tempest-2102529866-user
ServerActionsTestJSON-tempest-2102529866-tenant] Running cmd (subprocess): sudo
nova-rootwrap /etc/nova/rootwrap.conf chown 1006
/opt/stack/data/nova/instances/10aace14-23c1-4cec-9bfd-2c873df1fbee/console.log
execute /opt/stack/new/nova/nova/openstack/common/processutils.py:147
2013-11-16 21:41:20.993 DEBUG nova.openstack.common.rpc.amqp
[req-7a2ee0ab-c977-4957-abb5-1d84191bf30c
ServerActionsTestJSON-tempest-2102529866-user
ServerActionsTestJSON-tempest-2102529866-tenant] UNIQUE_ID is
7abfb6072ea44239ae71367bde0a4485. _add_unique_id
/opt/stack/new/nova/nova/openstack/common/rpc/amqp.py:341
2013-11-16 21:41:20.995 DEBUG nova.openstack.common.rpc.amqp
[req-7a2ee0ab-c977-4957-abb5-1d84191bf30c
ServerActionsTestJSON-tempest-2102529866-user
ServerActionsTestJSON-tempest-2102529866-tenant] UNIQUE_ID is
b463e1d350f441efb159170784f9ba41. _add_unique_id
/opt/stack/new/nova/nova/openstack/common/rpc/amqp.py:341
In other words, nova doesn't log much here, but I think the console
log might be genuinely empty?
To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1251920/+subscriptions
--
Mailing list: https://launchpad.net/~yahoo-eng-team
Post to : yahoo-eng-team@lists.launchpad.net
Unsubscribe : https://launchpad.net/~yahoo-eng-team
More help : https://help.launchpad.net/ListHelp
