check-tempest-dsvm-docker: Cannot start container Error mounting \'/dev/', u'code': 500

Bug #1403439 reported by Michael Berlin on 2014-12-17
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
nova-docker
Undecided
Davanum Srinivas (DIMS)
tempest
Undecided
Unassigned

Bug Description

seen here: http://logs.openstack.org/42/117442/24/check//check-tempest-dsvm-docker/a47638e/console.html

Sorry, when I hit the wrong project. I've created the bug mainly to be able to recheck this change: https://review.openstack.org/#/c/117442/

Example for tempest errors:

2014-12-16 20:31:50.078 | tempest.api.compute.servers.test_disk_config.ServerDiskConfigTestJSON.test_rebuild_server_with_manual_disk_config[gate]
2014-12-16 20:31:50.078 | -----------------------------------------------------------------------------------------------------------------------
2014-12-16 20:31:50.078 |
2014-12-16 20:31:50.078 | Captured traceback:
2014-12-16 20:31:50.078 | ~~~~~~~~~~~~~~~~~~~
2014-12-16 20:31:50.078 | Traceback (most recent call last):
2014-12-16 20:31:50.079 | File "tempest/api/compute/servers/test_disk_config.py", line 57, in test_rebuild_server_with_manual_disk_config
2014-12-16 20:31:50.079 | self.client.wait_for_server_status(server['id'], 'ACTIVE')
2014-12-16 20:31:50.079 | File "tempest/services/compute/json/servers_client.py", line 183, in wait_for_server_status
2014-12-16 20:31:50.079 | ready_wait=ready_wait)
2014-12-16 20:31:50.079 | File "tempest/common/waiters.py", line 77, in wait_for_server_status
2014-12-16 20:31:50.079 | server_id=server_id)
2014-12-16 20:31:50.079 | BuildErrorException: Server 304d3583-2f82-4a87-ba60-1aa54f13c8af failed to build and is in ERROR status
2014-12-16 20:31:50.079 | Details: {u'created': u'2014-12-16T20:20:21Z', u'message': u'404 Client Error: Not Found ("Cannot start container b290765b6ccc30e2efcff66ce9454023b1eff69eea669b46f6cecef425bfd22a: Error getting container b290765b6ccc30e2efcff66ce9454023b1eff69eea669b46f6cecef425bfd22a from driver devicemapper: Error mounting \'/dev/', u'code': 500}
2014-12-16 20:31:50.079 | Traceback (most recent call last):
2014-12-16 20:31:50.079 | _StringException: Empty attachments:
2014-12-16 20:31:50.079 | stderr
2014-12-16 20:31:50.079 | stdout
2014-12-16 20:31:50.080 |

excepts from nova compute log:

http://logs.openstack.org/42/117442/24/check//check-tempest-dsvm-docker/a47638e/logs/screen-n-cpu.txt.gz?

2014-12-16 20:20:21.167 ERROR nova.compute.manager [req-5a3efdeb-b703-4bb9-9942-5e8c0af43b68 ServerDiskConfigTestJSON-2115024492 ServerDiskConfigTestJSON-1220777223] [instance: 304d3583-2f82-4a87-ba60-1aa54f13c8af] Setting instance vm_state to ERROR
2014-12-16 20:20:21.167 14646 TRACE nova.compute.manager [instance: 304d3583-2f82-4a87-ba60-1aa54f13c8af] Traceback (most recent call last):
2014-12-16 20:20:21.167 14646 TRACE nova.compute.manager [instance: 304d3583-2f82-4a87-ba60-1aa54f13c8af] File "/opt/stack/new/nova/nova/compute/manager.py", line 6148, in _error_out_instance_on_exception
2014-12-16 20:20:21.167 14646 TRACE nova.compute.manager [instance: 304d3583-2f82-4a87-ba60-1aa54f13c8af] yield
2014-12-16 20:20:21.167 14646 TRACE nova.compute.manager [instance: 304d3583-2f82-4a87-ba60-1aa54f13c8af] File "/opt/stack/new/nova/nova/compute/manager.py", line 2869, in rebuild_instance
2014-12-16 20:20:21.167 14646 TRACE nova.compute.manager [instance: 304d3583-2f82-4a87-ba60-1aa54f13c8af] self._rebuild_default_impl(**kwargs)
2014-12-16 20:20:21.167 14646 TRACE nova.compute.manager [instance: 304d3583-2f82-4a87-ba60-1aa54f13c8af] File "/opt/stack/new/nova/nova/compute/manager.py", line 2724, in _rebuild_default_impl
2014-12-16 20:20:21.167 14646 TRACE nova.compute.manager [instance: 304d3583-2f82-4a87-ba60-1aa54f13c8af] block_device_info=new_block_device_info)
2014-12-16 20:20:21.167 14646 TRACE nova.compute.manager [instance: 304d3583-2f82-4a87-ba60-1aa54f13c8af] File "/opt/stack/new/nova-docker/novadocker/virt/docker/driver.py", line 437, in spawn
2014-12-16 20:20:21.167 14646 TRACE nova.compute.manager [instance: 304d3583-2f82-4a87-ba60-1aa54f13c8af] self._start_container(container_id, instance, network_info)
2014-12-16 20:20:21.167 14646 TRACE nova.compute.manager [instance: 304d3583-2f82-4a87-ba60-1aa54f13c8af] File "/opt/stack/new/nova-docker/novadocker/virt/docker/driver.py", line 394, in _start_container
2014-12-16 20:20:21.167 14646 TRACE nova.compute.manager [instance: 304d3583-2f82-4a87-ba60-1aa54f13c8af] self.docker.start(container_id, binds=binds, dns=dns)
2014-12-16 20:20:21.167 14646 TRACE nova.compute.manager [instance: 304d3583-2f82-4a87-ba60-1aa54f13c8af] File "/opt/stack/new/nova-docker/novadocker/virt/docker/client.py", line 36, in wrapper
2014-12-16 20:20:21.167 14646 TRACE nova.compute.manager [instance: 304d3583-2f82-4a87-ba60-1aa54f13c8af] out = f(*args, **kwds)
2014-12-16 20:20:21.167 14646 TRACE nova.compute.manager [instance: 304d3583-2f82-4a87-ba60-1aa54f13c8af] File "/usr/local/lib/python2.7/dist-packages/docker/client.py", line 975, in start
2014-12-16 20:20:21.167 14646 TRACE nova.compute.manager [instance: 304d3583-2f82-4a87-ba60-1aa54f13c8af] self._raise_for_status(res)
2014-12-16 20:20:21.167 14646 TRACE nova.compute.manager [instance: 304d3583-2f82-4a87-ba60-1aa54f13c8af] File "/usr/local/lib/python2.7/dist-packages/docker/client.py", line 89, in _raise_for_status
2014-12-16 20:20:21.167 14646 TRACE nova.compute.manager [instance: 304d3583-2f82-4a87-ba60-1aa54f13c8af] raise errors.APIError(e, response, explanation=explanation)
2014-12-16 20:20:21.167 14646 TRACE nova.compute.manager [instance: 304d3583-2f82-4a87-ba60-1aa54f13c8af] APIError: 404 Client Error: Not Found ("Cannot start container b290765b6ccc30e2efcff66ce9454023b1eff69eea669b46f6cecef425bfd22a: Error getting container b290765b6ccc30e2efcff66ce9454023b1eff69eea669b46f6cecef425bfd22a from driver devicemapper: Error mounting '/dev/mapper/docker-253:1-917682-b290765b6ccc30e2efcff66ce9454023b1eff69eea669b46f6cecef425bfd22a' on '/var/lib/docker/devicemapper/mnt/b290765b6ccc30e2efcff66ce9454023b1eff69eea669b46f6cecef425bfd22a': no such file or directory")
2014-12-16 20:20:21.167 14646 TRACE nova.compute.manager [instance: 304d3583-2f82-4a87-ba60-1aa54f13c8af]
2014-12-16 20:20:21.671 ERROR oslo.messaging.rpc.dispatcher [req-5a3efdeb-b703-4bb9-9942-5e8c0af43b68 ServerDiskConfigTestJSON-2115024492 ServerDiskConfigTestJSON-1220777223] Exception during message handling: 404 Client Error: Not Found ("Cannot start container b290765b6ccc30e2efcff66ce9454023b1eff69eea669b46f6cecef425bfd22a: Error getting container b290765b6ccc30e2efcff66ce9454023b1eff69eea669b46f6cecef425bfd22a from driver devicemapper: Error mounting '/dev/mapper/docker-253:1-917682-b290765b6ccc30e2efcff66ce9454023b1eff69eea669b46f6cecef425bfd22a' on '/var/lib/docker/devicemapper/mnt/b290765b6ccc30e2efcff66ce9454023b1eff69eea669b46f6cecef425bfd22a': no such file or directory")

Matthew Treinish (treinish) wrote :

So this most likely isn't a tempest bug. The tempest failure is being caused by a 500 response from nova (when using the docker driver) which is normally nova having an unhandled exception. So I've added the nova-docker project here as the primary project, because it raising an exception on a server create that the api layer doesn't know how to handle.

Feel free to re-add tempest in the future if you can show that tempest is doing something invalid to cause this. (or there is a some other bug or gap in tempest causing the failure w/ nova-docker) For example, I could see this being an issue w/ nova-docker not supporting disk-config and tempest not having a way to know that. However in that case it would still be primarily a nova-docker bug because raising a 500 is still incorrect if a feature isn't supported.

Changed in tempest:
status: New → Invalid
status: Invalid → Incomplete

I am hoping https://review.openstack.org/#/c/144662/ will help fix this problem

Changed in nova-docker:
status: New → In Progress
assignee: nobody → Davanum Srinivas (DIMS) (dims-v)

Can't find any instances of this log error in logstash, assuming the switch from devicemapper to aufs fixed it for our gate/check scenarios

Changed in nova-docker:
status: In Progress → Fix Committed
Yaroslav Lobankov (ylobankov) wrote :

It looks like this issue is not related to Tempest. As Matthew said, the Tempest failure is being caused by a 500 response from Nova. I don't see that Tempest was doing something wrong to cause this. So moving the bug status to "Invalid". Feel free to reopen the bug by providing the proof of wrong Tempest actions and set the bug status back to ''New''.

Changed in tempest:
status: Incomplete → Invalid
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers