Keystone synchronization fails because of log file permissions

[Pedro Marques]

If there is a permission problem with the log file, the API server openstack extension fails to initialize. The subsequent failure is very hard to debug... keystone tenant synchronization fails.

The vnc_openstack.err file should not be hardcoded into the code; this needs to be a configuration parameter (it should default to the api server file) and should be syslog compatible. Any initialization failure in the module should also cause the api-server initialization to fail so that the user is warned about the failure rather than continue without the ability to sync projects from keystone.

ERROR:stevedore.extension:[Errno 13] Permission denied: '/var/log/contrail/vnc_openstack.err'
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/stevedore/extension.py", line 162, in _
load_plugins
    verify_requirements,
  File "/usr/lib/python2.7/dist-packages/stevedore/extension.py", line 179, in _
load_one_plugin
    obj = plugin(*invoke_args, **invoke_kwds)
  File "/usr/lib/python2.7/dist-packages/vnc_openstack/__init__.py", line 530, i
n __init__
    self._openstack_drv = OpenstackDriver(api_server_ip, api_server_port, conf_s
ections)
  File "/usr/lib/python2.7/dist-packages/vnc_openstack/__init__.py", line 113, i
n __init__
    backupCount=5)
  File "/usr/lib/python2.7/logging/handlers.py", line 118, in __init__
    BaseRotatingHandler.__init__(self, filename, mode, encoding, delay)
  File "/usr/lib/python2.7/logging/handlers.py", line 65, in __init__
    logging.FileHandler.__init__(self, filename, mode, encoding, delay)
  File "/usr/lib/python2.7/logging/__init__.py", line 897, in __init__
    StreamHandler.__init__(self, self._open())
  File "/usr/lib/python2.7/logging/__init__.py", line 916, in _open
IOError: [Errno 13] Permission denied: '/var/log/contrail/vnc_openstack.err'

[Francois Eleouet (fanchon)]

As you mentionned, this issue is very hard to debug. It took me a while to figure out what was happening, and that this bug was causing my troubles. It prevents devstack + contrail-installer from working out of the box:

log files are present but not writeable, thus vnc_openstack will not fail to initialize, but logging will raise during exception handling in _resync_domains_projects_forever:

Traceback (most recent call last):
  File "/opt/stack/contrail/controller/src/config/vnc_openstack/vnc_openstack/__init__.py", line 509, in _resync_domains_projects_forever
    retry = self._resync_all_projects()
  File "/opt/stack/contrail/controller/src/config/vnc_openstack/vnc_openstack/__init__.py", line 427, in _resync_all_projects
    self._get_keystone_conn()
  File "/opt/stack/contrail/controller/src/config/vnc_openstack/vnc_openstack/__init__.py", line 160, in _ksv2_get_conn
    insecure=self._insecure)
  File "/opt/stack/python-keystoneclient/keystoneclient/v2_0/client.py", line 147, in __init__
    self.authenticate()
  File "/opt/stack/python-keystoneclient/keystoneclient/utils.py", line 318, in inner
    return func(*args, **kwargs)
  File "/opt/stack/python-keystoneclient/keystoneclient/httpclient.py", line 425, in authenticate
    resp = self.get_raw_token_from_identity_service(**kwargs)
  File "/opt/stack/python-keystoneclient/keystoneclient/v2_0/client.py", line 190, in get_raw_token_from_identity_service
    "%s" % e)
AuthorizationFailure: Authorization Failed: Unable to establish connection to http://192.168.122.11:5000/v2.0/tokens

As a consequence self._ks will never be reset to None (self._ks = keystoneclient.openstack.common.apiclient.exceptions.AuthorizationFailure), and neutron api will stay stuck even if keystone becomes available.:

Traceback (most recent call last):
  File "/opt/stack/contrail/controller/src/config/vnc_openstack/vnc_openstack/neutron_plugin_interface.py", line 146, in plugin_create_network
    net_info = cfgdb.network_create(network['resource'])
  File "/opt/stack/contrail/controller/src/config/vnc_openstack/vnc_openstack/neutron_plugin_db.py", line 2067, in network_create
    net_obj = self._network_neutron_to_vnc(network_q, CREATE)
  File "/opt/stack/contrail/controller/src/config/vnc_openstack/vnc_openstack/neutron_plugin_db.py", line 1107, in _network_neutron_to_vnc
    project_obj = self._project_read(proj_id=project_id)
  File "/opt/stack/contrail/controller/src/config/vnc_openstack/vnc_openstack/neutron_plugin_db.py", line 203, in _project_read
    proj_obj = self._vnc_lib.project_read(id=proj_id, fq_name=fq_name)
  File "/usr/local/lib/python2.7/dist-packages/vnc_api/gen/vnc_api_client_gen.py", line 4990, in project_read
    content = self._request_server(rest.OP_GET, uri, query_params)
  File "/usr/local/lib/python2.7/dist-packages/vnc_api/vnc_api.py", line 366, in _request_server
    % (op, url, data, content))
NoIdError: Unknown id: Error: oper 2 url /project/9fc74e34-8b83-4484-b476-cde62cf447f9 body {'exclude_back_refs': True, 'exclude_children': True} response No project object found for id 9fc74e34-8b83-4484-b476-cde62cf447f9

Traceback (most recent call last):
  File "/usr/local/lib/python2.7...

[Francois Eleouet (fanchon)]

This bug can be closed as it has been adressed by the following commits:

https://github.com/Juniper/contrail-controller/commit/5930f33bc32743250d5a61c3b1f58ce239e053ad
https://github.com/Juniper/contrail-controller/commit/f717c02853345c80068be84dc8753e304e27ec5b