search

sysown / proxysql

High-performance MySQL proxy with a GPL license.
http://www.proxysql.com
GNU General Public License v3.0
6.05k stars 983 forks source link

High CPU usage on an idle proxysql #2240

Open kashak88 opened 5 years ago

kashak88 commented 5 years ago

Ubuntu 16.04 LTS, proxysql 2.0.6, percona 5.7.26-29-1.xenial

The proxysql instance is installed on the web servers and is not currently in use - It's monitoring 2 databases, master and slave, but nothing is being sent through it. Load average is around 16-18 according to top, CPU usage is at 150% and VIRT is 4100008 and growing. The other web server has VIRT at 5107620 and growing. Both servers have 2 CPUs and 4Gb of RAM. Similar errors in logs on both servers:

2019-09-06 22:23:52 MySQL_Monitor.cpp:1109:monitor_read_only_thread(): [ERROR] Server 10.24.1.41:3306 missed 3 read_only checks. Assuming read_only=1
2019-09-06 22:23:56 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7fc74e1f3180 , MYSQL 0x7fc74e1fa700 , FD 33 : Lost connection to MySQL server during query
2019-09-06 22:23:56 MySQL_Monitor.cpp:2022:monitor_replication_lag_thread(): [ERROR] Error after 1000ms on server 10.24.1.41:3306 : timeout check
2019-09-06 22:23:56 MySQL_Monitor.cpp:2022:monitor_replication_lag_thread(): [ERROR] Error after 1000ms on server 10.24.1.41:3306 : timeout check
2019-09-06 22:23:57 MySQL_Monitor.cpp:978:monitor_read_only_thread(): [ERROR] Timeout on read_only check for 10.24.1.41:3306 after 1208ms. If the server is overload, increase mysql-monitor_read_only_timeout.
2019-09-06 22:23:57 MySQL_Monitor.cpp:1109:monitor_read_only_thread(): [ERROR] Server 10.24.1.41:3306 missed 3 read_only checks. Assuming read_only=1
2019-09-06 22:23:57 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7fc74e1f3f40 , MYSQL 0x7fc749812000 , FD 31 : timeout check
2019-09-06 22:24:01 MySQL_Monitor.cpp:955:monitor_read_only_thread(): [ERROR] Timeout on read_only check for 10.24.1.41:3306 after 1001ms. Unable to create a connection. If the server is overload, increase mysql-monitor_connect_timeout. Error: timeout on creating new connection: Lost connection to MySQL server at 'handshake: reading inital communication packet', system error: 110.
2019-09-06 22:24:01 MySQL_Monitor.cpp:1109:monitor_read_only_thread(): [ERROR] Server 10.24.1.41:3306 missed 3 read_only checks. Assuming read_only=1
2019-09-06 22:24:05 MySQL_Monitor.cpp:955:monitor_read_only_thread(): [ERROR] Timeout on read_only check for 10.24.1.41:3306 after 1005ms. Unable to create a connection. If the server is overload, increase mysql-monitor_connect_timeout. Error: timeout on creating new connection: Lost connection to MySQL server at 'handshake: reading inital communication packet', system error: 110.
2019-09-06 22:24:05 MySQL_Monitor.cpp:1109:monitor_read_only_thread(): [ERROR] Server 10.24.1.41:3306 missed 3 read_only checks. Assuming read_only=1

Followed by:

2019-09-06 22:33:46 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7fc74e0b81e0 , MYSQL 0x7fc7475d6600 , FD 28 : Lost connection to MySQL server during query
2019-09-06 22:33:52 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7fc74e0fe0a0 , MYSQL 0x7fc74e1f7f00 , FD 27 : Lost connection to MySQL server during query
2019-09-06 22:33:55 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7fc74e0fe1e0 , MYSQL 0x7fc74e0be400 , FD 25 : Lost connection to MySQL server during query
2019-09-06 22:33:59 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7fc74e1f21e0 , MYSQL 0x7fc74e0bd500 , FD 31 : Lost connection to MySQL server during query
2019-09-06 22:34:08 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7fc74e1f4940 , MYSQL 0x7fc74e1f7a00 , FD 32 : Lost connection to MySQL server during query
2019-09-06 22:34:12 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7fc74e1f4b20 , MYSQL 0x7fc74e0be900 , FD 35 : Lost connection to MySQL server during query
2019-09-06 22:34:15 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7fc74e0ba580 , MYSQL 0x7fc74e0bfd00 , FD 19 : Lost connection to MySQL server during query
2019-09-06 22:34:21 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7fc74e1f4f80 , MYSQL 0x7fc748252700 , FD 21 : Lost connection to MySQL server during query

There are lots of monitor users connected to the replica database, around 15 for each web server, which is unusual. Only 2 users per server on master.

Config:

+-----------------------------------------------------+------------------------------------------------------------------------+
| Variable_name                                       | Value                                                                  |
+-----------------------------------------------------+------------------------------------------------------------------------+
| admin-admin_credentials                             | admin:somePass                                                         |
| 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-mysql_ifaces                                  | 127.0.0.1:6032;/var/run/proxysql/proxysql_admin.sock                   |
| admin-read_only                                     | false                                                                  |
| admin-refresh_interval                              | 2000                                                                   |
| admin-stats_credentials                             | stats:stats                                                            |
| 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-vacuum_stats                                  | true                                                                   |
| admin-version                                       | 2.0.6-73-gc746bf7                                                      |
| admin-web_enabled                                   | false                                                                  |
| admin-web_port                                      | 6080                                                                   |
| mysql-add_ldap_user_comment                         |                                                                        |
| mysql-auditlog_filename                             |                                                                        |
| mysql-auditlog_filesize                             | 104857600                                                              |
| mysql-auto_increment_delay_multiplex                | 5                                                                      |
| mysql-autocommit_false_is_transaction               | false                                                                  |
| mysql-autocommit_false_not_reusable                 | false                                                                  |
| mysql-binlog_reader_connect_retry_msec              | 3000                                                                   |
| mysql-client_found_rows                             | true                                                                   |
| mysql-client_multi_statements                       | true                                                                   |
| mysql-client_session_track_gtid                     | true                                                                   |
| mysql-commands_stats                                | true                                                                   |
| mysql-connect_retries_delay                         | 1                                                                      |
| mysql-connect_retries_on_failure                    | 10                                                                     |
| mysql-connect_timeout_server                        | 3000                                                                   |
| 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                               | utf8mb4                                                                |
| mysql-default_max_latency_ms                        | 1500                                                                   |
| 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_default_log                         | 0                                                                      |
| mysql-eventslog_filename                            |                                                                        |
| mysql-eventslog_filesize                            | 104857600                                                              |
| mysql-eventslog_format                              | 1                                                                      |
| mysql-forward_autocommit                            | false                                                                  |
| mysql-free_connections_pct                          | 10                                                                     |
| mysql-have_compress                                 | true                                                                   |
| mysql-have_ssl                                      | true                                                                   |
| mysql-hostgroup_manager_verbose                     | 1                                                                      |
| mysql-init_connect                                  |                                                                        |
| mysql-interfaces                                    | 0.0.0.0:6033;0.0.0.0:6034;0.0.0.0:6035;/var/run/proxysql/proxysql.sock |
| mysql-keep_multiplexing_variables                   | tx_isolation,version                                                   |
| mysql-kill_backend_connection_when_disconnect       | true                                                                   |
| mysql-ldap_user_variable                            |                                                                        |
| mysql-long_query_time                               | 1000                                                                   |
| mysql-max_allowed_packet                            | 67108864                                                               |
| mysql-max_connections                               | 2048                                                                   |
| mysql-max_stmts_cache                               | 10000                                                                  |
| mysql-max_stmts_per_connection                      | 20                                                                     |
| mysql-max_transaction_time                          | 14400000                                                               |
| mysql-min_num_servers_lantency_awareness            | 1000                                                                   |
| mysql-mirror_max_concurrency                        | 16                                                                     |
| mysql-mirror_max_queue_length                       | 32000                                                                  |
| mysql-monitor_connect_interval                      | 60000                                                                  |
| mysql-monitor_connect_timeout                       | 600                                                                    |
| mysql-monitor_enabled                               | true                                                                   |
| mysql-monitor_galera_healthcheck_interval           | 5000                                                                   |
| mysql-monitor_galera_healthcheck_max_timeout_count  | 3                                                                      |
| mysql-monitor_galera_healthcheck_timeout            | 800                                                                    |
| mysql-monitor_groupreplication_healthcheck_interval | 5000                                                                   |
| mysql-monitor_groupreplication_healthcheck_timeout  | 800                                                                    |
| mysql-monitor_history                               | 600000                                                                 |
| mysql-monitor_password                              | somePass                                                           |
| mysql-monitor_ping_interval                         | 10000                                                                  |
| 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                    | 1500                                                                   |
| mysql-monitor_read_only_max_timeout_count           | 3                                                                      |
| mysql-monitor_read_only_timeout                     | 1200                                                                   |
| mysql-monitor_replication_lag_interval              | 100                                                                    |
| mysql-monitor_replication_lag_timeout               | 1000                                                                   |
| mysql-monitor_replication_lag_use_percona_heartbeat |                                                                        |
| mysql-monitor_slave_lag_when_null                   | 60                                                                     |
| mysql-monitor_threads_max                           | 16                                                                     |
| mysql-monitor_threads_min                           | 2                                                                      |
| mysql-monitor_threads_queue_maxsize                 | 128                                                                    |
| mysql-monitor_username                              | psql_monitor                                                           |
| mysql-monitor_wait_timeout                          | true                                                                   |
| mysql-monitor_writer_is_also_reader                 | true                                                                   |
| mysql-multiplexing                                  | true                                                                   |
| mysql-ping_interval_server_msec                     | 120000                                                                 |
| mysql-ping_timeout_server                           | 800                                                                    |
| mysql-poll_timeout                                  | 2000                                                                   |
| mysql-poll_timeout_on_failure                       | 100                                                                    |
| mysql-query_cache_size_MB                           | 256                                                                    |
| mysql-query_cache_stores_empty_result               | true                                                                   |
| 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_digests_normalize_digest_text           | false                                                                  |
| mysql-query_digests_replace_null                    | false                                                                  |
| mysql-query_digests_track_hostname                  | false                                                                  |
| mysql-query_processor_iterations                    | 0                                                                      |
| mysql-query_processor_regex                         | 1                                                                      |
| mysql-query_retries_on_failure                      | 1                                                                      |
| mysql-reset_connection_algorithm                    | 2                                                                      |
| mysql-server_capabilities                           | 47626                                                                  |
| mysql-server_version                                | 5.7.27                                                                 |
| mysql-servers_stats                                 | true                                                                   |
| mysql-session_idle_ms                               | 1000                                                                   |
| mysql-session_idle_show_processlist                 | true                                                                   |
| mysql-sessions_sort                                 | true                                                                   |
| mysql-set_query_lock_on_hostgroup                   | 0                                                                      |
| mysql-show_processlist_extended                     | 0                                                                      |
| mysql-shun_on_failures                              | 5                                                                      |
| mysql-shun_recovery_time_sec                        | 10                                                                     |
| mysql-ssl_p2s_ca                                    | /etc/ssl/certs/ca.pem                                                  |
| mysql-ssl_p2s_cert                                  | /etc/ssl/certs/client-cert.pem                                         |
| mysql-ssl_p2s_cipher                                |                                                                        |
| mysql-ssl_p2s_key                                   | /etc/ssl/certs/client-key.pem                                          |
| mysql-stacksize                                     | 1048576                                                                |
| mysql-stats_time_backend_query                      | false                                                                  |
| mysql-stats_time_query_processor                    | false                                                                  |
| mysql-threads                                       | 1                                                                      |
| 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       | 0                                                                      |
| mysql-throttle_ratio_server_to_client               | 0                                                                      |
| mysql-verbose_query_error                           | false                                                                  |
| mysql-wait_timeout                                  | 28800000                                                               |
+-----------------------------------------------------+------------------------------------------------------------------------+

Restarting proxysql daemon brings servers back to under 1 LA. Another set of servers that we have are doing just fine and they are actually routing via proxysql. Low CPU usage but VIRT is at 15.762g. On UAT, proxysql has non-existant CPU usage and only 174948 VIRT. All of these servers and their backends are virtually identical. Proxysql is deployed via ansible and the settings are also identical across the board. Please let me know if I've missed something.

kashak88 commented 5 years ago

I've adjusted some timeout values on all servers and decided to monitor for growing CPU usage and VIRT overnight. One server had a particularly high values so I decided to investigate:

2019-09-07 15:27:04 [INFO] Received command set mysql-monitor_connect_timeout=1500
2019-09-07 15:27:04 [INFO] Received command set mysql-monitor_ping_timeout=1500
2019-09-07 15:27:04 [INFO] Received command set mysql-monitor_replication_lag_timeout=1500
2019-09-07 15:27:04 [INFO] Received command set mysql-monitor_query_timeout=300
2019-09-07 15:27:04 [INFO] Received command set mysql-monitor_read_only_timeout=1500
2019-09-07 15:27:04 [INFO] Received LOAD MYSQL VARIABLES TO RUNTIME command
2019-09-07 15:27:04 [INFO] Received SAVE MYSQL VARIABLES TO DISK command
2019-09-07 15:39:17 [INFO] Received command set mysql-monitor_replication_lag_interval=10000
2019-09-07 15:39:17 [INFO] Received LOAD MYSQL VARIABLES TO RUNTIME command
2019-09-07 15:39:17 [INFO] Received SAVE MYSQL VARIABLES TO DISK command
2019-09-08 05:25:45 MySQL_Monitor.cpp:978:monitor_read_only_thread(): [ERROR] Timeout on read_only check for 10.34.1.40:3306 after 1500ms. If the server is overload, increase mysql-monitor_read_only_timeout.
2019-09-08 05:25:45 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7fad3d8e4780 , MYSQL 0x7fad3f6de100 , FD 20 : timeout check
2019-09-08 06:56:20 MySQL_Monitor.cpp:978:monitor_read_only_thread(): [ERROR] Timeout on read_only check for 10.34.1.40:3306 after 1504ms. If the server is overload, increase mysql-monitor_read_only_timeout.
2019-09-08 06:56:20 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7fad3d8e8600 , MYSQL 0x7fad3f619200 , FD 21 : timeout check
2019-09-08 06:57:32 MySQL_Monitor.cpp:978:monitor_read_only_thread(): [ERROR] Timeout on read_only check for 10.34.1.40:3306 after 1501ms. If the server is overload, increase mysql-monitor_read_only_timeout.
2019-09-08 06:57:32 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7fad3d8a1980 , MYSQL 0x7fad40ed3d00 , FD 24 : timeout check

5:25 is around the time Veeam backs up our backend DB servers. Maybe related? EDIT: Just checked other web servers that use the same backend servers, all of them got the same error, so this must be due to Veeam(at least the errors).

renecannao commented 5 years ago

@kashak88 : maybe related to #2244 ?

kashak88 commented 5 years ago

@renecannao perhaps, but our frontend connection no longer has SSL. We've had an issue with some(not all) simple PDO SELECT queries getting stuck when sending them via proxysql(2.0.5, 2.0.6). The load average on the server would always jump after executing them and I could see them get stuck in proxysql processlist until daemon restart. Once in a blue the query would execute successfully, maybe 1 out of 20 times, completely random. Slightly modifying the queries to produce less results made them execute without issues, which was weird. Couldn't figure it out until we tried to disable these options:

                        $sslOptionKeys = [
                            PDO::MYSQL_ATTR_SSL_KEY,
                            PDO::MYSQL_ATTR_SSL_CERT,
                            PDO::MYSQL_ATTR_SSL_CA,
                            PDO::MYSQL_ATTR_SSL_CIPHER
                            ];

After doing so, everything executed without issues. Backend SSL still enabled. So something was causing issues when frontend SSL connection was enabled.

Regarding the issue in this ticket, after adjusting mysql-monitor_read_only_timeout=10000 (and other timeout values which were showing errors in the log) the VIRT on all (40+ that were affected) servers hasn't grown over 250,000 and load average is very low after 3 days, even where proxysql is active. Usually the issue would start in less than a day after restarting proxysql daemon.

kashak88 commented 5 years ago

Well, I spoke too soon. Another timeout error appeared in the log about 3 hours ago, on a server that is not using proxysql yet (idle):

2019-09-09 19:02:30 MySQL_HostGroups_Manager.cpp:2807:replication_lag_action(): [WARNING] Shunning server 10.30.1.46:3306 from HG 1 with replication lag of 5 second
2019-09-09 19:02:40 MySQL_HostGroups_Manager.cpp:2818:replication_lag_action(): [WARNING] Re-enabling server 10.30.1.46:3306 from HG 1 with replication lag of 0 second
2019-09-09 19:04:10 MySQL_HostGroups_Manager.cpp:2807:replication_lag_action(): [WARNING] Shunning server 10.30.1.46:3306 from HG 1 with replication lag of 2 second
2019-09-09 19:04:20 MySQL_HostGroups_Manager.cpp:2818:replication_lag_action(): [WARNING] Re-enabling server 10.30.1.46:3306 from HG 1 with replication lag of 0 second
2019-09-09 19:04:30 MySQL_HostGroups_Manager.cpp:2807:replication_lag_action(): [WARNING] Shunning server 10.30.1.46:3306 from HG 1 with replication lag of 4 second
2019-09-09 19:04:40 MySQL_HostGroups_Manager.cpp:2818:replication_lag_action(): [WARNING] Re-enabling server 10.30.1.46:3306 from HG 1 with replication lag of 0 second
2019-09-09 19:06:40 MySQL_HostGroups_Manager.cpp:2807:replication_lag_action(): [WARNING] Shunning server 10.30.1.46:3306 from HG 1 with replication lag of 7 second
2019-09-09 19:06:50 MySQL_HostGroups_Manager.cpp:2818:replication_lag_action(): [WARNING] Re-enabling server 10.30.1.46:3306 from HG 1 with replication lag of 0 second
2019-09-09 19:08:20 MySQL_HostGroups_Manager.cpp:2807:replication_lag_action(): [WARNING] Shunning server 10.30.1.46:3306 from HG 1 with replication lag of 7 second
2019-09-09 19:08:51 MySQL_HostGroups_Manager.cpp:2818:replication_lag_action(): [WARNING] Re-enabling server 10.30.1.46:3306 from HG 1 with replication lag of 0 second
2019-09-09 19:09:50 MySQL_HostGroups_Manager.cpp:2807:replication_lag_action(): [WARNING] Shunning server 10.30.1.46:3306 from HG 1 with replication lag of 5 second
2019-09-09 19:10:00 MySQL_HostGroups_Manager.cpp:2818:replication_lag_action(): [WARNING] Re-enabling server 10.30.1.46:3306 from HG 1 with replication lag of 0 second
2019-09-10 11:35:33 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f0004208d60 , MYSQL 0x7f0003403700 , FD 20 : Lost connection to MySQL server during query
2019-09-10 11:37:52 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f0004209ee0 , MYSQL 0x7f000391a000 , FD 22 : Lost connection to MySQL server during query
2019-09-10 11:39:52 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f00042356c0 , MYSQL 0x7efffd631300 , FD 20 : Lost connection to MySQL server during query
2019-09-10 11:41:52 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f000421d840 , MYSQL 0x7efffe29ef00 , FD 21 : Lost connection to MySQL server during query
2019-09-10 11:43:52 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f0004223b20 , MYSQL 0x7efffd232700 , FD 20 : Lost connection to MySQL server during query
2019-09-10 11:45:52 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f00042234e0 , MYSQL 0x7f0000c30e00 , FD 21 : Lost connection to MySQL server during query
2019-09-10 12:52:33 MySQL_Monitor.cpp:955:monitor_read_only_thread(): [ERROR] Timeout on read_only check for 10.30.1.45:3306 after 1001ms. Unable to create a connection. If the server is overload, increase mysql-monitor_connect_timeout. Error: timeout on creating new connection: Can't connect to MySQL server on '10.30.1.45' (110).
2019-09-10 12:55:31 MySQL_HostGroups_Manager.cpp:2807:replication_lag_action(): [WARNING] Shunning server 10.30.1.46:3306 from HG 1 with replication lag of 2 second
2019-09-10 12:55:41 MySQL_HostGroups_Manager.cpp:2818:replication_lag_action(): [WARNING] Re-enabling server 10.30.1.46:3306 from HG 1 with replication lag of 1 second
2019-09-10 12:55:51 MySQL_HostGroups_Manager.cpp:2807:replication_lag_action(): [WARNING] Shunning server 10.30.1.46:3306 from HG 1 with replication lag of 2 second
2019-09-10 12:56:16 MySQL_Monitor.cpp:955:monitor_read_only_thread(): [ERROR] Timeout on read_only check for 10.30.1.45:3306 after 1001ms. Unable to create a connection. If the server is overload, increase mysql-monitor_connect_timeout. Error: timeout on creating new connection: Can't connect to MySQL server on '10.30.1.45' (110).
2019-09-10 12:56:31 MySQL_HostGroups_Manager.cpp:2818:replication_lag_action(): [WARNING] Re-enabling server 10.30.1.46:3306 from HG 1 with replication lag of 0 second
2019-09-10 12:57:11 MySQL_HostGroups_Manager.cpp:2807:replication_lag_action(): [WARNING] Shunning server 10.30.1.46:3306 from HG 1 with replication lag of 2 second
2019-09-10 12:58:01 MySQL_HostGroups_Manager.cpp:2818:replication_lag_action(): [WARNING] Re-enabling server 10.30.1.46:3306 from HG 1 with replication lag of 1 second

VIRT became 4332448 and CPU usage is at 100% by proxysql:

   PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                                                                                                                                                  
 43548 proxysql  20   0 4332448 269220   8680 S 100.3  3.3 184:22.21 proxysql -c /etc/proxysql.cnf -D /var/lib/proxysql

Other servers seem fine for now... Interestingly enough, the read_only check failed after 1001ms yet here are the runtime settings:

mysql> select * from runtime_global_variables where variable_name like 'mysql-monitor%timeout';
+----------------------------------------------------+----------------+
| variable_name                                      | variable_value |
+----------------------------------------------------+----------------+
| mysql-monitor_connect_timeout                      | 1500           |
| mysql-monitor_ping_timeout                         | 1500           |
| mysql-monitor_read_only_timeout                    | 10000          |
| mysql-monitor_replication_lag_timeout              | 1500           |
| mysql-monitor_groupreplication_healthcheck_timeout | 800            |
| mysql-monitor_galera_healthcheck_timeout           | 800            |
| mysql-monitor_query_timeout                        | 300            |
| mysql-monitor_wait_timeout                         | true           |
+----------------------------------------------------+----------------+
kashak88 commented 5 years ago

Another single server occurrence:

2019-09-12 07:34:49 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb78d6640 , MYSQL 0x7f9eac8c7900 , FD 27 : Lost connection to MySQL server during query
2019-09-12 07:36:30 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb78d6820 , MYSQL 0x7f9eb2b33900 , FD 19 : Lost connection to MySQL server during query
2019-09-12 07:38:10 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb78d9520 , MYSQL 0x7f9eac898100 , FD 21 : Lost connection to MySQL server during query
2019-09-12 07:39:51 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb60f4ae0 , MYSQL 0x7f9eac898b00 , FD 23 : Lost connection to MySQL server during query
2019-09-12 07:41:31 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb78d7ae0 , MYSQL 0x7f9eac895400 , FD 20 : Lost connection to MySQL server during query
2019-09-12 07:43:12 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb60f4e00 , MYSQL 0x7f9eb2ad4700 , FD 19 : Lost connection to MySQL server during query
2019-09-12 07:44:52 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb78da740 , MYSQL 0x7f9eb2a16e00 , FD 21 : Lost connection to MySQL server during query
2019-09-12 07:44:53 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb78d7ea0 , MYSQL 0x7f9eb2a18700 , FD 20 : Unknown MySQL error
2019-09-12 07:46:34 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb78d8080 , MYSQL 0x7f9eb2ad3d00 , FD 19 : Lost connection to MySQL server during query
2019-09-12 07:48:15 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb60f5800 , MYSQL 0x7f9eb2b36600 , FD 21 : Lost connection to MySQL server during query
2019-09-12 07:49:55 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb78da880 , MYSQL 0x7f9eac896300 , FD 19 : Lost connection to MySQL server during query
2019-09-12 07:51:36 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb78d8580 , MYSQL 0x7f9eac894a00 , FD 20 : Lost connection to MySQL server during query
2019-09-12 07:53:16 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb60f47c0 , MYSQL 0x7f9eb2b36100 , FD 21 : Lost connection to MySQL server during query
2019-09-12 07:54:57 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb78d9e80 , MYSQL 0x7f9eb2bad800 , FD 19 : Lost connection to MySQL server during query
2019-09-12 07:56:37 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb78d9200 , MYSQL 0x7f9eb2ad4200 , FD 21 : Lost connection to MySQL server during query
2019-09-12 07:58:18 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb78d6320 , MYSQL 0x7f9eb2a18700 , FD 19 : Lost connection to MySQL server during query
2019-09-12 07:59:58 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb78d8da0 , MYSQL 0x7f9eb2b34800 , FD 21 : Lost connection to MySQL server during query
2019-09-12 08:01:39 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb78dab00 , MYSQL 0x7f9eb2a16400 , FD 19 : Lost connection to MySQL server during query
2019-09-12 08:03:20 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb78d70e0 , MYSQL 0x7f9eb2baec00 , FD 20 : Lost connection to MySQL server during query
2019-09-12 08:05:00 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb60f4540 , MYSQL 0x7f9eac894000 , FD 19 : Lost connection to MySQL server during query
2019-09-12 08:06:41 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb78d8300 , MYSQL 0x7f9eb2b33400 , FD 29 : Lost connection to MySQL server during query
2019-09-12 08:08:21 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb60f53a0 , MYSQL 0x7f9eb2b33e00 , FD 19 : Lost connection to MySQL server during query
2019-09-12 08:10:02 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb78d9a20 , MYSQL 0x7f9eb2baf600 , FD 21 : Lost connection to MySQL server during query
2019-09-12 08:11:42 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb78d8b20 , MYSQL 0x7f9eb2babf00 , FD 19 : Lost connection to MySQL server during query
2019-09-12 08:13:23 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb60f3be0 , MYSQL 0x7f9eb2a19100 , FD 21 : Lost connection to MySQL server during query
2019-09-12 08:15:03 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb78d9ca0 , MYSQL 0x7f9eb2b35700 , FD 20 : Lost connection to MySQL server during query
2019-09-12 08:16:44 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb78d7f40 , MYSQL 0x7f9eb2ad2e00 , FD 19 : Lost connection to MySQL server during query
2019-09-12 08:18:24 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb60f3000 , MYSQL 0x7f9eb2ad3800 , FD 20 : Lost connection to MySQL server during query
2019-09-12 08:20:05 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb78d6c80 , MYSQL 0x7f9eb2b35200 , FD 21 : Lost connection to MySQL server during query
2019-09-12 08:20:05 MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f9eb60f3f00 , MYSQL 0x7f9eb2b34800 , FD 19 : Unknown MySQL error

VIRT grew to 13G, CPU usage was OK. 2nd Web server in the cluster with identical resources, proxysql configuration, identical code and identical backend connections did not produce any errors. Setting variables on all servers to this, increasing mysql-monitor_read_only_interval:

+-----------------------------------------------------+-------+
| Variable_name                                       | Value |
+-----------------------------------------------------+-------+
| mysql-monitor_connect_timeout                       | 10000 |
| mysql-monitor_ping_timeout                          | 3000  |
| mysql-monitor_replication_lag_timeout               | 1500  |
| mysql-monitor_groupreplication_healthcheck_interval | 5000  |
| mysql-monitor_groupreplication_healthcheck_timeout  | 800   |
| mysql-monitor_galera_healthcheck_interval           | 5000  |
| mysql-monitor_galera_healthcheck_timeout            | 800   |
| mysql-monitor_query_interval                        | 60000 |
| mysql-monitor_query_timeout                         | 300   |
| mysql-monitor_wait_timeout                          | true  |
| mysql-monitor_connect_interval                      | 60000 |
| mysql-monitor_ping_interval                         | 10000 |
| mysql-monitor_read_only_interval                    | 10000 |
| mysql-monitor_read_only_timeout                     | 10000 |
| mysql-monitor_replication_lag_interval              | 10000 |
+-----------------------------------------------------+-------+

Will report if we get any errors again...

kashak88 commented 5 years ago

Got a few of these again on 2 servers (out of total 3):

MySQL_Monitor.cpp:1123:monitor_read_only_thread(): [ERROR] Got error: mmsd 0x7f42dd807320 , MYSQL 0x7f42da70b900 , FD 24 : Lost connection to MySQL server during query

Server load is fine, but VIRT is at 13-15G Hopefully this is indeed related to #2244 ...

kashak88 commented 5 years ago

VIRT has not grown to larger than 280K on any of our servers since we've upgraded to 2.0.7, so I am guessing this was related to openssl issue outlined in #2244 .

Thanks, closing this

jurim76 commented 4 years ago

Same issue for proxysql 2.0.12 After a couple of days, proxysql starts to eat CPU (no high load, no client's connection). OS debian 10, hosted on KVM hypervisor Proxysql variables https://gist.github.com/jurim76/c7a2b40074efa4db36a13c2cac3e44bd

renecannao commented 4 years ago

Hi @jurim76 , you aren't showing the problem. Some output from top (or similar), several outputs of status variables, AND output of perf top and perf report would be a great way to start pointing to an issue

jurim76 commented 4 years ago

Hello, here are some samples.

perf top perf report htop output stats

renecannao commented 4 years ago

Hi @jurim76 . Thank you for the output. Can you provide new output of status variables?

You claim that "no client's connection", while ProxySQL says there are 132 clients connected: can you confirm them? I also see that are perhaps relevant:

| Client_Connections_aborted                  | 40             |
| Client_Connections_connected                | 132            |
| Client_Connections_created                  | 3872           |
| Queries_frontends_bytes_recv                | 153675         |
| Queries_frontends_bytes_sent                | 308583         |
| Questions                                   | 0              |

Please also send the full error log. Re-opening this issue.

jurim76 commented 4 years ago

Looks like connections from openvas security scanner. I will report later, when security scan will be disabled.

jurim76 commented 4 years ago

Similar to https://github.com/sysown/proxysql/issues/1846

renecannao commented 4 years ago

What "similar" means? #1846 is about a crash

jurim76 commented 4 years ago

In my case, openvas is a troublemaker, so it's the openvas issue. When openvas finished scan, proxysql doesn't crashed, but eat CPU with a bunch of connections in CLOSE_WAIT state.

renecannao commented 4 years ago

Ok, so I wouldn't consider it "similar". Please run this in Admin, and attach the file /tmp/log2240.txt

tee /tmp/log2240.txt
SET mysql-show_processlist_extended=1;
LOAD MYSQL VARIABLES TO RUNTIME;
SELECT * FROM stats_mysql_processlist\G
SET mysql-show_processlist_extended=2;
LOAD MYSQL VARIABLES TO RUNTIME;
SELECT * FROM stats_mysql_processlist\G

Thanks

jurim76 commented 4 years ago

Sorry, unable to execute commands

mysql Welcome to the MariaDB monitor. Commands end with ; or \g. Your MySQL connection id is 122964 Server version: 10.3.23 (ProxySQL Admin Module)

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

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

Admin> tee /tmp/log2240.txt Logging to file '/tmp/log2240.txt' Admin> SET mysql-show_processlist_extended=1; Query OK, 1 row affected (0.006 sec)

Admin> LOAD MYSQL VARIABLES TO RUNTIME; Query OK, 0 rows affected (0.002 sec)

Admin> SELECT * FROM stats_mysql_processlist\G ERROR 2013 (HY000): Lost connection to MySQL server during query

After that, hunged connections disappeared and proxysql returned to normal state (no cpu consumption)

renecannao commented 4 years ago

It means proxysql crashed while trying to collect metrics (probably a known bug fixed in 2.0.13). Do you have a core dump?

DBA-Ray commented 4 years ago

I also encountered the same problem. When the CPU usage is high on an idle proxysql, the log looks like this:

Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Received malformed line (no colon). Closing connection. Error processing request (HTTP response code is 400 (<html><head><title>Request malformed</title></head><body>Your HTTP request was syntactically incorrect.</body></html>')). Closing connection. Failed to send data in request for/tunnel'. Received malformed line (no colon). Closing connection. Error processing request (HTTP response code is 400 (<html><head><title>Request malformed</title></head><body>Your HTTP request was syntactically incorrect.</body></html>')). Closing connection. Failed to send data in request for/tunnel'. Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Error: received handshake message out of context Received HTTP 1.1 request without Host' header. Received HTTP 1.1 request withoutHost' header. Received HTTP 1.1 request without Host' header. Received HTTP 1.1 request withoutHost' header. Received HTTP 1.1 request without Host' header. Received HTTP 1.1 request withoutHost' header. Received HTTP 1.1 request without Host' header. Received HTTP 1.1 request withoutHost' header. Received HTTP 1.1 request without Host' header. Received HTTP 1.1 request withoutHost' header. Received HTTP 1.1 request without Host' header. Received HTTP 1.1 request withoutHost' header. Received HTTP 1.1 request without Host' header. Received HTTP 1.1 request withoutHost' header. Received HTTP 1.1 request without Host' header. Received HTTP 1.1 request withoutHost' header. Received HTTP 1.1 request without Host' header. Received HTTP 1.1 request withoutHost' header. Received HTTP 1.1 request without Host' header. Received HTTP 1.1 request withoutHost' header. Received HTTP 1.1 request without Host' header. Received HTTP 1.1 request withoutHost' header. Received HTTP 1.1 request without Host' header. Received HTTP 1.1 request withoutHost' header. Received HTTP 1.1 request without Host' header. Received HTTP 1.1 request withoutHost' header. Received HTTP 1.1 request without Host' header. Received HTTP 1.1 request withoutHost' header. Received HTTP 1.1 request without Host' header. Received HTTP 1.1 request withoutHost' header. Received HTTP 1.1 request without Host' header. Received HTTP 1.1 request withoutHost' header. Received HTTP 1.1 request without Host' header. Received HTTP 1.1 request withoutHost' header. Received HTTP 1.1 request without Host' header. Received HTTP 1.1 request withoutHost' header. Received HTTP 1.1 request without Host' header. Received HTTP 1.1 request withoutHost' header. Received HTTP 1.1 request without Host' header. Received HTTP 1.1 request withoutHost' header. Received HTTP 1.1 request without Host' header. Received HTTP 1.1 request withoutHost' header. Received HTTP 1.1 request without Host' header. Received HTTP 1.1 request withoutHost' header. Received HTTP 1.1 request without Host' header. Received HTTP 1.1 request withoutHost' header. Received HTTP 1.1 request without Host' header. Received HTTP 1.1 request withoutHost' header. Error: received handshake message out of context Error: received handshake message out of context 2020-06-17 23:53:01 MySQL_Session.cpp:4589:handler_status_CONNECTINGCLIENTSTATE_SERVER_HANDSHAKE(): [ERROR] ProxySQL Error: Access denied for user 'htr'@'172.21.0.35' (using password: YES) 2020-06-17 23:53:02 MySQL_Session.cpp:4589:handler_status_CONNECTINGCLIENTSTATE_SERVER_HANDSHAKE(): [ERROR] ProxySQL Error: Access denied for user 'htr'@'172.21.0.35' (using password: YES) Received malformed line (no colon). Closing connection. Error processing request (HTTP response code is 400 (<html><head><title>Request malformed</title></head><body>Your HTTP request was syntactically incorrect.</body></html>')). Closing connection. Received malformed line (no colon). Closing connection. Error processing request (HTTP response code is 400 (Request malformedYour HTTP request was syntactically incorrect.')). Closing connection.

renecannao commented 4 years ago

@DBA-Ray: from the input you provided, there is no evidence that proxysql is idle, actually the opposite. Seems more like someone is attacking proxysql on multiple ports, including webui

DBA-Ray commented 4 years ago

@renecannao Thanks a lot.Someone is indeed scanning my server.I was just notified.

jurim76 commented 4 years ago

@renecannao core dump

jurim76 commented 4 years ago

Hi @renecannao

Proxysql has been updated to 2.0.13, but the issue still persists. However, I'm able to produce extended processlist now. Here is proxysql stats. Hope it helps.