socket.error: [Errno 111] Connection refuse in /opt/stack/new/glance/bin/glance-manage db_sync

[Walt Boring]

Devstack's gate-tempest-devstack-vm-full is failing occasionally with an exception.

Here are a few reviews that are currently broken
https://review.openstack.org/#/c/22282/
https://jenkins.openstack.org/job/gate-tempest-devstack-vm-full/4196/consoleFull

For review :
https://review.openstack.org/#/c/19992/
http://logs.openstack.org/19992/16/gate/gate-tempest-devstack-vm-full/4151/console.html

"2013-02-19 20:49:52.775 | 2013-02-19 20:49:52 + [[ ,g-api,g-reg,key,n-api,n-crt,n-obj,n-cpu,n-sch,horizon,mysql,rabbit,tempest,swift,cinder,c-api,c-vol,c-sch,n-cond,n-net, =~ ,n-net, ]]
2013-02-19 20:49:52.777 | 2013-02-19 20:49:52 + return 0
2013-02-19 20:49:52.780 | 2013-02-19 20:49:52 + /opt/stack/new/nova/bin/nova-manage network create private 10.1.0.0/24 1 256
2013-02-19 20:49:52.782 | 2013-02-19 20:49:52 2013-02-19 20:49:52.278 11949 INFO nova.network.driver [-] Loading network driver 'nova.network.linux_net'
2013-02-19 20:49:52.785 | 2013-02-19 20:49:52 2013-02-19 20:49:52.278 11949 DEBUG nova.servicegroup.api [-] ServiceGroup driver defined as an instance of db __new__ /opt/stack/new/nova/nova/servicegroup/api.py:59
2013-02-19 20:49:52.787 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 CRITICAL nova [req-fcabf37c-97e9-4f9d-b739-4f05f9ac7630 None None] (ProgrammingError) (1146, "Table 'nova.networks' doesn't exist") 'SELECT networks.created_at AS networks_created_at, networks.updated_at AS networks_updated_at, networks.deleted_at AS networks_deleted_at, networks.deleted AS networks_deleted, networks.id AS networks_id, networks.label AS networks_label, networks.injected AS networks_injected, networks.cidr AS networks_cidr, networks.cidr_v6 AS networks_cidr_v6, networks.multi_host AS networks_multi_host, networks.gateway_v6 AS networks_gateway_v6, networks.netmask_v6 AS networks_netmask_v6, networks.netmask AS networks_netmask, networks.bridge AS networks_bridge, networks.bridge_interface AS networks_bridge_interface, networks.gateway AS networks_gateway, networks.broadcast AS networks_broadcast, networks.dns1 AS networks_dns1, networks.dns2 AS networks_dns2, networks.vlan AS networks_vlan, networks.vpn_public_address AS networks_vpn_public_address, networks.vpn_public_port AS networks_vpn_public_port, networks.vpn_private_address AS networks_vpn_private_address, networks.dhcp_start AS networks_dhcp_start, networks.rxtx_base AS networks_rxtx_base, networks.project_id AS networks_project_id, networks.priority AS networks_priority, networks.host AS networks_host, networks.uuid AS networks_uuid \nFROM networks \nWHERE networks.deleted = %s' (0,)
2013-02-19 20:49:52.789 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 11949 TRACE nova Traceback (most recent call last):
2013-02-19 20:49:52.791 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 11949 TRACE nova File "/opt/stack/new/nova/bin/nova-manage", line 1229, in <module>
2013-02-19 20:49:52.794 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 11949 TRACE nova main()
2013-02-19 20:49:52.796 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 11949 TRACE nova File "/opt/stack/new/nova/bin/nova-manage", line 1221, in main
2013-02-19 20:49:52.802 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 11949 TRACE nova fn(*fn_args, **fn_kwargs)
2013-02-19 20:49:52.804 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 11949 TRACE nova File "/opt/stack/new/nova/bin/nova-manage", line 485, in create
2013-02-19 20:49:52.807 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 11949 TRACE nova net_manager.create_networks(context.get_admin_context(), **kwargs)
2013-02-19 20:49:52.809 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 11949 TRACE nova File "/opt/stack/new/nova/nova/network/manager.py", line 1024, in create_networks
2013-02-19 20:49:52.811 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 11949 TRACE nova return self._do_create_networks(context, **kwargs)
2013-02-19 20:49:52.813 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 11949 TRACE nova File "/opt/stack/new/nova/nova/network/manager.py", line 1064, in _do_create_networks
2013-02-19 20:49:52.815 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 11949 TRACE nova nets = self.db.network_get_all(context)
2013-02-19 20:49:52.817 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 11949 TRACE nova File "/opt/stack/new/nova/nova/db/api.py", line 819, in network_get_all
2013-02-19 20:49:52.819 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 11949 TRACE nova return IMPL.network_get_all(context)
2013-02-19 20:49:52.821 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 11949 TRACE nova File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 145, in wrapper
2013-02-19 20:49:52.824 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 11949 TRACE nova return f(*args, **kwargs)
2013-02-19 20:49:52.826 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 11949 TRACE nova File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 2138, in network_get_all
2013-02-19 20:49:52.828 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 11949 TRACE nova result = model_query(context, models.Network, read_deleted="no").all()
2013-02-19 20:49:52.830 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 11949 TRACE nova File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2115, in all
2013-02-19 20:49:52.832 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 11949 TRACE nova return list(self)
2013-02-19 20:49:52.834 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 11949 TRACE nova File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2227, in __iter__
2013-02-19 20:49:52.837 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 11949 TRACE nova return self._execute_and_instances(context)
2013-02-19 20:49:52.839 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 11949 TRACE nova File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2242, in _execute_and_instances
2013-02-19 20:49:52.842 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 11949 TRACE nova result = conn.execute(querycontext.statement, self._params)
2013-02-19 20:49:52.845 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 11949 TRACE nova File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1449, in execute
2013-02-19 20:49:52.849 | 2013-02-19 20:49:52 2013-02-19 20:49:52.587 11949 TRACE nova params)
2013-02-19 20:50:04.985 | Process leaked file descriptors. See http://wiki.jenkins-ci.org/display/JENKINS/Spawning+processes+from+build for more information
2013-02-19 20:50:05.249 | Build step 'Execute shell' marked build as failure
2013-02-19 20:50:06.702 | [SCP] Connecting to static.openstack.org"

[Nachi Ueno (nati-ueno)]

It looks mysql connection is refused

013-02-19 20:49:39.124 | 2013-02-19 20:49:39 + local db=glance
2013-02-19 20:49:39.126 | 2013-02-19 20:49:39 + local charset=utf8
2013-02-19 20:49:39.129 | 2013-02-19 20:49:39 + mysql -uroot -psecret -e 'DROP DATABASE IF EXISTS glance;'
2013-02-19 20:49:39.131 | 2013-02-19 20:49:39 + mysql -uroot -psecret -e 'CREATE DATABASE glance CHARACTER SET utf8;'
2013-02-19 20:49:39.133 | 2013-02-19 20:49:39 + /opt/stack/new/glance/bin/glance-manage db_sync
2013-02-19 20:49:39.137 | 2013-02-19 20:49:39 Traceback (most recent call last):
2013-02-19 20:49:39.140 | 2013-02-19 20:49:39 File "/opt/stack/new/glance/bin/glance-manage", line 132, in <module>
2013-02-19 20:49:39.142 | 2013-02-19 20:49:39 main()
2013-02-19 20:49:39.145 | 2013-02-19 20:49:39 File "/opt/stack/new/glance/bin/glance-manage", line 121, in main
2013-02-19 20:49:39.146 | 2013-02-19 20:49:39 config.setup_logging()
2013-02-19 20:49:39.151 | 2013-02-19 20:49:39 File "/opt/stack/new/glance/glance/common/config.py", line 129, in setup_logging
2013-02-19 20:49:39.156 | 2013-02-19 20:49:39 facility=facility)
2013-02-19 20:49:39.158 | 2013-02-19 20:49:39 File "/usr/lib/python2.7/logging/handlers.py", line 729, in __init__
2013-02-19 20:49:39.158 | 2013-02-19 20:49:39 self._connect_unixsocket(address)
2013-02-19 20:49:39.161 | 2013-02-19 20:49:39 File "/usr/lib/python2.7/logging/handlers.py", line 745, in _connect_unixsocket
2013-02-19 20:49:39.161 | 2013-02-19 20:49:39 self.socket.connect(address)
2013-02-19 20:49:39.166 | 2013-02-19 20:49:39 File "/usr/lib/python2.7/socket.py", line 224, in meth
2013-02-19 20:49:39.166 | 2013-02-19 20:49:39 return getattr(self._sock,name)(*args)
2013-02-19 20:49:39.171 | 2013-02-19 20:49:39 socket.error: [Errno 111] Connection refuse

[Nachi Ueno (nati-ueno)]

it looks not mysql connection error but logging.

[Vish Ishaya (vishvananda)]

This appears to be an error connecting to rsyslog when setting up logging so the db sync commands fail.

[Davanum Srinivas (DIMS) (dims-v)]

vishy, is this related to https://review.openstack.org/#/c/22388/ ?

[Vish Ishaya (vishvananda)]

I think this has stopped since we stopped using syslog.

[Vish Ishaya (vishvananda)]

the above fix allows us to get proper error messages when we fail to connect to syslog, but it won't fix this particular problem.