[
https://issues.apache.org/jira/browse/GUACAMOLE-1928?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Nick Couchman updated GUACAMOLE-1928:
-------------------------------------
Priority: Minor (was: Major)
> Show better error description in logs on MySQL authentication failure
> ---------------------------------------------------------------------
>
> Key: GUACAMOLE-1928
> URL: https://issues.apache.org/jira/browse/GUACAMOLE-1928
> Project: Guacamole
> Issue Type: Improvement
> Components: guacamole-auth-jdbc-mysql
> Affects Versions: 1.5.4
> Environment: AlmaLinux 9, Tomcat 9.0.62-37.el9_3.1, guacd
> 1.5.4-1.el9, mariadb-java-client-3.3.3.jar, Extension: mysql, ldap
> Reporter: Stefan Bluhm
> Priority: Minor
>
> The information logging of the MySQL/MariaDB extention is not sufficient and
> should show more reasons of connection failures.
> Example: When the DB server has an expired SSL certificate, Guacamole only
> logs:
>
> {quote}Mar 04 19:29:52 server.example.com server[972]: 19:29:52.465
> [http-nio-8080-exec-10] WARN o.a.g.e.AuthenticationProviderFacade - The
> "mysql" authentication provider has encountered an internal error which will
> halt the authentication process. If this is unexpected or you are the
> developer of this authentication provider, you may wish to enable debug-level
> logging. If this is expected and you wish to ignore such failures in the
> future, please set "skip-if-unavailable: mysql" within your
> guacamole.properties.
> Mar 04 19:29:52 server.example.com server[972]: 19:29:52.468
> [http-nio-8080-exec-10] ERROR o.a.g.rest.RESTExceptionMapper - Unexpected
> internal error:
> Mar 04 19:29:52 server.example.com server[972]: ### Error querying database.
> Cause: com.mysql.cj.jdbc.exceptions.CommunicationsException: Communications
> link failure
> Mar 04 19:29:52 server.example.com server[972]: The last packet sent
> successfully to the server was 0 milliseconds ago. The driver has not
> received any packets from the server.
> Mar 04 19:29:52 server.example.com server[972]: ### The error may exist in
> org/apache/guacamole/auth/jdbc/user/UserMapper.xml
> Mar 04 19:29:52 server.example.com server[972]: ### The error may involve
> org.apache.guacamole.auth.jdbc.user.UserMapper.selectOne
> Mar 04 19:29:52 server.example.com server[972]: ### The error occurred while
> executing a query
> Mar 04 19:29:52 server.example.com server[972]: ### Cause:
> com.mysql.cj.jdbc.exceptions.CommunicationsException: Communications link
> failure
> Mar 04 19:29:52 server.example.com server[972]: The last packet sent
> successfully to the server was 0 milliseconds ago. The driver has not
> received any packets from the server.
> {quote}
>
> The DB Server only phrases that that the connection has been closed by the
> client.
>
> Debug mode gave more information:
> {quote}{{Mar 5 12:06:45 server.example.com server[62724]: Caused by:
> javax.net.ssl.SSLHandshakeException: NotAfter: Sat Jan 13 17:21:58 CET 2024}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> java.base/sun.security.ssl.Alert.createSSLException(Alert.java:131)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:360)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:303)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:298)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> java.base/sun.security.ssl.CertificateMessage$T13CertificateConsumer.checkServerCerts(CertificateMessage.java:1357)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> java.base/sun.security.ssl.CertificateMessage$T13CertificateConsumer.onConsumeCertificate(CertificateMessage.java:1232)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> java.base/sun.security.ssl.CertificateMessage$T13CertificateConsumer.consume(CertificateMessage.java:1175)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> java.base/sun.security.ssl.SSLHandshake.consume(SSLHandshake.java:392)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> java.base/sun.security.ssl.HandshakeContext.dispatch(HandshakeContext.java:443)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> java.base/sun.security.ssl.HandshakeContext.dispatch(HandshakeContext.java:421)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> java.base/sun.security.ssl.TransportContext.dispatch(TransportContext.java:183)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> java.base/sun.security.ssl.SSLTransport.decode(SSLTransport.java:172)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> java.base/sun.security.ssl.SSLSocketImpl.decode(SSLSocketImpl.java:1511)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> java.base/sun.security.ssl.SSLSocketImpl.readHandshakeRecord(SSLSocketImpl.java:1421)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> java.base/sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:456)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> java.base/sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:427)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> com.mysql.cj.protocol.ExportControlled.performTlsHandshake(ExportControlled.java:214)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> com.mysql.cj.protocol.StandardSocketFactory.performTlsHandshake(StandardSocketFactory.java:191)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> com.mysql.cj.protocol.a.NativeSocketConnection.performTlsHandshake(NativeSocketConnection.java:101)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> com.mysql.cj.protocol.a.NativeProtocol.negotiateSSLConnection(NativeProtocol.java:370)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011... 100 common frames
> omitted}}
> {{Mar 5 12:06:45 server.example.com server[62724]: Caused by:
> java.security.cert.CertificateExpiredException: NotAfter: Sat Jan 13 17:21:58
> CET 2024}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> java.base/sun.security.x509.CertificateValidity.valid(CertificateValidity.java:277)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> java.base/sun.security.x509.X509CertImpl.checkValidity(X509CertImpl.java:669)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> java.base/sun.security.x509.X509CertImpl.checkValidity(X509CertImpl.java:642)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> com.mysql.cj.protocol.ExportControlled$X509TrustManagerWrapper.checkServerTrusted(ExportControlled.java:680)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> java.base/sun.security.ssl.AbstractTrustManagerWrapper.checkServerTrusted(SSLContextImpl.java:1533)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011at
> java.base/sun.security.ssl.CertificateMessage$T13CertificateConsumer.checkServerCerts(CertificateMessage.java:1341)}}
> {{Mar 5 12:06:45 server.example.com server[62724]: #011... 115 common frames
> omitted}}
> {quote}
>
> This information should have been passed on to the logs as ERROR.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
