search

Icinga / icingaweb2

A lightweight and extensible web interface to keep an eye on your environment. Analyse problems and act on them.
https://icinga.com/get-started/
GNU General Public License v2.0
808 stars 280 forks source link

MySQL SSL connection error brings up no explanation #3249

Closed lazyfrosch closed 6 years ago

lazyfrosch commented 6 years ago

When connecting to a MySQL Server via SSL, the error message can be empty

Set in config:

Of course it works when the FQDN host is used...

Expected Behavior

Error should be something like:

SQLSTATE[HY000] [2002] SSL error, hostname does not match ...

Current Behavior

Error is:

SQLSTATE[HY000] [2002]

Your Environment

lazyfrosch commented 6 years ago

Is this a PHP problem, or because we don't retrieve the error correctly?

lippserd commented 6 years ago

The stacktrace would be interesting. Afaik, we don't change PDO error messages.

wwkimball commented 6 years ago

This issue appears to have stalled awaiting feedback. I'd like to add that I just encountered the same error message with the director module while deploying via the icingaweb2 Puppet module onto CentOS 7. My situation is slightly different as my hosts are all using FQDNs and yet, still the same error arises. From this, I should be able to help provide some troubleshooting.

Command and error message:

root@monitor ~
# icingacli director migration run
ERROR: Icinga\Exception\IcingaException in /usr/share/icingaweb2/modules/director/library/Director/Db/Migration.php:50 with message: Migration 0 failed (SQLSTATE[HY000] [2002] ) while running --
-- MySQL schema
-- ============
--
-- You should normally not be required to care about schema handling.
-- Director does all the migrations for you and guides you either in
-- the frontend or provides everything you need for automated migration
-- handling. Please find more related information in our documentation.

SET sql_mode = 'STRICT_ALL_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,NO_ENGINE_SUBSTITUTION,PIPES_AS_CONCAT,ANSI_QUOTES,ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER'

Note that the error is emitted without any connection attempt being made, so this seems to be PDO rejecting the configuration. On that note, here's the relevant configuration:

# cat /etc/icingaweb2/resources.ini
[icingaweb2-module-director]
type = "db"
db = "mysql"
host = "data.localdomain"
port = "3306"
dbname = "icingaweb2director"
username = "icinga2director"
password = "nvoasy7n20vn"
charset = "utf8"
use_ssl = "1"
ssl_cert = "/etc/pki/icinga2-mysql/hostcert.pem"
ssl_key = "/etc/pki/icinga2-mysql/hostprivkey.pem"
ssl_ca = "/etc/pki/icinga2-mysql/ca.pem"
ssl_cipher = "DHE-RSA-AES256-GCM-SHA384"
wwkimball commented 6 years ago

And incidentally, the Icinga Web 2 application itself also cannot connect for the same error "state" (HY000 and 2002) but this time with a not-quite-helpful message, "Permission denied" (permission was denied to ... what, exactly?). From /var/log/icingaweb2/icingaweb2.log:

2018-05-24T12:43:56-05:00 - ERROR - Icinga\Exception\AuthenticationException in /usr/share/php/Icinga/Authentication/User/DbUserBackend.php:221 with message: Failed to authenticate user "icingaadmin" against backend "mysql-auth". An exception was thrown: <- Zend_Db_Adapter_Exception in /usr/share/icingaweb2/library/vendor/Zend/Db/Adapter/Pdo/Abstract.php:139 with message: SQLSTATE[HY000] [2002] Permission denied <- PDOException in /usr/share/icingaweb2/library/vendor/Zend/Db/Adapter/Pdo/Abstract.php:124 with message: SQLSTATE[HY000] [2002] Permission denied

Again, the error is emitted before a connection attempt is made (I watched the MySQL connection log and there was no activity from Icinga Web 2), so this appears to be an issue with configuration parsing. Relevant configuration for this:

# cat /etc/icingaweb2/authentication.ini
[mysql-auth]
backend = "db"
resource = "mysql-icingaweb2"

# cat /etc/icingaweb2/config.ini
[global]
show_stacktraces = "0"
module_path = "/usr/share/icingaweb2/modules"
config_backend = "db"
config_resource = "mysql-icingaweb2"

[logging]
log = "file"
file = "/var/log/icingaweb2/icingaweb2.log"
level = "INFO"

# cat /etc/icingaweb2/groups.ini
[mysql-group]
backend = "db"
resource = "mysql-icingaweb2"

# cat /etc/icingaweb2/resources.ini
[mysql-icingaweb2]
type = "db"
db = "mysql"
host = "data.localdomain"
port = "3306"
dbname = "icingaweb2"
username = "icinga2web"
password = "qh2nv9h9hap"
use_ssl = "1"
ssl_cert = "/etc/pki/icinga2-mysql/hostcert.pem"
ssl_key = "/etc/pki/icinga2-mysql/hostprivkey.pem"
ssl_ca = "/etc/pki/icinga2-mysql/ca.pem"
ssl_cipher = "DHE-RSA-AES256-GCM-SHA384"

From that error, the issue appears to be stemming from somewhere within lines 119 and 140 of the abstract DB Adapter. If we correlate that with the PDO constructor documentation and the implementation, I consider:

  1. The process can't read the TLS certificate files (Permission denied).
  2. There's a bug in the DSN construction or building of the PDO driver_options that is leading to an invalid/unknown parameter key name or malformed value.
  3. SELinux is getting in the way.

I ruled out consideration 1 by opening up the permissions on the TLS certificate files and directory, so that's probably not it. I then stopped SELinux and -- to my surprise -- got a much more informative error message:

2018-05-24T16:27:19-05:00 - ERROR - Icinga\Exception\AuthenticationException in /usr/share/php/Icinga/Authentication/User/DbUserBackend.php:221 with message: Failed to authenticate user "icingaadmin" against backend "mysql-auth". An exception was thrown: <- Zend_Db_Adapter_Exception in /usr/share/icingaweb2/library/vendor/Zend/Db/Adapter/Pdo/Abstract.php:139 with message: SQLSTATE[HY000] [2002]  <- PDOException in /usr/share/icingaweb2/library/vendor/Zend/Db/Adapter/Pdo/Abstract.php:124 with message: SQLSTATE[HY000] [2002]  <- PDOException in /usr/share/icingaweb2/library/vendor/Zend/Db/Adapter/Pdo/Abstract.php:124 with message: PDO::__construct(): SSL operation failed with code 1. OpenSSL Error messages:
error:140830B5:SSL routines:ssl3_client_hello:no ciphers available

However, the same machine is connecting just fine to MySQL over TLS via IDO with SELinux running in enforcing mode. So, this error from OpenSSL is a misdirection. I suspect it more likely that there's some junk in the DSN construction or a bug in the application of the PDO::MYSQL_ATTR_SSL_* settings. This is however, only a guess.

I'm happy to answer any questions to help troubleshoot this further.

wwkimball commented 6 years ago

For anyone curious, here is proof that MySQL TLS is properly configured on both the Icinga Web 2 and MySQL (MariaDB) servers for all affected accounts. It also shows quite clearly that the MySQL client has access to the required cipher.

It seems obvious that this is an issue with PDO.

Icinga Web 2 User Authentication Works as the Apache Web Server User from the Command Line

Note in particular that the requested cipher is, in fact, "available" and working:

# su -s /bin/bash apache -c "mysql -T -h 'data.localdomain' -P '3306' -u 'icinga2web' -p'qh2nv9h9hap' 'icingaweb2'"
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MariaDB connection id is 9210
Server version: 5.5.56-MariaDB MariaDB Server

Copyright (c) 2000, 2017, Oracle, MariaDB Corporation Ab and others.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

MariaDB [icingaweb2]> \s
--------------
mysql  Ver 15.1 Distrib 5.5.56-MariaDB, for Linux (x86_64) using readline 5.1

Connection id:     9210
Current database:  icingaweb2
Current user:      monicinga2web@monitor.localdomain
SSL:           Cipher in use is DHE-RSA-AES256-GCM-SHA384
Current pager:     stdout
Using outfile:     ''
Using delimiter:   ;
Server:            MariaDB
Server version:        5.5.56-MariaDB MariaDB Server
Protocol version:  10
Connection:        data.localdomain via TCP/IP
Server characterset:   latin1
Db     characterset:   utf8
Client characterset:   utf8
Conn.  characterset:   utf8
TCP port:      3306
Uptime:            7 days 19 hours 13 min 3 sec

Threads: 6  Questions: 572400  Slow queries: 0  Opens: 735  Flush tables: 6  Open tables: 94  Queries per second avg: 0.849
--------------

MariaDB [icingaweb2]> \q
Bye

User time 0.02, System time 0.00
Maximum resident set size 5508, Integral resident set size 0
Non-physical pagefaults 1894, Physical pagefaults 0, Swaps 0
Blocks in 0 out 0, Messages in 0 out 0, Signals 0
Voluntary context switches 22, Involuntary context switches 1

Same for the Director User But run as root (as Puppet would run this command)

# mysql -T -h 'data.localdomain' -P '3306' -u 'icinga2director' -p'nvoasy7n20vn' 'icingaweb2director'
Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MariaDB connection id is 9211
Server version: 5.5.56-MariaDB MariaDB Server

Copyright (c) 2000, 2017, Oracle, MariaDB Corporation Ab and others.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

MariaDB [icingaweb2director]> \s
--------------
mysql  Ver 15.1 Distrib 5.5.56-MariaDB, for Linux (x86_64) using readline 5.1

Connection id:     9211
Current database:  icingaweb2director
Current user:      icinga2director@monitor.localdomain
SSL:           Cipher in use is DHE-RSA-AES256-GCM-SHA384
Current pager:     stdout
Using outfile:     ''
Using delimiter:   ;
Server:            MariaDB
Server version:        5.5.56-MariaDB MariaDB Server
Protocol version:  10
Connection:        data.localdomain via TCP/IP
Server characterset:   latin1
Db     characterset:   utf8
Client characterset:   utf8
Conn.  characterset:   utf8
TCP port:      3306
Uptime:            7 days 19 hours 14 min 1 sec

Threads: 6  Questions: 572636  Slow queries: 0  Opens: 735  Flush tables: 6  Open tables: 94  Queries per second avg: 0.849
--------------

MariaDB [icingaweb2director]> \q
Bye

User time 0.02, System time 0.00
Maximum resident set size 5464, Integral resident set size 0
Non-physical pagefaults 1514, Physical pagefaults 0, Swaps 0
Blocks in 0 out 8, Messages in 0 out 0, Signals 0
Voluntary context switches 19, Involuntary context switches 0

The necessary /etc/my.cnf.d/client.ini for the above MySQL CLI commands

# cat /etc/my.cnf.d/client.cnf
[client]
ssl-verify-server-cert = 1
ssl-ca = /etc/pki/icinga2-mysql/ca.pem
ssl-cert = /etc/pki/icinga2-mysql/hostcert.pem
ssl-key = /etc/pki/icinga2-mysql/hostprivkey.pem
ssl-cipher = DHE-RSA-AES256-GCM-SHA384
wwkimball commented 6 years ago

Out of curiosity, I wrote a small PHP CLI script to see whether I could reproduce and perhaps identify a solid fix for this issue.

With very little code (below), I was able to reproduce the original message that started this thread. The issue appears to be two-fold:

  1. PDO is returning multiple errors with separate Stack Traces. The last entry in the stack has the useless message, PDOException: SQLSTATE[HY000] [2002]. Note that there really is no text message for this error; it's junk.
  2. However, the first error in the same stack actually has a useful message, but the Icinga code (really the Zend code that Icinga is using) is discarding it. That message is, SSL operation failed with code 1. OpenSSL Error messages:\nerror:140830B5:SSL routines:ssl3_client_hello:no ciphers available.

Having reproduced the error, I set about troubleshooting it and found a hard block. For some reason, the PHP version being installed with Icinga2 doesn't support the same TLS ciphers that MySQL/MaridaDB does on the same machine. So, when we ask Icinga to use a particular cipher with PDO that PDO doesn't understand -- but which we know for certain that MySQL/MariaDB does support -- it throws "no ciphers available" [aside: this message would be more accurately written as, "None of the requested ciphers are available to your installed version of OpenSSL."]. The message unfortunately gets discarded due to how Icinga/Zend is querying the error message from PDO; it only reports the junk message at the end of the stack.

I poked around and was able to generate more OpenSSL errors under different conditions. All of them result in the same useless message because the good message is being discarded. For example, if I don't provide a cipher list to PHP -- allow it to use any available cipher -- but leave the MySQL/MariaDB server to require a cipher that PDO doesn't understand, I can trigger SSL operation failed with code 1. OpenSSL Error messages:\nerror:14094410:SSL routines:ssl3_read_bytes:sslv3 alert handshake failure but Icinga will still report only the useless SQLSTATE[HY000] [2002].

Bottom-Line

https://github.com/Icinga/icingaweb2/blob/master/library/vendor/Zend/Db/Adapter/Pdo/Abstract.php#L139 discards useful error messages in the stack. This should be considered a bug in Zend's PDO wrapper and not a bug in Icinga, per say. That said, it should still behoove Icinga to find a better way to handle PDO issues such that informative errors are returned.

The Test PHP Script

<?php
$pdo = new PDO(
    'mysql:host=data.localdomain;dbname=icingaweb2',
    'icinga2web',
    'qh2nv9h9hap',
    array(
        PDO::MYSQL_ATTR_SSL_KEY    => '/etc/pki/icinga2-mysql/hostprivkey.pem',
        PDO::MYSQL_ATTR_SSL_CERT   => '/etc/pki/icinga2-mysql/hostcert.pem',
        PDO::MYSQL_ATTR_SSL_CA     => '/etc/pki/icinga2-mysql/ca.pem',
        PDO::MYSQL_ATTR_SSL_CIPHER => 'DHE-RSA-AES256-GCM-SHA384'
    )
);
// Note that the code never gets this far; PDO has already crashed during construction
$statement = $pdo->query("SHOW SESSION STATUS LIKE 'Ssl_%';");
$result = $statement->fetchAll();
print_r($result);
?>
wwkimball commented 6 years ago

Incidentally, if it weren't obvious, I've resolved the issue as it affected me. I just had to add a PDO-compatible cipher to the permissible cipher list at the MySQL server and update the Icinga Web 2 resources accordingly.

lippserd commented 6 years ago

@wwkimball Thanks mate for sharing your findings. We may just patch Zend because we're shipping our own fork 😆

nilmerg commented 6 years ago

Actually, it's really an issue with PHP's pdo_mysql driver: https://bugs.php.net/bug.php?id=76604

dnsmichi commented 6 years ago

That reads like as if PHP's OpenSSL implementation doesn't respect the error stack state machine in a certain way. We've seen such problems with Icinga 2 in a similar fashion already.