lot of connection error from ProxySQL logs and timeout error from ProxySQL logs or MariaDB primary server.

768 views

Skip to first unread message

dipesh acharya

unread,

Apr 27, 2020, 6:41:51 PM4/27/20

to proxysql

Hi,

we had an incident where our all the slaves nodes of mariadb replication got haulted. Would like to understand what really cause the issue as I see a lot of errors in proxysql regarding connections. Wanted to also understand what was going on between proxysql and mariadb primary db why we were receiving too many connection error.

Our global variables below

MySQL [(none)]> show global variables;

+-----------------------------------------------------+---------------------------------------+

| Variable_name | Value |

| admin-checksum_mysql_query_rules | true |

| admin-checksum_mysql_servers | true |

| admin-checksum_mysql_users | true |

| admin-cluster_check_interval_ms | 1000 |

| admin-cluster_check_status_frequency | 10 |

| admin-cluster_mysql_query_rules_diffs_before_sync | 3 |

| admin-cluster_mysql_query_rules_save_to_disk | true |

| admin-cluster_mysql_servers_diffs_before_sync | 3 |

| admin-cluster_mysql_servers_save_to_disk | true |

| admin-cluster_mysql_users_diffs_before_sync | 3 |

| admin-cluster_mysql_users_save_to_disk | true |

| admin-cluster_password | |

| admin-cluster_proxysql_servers_diffs_before_sync | 3 |

| admin-cluster_proxysql_servers_save_to_disk | true |

| admin-cluster_username | |

| admin-hash_passwords | true |

| admin-read_only | false |

| admin-refresh_interval | 2000 |

| admin-stats_mysql_connection_pool | 60 |

| admin-stats_mysql_connections | 60 |

| admin-stats_mysql_query_cache | 60 |

| admin-stats_system_cpu | 60 |

| admin-stats_system_memory | 60 |

| admin-telnet_admin_ifaces | (null) |

| admin-telnet_stats_ifaces | (null) |

| admin-version | 1.4.16-percona-1.1 |

| admin-web_enabled | false |

| admin-web_port | 6080 |

| mysql-auto_increment_delay_multiplex | 5 |

| mysql-autocommit_false_is_transaction | false |

| mysql-autocommit_false_not_reusable | false |

| mysql-client_found_rows | true |

| mysql-client_multi_statements | true |

| mysql-commands_stats | true |

| mysql-connect_retries_delay | 1 |

| mysql-connect_retries_on_failure | 10 |

| mysql-connect_timeout_server | 1000 |

| mysql-connect_timeout_server_max | 10000 |

| mysql-connection_delay_multiplex_ms | 0 |

| mysql-connection_max_age_ms | 0 |

| mysql-connpoll_reset_queue_length | 50 |

| mysql-default_charset | utf8 |

| mysql-default_max_latency_ms | 1000 |

| mysql-default_query_delay | 0 |

| mysql-default_query_timeout | 86400000 |

| mysql-default_reconnect | true |

| mysql-default_schema | information_schema |

| mysql-default_sql_mode | |

| mysql-default_time_zone | SYSTEM |

| mysql-enforce_autocommit_on_reads | false |

| mysql-eventslog_filename | |

| mysql-eventslog_filesize | 104857600 |

| mysql-forward_autocommit | false |

| mysql-free_connections_pct | 2 |

| mysql-have_compress | true |

| mysql-hostgroup_manager_verbose | 1 |

| mysql-init_connect | |

| mysql-kill_backend_connection_when_disconnect | true |

| mysql-long_query_time | 1000 |

| mysql-max_allowed_packet | 4194304 |

| mysql-max_connections | 10000 |

| mysql-max_stmts_cache | 10000 |

| mysql-max_stmts_per_connection | 20 |

| mysql-max_transaction_time | 14400000 |

| mysql-mirror_max_concurrency | 16 |

| mysql-mirror_max_queue_length | 32000 |

| mysql-monitor_connect_interval | 120000 |

| mysql-monitor_connect_timeout | 600 |

| mysql-monitor_enabled | true |

| mysql-monitor_groupreplication_healthcheck_interval | 5000 |

| mysql-monitor_groupreplication_healthcheck_timeout | 800 |

| mysql-monitor_history | 600000 |

| mysql-monitor_password | |

| mysql-monitor_ping_interval | 8000 |

| mysql-monitor_ping_max_failures | 3 |

| mysql-monitor_ping_timeout | 1000 |

| mysql-monitor_query_interval | 60000 |

| mysql-monitor_query_timeout | 100 |

| mysql-monitor_read_only_interval | 1000 |

| mysql-monitor_read_only_max_timeout_count | 3 |

| mysql-monitor_read_only_timeout | 800 |

| mysql-monitor_replication_lag_interval | 10000 |

| mysql-monitor_replication_lag_timeout | 1000 |

| mysql-monitor_replication_lag_use_percona_heartbeat | |

| mysql-monitor_slave_lag_when_null | 60 |

| mysql-monitor_username | proxysql |

| mysql-monitor_wait_timeout | true |

| mysql-monitor_writer_is_also_reader | true |

| mysql-multiplexing | true |

| mysql-ping_interval_server_msec | 10000 |

| mysql-ping_timeout_server | 200 |

| mysql-poll_timeout | 2000 |

| mysql-poll_timeout_on_failure | 100 |

| mysql-query_cache_size_MB | 256 |

| mysql-query_digests | true |

| mysql-query_digests_lowercase | false |

| mysql-query_digests_max_digest_length | 2048 |

| mysql-query_digests_max_query_length | 65000 |

| mysql-query_processor_iterations | 0 |

| mysql-query_processor_regex | 1 |

| mysql-query_retries_on_failure | 1 |

| mysql-server_capabilities | 45578 |

| mysql-server_version | 5.5.30 |

| mysql-servers_stats | true |

| mysql-session_idle_ms | 1000 |

| mysql-session_idle_show_processlist | true |

| mysql-sessions_sort | true |

| mysql-shun_on_failures | 5 |

| mysql-shun_recovery_time_sec | 30 |

| mysql-ssl_p2s_ca | |

| mysql-ssl_p2s_cert | / |

| mysql-ssl_p2s_cipher | |

| mysql-ssl_p2s_key | |

| mysql-stacksize | 1048576 |

| mysql-stats_time_backend_query | false |

| mysql-stats_time_query_processor | false |

| mysql-threads | 4 |

| mysql-threshold_query_length | 524288 |

| mysql-threshold_resultset_size | 4194304 |

| mysql-throttle_connections_per_sec_to_hostgroup | 1000000 |

| mysql-throttle_max_bytes_per_second_to_client | 2147483647 |

| mysql-throttle_ratio_server_to_client | 0 |

| mysql-verbose_query_error | false |

| mysql-wait_timeout | 600000 |

+-----------------------------------------------------+---------------------------------------+

129 rows in set (0.00 sec)

Is this an issue with network I will like to know. as I see proxysql is able to connect again and then get timeout again

Below is the messages from the error log.

2020-04-17 17:59:10 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 4006162us

2020-04-17 17:59:10 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 4005408us

2020-04-17 17:59:10 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 4004515us

2020-04-17 17:59:10 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 4006409us

2020-04-17 17:59:14 main.cpp:1091:main(): [ERROR] Watchdog: 4 threads missed a heartbeat

2020-04-17 17:59:17 main.cpp:1091:main(): [ERROR] Watchdog: 2 threads missed a heartbeat

2020-04-17 17:59:20 main.cpp:1091:main(): [ERROR] Watchdog: 4 threads missed a heartbeat

2020-04-17 17:59:20 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 4003642us

2020-04-17 17:59:20 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 9010589us

2020-04-17 17:59:20 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 4002917us

2020-04-17 17:59:23 main.cpp:1091:main(): [ERROR] Watchdog: 1 threads missed a heartbeat

2020-04-17 17:59:25 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 4007065us

2020-04-17 17:59:25 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 4002452us

2020-04-17 17:59:26 main.cpp:1091:main(): [ERROR] Watchdog: 2 threads missed a heartbeat

2020-04-17 17:59:29 main.cpp:1091:main(): [ERROR] Watchdog: 4 threads missed a heartbeat

2020-04-17 17:59:30 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 4003231us

2020-04-17 17:59:32 main.cpp:1091:main(): [ERROR] Watchdog: 3 threads missed a heartbeat

2020-04-17 17:59:35 main.cpp:1091:main(): [ERROR] Watchdog: 4 threads missed a heartbeat

2020-04-17 17:59:35 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 14015511us

2020-04-17 17:59:35 mysql_connection.cpp:650:handler(): [ERROR] Failed to mysql_real_connect() on t1v.rd2dc.local:3306 , FD (Conn:1452 , MyDS:1452) , 2013: Lost connection to MySQL server at 'reading authorization packet', system error: 115.

2020-04-17 17:59:35 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 24030180us

2020-04-17 17:59:35 MySQL_HostGroups_Manager.cpp:311:connect_error(): [ERROR] Shunning server t1v.rd2dc.local:3306 with 5 errors/sec. Shunning for 30 seconds

2020-04-17 17:59:35 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 24030180us

2020-04-17 17:59:38 main.cpp:1091:main(): [ERROR] Watchdog: 2 threads missed a heartbeat

2020-04-17 17:59:40 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 4002566us

2020-04-17 17:59:40 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 14016157us

2020-04-17 17:59:40 MySQL_HostGroups_Manager.cpp:311:connect_error(): [ERROR] Shunning server t1v.rd2dc.local:3306 with 5 errors/sec. Shunning for 30 seconds

2020-04-17 17:59:40 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 14016157us

2020-04-17 17:59:40 MySQL_HostGroups_Manager.cpp:311:connect_error(): [ERROR] Shunning server t1v.rd2dc.local:3306 with 5 errors/sec. Shunning for 30 seconds

2020-04-17 17:59:41 main.cpp:1091:main(): [ERROR] Watchdog: 2 threads missed a heartbeat

2020-04-17 17:59:44 main.cpp:1091:main(): [ERROR] Watchdog: 2 threads missed a heartbeat

2020-04-17 17:59:45 MySQL_Session.cpp:989:handler_again___status_PINGING_SERVER(): [ERROR] Ping timeout during ping on t1v.rd2dc.local , 3306

2020-04-17 17:59:45 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 14013411us

2020-04-17 17:59:47 main.cpp:1091:main(): [ERROR] Watchdog: 3 threads missed a heartbeat

2020-04-17 17:59:47 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 4006390us

2020-04-17 17:59:47 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 4121985us

2020-04-17 17:59:47 MySQL_HostGroups_Manager.cpp:311:connect_error(): [ERROR] Shunning server t1v.rd2dc.local:3306 with 5 errors/sec. Shunning for 30 seconds

2020-04-17 17:59:47 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 4121985us

2020-04-17 17:59:53 main.cpp:1091:main(): [ERROR] Watchdog: 3 threads missed a heartbeat

2020-04-17 17:59:56 main.cpp:1091:main(): [ERROR] Watchdog: 4 threads missed a heartbeat

2020-04-17 17:59:59 main.cpp:1091:main(): [ERROR] Watchdog: 4 threads missed a heartbeat

2020-04-17 18:00:02 main.cpp:1091:main(): [ERROR] Watchdog: 4 threads missed a heartbeat

2020-04-17 18:00:05 main.cpp:1091:main(): [ERROR] Watchdog: 4 threads missed a heartbeat

2020-04-17 18:00:08 main.cpp:1091:main(): [ERROR] Watchdog: 4 threads missed a heartbeat

2020-04-17 18:00:10 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306: exceeded by 19019330us

2020-04-17 18:00:10 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 19019330us

2020-04-17 18:00:10 mysql_connection.cpp:650:handler(): [ERROR] Failed to mysql_real_connect() on t1v.rd2dc.local:3306 , FD (Conn:1627 , MyDS:1627) , 2013: Lost connection to MySQL server at 'reading authorization packet', system error: 115.

2020-04-17 18:00:10 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 19019330us

2020-04-17 18:00:10 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 29029523us

2020-04-17 18:00:10 MySQL_HostGroups_Manager.cpp:311:connect_error(): [ERROR] Shunning server t1v.rd2dc.local:3306 with 5 errors/sec. Shunning for 30 seconds

2020-04-17 18:00:10 mysql_connection.cpp:650:handler(): [ERROR] Failed to mysql_real_connect() on t1v.rd2dc.local:3306 , FD (Conn:1425 , MyDS:1425) , 2013: Lost connection to MySQL server at 'reading authorization packet', system error: 107.

2020-04-17 18:00:10 mysql_connection.cpp:650:handler(): [ERROR] Failed to mysql_real_connect() on t1v.rd2dc.local:3306 , FD (Conn:1442 , MyDS:1442) , 2013: Lost connection to MySQL server at 'reading authorization packet', system error: 107.

2020-04-17 18:00:10 mysql_connection.cpp:650:handler(): [ERROR] Failed to mysql_real_connect() on t1v.rd2dc.local:3306 , FD (Conn:1625 , MyDS:1625) , 2013: Lost connection to MySQL server at 'reading authorization packet', system error: 107.

2020-04-17 18:00:10 mysql_connection.cpp:650:handler(): [ERROR] Failed to mysql_real_connect() on t1v.rd2dc.local:3306 , FD (Conn:1629 , MyDS:1629) , 2013: Lost connection to MySQL server at 'reading authorization packet', system error: 107.

2020-04-17 18:00:10 mysql_connection.cpp:650:handler(): [ERROR] Failed to mysql_real_connect() on t1v.rd2dc.local:3306 , FD (Conn:1633 , MyDS:1633) , 2013: Lost connection to MySQL server at 'reading authorization packet', system error: 107.

2020-04-17 18:00:28 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 14125111us

2020-04-17 18:00:28 MySQL_HostGroups_Manager.cpp:311:connect_error(): [ERROR] Shunning server t1v.rd2dc.local:3306 with 5 errors/sec. Shunning for 30 seconds

2020-04-17 18:00:28 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 14125111us

2020-04-17 18:00:28 mysql_connection.cpp:650:handler(): [ERROR] Failed to mysql_real_connect() on t1v.rd2dc.local:3306 , FD (Conn:1682 , MyDS:1682) , 1040: Too many connections.

2020-04-17 18:00:28 mysql_connection.cpp:686:handler(): [ERROR] Connect timeout on t1v.rd2dc.local:3306 : exceeded by 14125111us

1342,1 33%

Danny

unread,

Dec 22, 2020, 11:11:59 AM12/22/20

to proxysql

Did you ever make any progress with this? We've recently come up against the same issue, and have been unable to pinpoint the exact cause. The ProxySQL starts slamming the MariaDB servers so much, that eventually the Threads_connected on the DBs gets too high, the cluster stops taking in reads and writes. Stopping ProxySQL and Keepalived is the only course of actions, waiting, sometimes needing to restart the cluster, and then good to go for a few days. We are running:

CentOS 7 (latest patches)

proxysql-2.0.15-1.x86_64

MariaDB-server-10.4.17-1.el7.centos.x86_64

René Cannaò

unread,

Dec 22, 2020, 11:22:07 AM12/22/20

to Danny, proxysql

> The ProxySQL starts slamming the MariaDB servers so much, that eventually the Threads_connected on the DBs gets too high, the cluster stops taking in reads and writes

Have you considered that maybe the order is different?

For example, the cluster stops taking in reads and writes, then ProxySQL starts creating a lot of connections?

If the backend is not serving traffic, the established connections cannot be re-used, so new connections are created.

In fact, we always recommend configuring mysql_servers.max_connections to a reasonably small value: if the backend isn't able to cope with load, creating more connections will only make things worse.

When you stop proxysql you are basically killing all the backend connections, giving the backend the ability to recover.

Interestingly enough, you write sometime you need to restart the cluster: this supports even more my hypothesis that the backends are the root cause of the problem.

With regards to proxysql I want to renew my suggestion of configuring mysql_servers.max_connections to a reasonably small value.

If max_connections is reached do not just increase it: proxysql is probably trying to protect the backend from extra load.

--
You received this message because you are subscribed to the Google Groups "proxysql" group.
To unsubscribe from this group and stop receiving emails from it, send an email to proxysql+u...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/proxysql/c814bc91-e64b-4daf-ace5-75368d7e3348n%40googlegroups.com.

Danny

unread,

Dec 22, 2020, 2:13:29 PM12/22/20

to proxysql

Interesting thought, and I have considered that. I've monitored load on the backend DBs, and that never seems to be an issue. When the issue comes, I quickly SSH into each of the DB nodes, and perform various checks (top, iftop, etc.) to see what is going on. I'll tail the /var/log/mariadb/mariadb.log and nothing really jumps out at me.

The only time I have to restart the cluster, is if I don't catch things quick enough and the Threads_connected get to be too high. However, since I've enhanced my alerting, I have not had to restart the cluster in quite some time now. All I've really had to do, is just stop Keepalived for a few minutes, and then start it back up. Once the client VIP is back on, things return to normal.

I have never adjusted the max_connections, and just left them at the defaults (1000 I think). I've seen the Threads_connected be as low as 180, but continuously grow and grow (nowhere near 1000) but the "Lock wait timeout exceeded;" message just scroll by so quickly I can't keep track. It logs the destination database IP, which is always my primary writer DB, but I can't tell quickly enough what the client is. It would be good if the log entry also had the client IP, so I could tell if it was the same client over and over, or different clients.

Reply all

Reply to author

Forward

0 new messages