yahoo-eng-team team mailing list archive

[Matt Riedemann <mriedem.os@xxxxxxxxx>]

Looking at one of the failures, g-api starts in ~3 seconds:

http://logs.openstack.org/55/625555/1/check/tempest-
full/60bd495/controller/logs/screen-g-api.txt.gz

Dec 17 18:37:34.594832 ubuntu-bionic-rax-dfw-0001240665
devstack@g-api.service[1909]: WSGI app 0 (mountpoint='') ready in 3
seconds on interpreter 0x562a8bbd57c0 pid: 1910 (default app)

Dec 17 18:37:34.620388 ubuntu-bionic-rax-dfw-0001240665
devstack@g-api.service[1909]: WSGI app 0 (mountpoint='') ready in 3
seconds on interpreter 0x562a8bbd57c0 pid: 1911 (default app)

but it looks like GET /images requests are returning a 503;

2018-12-17 20:34:07.843 | ++ ::                                       :   curl -g -k --noproxy '*' -s -o /dev/null -w '%{http_code}' https://10.209.34.117/image
2018-12-17 20:34:07.874 | + ::                                       :   [[ 503 == 503 ]]

I don't see anything wrong in the glance logs, but I do see proxy errors
in the apache logs:

http://logs.openstack.org/55/625555/1/check/tempest-
full/60bd495/controller/logs/apache/error_log.txt.gz

[Mon Dec 17 20:33:08.847250 2018] [proxy:error] [pid 8631:tid 140513730557696] (111)Connection refused: AH00957: HTTP: attempt to connect to 127.0.0.1:60998 (127.0.0.1) failed
[Mon Dec 17 20:33:08.847344 2018] [proxy_http:error] [pid 8631:tid 140513730557696] [client 10.209.34.117:51988] AH01114: HTTP: failed to make connection to backend: 127.0.0.1

And in the access log:

http://logs.openstack.org/55/625555/1/check/tempest-
full/60bd495/controller/logs/apache/access_log.txt.gz

10.209.34.117 - - [17/Dec/2018:20:33:15 +0000] "GET /image HTTP/1.1" 503 568 "-" "curl/7.58.0"
10.209.34.117 - - [17/Dec/2018:20:33:16 +0000] "GET /image HTTP/1.1" 503 568 "-" "curl/7.58.0"
10.209.34.117 - - [17/Dec/2018:20:33:17 +0000] "GET /image HTTP/1.1" 503 568 "-" "curl/7.58.0"
10.209.34.117 - - [17/Dec/2018:20:33:18 +0000] "GET /image HTTP/1.1" 503 568 "-" "curl/7.58.0"

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

** Summary changed:

- devstack timeout because n-api/g-api takes longer than 60 seconds to start
+ devstack timeout because g-api takes longer than 60 seconds to start

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to Glance.
https://bugs.launchpad.net/bugs/1806912

Title:
  devstack timeout because g-api takes longer than 60 seconds to start

Status in Glance:
  New
Status in OpenStack-Gate:
  Confirmed

Bug description:
  For example:

  http://logs.openstack.org/60/620660/1/check/heat-functional-orig-
  mysql-lbaasv2/bc7ef21/logs/devstacklog.txt#_2018-11-30_20_14_13_418

  2018-11-30 20:14:13.418 | + lib/glance:start_glance:353              :
  die 353 'g-api did not start'

  The g-api logs show it took 62 seconds to start:

  http://logs.openstack.org/60/620660/1/check/heat-functional-orig-
  mysql-lbaasv2/bc7ef21/logs/screen-g-api.txt.gz#_Nov_30_20_14_12_852280

  Nov 30 20:14:12.852280 ubuntu-xenial-ovh-bhs1-0000840057
  devstack@g-api.service[7937]: WSGI app 0 (mountpoint='') ready in 62
  seconds on interpreter 0xb23d10 pid: 7942 (default app)

  Looks like this primarily happens on ovh-bhs1 nodes.

  http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22-api%20did%20not%20start%5C%22%20AND%20tags%3A%5C%22console%5C%22&from=7d

To manage notifications about this bug go to:
https://bugs.launchpad.net/glance/+bug/1806912/+subscriptions