glance startup gives ERROR: Could not bind to 0.0.0.0:9292 after trying for 30 seconds on stable-kilo after attempting service restart

[John Griffith]

Have a running stable-kilo setup, recently did a restart of all services and glance won't start up. Following error in g-api log:

2015-08-13 09:44:29.916 28813 DEBUG glance.common.config [-] image_format.disk_formats = ['ami', 'ari', 'aki', 'vhd', 'vmdk', 'raw', 'qcow2', 'vdi', 'iso'] log_opt_values /usr/local/lib/python2.7/dist-packages/oslo_config/cfg.py:2195
2015-08-13 09:44:29.916 28813 DEBUG glance.common.config [-] oslo_policy.policy_default_rule = default log_opt_values /usr/local/lib/python2.7/dist-packages/oslo_config/cfg.py:2195
2015-08-13 09:44:29.916 28813 DEBUG glance.common.config [-] oslo_policy.policy_dirs = ['policy.d'] log_opt_values /usr/local/lib/python2.7/dist-packages/oslo_config/cfg.py:2195
2015-08-13 09:44:29.916 28813 DEBUG glance.common.config [-] oslo_policy.policy_file = policy.json log_opt_values /usr/local/lib/python2.7/dist-packages/oslo_config/cfg.py:2195
2015-08-13 09:44:29.916 28813 DEBUG glance.common.config [-] ******************************************************************************** log_opt_values /usr/local/lib/python2.7/dist-packages/oslo_config/cfg.py:2197
^[kERROR: Could not bind to 0.0.0.0:9292 after trying for 30 seconds

And same in the g-reg logs:

-08-13 09:44:20.743 28806 DEBUG glance.common.config [-] keystone_authtoken.user_id = None log_opt_values /usr/local/lib/python2.7/dist-packages/oslo_config/cfg.py:2195
2015-08-13 09:44:20.743 28806 DEBUG glance.common.config [-] keystone_authtoken.username = glance log_opt_values /usr/local/lib/python2.7/dist-packages/oslo_config/cfg.py:2195
2015-08-13 09:44:20.743 28806 DEBUG glance.common.config [-] image_format.container_formats = ['ami', 'ari', 'aki', 'bare', 'ovf', 'ova'] log_opt_values /usr/local/lib/python2.7/dist-packages/oslo_config/cfg.py:2195
2015-08-13 09:44:20.743 28806 DEBUG glance.common.config [-] image_format.disk_formats = ['ami', 'ari', 'aki', 'vhd', 'vmdk', 'raw', 'qcow2', 'vdi', 'iso'] log_opt_values /usr/local/lib/python2.7/dist-packages/oslo_config/cfg.py:2195
2015-08-13 09:44:20.743 28806 DEBUG glance.common.config [-] oslo_policy.policy_default_rule = default log_opt_values /usr/local/lib/python2.7/dist-packages/oslo_config/cfg.py:2195
2015-08-13 09:44:20.744 28806 DEBUG glance.common.config [-] oslo_policy.policy_dirs = ['policy.d'] log_opt_values /usr/local/lib/python2.7/dist-packages/oslo_config/cfg.py:2195
2015-08-13 09:44:20.744 28806 DEBUG glance.common.config [-] oslo_policy.policy_file = policy.json log_opt_values /usr/local/lib/python2.7/dist-packages/oslo_config/cfg.py:2195
2015-08-13 09:44:20.744 28806 DEBUG glance.common.config [-] ******************************************************************************** log_opt_values /usr/local/lib/python2.7/dist-packages/oslo_config/cfg.py:2197
ERROR: Could not bind to 0.0.0.0:9191 after trying for 30 seconds

[Stuart McLaren (stuart-mclaren)]

Do the original glance processes still have the port open?

Does

# lsof -iTCP -sTCP:LISTEN

indicate something listening on 9191/9292?

[Tomi Juvonen (tomi-juvonen-q)]

My devstack env got this working after host reboot. Old school way of fixing after relocated /opt/stack under /home as otherwise run out of disk for any VMs.

[Sreekumar S (sreesiv)]

This looks similar to bug 995205.
https://bugs.launchpad.net/devstack/+bug/995205/comments/7

[Sabari Murugesan (smurugesan)]

hmm, looks like the original process was still running.
Can you post additional trace from glance-api log before the new process tried to bind to the port ?

[Lenny (lennyb)]

Looks that the problem is glance-api and glance-registry procs that were not killed for some reason
( most likely pid were not present at time of ./unstack.sh )

This patch should fix this issue

https://review.openstack.org/#/c/237536/

[zhangjian (jian-zhang8)]

same issue in stable/liberty devstack

[Tharanya Selvaraj (tharanya-selvaraj)]

Hi,
I am trying to reproduce this bug in both devstack and manual installation of kilo version. But i am unable to reproduce this issue. So, please share me the steps/details to reproduce this bug.

[Kashyap Chamarthy (kashyapc)]

As one might've guessed, a workaround is to: Killing the existing stale 'g-api' and 'g-reg' services, and start them again (from the `screen` session).

[Bhargavi (bhargavi-c81)]

Am using kilo on ubuntu 14.04.

I was unable to observe behavior,tried multiple times restart and it's working as expected..

are you able to observer this issue now also?

could you please confirm.

[Lujin Luo (luo-lujin)]

I think I just ran into this bug.

I am using the latest DevStack codes with ubuntu 14.04

The way to reproduce is a bit tricky.

I had a DevStack environment running for some time, then I decided to unstack and stack again because parts of the source codes are not up-to-date. So I did the following:

1. unstack.sh
2. clean.sh
3. rm -rf devstck
4. git clone devstack
5. stack.sh

Then in g-api and g-reg screen something similar to the following
"Could not bind to 0.0.0.0:9191/9292"
is shown

I checked by using
# lsof -iTCP -sTCP:LISTEN | grep 9191/9292
Active processes existed.

Then I killed the processes manually and tried the step 1, 2 and 5 again.

DevStack is successfully built.

[Anseela M M (anseela-m00)]

I have created test cases for verifying the bug. please execute these test cases once the fix is done.

Test case id: OPNST_Glance_bug_1484588_ glance startup gives ERROR: Could not bind to 0.0.0.0:9292 after trying for 30 seconds on stable-kilo after attempting service restart_1
Metric: 30 minutes
Test purpose: Verify that the glance API restart should not give any error
Configuration: An OpenStack environment with at least one controller (with keystone, glance), one compute node and one network node installed.
Test tool: tempest
References:
Applicability: Could not bind to 0.0.0.0:9292 after trying for 30 seconds on stable-kilo after attempting service restart
Pre-test conditions: OpenStack should be installed
Step Description:
1. Do some changes in glance.conf file ( /etc/glance/glance-api.conf)
2. service glance-api restart
3. service glance-registry restart
4. list the glance images
 Result:
1. User should be able to edit the glance.conf file
2. Glance API should restart successfully
3. glance-registry should restart successfully
4. user should be able to list the glance images

Test verdict: TC pass only if user can delete the image tag without any error else TC failed

[sanjana (sanjana)]

I am using liberty on ubuntu 14.04, still the same issue exists.

ERROR: Could not bind to 0.0.0.0:9292 after trying for 30 seconds

However lsof -iTCP -sTCP:LISTEN gives output:
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
glance-re 4359 stack 4u IPv4 22678 0t0 TCP *:9191 (LISTEN)
glance-ap 28958 stack 4u IPv4 159620 0t0 TCP *:9292 (LISTEN)
glance-re 30151 stack 4u IPv4 22678 0t0 TCP *:9191 (LISTEN)
glance-re 30154 stack 4u IPv4 22678 0t0 TCP *:9191 (LISTEN)
glance-ap 30452 stack 4u IPv4 159620 0t0 TCP *:9292 (LISTEN)
glance-ap 30453 stack 4u IPv4 159620 0t0 TCP *:9292 (LISTEN)

[Tomi Juvonen (tomi-juvonen-q)]

Just got this again after needed to run ./stack.sh and ./unstack.sh several times before got everything in place to run my test env against latest master (Ocata). As of this, do not have tracking what was done. Problem was the old glance-api processes were still running and got working only when killed those by hand.

[Himani (himani-relan)]

I encountered the same problem again. Old glance-api and glance-reg processes were running already and hence it failed to start. Got them working only after killing the processes and then restart them again from the screen.

[Cyril Roelandt (cyril-roelandt)]

Kilo and Python2 are no longer supported, screen is no longer supported in devstack, and this bug has not been updated in 5 years. I'm closing it, feel free to reopen if needed.