The contrail-api needs to communicate with keystone to sync up the tenant (project) information. Therefore, a keystone database problem may affact the contrail-api process status.
In all three Contrail controllers, the contrail-api gets stuck in 'initializing' status.
'initializing'
initializing (Generic Connection:Keystone[Error: badly formed hexadecimal UUID string
'contrail-status -d
root@cont102:~# contrail-status -d == Contrail Control == supervisor-control: active contrail-control active pid 27676, uptime 3:46:38 contrail-control-nodemgr active pid 27675, uptime 3:46:38 contrail-dns active pid 27677, uptime 3:46:38 contrail-named active pid 27678, uptime 3:46:38 == Contrail Analytics == supervisor-analytics: active contrail-alarm-gen active pid 1623, uptime 29 days, 4:41:25 contrail-analytics-api active pid 1622, uptime 29 days, 4:41:25 contrail-analytics-nodemgr active pid 1616, uptime 29 days, 4:41:25 contrail-collector active pid 1620, uptime 29 days, 4:41:25 contrail-query-engine active pid 1621, uptime 29 days, 4:41:25 contrail-snmp-collector active pid 21578, uptime 29 days, 3:10:05 contrail-topology active pid 14893, uptime 22 days, 1:12:23 == Contrail Config == supervisor-config: active contrail-api:0 initializing (Generic Connection:Keystone[Error: badly formed hexadecimal UUID string at UTC 2018-12-08 01:25:46.670537] connection down)pid 15565, uptime 6:40:14 contrail-config-nodemgr active pid 15562, uptime 6:40:14 contrail-device-manager backup pid 15566, uptime 6:40:14 contrail-discovery:0 active pid 15564, uptime 6:40:14 contrail-schema backup pid 15567, uptime 6:40:14 contrail-svc-monitor backup pid 15568, uptime 6:40:14 ifmap active pid 15563, uptime 6:40:14 == Contrail Web UI == supervisor-webui: active contrail-webui active pid 1606, uptime 29 days, 4:41:25 contrail-webui-middleware active pid 1608, uptime 29 days, 4:41:25 == Contrail Database == contrail-database: active == Contrail Supervisor Database == supervisor-database: active contrail-database-nodemgr active pid 1601, uptime 29 days, 4:41:25 kafka active pid 13221, uptime 23 days, 22:43:05 == Contrail Support Services == supervisor-support-service: active rabbitmq-server active pid 1600, uptime 29 days, 4:41:25
In the contrail-api.log and contrail-api-0-stdout.log , the following messages can be found:
172.29.0.22 - - [2018-11-13 00:00:20] "POST /fqname-to-id HTTP/1.1" 200 156 0.027712 INFO:pycassa.pool:Connection 139776041287824 (172.29.2.248:9160) in pool 139776426408848 failed: UnavailableException(_message=None) ERROR:contrail-api:Session Event: TCP Connection Closed ERROR:contrail-api:SANDESH: [DROP: WrongClientSMState] NodeStatusUVE: data = << name = zrdm3ccnt01.rdm3.cci.att.com process_status = [ << module_id = contrail-api instance_id = 0 state = Non-Functional connection_infos = [ << type = IFMap name = IfMap server_addrs = [ 172.29.2.249:8443, ] status = Up description = >>, << type = Collector name = server_addrs = [ 172.29.2.247:8086, ] status = Down description = ClientInit to Idle on EvConnectTimerExpired >>, << type = Database name = RabbitMQ server_addrs = [ 172.29.0.21, ] status = Up description = >>, << type = Zookeeper name = Zookeeper server_addrs = [ 172.29.2.248:2181, 172.29.2.249:2181, 172.29.2.250:2181, ] status = Up description = >>, << type = Discovery name = ApiServer server_addrs = [ 172.29.0.21:5998, ] status = Up description = Publish Success >>, << type = Discovery name = IfmapServer server_addrs = [ 172.29.0.21:5998, ] status = Up description = Publish Success >>, << type = Discovery name = Collector server_addrs = [ 172.29.0.21:5998, ] status = Up description = Subscribe Response >>, << type = Database name = Cassandra server_addrs = [ 172.29.2.248:9160, 172.29.2.249:9160, 172.29.2.250:9160, ] status = Up description = >>, << type = Generic Connection name = Keystone server_addrs = [ https://identity-aic.rdm3.cci.att.com:35357/v2.0, ] status = Down description = Error: badly formed hexadecimal UUID string at UTC 2018-11-12 23:59:20.835793 >>, ] description = Collector, Generic Connection:Keystone[Error: badly formed hexadecimal UUID string at UTC 2018-11-12 23:59:20.835793] connection down >>, ] >>
When this issue occurs, the contrail-api service can actually be up and running, but it has a problem syncing up data from keystone, which is indicated by the error message. There may not be any service impact observed.
The 'badly formed hexadecimal UUID string' error is a generic python error when uuid module is fed with an invalid UUID.
'badly formed hexadecimal UUID string'
root@cont102:~# python Python 2.7.6 (default, Jun 22 2015, 17:58:13) [GCC 4.8.2] on linux2 Type "help", "copyright", "credits" or "license" for more information. >>> import uuid >>> str(uuid.UUID('abc')) Traceback (most recent call last): File " <stdin> ", line 1, in <module> File "/usr/lib/python2.7/uuid.py", line 134, in __init__ raise ValueError('badly formed hexadecimal UUID string') ValueError: badly formed hexadecimal UUID string
When contrail-api is trying to read the keystone DB, a 'badly-formed UUID' in any record of the keystone table may trigger the error. The same exact issue can be replicated by manually adding a project record in keystone that does not have a valid UUID.
Login to keystone mysql
root@opsk99:~# mysql -ukeystone -pc0ntrail123 Welcome to the MySQL monitor. Commands end with ; or \g. Your MySQL connection id is 275742 Server version: 5.5.37 MySQL Community Server (GPL), wsrep_25.10.r3990 Copyright (c) 2000, 2016, Oracle and/or its affiliates. All rights reserved. Oracle is a registered trademark of Oracle Corporation and/or its affiliates. Other names may be trademarks of their respective owners.
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
'help;'
'\h'
'\c'
mysql> show databases; +--------------------+ | Database | +--------------------+ | information_schema | | keystone | | test | +--------------------+ 3 rows in set (0.00 sec)
Select keystone DB:
mysql> use keystone; Reading table information for completion of table and column names You can turn off this feature to get a quicker startup with -A Database changed
List tables in the keystone DB:
mysql> show tables; +------------------------+ | Tables_in_keystone | +------------------------+ | access_token | | assignment | | consumer | | credential | | domain | | endpoint | | endpoint_group | | federation_protocol | | group | | id_mapping | | identity_provider | | idp_remote_ids | | mapping | | migrate_version | | policy | | policy_association | | project | | project_endpoint | | project_endpoint_group | | region | | request_token | | revocation_event | | role | | sensitive_config | | service | | service_provider | | token | | trust | | trust_role | | user | | user_group_membership | | whitelisted_config | +------------------------+ 32 rows in set (0.00 sec)
List the project table:
mysql> select * from project; +----------------------------------+--------------------+-------+-------------+---------+-----------+-----------+ | id | name | extra | description | enabled | domain_id | parent_id | +----------------------------------+--------------------+-------+-------------+---------+-----------+-----------+ | 05b091dfd9bd4191926072ff19aecb10 | niranjants | {} | | 1 | default | NULL | | 109ac1f3c5034b61baa7296a9aa85f21 | service | {} | | 1 | default | NULL | | 15dbc03fbdda4eb380ea1f014d9be0d7 | test2 | {} | NULL | 1 | default | NULL | | 295a084ab8e84a13b001cd35f9cc9741 | aamonker | {} | | 1 | default | NULL | | 3cbd379c48f34a06a6e9ecfe86012283 | invisible_to_admin | {} | NULL | 1 | default | NULL | | 4209ff6c449e4dd39b58583b7bdb7328 | jlu | {} | | 1 | default | NULL | | 5b3ebb0c0a794f27be662242290a593a | test1 | {} | NULL | 1 | default | NULL | | 6259d182fc9b4a0aac7e3fcb28ac9f5b | bfarooq | {} | | 1 | default | NULL | | 7ecef979004c45acadb8c88b96e96fd3 | demo | {} | | 1 | default | NULL | | 7fccf71a7e7d4c798413513ee809435a | jjzhang | {} | | 1 | default | NULL | | 98e0a0be21e746b0b4e18194515d2918 | AnalyticsAPITest | {} | 3212 test | 1 | default | NULL | | a791f02319ed4450888d167c935eb94b | cheny | {} | | 1 | default | NULL | | abb527ab95d946438097ecf64cba3d02 | nzhong | {} | | 1 | default | NULL | | acae6b2a3291444596179e23a271c980 | pings | {} | | 1 | default | NULL | | ede15b5d21eb4401bd2a56e8d373aa71 | admin | {} | NULL | 1 | default | NULL | +----------------------------------+--------------------+-------+-------------+---------+-----------+-----------+ 15 rows in set (0.00 sec)
To replicate the issue, insert a 'bogus' record without a valid UUID in the project table:
mysql> insert into project ( id, name, domain_id ) values ( "default", "bogus_project", "default" ); ^^^^^^^ (invalid UUID) mysql> select * from project; +----------------------------------+--------------------+-------+-------------+---------+-----------+-----------+ | id | name | extra | description | enabled | domain_id | parent_id | +----------------------------------+--------------------+-------+-------------+---------+-----------+-----------+ | 05b091dfd9bd4191926072ff19aecb10 | niranjants | {} | | 1 | default | NULL | | 109ac1f3c5034b61baa7296a9aa85f21 | service | {} | | 1 | default | NULL | | 15dbc03fbdda4eb380ea1f014d9be0d7 | test2 | {} | NULL | 1 | default | NULL | | 295a084ab8e84a13b001cd35f9cc9741 | aamonker | {} | | 1 | default | NULL | | 3cbd379c48f34a06a6e9ecfe86012283 | invisible_to_admin | {} | NULL | 1 | default | NULL | | 4209ff6c449e4dd39b58583b7bdb7328 | jlu | {} | | 1 | default | NULL | | 5b3ebb0c0a794f27be662242290a593a | test1 | {} | NULL | 1 | default | NULL | | 6259d182fc9b4a0aac7e3fcb28ac9f5b | bfarooq | {} | | 1 | default | NULL | | 7ecef979004c45acadb8c88b96e96fd3 | demo | {} | | 1 | default | NULL | | 7fccf71a7e7d4c798413513ee809435a | jjzhang | {} | | 1 | default | NULL | | 98e0a0be21e746b0b4e18194515d2918 | AnalyticsAPITest | {} | 3212 test | 1 | default | NULL | | a791f02319ed4450888d167c935eb94b | cheny | {} | | 1 | default | NULL | | abb527ab95d946438097ecf64cba3d02 | nzhong | {} | | 1 | default | NULL | | acae6b2a3291444596179e23a271c980 | pings | {} | | 1 | default | NULL | | default | bogus_project | NULL | NULL | NULL | default | NULL | | ede15b5d21eb4401bd2a56e8d373aa71 | admin | {} | NULL | 1 | default | NULL | +----------------------------------+--------------------+-------+-------------+---------+-----------+-----------+ 16 rows in set (0.00 sec)
Immediately after the bad record is inserted in the project table, in all Contrail controllers, the exact error messages from contrail-api will show up:
== Contrail Config == supervisor-config: active contrail-api:0 initializing (Generic Connection:Keystone[Error: <type 'NoneType'> can't be decoded (HTTP 400) (Request-ID: req-6eabcc90-1492-4c19-9fc2-5182bb3c7010) at UTC 2018-12-08 00:58:44.289556] connection down)pid 15565, uptime 6:13:01 contrail-config-nodemgr active pid 15562, uptime 6:13:01 contrail-device-manager backup pid 15566, uptime 6:13:01 contrail-discovery:0 active pid 15564, uptime 6:13:01 contrail-schema backup pid 15567, uptime 6:13:01 contrail-svc-monitor backup pid 15568, uptime 6:13:01 ifmap active pid 15563, uptime 6:13:01 mysql> delete from project where id="default"; Query OK, 1 row affected (0.00 sec) == Contrail Config == supervisor-config: active contrail-api:0 active pid 15565, uptime 6:13:39 contrail-config-nodemgr active pid 15562, uptime 6:13:39 contrail-device-manager backup pid 15566, uptime 6:13:39 contrail-discovery:0 active pid 15564, uptime 6:13:39 contrail-schema backup pid 15567, uptime 6:13:39 contrail-svc-monitor backup pid 15568, uptime 6:13:39 ifmap active pid 15563, uptime 6:13:39 mysql> insert into project ( id, name, extra, description, enabled, domain_id ) values ( "default", "bogus_project", "{}", "crash api", 1, "default" ); == Contrail Config == supervisor-config: active contrail-api:0 initializing (Generic Connection:Keystone[Error: badly formed hexadecimal UUID string at UTC 2018-12-08 01:11:45.275981] connection down)pid 15565, uptime 6:25:49 contrail-config-nodemgr active pid 15562, uptime 6:25:49 contrail-device-manager backup pid 15566, uptime 6:25:49 contrail-discovery:0 active pid 15564, uptime 6:25:49 contrail-schema backup pid 15567, uptime 6:25:49 contrail-svc-monitor backup pid 15568, uptime 6:25:49 ifmap active pid 15563, uptime 6:25:49
To clear the issue, drop the 'bogus' record from the project table:
mysql> delete from project where id="default"; Query OK, 1 row affected (0.00 sec)