Mango v4.2 with mysql server 8 - Failed to validate connection
-
I have a freshly installed Mango v4.2 using mysql server 8. It keeps getting a HikariPool-1 - Failed to validate connection warning. Any ideas?
WARN 2021-10-09T05:04:03,568 (com.serotonin.m2m2.TimedLicenseRegistrar.checkLicenses:65) - Mango NoSQL database is running in free mode, Mango will shutdown at 1:04:03 9/10/2021.
INFO 2021-10-09T05:04:03,750 (com.serotonin.m2m2.db.BasePooledProxy.initializeImpl:28) - Initializing pooled connection manager
INFO 2021-10-09T05:04:06,791 (com.serotonin.m2m2.db.upgrade.DBUpgrade.checkUpgrade:37) - Starting instance with core version 4.2.1, schema v42
INFO 2021-10-09T05:04:06,936 (com.infiniteautomation.nosql.MangoNoSqlProxy.initialize:68) - Starting MangoNoSql Database
INFO 2021-10-09T05:04:06,980 (com.infiniteautomation.tsdb.impl.IasTsdbImpl.<init>:149) - Database at /opt/mango-data/databases/mangoTSDB started
INFO 2021-10-09T05:04:07,015 (com.infiniteautomation.tsdb.impl.IasTsdbImpl.<init>:178) - Empty dir delete for database at /opt/mango-data/databases/mangoTSDB took 7ms
INFO 2021-10-09T05:04:07,030 (com.infiniteautomation.tsdb.impl.IasTsdbImpl.<init>:149) - Database at /opt/mango-data/databases/mangoTSDBAux started
INFO 2021-10-09T05:04:07,060 (com.infiniteautomation.tsdb.impl.IasTsdbImpl.<init>:178) - Empty dir delete for database at /opt/mango-data/databases/mangoTSDBAux took 4ms
INFO 2021-10-09T05:04:12,287 (com.infiniteautomation.mango.spring.MangoRuntimeContextConfiguration.contextRefreshed:159) - Spring context 'runtimeContext' refreshed: org.springframework.context.annotation.AnnotationConfigApplicationContext@6ce15112
INFO 2021-10-09T05:04:12,290 (com.infiniteautomation.mango.spring.MangoRuntimeContextConfiguration.contextStarted:173) - Spring context 'runtimeContext' started: org.springframework.context.annotation.AnnotationConfigApplicationContext@6ce15112
INFO 2021-10-09T05:04:14,301 (com.serotonin.m2m2.rt.DataSourceGroupInitializer.process:35) - Initializing 1 NORMAL priority data sources in 1 threads
INFO 2021-10-09T05:04:14,399 (com.serotonin.m2m2.rt.DataPointGroupInitializer.initialize:40) - Initializing 25 data points in 1 threads
INFO 2021-10-09T05:04:14,405 (com.serotonin.m2m2.rt.DataPointGroupInitializer.processItem:64) - Initializing group 0 of 25 data points
INFO 2021-10-09T05:04:14,479 (com.serotonin.m2m2.rt.DataPointGroupInitializer.processItem:120) - Group 0 successfully initialized 25 of 25 data points in 74 ms
INFO 2021-10-09T05:04:14,484 (com.serotonin.m2m2.rt.DataPointGroupInitializer.initialize:54) - Initialization of 25 data points in 1 threads took 84 ms
INFO 2021-10-09T05:04:14,484 (com.serotonin.m2m2.rt.RuntimeManagerImpl.startDataSource:321) - Data source (name=Mango Internal, id=1, type=InternalDataSourceRT) took 175ms to start
INFO 2021-10-09T05:04:14,484 (com.serotonin.m2m2.rt.DataSourceGroupInitializer.process:40) - Initialization of 1 NORMAL priority data sources in 1 threads took 184 ms
INFO 2021-10-09T05:04:14,767 (com.serotonin.m2m2.rt.RuntimeManagerImpl.initialize:183) - Starting 0 Publishers...
INFO 2021-10-09T05:04:14,779 (com.serotonin.m2m2.rt.RuntimeManagerImpl.initialize:194) - 0 Publisher's started in 19ms
INFO 2021-10-09T05:04:16,561 (com.infiniteautomation.mango.spring.MangoRuntimeContextConfiguration.contextRefreshed:159) - Spring context 'rootWebContext' refreshed: Root WebApplicationContext
WARN 2021-10-09T05:04:16,967 (org.springframework.core.log.CompositeLog.warn:127) - For Jackson Kotlin classes support please add "com.fasterxml.jackson.module:jackson-module-kotlin" to the classpath
INFO 2021-10-09T05:04:17,130 (com.infiniteautomation.mango.spring.MangoRuntimeContextConfiguration.contextRefreshed:159) - Spring context 'restDispatcherContext' refreshed: WebApplicationContext for namespace 'REST_DISPATCHER-servlet'
INFO 2021-10-09T05:04:21,000 (com.infiniteautomation.mango.spring.MangoRuntimeContextConfiguration.contextRefreshed:159) - Spring context 'restV3Context' refreshed: WebApplicationContext for namespace 'restV3DispatcherServlet-servlet'
WARN 2021-10-09T05:14:16,684 (com.zaxxer.hikari.pool.PoolBase.isConnectionAlive:184) - HikariPool-1 - Failed to validate connection com.mysql.cj.jdbc.ConnectionImpl@6a1ff639 (No operations allowed after connection closed.). Possibly consider using a shorter maxLifetime value.
WARN 2021-10-09T05:14:16,685 (com.zaxxer.hikari.pool.PoolBase.isConnectionAlive:184) - HikariPool-1 - Failed to validate connection com.mysql.cj.jdbc.ConnectionImpl@3b4d7ce9 (No operations allowed after connection closed.). Possibly consider using a shorter maxLifetime value. -
@ricardo said in Mango v4.2 with mysql server 8 - Failed to validate connection:
Possibly consider using a shorter maxLifetime value
My guess is that your MySQL server's
wait_timeout
setting is below the default for our connection pool (30 minutes). The default that MySQL normally uses is 8hrs and yours may be set lower. I haven't seen this before but we normally don't change that setting on MySQL either. -
@terrypacker the wait_timeout is at default 28,800 secs (8 hours).
$ mysql
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 65191
Server version: 8.0.15.0 Source distributionCopyright (c) 2000, 2021, Oracle and/or its affiliates.
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.
mysql> SHOW VARIABLES like '%timeout%';
+-----------------------------------+----------+
| Variable_name | Value |
+-----------------------------------+----------+
| connect_timeout | 10 |
| delayed_insert_timeout | 300 |
| have_statement_timeout | YES |
| innodb_flush_log_at_timeout | 1 |
| innodb_lock_wait_timeout | 50 |
| innodb_log_closer_timeout | 1000 |
| innodb_log_flush_notifier_timeout | 10 |
| innodb_log_flusher_timeout | 10 |
| innodb_log_wait_for_flush_timeout | 1000 |
| innodb_log_wait_for_write_timeout | 1000 |
| innodb_log_write_notifier_timeout | 10 |
| innodb_log_writer_timeout | 10 |
| innodb_rollback_on_timeout | OFF |
| interactive_timeout | 28800 |
| lock_wait_timeout | 31536000 |
| net_read_timeout | 120 |
| net_write_timeout | 240 |
| rpl_stop_slave_timeout | 31536000 |
| slave_net_timeout | 60 |
| thread_pool_batch_wait_timeout | 10000 |
| wait_timeout | 28800 |
+-----------------------------------+----------+
21 rows in set (0.01 sec) -
@Ricardo thanks, that all looks ok to me. Basically what is happening is that Mango uses a pool of TCP/IP connections to the database and when choosing one to use it tests it first to ensure it is still connected. In this case Mango sees that the connection is broken and the database pool library (Hikari) is logging that.
For some reason the database connections that Mango is opening are being closed. This is not normal. From your log posting I can see that the delay is pretty close to 10 minutes, so I would be looking for any settings between Mango and your MySQL server that timeout at 10 minutes. It is possible you have a Proxy or Firewall between the 2 that is severing the connections at 10 minutes...
If none of that helps then I suggest you post the mango.properties for your database. The begin like this:
# MySQL database settings. Your MySQL instance must already be running and configured before this can be used. db.type=mysql ...