Sporadic 503 failures of haproxy backend status lead to nova entities creation issues

[Vladimir Kuklin]

VERSION:
  feature_groups:
    - mirantis
  production: "docker"
  release: "6.1"
  openstack_version: "2014.2.2-6.1"
  api: "1.0"
  build_number: "352"
  build_id: "2015-04-26_22-54-38"
  nailgun_sha: "f9f17fe395f3e38c27d3d484302728a37ad8012d"
  python-fuelclient_sha: "2b311b3b82a1e2df1dc3484a0f37e282273cd988"
  astute_sha: "c1793f982fda7e3fc7b937ccaa613c649be6a144"
  fuel-library_sha: "6bdf783e2bffdce80ecffcca2915e6d32a8ccdd7"
  fuel-ostf_sha: "b38602c841deaa03ddffc95c02f319360462cbe3"
  fuelmain_sha: "01288380950bc89d572cf5902141c9a393ada950"

Deploy cluster with 3 controllers, add two new ones.

Here are the errors in logs

2015-04-27 05:42:05 +0000 Haproxy_backend_status[nova-api](provider=haproxy) (debug): Call 'ensure' on HAProxy backend 'nova-api-2'
2015-04-27 05:42:05 +0000 Haproxy_backend_status[nova-api](provider=haproxy) (debug): Get CSV from url 'http://10.109.18.2:10000/;csv'
2015-04-27 05:42:05 +0000 Haproxy_backend_status[nova-api](provider=haproxy) (debug): Return: up
2015-04-27 05:42:05 +0000 /Stage[main]/Main/Haproxy_backend_status[nova-api] (info): Evaluated in 0.06 seconds
2015-04-27 05:42:05 +0000 /Stage[main]/Main/Exec[create-m1.micro-flavor] (info): Starting to evaluate the resource
2015-04-27 05:42:05 +0000 Exec[create-m1.micro-flavor](provider=posix) (debug): Executing check 'bash -c "nova flavor-list | grep -q m1.micro"'
2015-04-27 05:42:05 +0000 Puppet (debug): Executing 'bash -c "nova flavor-list | grep -q m1.micro"'
2015-04-27 05:42:19 +0000 /Stage[main]/Main/Exec[create-m1.micro-flavor]/unless (debug): ERROR (ClientException): Unknown Error (HTTP 503)
2015-04-27 05:42:19 +0000 Exec[create-m1.micro-flavor](provider=posix) (debug): Executing 'bash -c "nova flavor-create --is-public true m1.micro auto 64 0 1"'
2015-04-27 05:42:19 +0000 Puppet (debug): Executing 'bash -c "nova flavor-create --is-public true m1.micro auto 64 0 1"'
2015-04-27 05:42:20 +0000 /Stage[main]/Main/Exec[create-m1.micro-flavor]/returns (notice): ERROR (ClientException): Unknown Error (HTTP 503)
2015-04-27 05:42:20 +0000 Puppet (err): bash -c "nova flavor-create --is-public true m1.micro auto 64 0 1" returned 1 instead of one of [0]

but haproxy is actually not ready to serve the service

it becomes available only 15 seconds later:

2015-04-27T05:42:05.367195+00:00 info: Connect from 10.109.18.4:52415 to 10.109.18.2:10000 (Stats/HTTP)
2015-04-27T05:42:05.783145+00:00 alert: Server nova-api-1/node-1 is DOWN, reason: Layer4 connection problem, info: "Connection refused", check duration: 0ms. 0 active and 0 backup servers left. 0 sessions active, 0 requeued, 0 remaining in queue.
2015-04-27T05:42:05.783145+00:00 emerg: proxy nova-api-1 has no server available!
2015-04-27T05:42:09.786630+00:00 notice: Server nova-api-1/node-1 is UP, reason: Layer4 check passed, check duration: 0ms. 1 active and 0 backup servers online. 0 sessions requeued, 0 total in queue.
2015-04-27T05:42:13.967784+00:00 alert: Server nova-api-2/node-1 is DOWN, reason: Layer4 connection problem, info: "Connection refused", check duration: 0ms. 0 active and 0 backup servers left. 0 sessions active, 0 requeued, 0 remaining in queue.
2015-04-27T05:42:13.967784+00:00 emerg: proxy nova-api-2 has no server available!
2015-04-27T05:42:19.289508+00:00 info: 10.109.18.4:49525 [27/Apr/2015:05:42:10.365] keystone-1 keystone-1/node-1 1/0/0/8916/8924 200 3960 - - ---- 8/0/0/0/0 0/0 "POST /v2.0/tokens HTTP/1.1"
2015-04-27T05:42:19.308480+00:00 info: 10.109.13.4:42741 [27/Apr/2015:05:42:19.307] nova-api-2 nova-api-2/<NOSRV> 0/-1/-1/-1/0 503 212 - - SC-- 8/0/0/0/0 0/0 "GET /v2/bd0f54e7b6fe4031a43d093ca916ee29/flavors/detail HTTP/1.1"
2015-04-27T05:42:20.188794+00:00 info: 10.109.18.4:49657 [27/Apr/2015:05:42:20.032] keystone-1 keystone-1/node-1 0/0/0/148/155 200 3960 - - ---- 8/0/0/0/0 0/0 "POST /v2.0/tokens HTTP/1.1"
2015-04-27T05:42:20.198280+00:00 info: 10.109.13.4:42752 [27/Apr/2015:05:42:20.197] nova-api-2 nova-api-2/<NOSRV> 0/-1/-1/-1/0 503 212 - - SC-- 8/0/0/0/0 0/0 "POST /v2/bd0f54e7b6fe4031a43d093ca916ee29/flavors HTTP/1.1"
2015-04-27T05:42:20.994621+00:00 notice: Server nova-api-2/node-1 is UP, reason: Layer7 check passed, code: 200, info: "OK", check duration: 2ms. 1 active and 0 backup servers online. 0 sessions requeued, 0 total in queue.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/179131

[Vladimir Kuklin (vkuklin)]

https://review.openstack.org/179131 fix is a related one. we will introduce more debug output to catch this bug. but it does not seem to be reproducible

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/179131
Committed: https://git.openstack.org/cgit/stackforge/fuel-library/commit/?id=c2f2189978b750b4d9605999ab6a18199d310a89
Submitter: Jenkins
Branch: master

commit c2f2189978b750b4d9605999ab6a18199d310a89
Author: Dmitry Ilyin <email address hidden>
Date: Thu Apr 30 18:25:18 2015 +0300

    Refactor Haproxy_backend_status

    * Clean the code up
    * Improved debugging

    Change-Id: Ie1ba15e2f40c903efdf970447676987a14156ed4
    Related-Bug: 1449219
    Related-Bug: 1459357