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

Bug #1484588 reported by John Griffith
40
This bug affects 9 people
Affects Status Importance Assigned to Milestone
Glance
Undecided
Bhargavi

Bug Description

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

Revision history for this message
Stuart McLaren (stuart-mclaren) wrote :

Do the original glance processes still have the port open?

Does

# lsof -iTCP -sTCP:LISTEN

indicate something listening on 9191/9292?

Revision history for this message
Tomi Juvonen (tomi-juvonen-q) wrote :

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.

Revision history for this message
Sreekumar S (sreesiv) wrote :
Revision history for this message
Sabari Murugesan (smurugesan) wrote :

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 ?

Ivan Kolodyazhny (e0ne)
Changed in glance:
status: New → Confirmed
Revision history for this message
Lenny (lennyb) wrote :

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/

Revision history for this message
zhangjian (jian-zhang8) wrote :

same issue in stable/liberty devstack

Changed in glance:
assignee: nobody → Mohammed Ashraf (mohammed-asharaf)
Revision history for this message
Tharanya Selvaraj (tharanya-selvaraj) wrote :

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.

Changed in glance:
assignee: Mohammed Ashraf (mohammed-asharaf) → nobody
Revision history for this message
Kashyap Chamarthy (kashyapc) wrote :

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)
Changed in glance:
assignee: nobody → Bhargavi (bhargavi-c81)
Revision history for this message
Bhargavi (bhargavi-c81) wrote :

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.

Bhargavi (bhargavi-c81)
Changed in glance:
status: Confirmed → Incomplete
Revision history for this message
Lujin Luo (luo-lujin) wrote :

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.

Revision history for this message
Anseela M M (anseela-m00) wrote :

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

Revision history for this message
sanjana (sanjana) wrote :

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)

Revision history for this message
Tomi Juvonen (tomi-juvonen-q) wrote :

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.

Revision history for this message
Himani (himani-relan) wrote :

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.

Revision history for this message
Cyril Roelandt (cyril-roelandt) wrote :

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.

Changed in glance:
status: Incomplete → Won't Fix
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers