Registry client request GET /images/UUID raised ClientConnectionError

[Dolph Mathews]

From tempest:

2013-10-14 20:57:53.231 | FAIL: setUpClass (tempest.api.compute.images.test_list_image_filters.ListImageFiltersTestXML)
2013-10-14 20:57:53.231 | setUpClass (tempest.api.compute.images.test_list_image_filters.ListImageFiltersTestXML)
2013-10-14 20:57:53.231 | ----------------------------------------------------------------------
2013-10-14 20:57:53.232 | _StringException: Traceback (most recent call last):
2013-10-14 20:57:53.232 | File "tempest/api/compute/images/test_list_image_filters.py", line 64, in setUpClass
2013-10-14 20:57:53.232 | cls.client.wait_for_image_status(cls.image2_id, 'ACTIVE')
2013-10-14 20:57:53.233 | File "tempest/services/compute/xml/images_client.py", line 153, in wait_for_image_status
2013-10-14 20:57:53.233 | raise exceptions.TimeoutException
2013-10-14 20:57:53.233 | TimeoutException: Request timed out

I'm not sure they're related, but there's about a 5 second gap in both the tempest and glance logs around the time of this failure (near 2013-10-14 20:44:30.948), and a Not Found reported at about the same time in the glance logs:

screen-g-reg.txt.gz contains:

2013-10-14 20:44:28.170 20481 DEBUG glance.db.sqlalchemy.api [8faf11f8-bdeb-4e23-b678-40d79719f0aa 9a04646b5d1d4d36b74e3ba4f3b8868b d8e9d5f5137b4865a89bac9fe38f3bbd] No image found with ID 2649efec-f35a-4a44-a02b-6e09244a7389 _image_get /opt/stack/new/glance/glance/db/sqlalchemy/api.py:334
2013-10-14 20:44:28.171 20481 INFO glance.registry.api.v1.images [8faf11f8-bdeb-4e23-b678-40d79719f0aa 9a04646b5d1d4d36b74e3ba4f3b8868b d8e9d5f5137b4865a89bac9fe38f3bbd] Image 2649efec-f35a-4a44-a02b-6e09244a7389 not found

screen-g-api.txt.gz contains:

2013-10-14 20:44:28.173 20525 INFO glance.registry.client.v1.client [e5cc3b13-9109-4bbb-967a-a52cb155e6a0 9a04646b5d1d4d36b74e3ba4f3b8868b d8e9d5f5137b4865a89bac9fe38f3bbd] Registry client request GET /images/2649efec-f35a-4a44-a02b-6e09244a7389 raised NotFound
2013-10-14 20:44:28.173 20525 DEBUG glance.api.v1.controller [e5cc3b13-9109-4bbb-967a-a52cb155e6a0 9a04646b5d1d4d36b74e3ba4f3b8868b d8e9d5f5137b4865a89bac9fe38f3bbd] Image with identifier 2649efec-f35a-4a44-a02b-6e09244a7389 not found get_image_meta_or_404 /opt/stack/new/glance/glance/api/v1/controller.py:44

[Joe Gordon (jogo)]

 not found get_image_meta_or_404 is found in many successful runs so not clear if that is related. FOr now here is a logstash query that checks tempest output:

@message:"tempest/services" AND @message:"/images_client.py" AND @message:"wait_for_image_status" AND @tags:"console.html"

[Matt Riedemann (mriedem)]

While not exactly the same, this looks related:

http://logs.openstack.org/31/49231/10/check/check-tempest-devstack-vm-full/63d70fd/console.html

[Alvaro Lopez (aloga)]

Same with this: http://logs.openstack.org/17/36417/19/check/check-tempest-devstack-vm-full/5a6b4a2/

[Joe Gordon (jogo)]

better query: message:" Registry client request" AND message:"raised ClientConnectionError" AND filename:"logs/screen-g-api.txt"

[Joe Gordon (jogo)]

http://logstash.openstack.org/#eyJzZWFyY2giOiJtZXNzYWdlOlwiIFJlZ2lzdHJ5IGNsaWVudCByZXF1ZXN0XCIgQU5EIG1lc3NhZ2U6XCJyYWlzZWQgQ2xpZW50Q29ubmVjdGlvbkVycm9yXCIgQU5EIGZpbGVuYW1lOlwibG9ncy9zY3JlZW4tZy1hcGkudHh0XCIiLCJmaWVsZHMiOltdLCJvZmZzZXQiOjAsInRpbWVmcmFtZSI6IjE3MjgwMCIsImdyYXBobW9kZSI6ImNvdW50IiwidGltZSI6eyJ1c2VyX2ludGVydmFsIjowfSwic3RhbXAiOjEzODUxNTM2NDYzMzgsIm1vZGUiOiIiLCJhbmFseXplX2ZpZWxkIjoiIn0=

[Joe Gordon (jogo)]

this hasn't been seen in two weeks, marking as resolved