Keystone leader fails to connect to itself while running identity-service-relation-changed hook

Bug #2015103 reported by Alexander Balderson
26
This bug affects 4 people
Affects Status Importance Assigned to Milestone
Charm Helpers
Fix Committed
Undecided
Unassigned
MySQL InnoDB Cluster Charm
Triaged
Medium
Unassigned
OpenStack Keystone Charm
Fix Committed
Undecided
Unassigned
2023.1
Fix Committed
Undecided
Unassigned
Train
Fix Committed
Undecided
Unassigned
Ussuri
Fix Committed
Undecided
Unassigned
Victoria
Fix Committed
Undecided
Unassigned
Wallaby
Fix Committed
Undecided
Unassigned
Xena
Fix Committed
Undecided
Unassigned
Yoga
Fix Committed
Undecided
Unassigned
Zed
Fix Committed
Undecided
Unassigned

Bug Description

Testing Yoga Focal bits but using a converged networking configuration.
Vault is unsealed and has issued certificates but no further steps have been taken against the cloud other than unsealing vault.

Keystone leader runs the identity-relation-changed hook but fails with a connection refused to `http://localhost:35337/v3/auth/tokens`

Looking through the logs, it looks like the keystone service is up and running, pacemaker and haproxy both look happy. It seems like everything is happy, and I cant seem to find why it cant connect to that address.

2023-04-01 12:35:28 DEBUG unit.keystone/1.juju-log server.go:316 identity-service:134: This unit (keystone/1) is in allowed unit list from keystone-mysql-router/0
2023-04-01 12:35:29 DEBUG unit.keystone/1.juju-log server.go:316 identity-service:134: Database is initialised
2023-04-01 12:36:15 ERROR unit.keystone/1.juju-log server.go:316 identity-service:134: The call within manager.py failed with the error: 'Unable to establish connection to http://localhost:35337/v3/auth/tokens: HTTPConnectionPool(host='localhost', port=35337): Max retries exceeded with url: /v3/auth/tokens (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f05543597c0>: Failed to establish a new connection: [Errno 111] Connection refused'))'. The call was: path=['list_services'], args=(), kwargs={}, api_version=None
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 Traceback (most recent call last):
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 File "/var/lib/juju/agents/unit-keystone-1/charm/hooks/identity-service-relation-changed", line 937, in <module>
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 main()
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 File "/var/lib/juju/agents/unit-keystone-1/charm/hooks/identity-service-relation-changed", line 930, in main
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 hooks.execute(sys.argv)
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 File "/var/lib/juju/agents/unit-keystone-1/charm/charmhelpers/core/hookenv.py", line 963, in execute
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 self._hooks[hook_name]()
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 File "/var/lib/juju/agents/unit-keystone-1/charm/charmhelpers/contrib/openstack/utils.py", line 1896, in wrapped_f
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 return restart_on_change_helper(
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 File "/var/lib/juju/agents/unit-keystone-1/charm/charmhelpers/core/host.py", line 863, in restart_on_change_helper
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 r = lambda_f()
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 File "/var/lib/juju/agents/unit-keystone-1/charm/charmhelpers/contrib/openstack/utils.py", line 1897, in <lambda>
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 (lambda: f(*args, **kwargs)),
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 File "/var/lib/juju/agents/unit-keystone-1/charm/hooks/identity-service-relation-changed", line 445, in identity_changed
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 add_service_to_keystone(relation_id, remote_unit)
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 File "/var/lib/juju/agents/unit-keystone-1/charm/hooks/keystone_utils.py", line 1991, in add_service_to_keystone
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 _list_services_result = manager.list_services()
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 File "/var/lib/juju/agents/unit-keystone-1/charm/hooks/keystone_utils.py", line 1237, in __call__
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 return _proxy_manager_call(self._path, self.api_version, args, kwargs)
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 File "/var/lib/juju/agents/unit-keystone-1/charm/charmhelpers/core/decorators.py", line 40, in _retry_on_exception_inner_2
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 return f(*args, **kwargs)
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 File "/var/lib/juju/agents/unit-keystone-1/charm/hooks/keystone_utils.py", line 1281, in _proxy_manager_call
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 raise e
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 File "/var/lib/juju/agents/unit-keystone-1/charm/hooks/keystone_utils.py", line 1275, in _proxy_manager_call
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 raise RuntimeError(s)
2023-04-01 12:36:15 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 RuntimeError: The call within manager.py failed with the error: 'Unable to establish connection to http://localhost:35337/v3/auth/tokens: HTTPConnectionPool(host='localhost', port=35337): Max retries exceeded with url: /v3/auth/tokens (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f05543597c0>: Failed to establish a new connection: [Errno 111] Connection refused'))'. The call was: path=['list_services'], args=(), kwargs={}, api_version=None
2023-04-01 12:36:16 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 Traceback (most recent call last):
2023-04-01 12:36:16 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 File "/usr/lib/python3/dist-packages/urllib3/connection.py", line 159, in _new_conn
2023-04-01 12:36:16 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 conn = connection.create_connection(
2023-04-01 12:36:16 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 File "/usr/lib/python3/dist-packages/urllib3/util/connection.py", line 84, in create_connection
2023-04-01 12:36:16 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 raise err
2023-04-01 12:36:16 DEBUG unit.keystone/1.identity-service-relation-changed logger.go:60 Retrying 'get_keystone_manager' 5 more times (delay=3)
2023-04-01 12:36:16 DEBUG unit.keystone/1.identity-service-relation-changed logger.go:60 Retrying 'get_keystone_manager' 4 more times (delay=6)
2023-04-01 12:36:16 DEBUG unit.keystone/1.identity-service-relation-changed logger.go:60 Retrying 'get_keystone_manager' 3 more times (delay=9)
2023-04-01 12:36:16 DEBUG unit.keystone/1.identity-service-relation-changed logger.go:60 Retrying 'get_keystone_manager' 2 more times (delay=12)
2023-04-01 12:36:16 DEBUG unit.keystone/1.identity-service-relation-changed logger.go:60 Retrying 'get_keystone_manager' 1 more times (delay=15)

Initial testrun can be found at:
https://solutions.qa.canonical.com/v2/testruns/d8493662-77c2-4969-afa6-9fe359a9c231/
with crashdrump at:
https://oil-jenkins.canonical.com/artifacts/d8493662-77c2-4969-afa6-9fe359a9c231/generated/generated/openstack/juju-crashdump-openstack-2023-04-01-12.36.08.tar.gz
and all logs at:
https://oil-jenkins.canonical.com/artifacts/d8493662-77c2-4969-afa6-9fe359a9c231/index.html

Revision history for this message
Alex Kavanagh (ajkavanagh) wrote :
Download full text (6.9 KiB)

From keystone/1:

(keystone.server.flask.request_processing.middleware.auth_context): 2023-04-01 08:36:25,698 ERROR (pymysql.err.OperationalError) (2013, 'Lost connection to MySQL server during
 query')
(Background on this error at: https://sqlalche.me/e/14/e3q8)
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/sqlalchemy/engine/base.py", line 1802, in _execute_context
    self.dialect.do_execute(
  File "/usr/lib/python3/dist-packages/sqlalchemy/engine/default.py", line 732, in do_execute
    cursor.execute(statement, parameters)
  File "/usr/lib/python3/dist-packages/pymysql/cursors.py", line 148, in execute
    result = self._query(query)
  File "/usr/lib/python3/dist-packages/pymysql/cursors.py", line 310, in _query
    conn.query(q)
  File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 548, in query
    self._affected_rows = self._read_query_result(unbuffered=unbuffered)
  File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 775, in _read_query_result
    result.read()
  File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 1163, in read
    self._read_result_packet(first_packet)
  File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 1236, in _read_result_packet
    self._read_rowdata_packet()
  File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 1270, in _read_rowdata_packet
    packet = self.connection._read_packet()
  File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 725, in _read_packet
    packet.raise_for_error()
  File "/usr/lib/python3/dist-packages/pymysql/protocol.py", line 221, in raise_for_error
    err.raise_mysql_exception(self._data)
  File "/usr/lib/python3/dist-packages/pymysql/err.py", line 143, in raise_mysql_exception
    raise errorclass(errno, errval)
pymysql.err.OperationalError: (1053, 'Server shutdown in progress')

So "Server shutdown in progress" is a bit ominous.

From mysql-innodb-cluster/0 at the same time:

2023-04-01T08:36:23.178312Z 0 [Warning] [MY-011499] [Repl] Plugin group_replication reported: 'Members removed from the group: 192.168.33.61:3306'
2023-04-01T08:36:23.178353Z 0 [System] [MY-011500] [Repl] Plugin group_replication reported: 'Primary server with address 192.168.33.61:3306 left the group. Electing new Primary.'
2023-04-01T08:36:23.178515Z 0 [System] [MY-011507] [Repl] Plugin group_replication reported: 'A new primary with address 192.168.33.83:3306 was elected. The new primary will execute all previous group transactions before allowing writes.'
2023-04-01T08:36:23.178770Z 0 [System] [MY-011503] [Repl] Plugin group_replication reported: 'Group membership changed to 192.168.33.83:3306, 192.168.33.84:3306 on view 16803355385089891:10.'
2023-04-01T08:36:23.179472Z 68 [System] [MY-011565] [Repl] Plugin group_replication reported: 'Setting super_read_only=ON.'
2023-04-01T08:36:23.179579Z 68 [System] [MY-011511] [Repl] Plugin group_replication reported: 'This server is working as secondary member with primary member address 192.168.33.83:3306.'
2023-04-01T08:37:31.674902Z 0 [System] [MY-011503] [Repl] Plugin group_replication reported: 'Group membership changed to 192.168.33.61:3306, ...

Read more...

Changed in charm-keystone:
status: New → Triaged
Revision history for this message
Alex Kavanagh (ajkavanagh) wrote :

Marking invalid on keystone as it's not really keystone's fault that mysql was unavailable.

Changed in charm-keystone:
status: Triaged → Invalid
Revision history for this message
Alex Kavanagh (ajkavanagh) wrote :

Triaged mysql-innodb-cluster to medium; probably the right thing to do is to hold off all db-router/shared-db relation handling until it is clustered and has the TLS certificates from vault installed and restarted.

Changed in charm-mysql-innodb-cluster:
importance: Undecided → Medium
status: New → Triaged
Revision history for this message
Bas de Bruijne (basdbruijne) wrote :

Keystone retries the identity-service-relation-changed hook several times, also after the MySQL cluster has clustered, but it keeps failing with this message in the keystone log:

===================
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/sqlalchemy/engine/base.py", line 1802, in _execute_context
    self.dialect.do_execute(
  File "/usr/lib/python3/dist-packages/sqlalchemy/engine/default.py", line 732, in do_execute
    cursor.execute(statement, parameters)
  File "/usr/lib/python3/dist-packages/pymysql/cursors.py", line 148, in execute
    result = self._query(query)
  File "/usr/lib/python3/dist-packages/pymysql/cursors.py", line 310, in _query
    conn.query(q)
  File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 548, in query
    self._affected_rows = self._read_query_result(unbuffered=unbuffered)
  File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 775, in _read_query_result
    result.read()
  File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 1156, in read
    first_packet = self.connection._read_packet()
  File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 692, in _read_packet
    packet_header = self._read_bytes(4)
  File "/usr/lib/python3/dist-packages/pymysql/connections.py", line 748, in _read_bytes
    raise err.OperationalError(
pymysql.err.OperationalError: (2013, 'Lost connection to MySQL server during query')
===================

From comment #1 I understand that retrying the hook should solve the problem, but that does not seem to be the case.

If I switch the leader of Keystone it does pass this hook and starts updating the endpoints like normal. It is possible that the certificates can not be updated for the leader units and that that causes the connection issue?

Revision history for this message
Alex Kavanagh (ajkavanagh) wrote :

Based on your last comment:

> If I switch the leader of Keystone it does pass this hook and starts updating the endpoints like normal. It is possible that the certificates can not be updated for the leader units and that that causes the connection issue?

It sounds a bit like the underlying keystone service (running via apache2) hasn't been restarted. If this happens again, then try manually restarting the apache2 process first (on the leader) to see if this works around the issue.

I'll set the keystone part of this to incomplete for the moment.

Changed in charm-keystone:
status: Invalid → Incomplete
Revision history for this message
Alexander Litvinov (alitvinov) wrote (last edit ):

I am facing the same issue on a different environment.
Restarting apache2 on leader unit does not solve the issue.

Changed in charm-keystone:
status: Incomplete → New
Revision history for this message
Jeffrey Chang (modern911) wrote :

subscribe to field-high for this bug, since this is blocking all Solutions-QA test for Yoga at this moment.

Revision history for this message
Billy Olsen (billy-olsen) wrote :
Download full text (3.3 KiB)

Looking at the data that was provided in the description and the commentary from Alex in comment #1, I see the same thing. Unfortunately, keystone charm makes a request to the keystone API as part of the relation-changed hook and fails for the last time 1 second before the mysql-router service is actually restarted successfully and working.

However, if we look closely - we will also see that the identity-service-relation-changed hooks begin to fail with the following error (both before and after the database connection challenges):

--- Before ---
2023-04-01 08:36:00 ERROR unit.keystone/1.juju-log server.go:316 identity-service:134: The call within manager.py failed with the error: 'Unable to establish connection to http://localhost:35337/v3/auth/tokens: HTTPConnectionPool(host='localhost', port=35337): Max retries exceeded with url: /v3/auth/tokens (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f8975f19370>: Failed to establish a new connection: [Errno 111] Connection refused'))'. The call was: path=['list_services'], args=(), kwargs={}, api_version=None

--- After ---
2023-04-01 08:41:41 WARNING unit.keystone/1.identity-service-relation-changed logger.go:60 keystoneauth1.exceptions.connection.ConnectFailure: Unable to establish connection to http://localh
ost:35337/v3/auth/tokens: HTTPConnectionPool(host='localhost', port=35337): Max retries exceeded with url: /v3/auth/tokens (Caused by NewConnectionError('<urllib3.connection.HTTPConnection o
bject at 0x7f0a47851370>: Failed to establish a new connection: [Errno 111] Connection refused'))
2023-04-01 08:41:41 ERROR juju.worker.uniter.operation runhook.go:153 hook "identity-service-relation-changed" (via explicit, bespoke hook script) failed: exit status 1

--- Even later ---
2023-04-01 08:47:31 ERROR unit.keystone/1.juju-log server.go:316 identity-service:134: The call within manager.py failed with the error: 'Unable to establish connection to http://localhost:35337/v3/auth/tokens: HTTPConnectionPool(host='localhost', port=35337): Max retries exceeded with url: /v3/auth/tokens (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7fe4e9b6f370>: Failed to establish a new connection: [Errno 111] Connection refused'))'. The call was: path=['list_services'], args=(), kwargs={}, api_version=None

However, this call will always fail in the current state. This is because the keystone services are not listening on port 35337, they are instead listening on 35347 per the listening.txt in the unit data from the crashdump.

Now, per the local port calculations in determine_api_port (called from add_service_to_keystone) this is forced to a singlenode_mode which automatically decrease the port count by 10. Additionally, the ca is found in the certificates relation so it will also decrease the port count by 10. As such, the charm is looking at interacting with port 35337 while apache2 is listening to port 35347. It's not clear yet *why* the port is not updated correctly. I suspect that when the last service evaluation occurred, it did not have the ca in the certificates relation yet and thus causing it not to go into https port mode.

This is unfo...

Read more...

Revision history for this message
Bas de Bruijne (basdbruijne) wrote :

The bug is very reproducible in our labs but I haven't been able to make a smaller bundle as a reproducer. Let us know if you would like to debug it in the SQA lab so we can give someone access.

Revision history for this message
Corey Bryant (corey.bryant) wrote :

I'm going to look around to see what may have changed in this cycle, since this wasn't seen with the yoga charmhub testing in the previous cycle.

Revision history for this message
Corey Bryant (corey.bryant) wrote :

Bas, do you have a juju status by any chance?

Revision history for this message
Corey Bryant (corey.bryant) wrote (last edit ):

It looks like this is all that is new in charm-keystone's stable/yoga branch since it's release:
 - [107e01e] Add auth_ttl into keystone.conf
 - [5a8463f] Use juju-exec in chron jobs for juju3 support
 - [8c691d4] Update the bundles to use the stable track, edge risk for yoga
 - [c200ccf] New option default_authorization_ttl
 - [d3e642a] Updates for stable branch creation

Revision history for this message
Bas de Bruijne (basdbruijne) wrote :
Download full text (4.5 KiB)

The juju status for keystone looks like

===============================
keystone/0 active idle 1/lxd/6 10.244.41.89 5000/tcp Unit is ready
  filebeat/56 active idle 10.244.41.89 Filebeat ready.
  hacluster-keystone/1 active idle 10.244.41.89 Unit is ready and clustered
  keystone-ldap/1 active idle 10.244.41.89 Unit is ready
  keystone-mysql-router/1 active idle 10.244.41.89 Unit is ready
  landscape-client/53 maintenance idle 10.244.41.89 Need computer-title and juju-info to proceed
  logrotated/49 active idle 10.244.41.89 Unit is ready.
  nrpe/63 active idle 10.244.41.89 icmp,5666/tcp Ready
  prometheus-grok-exporter/54 active idle 10.244.41.89 9144/tcp Unit is ready
  public-policy-routing/32 active idle 10.244.41.89 Unit is ready
  telegraf/55 active idle 10.244.41.89 9103/tcp Monitoring keystone/0 (source version/commit 23.01-4-...)
keystone/1* error idle 3/lxd/7 10.244.41.42 5000/tcp hook failed: "identity-service-relation-changed"
  filebeat/16 active idle 10.244.41.42 Filebeat ready.
  hacluster-keystone/0* active idle 10.244.41.42 Unit is ready and clustered
  keystone-ldap/0* active idle 10.244.41.42 Unit is ready
  keystone-mysql-router/0* active idle 10.244.41.42 Unit is ready
  landscape-client/16 maintenance idle 10.244.41.42 Need computer-title and juju-info to proceed
  logrotated/10 active idle 10.244.41.42 Unit is ready.
  nrpe/22 active idle 10.244.41.42 icmp,5666/tcp Ready
  prometheus-grok-exporter/16 active idle 10.244.41.42 9144/tcp Unit is ready
  public-policy-routing/3 active idle 10.244.41.42 Unit is ready
  telegraf/16 active idle 10.244.41.42 9103/tcp Monitoring keystone/1 (source version/commit 23.01-4-...)
keystone/2 active idle 5/lxd/7 10.244.41.94 5000/tcp Unit is ready
  filebeat/57 active idle 10.244.41.94 ...

Read more...

Revision history for this message
Corey Bryant (corey.bryant) wrote :

Thanks. That confirms keystone is on yoga/stable revision 595, which is the latest available on charmhub.

Revision history for this message
Corey Bryant (corey.bryant) wrote (last edit ):

For vault it looks like we have 2 changes in stable/1.7 since Aug 2022:
 - [acabfa3] Implement cert cache for vault units (v3)
 - [be34ad5] Pin tox to < 4.0.0

Revision history for this message
Corey Bryant (corey.bryant) wrote :

I'm tempted to bump the retry_on_exception to see if that fixes this, at least for testing purposes. It seems likely that it just needs more time to settle before the ports match. Currently we have:

@retry_on_exception(5, base_delay=3, exc_type=RetryProxyManagerCall)
def _proxy_manager_call(path, api_version, args, kwargs):

which retries at
3 seconds
6 seconds
9 seconds
12 seconds
15 seconds

before failing.

Revision history for this message
Bas de Bruijne (basdbruijne) wrote :

The identity-service-relation-changed hook from keystone is retried every 3 minutes already, but without success. Is _proxy_manager_call part of that?

Are there some commands I can run in the test environment to confirm if this approach will work? (Again, I can provide you access to it if that is easier)

Revision history for this message
Corey Bryant (corey.bryant) wrote :

That's a good point. It already has 4+ hours of retries according the the keystone log (first and last errors below):

2023-04-01 08:31:14 ERROR unit.keystone/1.juju-log server.go:316 identity-service:134: The call within manager.py failed with the error: 'Unable to establish connection to http://localhost:35337/v3/auth/tokens:

2023-04-01 12:36:15 ERROR unit.keystone/1.juju-log server.go:316 identity-service:134: The call within manager.py failed with the error: 'Unable to establish connection to http://localhost:35337/v3/auth/tokens:

If you have an environment where this is occurring, access to it would be great.

Revision history for this message
Corey Bryant (corey.bryant) wrote :

At the time of the identity-service-relation-changed hook failure, /etc/apache2/sites-enabled/openstack_https_frontend.conf hasn't been rendered since ApacheSSLContext won't render until there is certificate data on the relation.

At the time of the identity-service-relation-changed hook failure, we have:

$ juju exec --unit keystone/1 "relation-get -r certificates:245 - vault/0"
egress-subnets: 10.246.168.97/32
ingress-address: 10.246.168.97
private-address: 10.246.168.97

but show-unit shows the certificate data is available on the relation:

$ juju show-unit keystone/1
  - relation-id: 245
    endpoint: certificates
    related-endpoint: certificates
    application-data: {}
    related-units:
      vault/0:
        in-scope: true
        data:
          egress-subnets: 10.246.168.97/32
          ingress-address: 10.246.168.97
          ...
          keystone_1.processed_requests: '{"eth2.juju-ee22b4-4-lxd-7.nosilo.lab1.solutionsqa":
            {"cert": certificate data snipped>
            ...
          private-address: 10.246.168.97

After a lot of 'juju resolve --no-retry keystone/1' the relation-get started showing the certificate data and /etc/apache2/sites-enabled/openstack_https_frontend.conf was finally rendered as a result, and we see

$ netstat -dnlp | grep 353
(Not all processes could be identified, non-owned process info
 will not be shown, you would have to be root to see it all.)
tcp 0 0 0.0.0.0:35357 0.0.0.0:* LISTEN -
tcp6 0 0 :::35337 :::* LISTEN -
tcp6 0 0 :::35347 :::* LISTEN -
tcp6 0 0 :::35357 :::* LISTEN -

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to charm-keystone (master)
Changed in charm-keystone:
status: New → In Progress
Revision history for this message
Liam Young (gnuoy) wrote :

<tl;dr> I think the issue is due to a discrepancy between the
check the charm uses to decide whether to configure the payload
to use https and the check used to decide whether the client
should use https when talking to the local endpoint</tl;dr>

The `https` method is used to check if an endpoint is expected to
be http or https. One of the checks it performs is to examine the
the certificates relation. If the relation is present then it looks
for the existence of a CA. However the OpenStack charms do not
switch to https until a certificate is provided via the certificates
relation. This means there can be a disconnect if the
certificate provider has provided a CA but has not yet provided
the unit specific certificates. If this happens then the payload
will still be using http but the `https` method will return True.

Steps to reproduce:

Deploy a bundle with keystone, vault, glance, mysql and mysql router but omit
these relations:

keystone <-> vault
glance <-> keystone
glance <-> vault.

For vault also ensure the charm config options:

auto-generate-root-ca-cert: false
totally-unsecure-auto-unlock: false

Once hooks have finished (workload status will mention these missing relations
but ignore that).

1) Start debug hooks session on keystone
2) Start debug hooks session on vault
3) juju add-relation vault keystone
4) Issue command to unlock vault with
   "functest-configure -m ccc -c zaza.openstack.charm_tests.vault.setup.auto_initialize_no_validation_no_wait")
5) Execute all outstanding hooks in vault debug hooks session
6) Execute all outstanding hooks in keystone debug-hooks session
7) Execute hooks in vault debug hooks session until "relation-get" shows the
   certificate request from keystone. DO NOT EXECUTE AND EXIT THIS HOOK

8) At this point keystone has requested a cert (but not got it) and has
   received a CA verify this in keystone debug hooks session:
relation-get -r $(relation-ids certificates) - vault/0

8) juju add-relation glance keystone
9) Execute keystone hooks in debug-hooks session. The
   identity-service-relation-changed hook will fail.

Revision history for this message
Liam Young (gnuoy) wrote :
Revision history for this message
Liam Young (gnuoy) wrote :

Keystone charm with this fix is in the temporary charm branch yoga/edge/gnuoy

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Change abandoned on charm-keystone (master)

Change abandoned by "Corey Bryant <email address hidden>" on branch: master
Review: https://review.opendev.org/c/openstack/charm-keystone/+/880297
Reason: Abandon in favor of https://github.com/juju/charm-helpers/pull/769

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to charm-keystone (master)
Felipe Reyes (freyes)
Changed in charm-helpers:
status: New → Fix Committed
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to charm-keystone (master)

Reviewed: https://review.opendev.org/c/openstack/charm-keystone/+/882281
Committed: https://opendev.org/openstack/charm-keystone/commit/23e2642b4150a33e5749e32d4c9d551580f748b2
Submitter: "Zuul (22348)"
Branch: master

commit 23e2642b4150a33e5749e32d4c9d551580f748b2
Author: Liam Young <email address hidden>
Date: Thu May 4 11:50:00 2023 +0000

    Charmhelper sync for https() pending request fix

    Sync charmhelpers to pull in fix to https() so it returns false
    if there is a pending certificate request

    Change-Id: I6e79570070fb3b6aa85485bbb40a820cb352c68e
    Closes-Bug: #2015103

Changed in charm-keystone:
status: In Progress → Fix Committed
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to charm-keystone (stable/2023.1)

Fix proposed to branch: stable/2023.1
Review: https://review.opendev.org/c/openstack/charm-keystone/+/882946

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to charm-keystone (stable/2023.1)

Reviewed: https://review.opendev.org/c/openstack/charm-keystone/+/882946
Committed: https://opendev.org/openstack/charm-keystone/commit/0f0870520a0c1e6292cfd56b3d4af433ed1b60e6
Submitter: "Zuul (22348)"
Branch: stable/2023.1

commit 0f0870520a0c1e6292cfd56b3d4af433ed1b60e6
Author: Felipe Reyes <email address hidden>
Date: Thu May 11 09:02:24 2023 -0400

    charm-helpers sync

    Synchronize charm-helpers to get the bug fix when keystone leader fails
    to connect to itself while running identity-service-relation-changed
    hook.

    Change-Id: I8b815a6c14738c4e8f22fa6c281ab5116cfeb640
    Closes-Bug: #2015103

Revision history for this message
Corey Bryant (corey.bryant) wrote (last edit ):
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to charm-keystone (stable/zed)

Fix proposed to branch: stable/zed
Review: https://review.opendev.org/c/openstack/charm-keystone/+/884685

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to charm-keystone (stable/yoga)

Fix proposed to branch: stable/yoga
Review: https://review.opendev.org/c/openstack/charm-keystone/+/884686

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to charm-keystone (stable/xena)

Fix proposed to branch: stable/xena
Review: https://review.opendev.org/c/openstack/charm-keystone/+/884687

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to charm-keystone (stable/wallaby)

Fix proposed to branch: stable/wallaby
Review: https://review.opendev.org/c/openstack/charm-keystone/+/884688

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to charm-keystone (stable/victoria)

Fix proposed to branch: stable/victoria
Review: https://review.opendev.org/c/openstack/charm-keystone/+/884689

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to charm-keystone (stable/ussuri)

Fix proposed to branch: stable/ussuri
Review: https://review.opendev.org/c/openstack/charm-keystone/+/884690

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to charm-keystone (stable/train)

Fix proposed to branch: stable/train
Review: https://review.opendev.org/c/openstack/charm-keystone/+/884691

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to charm-keystone (stable/zed)

Reviewed: https://review.opendev.org/c/openstack/charm-keystone/+/884685
Committed: https://opendev.org/openstack/charm-keystone/commit/c8aca2e454abacce1a74b121087f5ab05637aebd
Submitter: "Zuul (22348)"
Branch: stable/zed

commit c8aca2e454abacce1a74b121087f5ab05637aebd
Author: Corey Bryant <email address hidden>
Date: Tue May 30 08:50:25 2023 -0400

    charm-helpers sync

    Synchronize charm-helpers to get the bug fix when keystone leader fails
    to connect to itself while running identity-service-relation-changed
    hook.

    Closes-Bug: #2015103
    Change-Id: I8a473197146d9631433a84aa6dde83a74c514607

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to charm-keystone (stable/yoga)

Reviewed: https://review.opendev.org/c/openstack/charm-keystone/+/884686
Committed: https://opendev.org/openstack/charm-keystone/commit/62fa41d4ae92d28a1631374482b9670364e9a1e9
Submitter: "Zuul (22348)"
Branch: stable/yoga

commit 62fa41d4ae92d28a1631374482b9670364e9a1e9
Author: Corey Bryant <email address hidden>
Date: Tue May 30 08:56:21 2023 -0400

    charm-helpers sync

    Synchronize charm-helpers to get the bug fix when keystone leader fails
    to connect to itself while running identity-service-relation-changed
    hook.

    Closes-Bug: #2015103
    Change-Id: Id740e9666d1ed10dfcb587a0daf2d6565ff7baec

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to charm-keystone (stable/xena)

Reviewed: https://review.opendev.org/c/openstack/charm-keystone/+/884687
Committed: https://opendev.org/openstack/charm-keystone/commit/a03cc532a011efe3c4a5f98002256a97ffa728fa
Submitter: "Zuul (22348)"
Branch: stable/xena

commit a03cc532a011efe3c4a5f98002256a97ffa728fa
Author: Corey Bryant <email address hidden>
Date: Tue May 30 08:57:37 2023 -0400

    charm-helpers sync

    Synchronize charm-helpers to get the bug fix when keystone leader fails
    to connect to itself while running identity-service-relation-changed
    hook.

    Closes-Bug: #2015103
    Change-Id: Ieb522471be927d51e3d5b8b30e21b73cda9ef56e

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to charm-keystone (stable/wallaby)

Reviewed: https://review.opendev.org/c/openstack/charm-keystone/+/884688
Committed: https://opendev.org/openstack/charm-keystone/commit/9670b7dac8f5fa5e3b2d7d43180dbd2110ec95e6
Submitter: "Zuul (22348)"
Branch: stable/wallaby

commit 9670b7dac8f5fa5e3b2d7d43180dbd2110ec95e6
Author: Corey Bryant <email address hidden>
Date: Tue May 30 08:58:35 2023 -0400

    charm-helpers sync

    Synchronize charm-helpers to get the bug fix when keystone leader fails
    to connect to itself while running identity-service-relation-changed
    hook.

    Closes-Bug: #2015103
    Change-Id: I4c354effe70df10e01ceb70ef9e223a99ebd42cd

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to charm-keystone (stable/victoria)

Reviewed: https://review.opendev.org/c/openstack/charm-keystone/+/884689
Committed: https://opendev.org/openstack/charm-keystone/commit/3c45852e864202a92568ca25302e9f1610d60b59
Submitter: "Zuul (22348)"
Branch: stable/victoria

commit 3c45852e864202a92568ca25302e9f1610d60b59
Author: Corey Bryant <email address hidden>
Date: Tue May 30 08:59:23 2023 -0400

    charm-helpers sync

    Synchronize charm-helpers to get the bug fix when keystone leader fails
    to connect to itself while running identity-service-relation-changed
    hook.

    Closes-Bug: #2015103
    Change-Id: I5282304131a73ef572430cba98c9b0d3a52f0877

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to charm-keystone (stable/ussuri)

Reviewed: https://review.opendev.org/c/openstack/charm-keystone/+/884690
Committed: https://opendev.org/openstack/charm-keystone/commit/6f426f3a66f0a4f93e0c319ec098f36e4042ec0a
Submitter: "Zuul (22348)"
Branch: stable/ussuri

commit 6f426f3a66f0a4f93e0c319ec098f36e4042ec0a
Author: Corey Bryant <email address hidden>
Date: Tue May 30 09:00:11 2023 -0400

    charm-helpers sync

    Synchronize charm-helpers to get the bug fix when keystone leader fails
    to connect to itself while running identity-service-relation-changed
    hook.

    Closes-Bug: #2015103
    Change-Id: I26c7659484815a15da8d36590a4e77c01a4b17bf

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to charm-keystone (stable/train)

Reviewed: https://review.opendev.org/c/openstack/charm-keystone/+/884691
Committed: https://opendev.org/openstack/charm-keystone/commit/11454ac2acb25f35d3a95331ce6935bc577566fd
Submitter: "Zuul (22348)"
Branch: stable/train

commit 11454ac2acb25f35d3a95331ce6935bc577566fd
Author: Corey Bryant <email address hidden>
Date: Tue May 30 09:04:07 2023 -0400

    charm-helpers sync

    Synchronize charm-helpers to get the bug fix when keystone leader fails
    to connect to itself while running identity-service-relation-changed
    hook.

    Closes-Bug: #2015103
    Change-Id: Ia7622a41467aa963b4940171d1aa718e3b9fcf8d

Revision history for this message
Edward Hope-Morley (hopem) wrote :

this patch has been found to break ssl for some charms - https://bugs.launchpad.net/charm-octavia/+bug/2022980

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.