search

processone / ejabberd

Robust, Ubiquitous and Massively Scalable Messaging Platform (XMPP, MQTT, SIP Server)
https://www.process-one.net/en/ejabberd/
Other
6.06k stars 1.51k forks source link

MySQL Issue When Migrating from 22.10 --> 23.01 #3981

Closed dkliss closed 1 year ago

dkliss commented 1 year ago

What I did.

Step 1: Migrated from 22.10 to 23.01. Step 2: Took latest MySQL schema changes from below link wget https://raw.githubusercontent.com/processone/ejabberd/master/sql/mysql.sql

Summary of issues.

ISSUE 1: MySQL Connection start to fail as per logs below when on 23.01. Rebooted MySQL and also re-created MySQL database and schema. No luck. ISSUE 2: When reverted back from 23.01 to 22.10, keeping same latest schema as in wget link above. MySQL connection error again on one node out of two in a cluster. One node started.

SOLVED: Reverted back to 22.10 with older MYSQL Schema (before 23.01) and the server was up and running.

Not sure what could be an issue or if I missed anything. Any advice will be much appreciated.

ISSUE 1 Logs. 

023-01-21 03:19:56.449655+00:00 [info] Loading configuration from /opt/ejabberd/conf/ejabberd.yml
2023-01-21 03:19:57.054312+00:00 [info] Configuration loaded successfully
2023-01-21 03:19:57.229007+00:00 [info] Got no NOTIFY_SOCKET, notifications disabled
2023-01-21 03:19:57.242887+00:00 [info] Building language translation cache
2023-01-21 03:19:57.514023+00:00 [info] Creating Mnesia ram table 'ejabberd_commands'
2023-01-21 03:19:57.560119+00:00 [info] Creating Mnesia ram table 'route'
2023-01-21 03:19:57.565595+00:00 [info] Creating Mnesia ram table 'route_multicast'
2023-01-21 03:19:57.578017+00:00 [info] Creating Mnesia ram table 'session'
2023-01-21 03:19:57.581209+00:00 [info] Creating Mnesia ram table 'session_counter'
2023-01-21 03:19:57.590835+00:00 [info] Creating Mnesia ram table 's2s'
2023-01-21 03:19:57.593880+00:00 [info] Creating Mnesia ram table 'temporarily_blocked'
2023-01-21 03:19:57.602639+00:00 [info] Loading modules for devchatbloc.com
2023-01-21 03:19:57.602980+00:00 [info] Creating Mnesia ram table 'mod_register_ip'
2023-01-21 03:19:57.712159+00:00 [info] Creating Mnesia ram table 'muc_online_room'
2023-01-21 03:19:57.878374+00:00 [error] p1_mysql_conn: ssl start failed: {options,
                                  {keyfile,
                                   "/opt/ejabberd/conf/mysql-client-cert.pem",
                                   []}}

2023-01-21 03:19:57.878784+00:00 [warning] mysql connection failed:
** Reason: normal
** Retry after: 5 seconds
2023-01-21 03:19:57.879239+00:00 [error] p1_mysql_conn: ssl start failed: {options,
                                  {keyfile,
                                   "/opt/ejabberd/conf/mysql-client-cert.pem",
                                   []}}

2023-01-21 03:19:57.879531+00:00 [warning] mysql connection failed:
** Reason: normal
** Retry after: 5 seconds
2023-01-21 03:19:57.879905+00:00 [error] p1_mysql_conn: ssl start failed: {options,
                                  {keyfile,
                                   "/opt/ejabberd/conf/mysql-client-cert.pem",
                                   []}}

2023-01-21 03:19:57.880188+00:00 [warning] mysql connection failed:
** Reason: normal
** Retry after: 5 seconds
2023-01-21 03:19:57.880626+00:00 [error] p1_mysql_conn: ssl start failed: {options,
                                  {keyfile,
                                   "/opt/ejabberd/conf/mysql-client-cert.pem",
                                   []}}

2023-01-21 03:19:57.880934+00:00 [warning] mysql connection failed:
** Reason: normal
** Retry after: 5 seconds
2023-01-21 03:19:57.881455+00:00 [error] p1_mysql_conn: ssl start failed: {options,
                                  {keyfile,
                                   "/opt/ejabberd/conf/mysql-client-cert.pem",
                                   []}}

2023-01-21 03:19:57.881989+00:00 [warning] mysql connection failed:
** Reason: normal
** Retry after: 5 seconds
2023-01-21 03:19:57.882365+00:00 [error] p1_mysql_conn: ssl start failed: {options,
                                  {keyfile,
                                   "/opt/ejabberd/conf/mysql-client-cert.pem",
                                   []}}

2023-01-21 03:19:57.882655+00:00 [warning] mysql connection failed:
** Reason: normal
** Retry after: 5 seconds
2023-01-21 03:19:57.883021+00:00 [error] p1_mysql_conn: ssl start failed: {options,
                                  {keyfile,
                                   "/opt/ejabberd/conf/mysql-client-cert.pem",
                                   []}}

2023-01-21 03:19:57.883287+00:00 [warning] mysql connection failed:
** Reason: normal
** Retry after: 5 seconds
2023-01-21 03:19:57.883655+00:00 [error] p1_mysql_conn: ssl start failed: {options,
                                  {keyfile,
                                   "/opt/ejabberd/conf/mysql-client-cert.pem",
                                   []}}

2023-01-21 03:19:57.883933+00:00 [warning] mysql connection failed:
** Reason: normal
** Retry after: 5 seconds
2023-01-21 03:19:57.884173+00:00 [error] p1_mysql_conn: ssl start failed: {options,
                                  {keyfile,
                                   "/opt/ejabberd/conf/mysql-client-cert.pem",
                                   []}}

2023-01-21 03:19:57.884414+00:00 [warning] mysql connection failed:
** Reason: normal
** Retry after: 5 seconds
2023-01-21 03:19:57.885091+00:00 [error] p1_mysql_conn: ssl start failed: {options,
                                  {keyfile,
                                   "/opt/ejabberd/conf/mysql-client-cert.pem",
                                   []}}

2023-01-21 03:19:57.885384+00:00 [warning] mysql connection failed:
** Reason: normal
** Retry after: 5 seconds
2023-01-21 03:19:58.723998+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:19:58.724239+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:19:58.724358+00:00 [warning] Unexpected call force_timeout from <0.644.0> in 'connecting'
2023-01-21 03:19:58.724438+00:00 [warning] Unexpected call force_timeout from <0.645.0> in 'connecting'
2023-01-21 03:19:58.730043+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:19:58.730300+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:19:58.730473+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:19:58.730645+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:19:58.730823+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:19:58.730995+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:19:58.731115+00:00 [warning] Unexpected call force_timeout from <0.646.0> in 'connecting'
2023-01-21 03:19:58.731211+00:00 [warning] Unexpected call force_timeout from <0.647.0> in 'connecting'
2023-01-21 03:19:58.731263+00:00 [warning] Unexpected call force_timeout from <0.649.0> in 'connecting'
2023-01-21 03:19:58.731310+00:00 [warning] Unexpected call force_timeout from <0.650.0> in 'connecting'
2023-01-21 03:19:58.731353+00:00 [warning] Unexpected call force_timeout from <0.651.0> in 'connecting'
2023-01-21 03:19:58.731395+00:00 [warning] Unexpected call force_timeout from <0.652.0> in 'connecting'
2023-01-21 03:19:58.731459+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:19:58.731559+00:00 [warning] Unexpected call force_timeout from <0.653.0> in 'connecting'
2023-01-21 03:19:58.731617+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:19:58.731712+00:00 [warning] Unexpected call force_timeout from <0.648.0> in 'connecting'
2023-01-21 03:19:59.723997+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:19:59.724252+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:19:59.724400+00:00 [warning] Unexpected call force_timeout from <0.654.0> in 'connecting'
2023-01-21 03:19:59.724725+00:00 [warning] Unexpected call force_timeout from <0.655.0> in 'connecting'
2023-01-21 03:19:59.730289+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:19:59.730563+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:19:59.730702+00:00 [warning] Unexpected call force_timeout from <0.663.0> in 'connecting'
2023-01-21 03:19:59.730846+00:00 [warning] Unexpected call force_timeout from <0.656.0> in 'connecting'
2023-01-21 03:19:59.730828+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:19:59.730953+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:19:59.730997+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:19:59.731125+00:00 [warning] Unexpected call force_timeout from <0.659.0> in 'connecting'
2023-01-21 03:19:59.731207+00:00 [warning] Unexpected call force_timeout from <0.658.0> in 'connecting'
2023-01-21 03:19:59.731157+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:19:59.731284+00:00 [warning] Unexpected call force_timeout from <0.660.0> in 'connecting'
2023-01-21 03:19:59.731321+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:19:59.731401+00:00 [warning] Unexpected call force_timeout from <0.661.0> in 'connecting'
2023-01-21 03:19:59.731481+00:00 [warning] Unexpected call force_timeout from <0.662.0> in 'connecting'
2023-01-21 03:19:59.731499+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:19:59.731745+00:00 [warning] Unexpected call force_timeout from <0.657.0> in 'connecting'
2023-01-21 03:20:00.724107+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:20:00.724102+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:20:00.724392+00:00 [warning] Unexpected call force_timeout from <0.665.0> in 'connecting'
2023-01-21 03:20:00.724473+00:00 [warning] Unexpected call force_timeout from <0.664.0> in 'connecting'
2023-01-21 03:20:00.730027+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:20:00.730018+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:20:00.730300+00:00 [warning] Unexpected call force_timeout from <0.673.0> in 'connecting'
2023-01-21 03:20:00.730300+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:20:00.730447+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:20:00.730465+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:20:00.730665+00:00 [warning] Unexpected call force_timeout from <0.669.0> in 'connecting'
2023-01-21 03:20:00.730618+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:20:00.730781+00:00 [warning] Unexpected call force_timeout from <0.668.0> in 'connecting'
2023-01-21 03:20:00.730781+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:20:00.730873+00:00 [warning] Unexpected call force_timeout from <0.672.0> in 'connecting'
2023-01-21 03:20:00.731063+00:00 [warning] Unexpected call force_timeout from <0.670.0> in 'connecting'
2023-01-21 03:20:00.731092+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:20:00.731283+00:00 [warning] Unexpected call force_timeout from <0.666.0> in 'connecting'
2023-01-21 03:20:00.734304+00:00 [warning] Unexpected call force_timeout from <0.667.0> in 'connecting'
2023-01-21 03:20:00.731282+00:00 [warning] Unexpected call force_timeout from <0.671.0> in 'connecting'
2023-01-21 03:20:01.723988+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:20:01.724003+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:20:01.724276+00:00 [warning] Unexpected call force_timeout from <0.678.0> in 'connecting'
2023-01-21 03:20:01.724335+00:00 [warning] Unexpected call force_timeout from <0.677.0> in 'connecting'
2023-01-21 03:20:01.730125+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:20:01.730313+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:20:01.730418+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:20:01.730514+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
2023-01-21 03:20:01.730607+00:00 [error] Keep alive query failed, closing connection: {error,
                                              <<"SQL connection failed">>}
licaon-kter commented 1 year ago

There were no SQL changes to take... https://docs.ejabberd.im/admin/upgrade/from_22.10_to_23.01/ not sure why/what you did.

Do you use "new_sql_schema" in config .yml?

Do add a gist of your cleaned up config.

prefiks commented 1 year ago

Could you show your ejabberd config? It looks like there is issue with estabilishing ssl connection, and this is why it failing.

dkliss commented 1 year ago

Could you show your ejabberd config? It looks like there is issue with estabilishing ssl connection, and this is why it failing.

Below is my MySQL config. This is the exact config I used for 22.10 and then 23.01. It works for 22.10 and have connection issues for 23.01. I will retest this to get some more logs and see if I can find any issue.

default_db: sql sql_type: mysql sql_server: "10.250.191.81" sql_database: "ejabberd" sql_username: "ejabberd" sql_password: "Password123" sql_port: 3306 sql_ssl: true sql_ssl_verify: true
sql_ssl_cafile: "/opt/ejabberd/conf/mysql-ca.pem" sql_ssl_certfile: "/opt/ejabberd/conf/mysql-client-cert.pem" sql_connect_timeout: 10 sql_keepalive_interval: 1

dkliss commented 1 year ago

https://raw.githubusercontent.com/processone/ejabberd/master/sql/mysql.sql

I used the schema from link below. I will re-run test and if no changes made to MySQL or Schema in 23.01, then I will look into my config.

https://raw.githubusercontent.com/processone/ejabberd/master/sql/mysql.sql

nosnilmot commented 1 year ago

sql_ssl_certfile: "/opt/ejabberd/conf/mysql-client-cert.pem"

Try removing this line from your config - I suspect it only contains a certificate and not the private key. Or try adding the right key to it :smile:

The reason it worked in ejabberd 22.10 is it was being ignored and ejabberd was not using mutual TLS / client certificate when connecting to MySQL - which was fixed by https://github.com/processone/ejabberd/commit/6fcfe80a65dad1cb83e2f291a3811ab776d499b7 and the corresponding change in p1_mysql

dkliss commented 1 year ago

sql_ssl_certfile: "/opt/ejabberd/conf/mysql-client-cert.pem"

Try removing this line from your config - I suspect it only contains a certificate and not the private key. Or try adding the right key to it 😄

The reason it worked in ejabberd 22.10 is it was being ignored and ejabberd was not using mutual TLS / client certificate when connecting to MySQL - which was fixed by 6fcfe80 and the corresponding change in p1_mysql

Thanks. I will copy client-cert.pem + client-key.pem -> mysql-client-cert.pem & retest. Much appreciate your input.

dkliss commented 1 year ago

sql_ssl_certfile: "/opt/ejabberd/conf/mysql-client-cert.pem"

Try removing this line from your config - I suspect it only contains a certificate and not the private key. Or try adding the right key to it 😄

The reason it worked in ejabberd 22.10 is it was being ignored and ejabberd was not using mutual TLS / client certificate when connecting to MySQL - which was fixed by 6fcfe80 and the corresponding change in p1_mysql

Hi, I updated my ejabberd.yml mysql-client-cert.pem to include both client-cert.pem + client-key.pem and also verified my SQL server to ensure it supports TLS ciphers as per logs below.

However, I continue to get the error shown below in logs. I did basic test such as restart mysql, reboot, delete and create new tables and database from mysql schema available, re tested if ssl user is accepted) but no outcome.

In SQL, I have below. The one I am providing to ejabberd.yml is a single file with client-cert.pem+client-key.pem. Guessing this is correct?

BTW, the exact PEM file i.e. client-cert.pem+client-key.pem, if i use in 22.10, it works. The one i tested this time on is current master branch. 

ca.pem               Self-signed CA certificate
ca-key.pem           CA private key
server-cert.pem      Server certificate
server-key.pem       Server private key
client-cert.pem      Client certificate
client-key.pem       Client private key

MySQL Logs.

  2023-02-09T03:15:02.494212Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
  2023-02-09T03:15:02.529417Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Bind-address: '::' port: 33060, socket: /var/run/mysqld/mysqlx.sock
  2023-02-09T03:15:02.529479Z 0 [System] [MY-010931] [Server] /usr/sbin/mysqld: ready for connections. Version: '8.0.32-0ubuntu0.22.04.2'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  (Ubuntu).

Ejabberd Logs.

2023-02-09 03:18:21.532542+00:00 [error] p1_mysql_conn: ssl start failed: {options,
                                  {keyfile,
                                   "/opt/ejabberd/conf/mysql-client-cert.pem",
                                   []}}

2023-02-09 03:18:21.533072+00:00 [error] p1_mysql_conn: ssl start failed: {options,
                                  {keyfile,
                                   "/opt/ejabberd/conf/mysql-client-cert.pem",
                                   []}}

2023-02-09 03:18:21.532824+00:00 [error] p1_mysql_conn: ssl start failed: {options,
                                  {keyfile,
                                   "/opt/ejabberd/conf/mysql-client-cert.pem",
                                   []}}

2023-02-09 03:18:21.533518+00:00 [warning] mysql connection failed:
** Reason: normal
** Retry after: 5 seconds
2023-02-09 03:18:21.533770+00:00 [error] p1_mysql_conn: ssl start failed: {options,
                                  {keyfile,
                                   "/opt/ejabberd/conf/mysql-client-cert.pem",
                                   []}}

2023-02-09 03:18:21.534065+00:00 [warning] mysql connection failed:
** Reason: normal
** Retry after: 5 seconds
2023-02-09 03:18:21.534318+00:00 [warning] mysql connection failed:
** Reason: normal
** Retry after: 5 seconds
2023-02-09 03:18:21.534801+00:00 [warning] mysql connection failed:
** Reason: normal
** Retry after: 5 seconds
2023-02-09 03:18:21.534974+00:00 [error] p1_mysql_conn: ssl start failed: {options,
                                  {keyfile,
                                   "/opt/ejabberd/conf/mysql-client-cert.pem",
                                   []}}

2023-02-09 03:18:21.535279+00:00 [error] p1_mysql_conn: ssl start failed: {options,
                                  {keyfile,
                                   "/opt/ejabberd/conf/mysql-client-cert.pem",
                                   []}}

2023-02-09 03:18:21.535748+00:00 [error] p1_mysql_conn: ssl start failed: {options,
                                  {keyfile,
                                   "/opt/ejabberd/conf/mysql-client-cert.pem",
                                   []}}
prefiks commented 1 year ago

You probably don't need sql_ssl_certfile at all. If it worked previously (when we didn't use that option for mysql connections), then you probably should be safe to remove it all together.

dkliss commented 1 year ago

You probably don't need sql_ssl_certfile at all. If it worked previously (when we didn't use that option for mysql connections), then you probably should be safe to remove it all together.

No luck with that as it start to give handshake errors.

Would it be possible to have mutual TLS as "optional feature" so what we had in 22.10 can continue to work along with an option to setup mutual TLS.

In 22.10, I have password protected MySQL, which only accept incoming SSL encrypted and both cluster and database are in private network. We still needed to provide the ssl cert file to ejabberd but I suspect it is not mutual TLS. Would having an option to have one way TLS and mutual TLS be an issue in any way (esp if DB is in private network).

prefiks commented 1 year ago

So after you removed line with sql_ssl_certfile: "/opt/ejabberd/conf/mysql-client-cert.pem" you still are getting error about {keyfile, "/opt/ejabberd/conf/mysql-client-cert.pem"}? Do you that file specified in different place?

You can have password protected mysql connection using tls, as long as you don't have sql_ssl_certfile specified it shouldn't attempt certificate authentication. I have it working like that on my test instance.

dkliss commented 1 year ago

So after you removed line with sql_ssl_certfile: "/opt/ejabberd/conf/mysql-client-cert.pem" you still are getting error about {keyfile, "/opt/ejabberd/conf/mysql-client-cert.pem"}? Do you that file specified in different place?

You can have password protected mysql connection using tls, as long as you don't have sql_ssl_certfile specified it shouldn't attempt certificate authentication. I have it working like that on my test instance.

First I commented out the sql_ssl_certfile option and also removed the file from every place I have specified then I got ERROR 1 below.

And then i totally disabled SSL from ejabberd i.e. setting ssl to false, then I had password error as shown in ERROR 2. I did had password still enabled.

I guess, having one way SSL\TLS may be okay for private network with an option of having two way (i.e. public networks).

I can retest with any specific config, which is working your test setup. My setup config is same as i sent before.


default_db: sql
sql_type: mysql
sql_server: "10.250.191.81"
sql_database: "ejabberd"
sql_username: "ejabberd"
sql_password: "Password123"
sql_port: 3306
sql_ssl: true.  -----> ERROR 2 is generated when i set this to false.
sql_ssl_verify: true
sql_ssl_cafile: "/opt/ejabberd/conf/mysql-ca.pem"
sql_ssl_certfile: "/opt/ejabberd/conf/mysql-client-cert.pem". ---> ERROR 1 is generated when i comment this out.
sql_connect_timeout: 10
sql_keepalive_interval: 1

ERROR 1, when sql_ssl_certfile was disabled\commented out and all places, it is removed.

2023-02-09 11:12:18.312607+00:00 [notice] TLS client: In state wait_cert at ssl_handshake.erl:2084 generated CLIENT ALERT: Fatal - Handshake Failure
 - {bad_cert,hostname_check_failed}
2023-02-09 11:12:18.312641+00:00 [notice] TLS client: In state wait_cert at ssl_handshake.erl:2084 generated CLIENT ALERT: Fatal - Handshake Failure
 - {bad_cert,hostname_check_failed}
2023-02-09 11:12:18.312675+00:00 [notice] TLS client: In state wait_cert at ssl_handshake.erl:2084 generated CLIENT ALERT: Fatal - Handshake Failure
 - {bad_cert,hostname_check_failed}
2023-02-09 11:12:18.320704+00:00 [error] p1_mysql_conn: ssl start failed: {tls_alert,
                                  {handshake_failure,
                                   "TLS client: In state wait_cert at ssl_handshake.erl:2084 generated CLIENT ALERT: Fatal - Handshake Failure\n {bad_cert,hostname_check_failed}"}}

ERROR 2: When ssl is set to false i.e. no ssl at all. Then I got following. 


  2023-02-09 11:15:32.445758+00:00 [error] p1_mysql_conn: init error 1045: "#28000Access denied for user 'ejabberd'@'ip-10-251-192-102.ec2.internal' (using password: YES)"

  2023-02-09 11:15:32.446275+00:00 [warning] mysql connection failed:
  ** Reason: normal
  ** Retry after: 5 seconds
  2023-02-09 11:15:32.485166+00:00 [error] p1_mysql_conn: init error 1045: "#28000Access denied for user 'ejabberd'@'ip-10-251-192-102.ec2.internal' (using password: YES)"

  2023-02-09 11:15:32.485674+00:00 [warning] mysql connection failed:
  ** Reason: normal
  ** Retry after: 5 seconds
  2023-02-09 11:15:32.488610+00:00 [error] p1_mysql_conn: init error 1045: "#28000Access denied for user 'ejabberd'@'ip-10-251-192-102.ec2.internal' (using password: YES)"

Error when sql_ssl_certfile was not disabled i.e. mutual SSL issue.

2023-02-09 08:03:54.471475+00:00 [error] p1_mysql_conn: ssl start failed: {options,
                                  {keyfile,
                                   "/opt/ejabberd/conf/mysql-client-cert.pem",
                                   []}}
prefiks commented 1 year ago

Ok, you are getting {bad_cert,hostname_check_failed} because name in certificate doesn't match what you use to connect. You could change sql_server value to one that match, and which resolve to that address, or possibly try using sql_ssl_verify: false, but not sure if this will relax that check. Still try to use that without sql_ssl_certfile

dkliss commented 1 year ago

Ok, you are getting {bad_cert,hostname_check_failed} because name in certificate doesn't match what you use to connect. You could change sql_server value to one that match, and which resolve to that address, or possibly try using sql_ssl_verify: false, but not sure if this will relax that check. Still try to use that without sql_ssl_certfile

Thanks you. The proposed approach works.

On looking at MySQL (8.0) doc, there is a note that "Host name identity verification with VERIFY_IDENTITY does not work with self-signed certificates that are created automatically by the server". Because I am using a self-signed certificate, and I guess enabling sql_ssl_verify true was failing as it was verifying the host name.

After disabling sql_ssl_verify to false and commenting out sql_ssl_certfile, it can now setup cluster.

Much appreciate your help.

Final Config Below.

default_db: sql
sql_type: mysql
sql_server: "10.250.191.81"
sql_database: "ejabberd"
sql_username: "ejabberd"
sql_password: "Password123"
sql_port: 3306
sql_ssl: true. 
sql_ssl_verify: false
sql_ssl_cafile: "/opt/ejabberd/conf/mysql-ca.pem"
#sql_ssl_certfile: "/opt/ejabberd/conf/mysql-client-cert.pem". 
sql_connect_timeout: 10
sql_keepalive_interval: 1
dkliss commented 1 year ago

Closing the issue as the master branch now works similar to as 22.10.

I also tried quickly to see if I uncomment sql_ssl_certfile i.s. re-enable but with sql_ssl_verify: false. In this case the original issue reappears.

Any high level suggestions on how this is supposed to work i.e. what to do on ejabberd side. 

2023-02-09 14:22:12.866292+00:00 [error] p1_mysql_conn: ssl start failed: {options,
                                  {keyfile,
                                   "/opt/ejabberd/conf/mysql-client-cert.pem",
                                   []}}
prefiks commented 1 year ago

Could you tell me what lines with '--- BEGIN' do you have in /opt/ejabberd/conf/mysql-client-cert.pem? Could be problem with missing or maybe encryped private key

dkliss commented 1 year ago

--- BEGIN' do you have in /opt/ejabberd/conf/mysql-client-cert.pem? Could be problem with missing or maybe encryped private key

Actually, I redid the test with sql_ssl_verify: false. In my previous test I did not copy the client-key.pem from MySQL to ejabberd. Now, in new test, my mysql-client-cert.pem has two files (client-cert.pem + client-key.pem). And interestingly it works this time!

So the issue seems like was due to sql_ssl_verify not set to false. Below is what now works. I only disabled sql_ssl_verify: false.

So, seems like all is good now. Thanks! 

default_db: sql
sql_type: mysql
sql_server: "10.250.191.81"
sql_database: "ejabberd"
sql_username: "ejabberd"
sql_password: "Password123"
sql_port: 3306
sql_ssl: true. 
sql_ssl_verify: false
sql_ssl_cafile: "/opt/ejabberd/conf/mysql-ca.pem"
sql_ssl_certfile: "/opt/ejabberd/conf/mysql-client-cert.pem". 
sql_connect_timeout: 10
sql_keepalive_interval: 1
Neustradamus commented 1 year ago

ejabberd 23.04 has been released with a lot of SQL improvements (some by @nosnilmot):

Note: there is: