search

sysown / proxysql

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

"In Transaction" flag incorrectly set on responses after a query causes an error. #4181

Open tsteiner opened 1 year ago

tsteiner commented 1 year ago

ProxySQL version: proxysql2-2.4.8-1.1.el7.x86_64 OS version: CentOS Linux release 7.9.2009 (Core)

While a client is connected to ProxySQL, if a client's query results in an error (eg: "BOGUS QUERY;"), responses to subsequent queries have the "In Transaction" flag set, even though they aren't set by the backend's responses. The following is a screenshot of Wireshark where I highlighted responses with the "In Transaction" flag. (0 is red, 1 is green)

image

ProxySQL is running locally on 127.0.0.1, with the backend server at 10.172.28.145. You can see that initially, both responses agree that "In Transaction" is unset after each of the first three "SELECT 1" queries. However, after the "BOGUS SQL" query causes an error, the responses to the last three "SELECT 1" queries disagree on whether the "In Transaction" flag is set.

The only message in proxysql.log is: 2023-04-14 15:49:25 MySQL_Session.cpp:4313:handler_minus1_LogErrorDuringQuery(): [WARNING] Error during query on (0,10.172.25.145,3306,1190307): 1064, You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'BOGUS SQL' at line 1

renecannao commented 1 year ago

Hi @tsteiner . Thank you for the report.

Can you please share the ProxySQL configuration?

I can't reproduce on a vanilla configuration. Here the output of tcpdump after running BUGUS SQL , SELECT 1 and DO 1 :

21:57:21.682661 IP 127.0.0.1.35378 > 127.0.0.1.6033: Flags [P.], seq 149:163, ack 352, win 512, options [nop,nop,TS val 3604184764 ecr 3604043357], length 14
        0x0000:  4500 0042 093f 4000 4006 3375 7f00 0001  E..B.?@.@.3u....
        0x0010:  7f00 0001 8a32 1791 bae3 1a0d 7bee 566c  .....2......{.Vl
        0x0020:  8018 0200 fe36 0000 0101 080a d6d3 7ebc  .....6........~.
        0x0030:  d6d1 565d 0a00 0000 0342 4f47 5553 2053  ..V].....BOGUS.S
        0x0040:  514c                                     QL
21:57:21.690780 IP 127.0.0.1.6033 > 127.0.0.1.35378: Flags [P.], seq 352:520, ack 163, win 512, options [nop,nop,TS val 3604184773 ecr 3604184764], length 168
        0x0000:  4500 00dc f32d 4000 4006 48ec 7f00 0001  E....-@.@.H.....
        0x0010:  7f00 0001 1791 8a32 7bee 566c bae3 1a1b  .......2{.Vl....
        0x0020:  8018 0200 fed0 0000 0101 080a d6d3 7ec5  ..............~.
        0x0030:  d6d3 7ebc a400 0001 ff28 0423 3432 3030  ..~......(.#4200
        0x0040:  3059 6f75 2068 6176 6520 616e 2065 7272  0You.have.an.err
        0x0050:  6f72 2069 6e20 796f 7572 2053 514c 2073  or.in.your.SQL.s
        0x0060:  796e 7461 783b 2063 6865 636b 2074 6865  yntax;.check.the
        0x0070:  206d 616e 7561 6c20 7468 6174 2063 6f72  .manual.that.cor
        0x0080:  7265 7370 6f6e 6473 2074 6f20 796f 7572  responds.to.your
        0x0090:  204d 7953 514c 2073 6572 7665 7220 7665  .MySQL.server.ve
        0x00a0:  7273 696f 6e20 666f 7220 7468 6520 7269  rsion.for.the.ri
        0x00b0:  6768 7420 7379 6e74 6178 2074 6f20 7573  ght.syntax.to.us
        0x00c0:  6520 6e65 6172 2027 424f 4755 5320 5351  e.near.'BOGUS.SQ
        0x00d0:  4c27 2061 7420 6c69 6e65 2031            L'.at.line.1
21:57:21.690823 IP 127.0.0.1.35378 > 127.0.0.1.6033: Flags [.], ack 520, win 511, options [nop,nop,TS val 3604184773 ecr 3604184773], length 0
        0x0000:  4500 0034 0940 4000 4006 3382 7f00 0001  E..4.@@.@.3.....
        0x0010:  7f00 0001 8a32 1791 bae3 1a1b 7bee 5714  .....2......{.W.
        0x0020:  8010 01ff fe28 0000 0101 080a d6d3 7ec5  .....(........~.
        0x0030:  d6d3 7ec5                                ..~.
21:57:26.185604 IP 127.0.0.1.35378 > 127.0.0.1.6033: Flags [P.], seq 163:176, ack 520, win 512, options [nop,nop,TS val 3604189267 ecr 3604184773], length 13
        0x0000:  4500 0041 0941 4000 4006 3374 7f00 0001  E..A.A@.@.3t....
        0x0010:  7f00 0001 8a32 1791 bae3 1a1b 7bee 5714  .....2......{.W.
        0x0020:  8018 0200 fe35 0000 0101 080a d6d3 9053  .....5.........S
        0x0030:  d6d3 7ec5 0900 0000 0353 454c 4543 5420  ..~......SELECT.
        0x0040:  31                                       1
21:57:26.196532 IP 127.0.0.1.6033 > 127.0.0.1.35378: Flags [P.], seq 520:576, ack 176, win 512, options [nop,nop,TS val 3604189277 ecr 3604189267], length 56
        0x0000:  4500 006c f32e 4000 4006 495b 7f00 0001  E..l..@.@.I[....
        0x0010:  7f00 0001 1791 8a32 7bee 5714 bae3 1a28  .......2{.W....(
        0x0020:  8018 0200 fe60 0000 0101 080a d6d3 905d  .....`.........]
        0x0030:  d6d3 9053 0100 0001 0117 0000 0203 6465  ...S..........de
        0x0040:  6600 0000 0131 000c 3f00 0200 0000 0881  f....1..?.......
        0x0050:  8000 0000 0500 0003 fe00 0002 0002 0000  ................
        0x0060:  0401 3105 0000 05fe 0000 0200            ..1.........
21:57:26.196575 IP 127.0.0.1.35378 > 127.0.0.1.6033: Flags [.], ack 576, win 512, options [nop,nop,TS val 3604189278 ecr 3604189277], length 0
        0x0000:  4500 0034 0942 4000 4006 3380 7f00 0001  E..4.B@.@.3.....
        0x0010:  7f00 0001 8a32 1791 bae3 1a28 7bee 574c  .....2.....({.WL
        0x0020:  8010 0200 fe28 0000 0101 080a d6d3 905e  .....(.........^
        0x0030:  d6d3 905d                                ...]
22:00:07.671064 IP 127.0.0.1.35378 > 127.0.0.1.6033: Flags [P.], seq 176:185, ack 576, win 512, options [nop,nop,TS val 3604350753 ecr 3604189277], length 9
        0x0000:  4500 003d 0943 4000 4006 3376 7f00 0001  E..=.C@.@.3v....
        0x0010:  7f00 0001 8a32 1791 bae3 1a28 7bee 574c  .....2.....({.WL
        0x0020:  8018 0200 fe31 0000 0101 080a d6d6 0721  .....1.........!
        0x0030:  d6d3 905d 0500 0000 0344 4f20 31         ...].....DO.1
22:00:07.687024 IP 127.0.0.1.6033 > 127.0.0.1.35378: Flags [P.], seq 576:587, ack 185, win 512, options [nop,nop,TS val 3604350769 ecr 3604350753], length 11
        0x0000:  4500 003f f32f 4000 4006 4987 7f00 0001  E..?./@.@.I.....
        0x0010:  7f00 0001 1791 8a32 7bee 574c bae3 1a31  .......2{.WL...1
        0x0020:  8018 0200 fe33 0000 0101 080a d6d6 0731  .....3.........1
        0x0030:  d6d6 0721 0700 0001 0000 0002 0000 00    ...!...........
22:00:07.687076 IP 127.0.0.1.35378 > 127.0.0.1.6033: Flags [.], ack 587, win 512, options [nop,nop,TS val 3604350769 ecr 3604350769], length 0
        0x0000:  4500 0034 0944 4000 4006 337e 7f00 0001  E..4.D@.@.3~....
        0x0010:  7f00 0001 8a32 1791 bae3 1a31 7bee 5757  .....2.....1{.WW
        0x0020:  8010 0200 fe28 0000 0101 080a d6d6 0731  .....(.........1
        0x0030:  d6d6 0731                                ...1

In my test I do not see SERVER_STATUS_IN_TRANS set, thus my first hypothesis is that we are using different configuration.

After reading https://github.com/unlcms/project-herbie/issues/366#issuecomment-1507635715 I think your issue is probably related to savepoint . Were you using autocommit=0 and savepoints in your test?

For reference, there was a similar issue in the past: https://github.com/sysown/proxysql/issues/3749

The underlying problem is that ProxySQL tracks savepoints , autocommit and SERVER_STATUS_IN_TRANS , but it seems that the MySQL protocol may lie about SERVER_STATUS_IN_TRANS , see MySQL bug 107875 for reference. On that specific edge case ProxySQL tries to stay "on the safe side" and reports a running transaction because ... the protocol may be lying, thus ProxySQL doesn't know, so probably there is a transaction.

If you can share the exact steps to reproduce it we can try to investigate it in more details.

Furthermore, we have several automated integration testing with 3rd party software, but currently Drupal is not in that list. If Drupal has automated database testing we can add it to the list of software we run automated testing against ProxySQL.

Thanks, René

tsteiner commented 1 year ago

I also initially suspected SAVEPOINT. It turns out that its sort of related as the Drupal installer is calling "RELEASE SAVEPOINT" and the ignoring the error that no SAVEPOINT exists. It seems to be the error from the MySQL server that is actually causing the incorrect flag to be set. After the installer ignores the error, it tries to call PDO::beginTransaction() which throws an exception because ProxySQL is telling it that a transaction exists.

I was able to recreate the issue with just the following SQL:

SELECT 1;
SELECT 1;
SELECT 1;
BOGUS SQL;
SELECT 1;
SELECT 1;
SELECT 1;

Here's the config dump:

mysql> SELECT * FROM runtime_global_variables;
+----------------------------------------------------------------------+------------------------------------------------------------------------+
| variable_name                                                        | variable_value                                                         |
+----------------------------------------------------------------------+------------------------------------------------------------------------+
| admin-admin_credentials                                              | <REDACTED>                                                             |
| admin-stats_credentials                                              | <REDACTED>                                                             |
| admin-stats_mysql_connections                                        | 60                                                                     |
| admin-stats_mysql_connection_pool                                    | 60                                                                     |
| admin-stats_mysql_query_cache                                        | 60                                                                     |
| admin-stats_mysql_query_digest_to_disk                               | 0                                                                      |
| admin-stats_system_cpu                                               | 60                                                                     |
| admin-stats_system_memory                                            | 60                                                                     |
| admin-mysql_ifaces                                                   | 0.0.0.0:6032                                                           |
| admin-telnet_admin_ifaces                                            | (null)                                                                 |
| admin-telnet_stats_ifaces                                            | (null)                                                                 |
| admin-refresh_interval                                               | 2000                                                                   |
| admin-read_only                                                      | false                                                                  |
| admin-hash_passwords                                                 | true                                                                   |
| admin-vacuum_stats                                                   | true                                                                   |
| admin-version                                                        | 2.4.8-percona-1.1                                                      |
| admin-cluster_username                                               |                                                                        |
| admin-cluster_password                                               |                                                                        |
| admin-cluster_check_interval_ms                                      | 1000                                                                   |
| admin-cluster_check_status_frequency                                 | 10                                                                     |
| admin-cluster_mysql_query_rules_diffs_before_sync                    | 3                                                                      |
| admin-cluster_mysql_servers_diffs_before_sync                        | 3                                                                      |
| admin-cluster_mysql_users_diffs_before_sync                          | 3                                                                      |
| admin-cluster_proxysql_servers_diffs_before_sync                     | 3                                                                      |
| admin-cluster_mysql_variables_diffs_before_sync                      | 3                                                                      |
| admin-cluster_admin_variables_diffs_before_sync                      | 3                                                                      |
| admin-cluster_ldap_variables_diffs_before_sync                       | 3                                                                      |
| admin-cluster_mysql_query_rules_save_to_disk                         | true                                                                   |
| admin-cluster_mysql_servers_save_to_disk                             | true                                                                   |
| admin-cluster_mysql_users_save_to_disk                               | true                                                                   |
| admin-cluster_proxysql_servers_save_to_disk                          | true                                                                   |
| admin-cluster_mysql_variables_save_to_disk                           | true                                                                   |
| admin-cluster_admin_variables_save_to_disk                           | true                                                                   |
| admin-cluster_ldap_variables_save_to_disk                            | true                                                                   |
| admin-checksum_mysql_query_rules                                     | true                                                                   |
| admin-checksum_mysql_servers                                         | true                                                                   |
| admin-checksum_mysql_users                                           | true                                                                   |
| admin-checksum_mysql_variables                                       | true                                                                   |
| admin-checksum_admin_variables                                       | true                                                                   |
| admin-checksum_ldap_variables                                        | true                                                                   |
| admin-restapi_enabled                                                | false                                                                  |
| admin-restapi_port                                                   | 6070                                                                   |
| admin-web_enabled                                                    | false                                                                  |
| admin-web_port                                                       | 6080                                                                   |
| admin-web_verbosity                                                  | 0                                                                      |
| admin-prometheus_memory_metrics_interval                             | 61                                                                     |
| mysql-default_charset                                                | utf8                                                                   |
| mysql-default_collation_connection                                   | utf8_general_ci                                                        |
| mysql-shun_on_failures                                               | 5                                                                      |
| mysql-shun_recovery_time_sec                                         | 10                                                                     |
| mysql-unshun_algorithm                                               | 0                                                                      |
| mysql-query_retries_on_failure                                       | 1                                                                      |
| mysql-client_host_cache_size                                         | 0                                                                      |
| mysql-client_host_error_counts                                       | 0                                                                      |
| mysql-connect_retries_on_failure                                     | 10                                                                     |
| mysql-connect_retries_delay                                          | 1                                                                      |
| mysql-connection_delay_multiplex_ms                                  | 0                                                                      |
| mysql-connection_max_age_ms                                          | 0                                                                      |
| mysql-connect_timeout_client                                         | 10000                                                                  |
| mysql-connect_timeout_server                                         | 3000                                                                   |
| mysql-connect_timeout_server_max                                     | 10000                                                                  |
| mysql-enable_client_deprecate_eof                                    | true                                                                   |
| mysql-enable_server_deprecate_eof                                    | true                                                                   |
| mysql-enable_load_data_local_infile                                  | false                                                                  |
| mysql-eventslog_filename                                             |                                                                        |
| mysql-eventslog_filesize                                             | 104857600                                                              |
| mysql-eventslog_default_log                                          | 0                                                                      |
| mysql-eventslog_format                                               | 1                                                                      |
| mysql-auditlog_filename                                              |                                                                        |
| mysql-auditlog_filesize                                              | 104857600                                                              |
| mysql-handle_unknown_charset                                         | 1                                                                      |
| mysql-free_connections_pct                                           | 10                                                                     |
| mysql-connection_warming                                             | false                                                                  |
| mysql-session_idle_ms                                                | 1                                                                      |
| mysql-have_ssl                                                       | false                                                                  |
| mysql-have_compress                                                  | true                                                                   |
| mysql-interfaces                                                     | 0.0.0.0:3306                                                           |
| mysql-log_mysql_warnings_enabled                                     | false                                                                  |
| mysql-monitor_enabled                                                | true                                                                   |
| mysql-monitor_history                                                | 600000                                                                 |
| mysql-monitor_connect_interval                                       | 60000                                                                  |
| mysql-monitor_connect_timeout                                        | 600                                                                    |
| mysql-monitor_ping_interval                                          | 10000                                                                  |
| mysql-monitor_ping_max_failures                                      | 3                                                                      |
| mysql-monitor_ping_timeout                                           | 1000                                                                   |
| mysql-monitor_read_only_interval                                     | 1500                                                                   |
| mysql-monitor_read_only_timeout                                      | 500                                                                    |
| mysql-monitor_read_only_max_timeout_count                            | 3                                                                      |
| mysql-monitor_replication_lag_group_by_host                          | false                                                                  |
| mysql-monitor_replication_lag_interval                               | 10000                                                                  |
| mysql-monitor_replication_lag_timeout                                | 1000                                                                   |
| mysql-monitor_replication_lag_count                                  | 1                                                                      |
| mysql-monitor_groupreplication_healthcheck_interval                  | 5000                                                                   |
| mysql-monitor_groupreplication_healthcheck_timeout                   | 800                                                                    |
| mysql-monitor_groupreplication_healthcheck_max_timeout_count         | 3                                                                      |
| mysql-monitor_groupreplication_max_transactions_behind_count         | 3                                                                      |
| mysql-monitor_groupreplication_max_transactions_behind_for_read_only | 1                                                                      |
| mysql-monitor_galera_healthcheck_interval                            | 5000                                                                   |
| mysql-monitor_galera_healthcheck_timeout                             | 800                                                                    |
| mysql-monitor_galera_healthcheck_max_timeout_count                   | 3                                                                      |
| mysql-monitor_username                                               | <REDACTED>                                                             |
| mysql-monitor_password                                               | <REDACTED>                                                             |
| mysql-monitor_replication_lag_use_percona_heartbeat                  |                                                                        |
| mysql-monitor_query_interval                                         | 60000                                                                  |
| mysql-monitor_query_timeout                                          | 100                                                                    |
| mysql-monitor_slave_lag_when_null                                    | 60                                                                     |
| mysql-monitor_threads_min                                            | 8                                                                      |
| mysql-monitor_threads_max                                            | 128                                                                    |
| mysql-monitor_threads_queue_maxsize                                  | 128                                                                    |
| mysql-monitor_local_dns_cache_ttl                                    | 300000                                                                 |
| mysql-monitor_local_dns_cache_refresh_interval                       | 60000                                                                  |
| mysql-monitor_local_dns_resolver_queue_maxsize                       | 128                                                                    |
| mysql-monitor_wait_timeout                                           | true                                                                   |
| mysql-monitor_writer_is_also_reader                                  | true                                                                   |
| mysql-max_allowed_packet                                             | 67108864                                                               |
| mysql-tcp_keepalive_time                                             | 0                                                                      |
| mysql-use_tcp_keepalive                                              | false                                                                  |
| mysql-automatic_detect_sqli                                          | false                                                                  |
| mysql-firewall_whitelist_enabled                                     | false                                                                  |
| mysql-firewall_whitelist_errormsg                                    | Firewall blocked this query                                            |
| mysql-throttle_connections_per_sec_to_hostgroup                      | 1000000                                                                |
| mysql-max_transaction_idle_time                                      | 14400000                                                               |
| mysql-max_transaction_time                                           | 14400000                                                               |
| mysql-multiplexing                                                   | true                                                                   |
| mysql-log_unhealthy_connections                                      | true                                                                   |
| mysql-enforce_autocommit_on_reads                                    | false                                                                  |
| mysql-autocommit_false_not_reusable                                  | false                                                                  |
| mysql-autocommit_false_is_transaction                                | false                                                                  |
| mysql-verbose_query_error                                            | false                                                                  |
| mysql-hostgroup_manager_verbose                                      | 1                                                                      |
| mysql-binlog_reader_connect_retry_msec                               | 3000                                                                   |
| mysql-threshold_query_length                                         | 524288                                                                 |
| mysql-threshold_resultset_size                                       | 4194304                                                                |
| mysql-query_digests_max_digest_length                                | 2048                                                                   |
| mysql-query_digests_max_query_length                                 | 65000                                                                  |
| mysql-query_digests_grouping_limit                                   | 3                                                                      |
| mysql-query_digests_groups_grouping_limit                            | 0                                                                      |
| mysql-wait_timeout                                                   | 28800000                                                               |
| mysql-throttle_max_bytes_per_second_to_client                        | 0                                                                      |
| mysql-throttle_ratio_server_to_client                                | 0                                                                      |
| mysql-max_connections                                                | 2048                                                                   |
| mysql-max_stmts_per_connection                                       | 20                                                                     |
| mysql-max_stmts_cache                                                | 10000                                                                  |
| mysql-mirror_max_concurrency                                         | 16                                                                     |
| mysql-mirror_max_queue_length                                        | 32000                                                                  |
| mysql-default_max_latency_ms                                         | 1000                                                                   |
| mysql-default_query_delay                                            | 0                                                                      |
| mysql-default_query_timeout                                          | 36000000                                                               |
| mysql-query_processor_iterations                                     | 0                                                                      |
| mysql-query_processor_regex                                          | 1                                                                      |
| mysql-set_query_lock_on_hostgroup                                    | 1                                                                      |
| mysql-reset_connection_algorithm                                     | 2                                                                      |
| mysql-auto_increment_delay_multiplex                                 | 5                                                                      |
| mysql-auto_increment_delay_multiplex_timeout_ms                      | 10000                                                                  |
| mysql-long_query_time                                                | 1000                                                                   |
| mysql-query_cache_size_MB                                            | 256                                                                    |
| mysql-ping_interval_server_msec                                      | 120000                                                                 |
| mysql-ping_timeout_server                                            | 500                                                                    |
| mysql-default_schema                                                 | information_schema                                                     |
| mysql-poll_timeout                                                   | 2000                                                                   |
| mysql-poll_timeout_on_failure                                        | 100                                                                    |
| mysql-server_capabilities                                            | 569899                                                                 |
| mysql-server_version                                                 | 5.7.40                                                                 |
| mysql-keep_multiplexing_variables                                    | tx_isolation,version                                                   |
| mysql-kill_backend_connection_when_disconnect                        | true                                                                   |
| mysql-client_session_track_gtid                                      | true                                                                   |
| mysql-sessions_sort                                                  | true                                                                   |
| mysql-session_idle_show_processlist                                  | true                                                                   |
| mysql-show_processlist_extended                                      | 0                                                                      |
| mysql-commands_stats                                                 | true                                                                   |
| mysql-query_digests                                                  | true                                                                   |
| mysql-query_digests_lowercase                                        | false                                                                  |
| mysql-query_digests_replace_null                                     | false                                                                  |
| mysql-query_digests_no_digits                                        | false                                                                  |
| mysql-query_digests_normalize_digest_text                            | false                                                                  |
| mysql-query_digests_track_hostname                                   | false                                                                  |
| mysql-query_digests_keep_comment                                     | false                                                                  |
| mysql-parse_failure_logs_digest                                      | false                                                                  |
| mysql-servers_stats                                                  | true                                                                   |
| mysql-default_reconnect                                              | true                                                                   |
| mysql-ssl_p2s_ca                                                     |                                                                        |
| mysql-ssl_p2s_capath                                                 |                                                                        |
| mysql-ssl_p2s_cert                                                   |                                                                        |
| mysql-ssl_p2s_key                                                    |                                                                        |
| mysql-ssl_p2s_cipher                                                 |                                                                        |
| mysql-ssl_p2s_crl                                                    |                                                                        |
| mysql-ssl_p2s_crlpath                                                |                                                                        |
| mysql-stacksize                                                      | 1048576                                                                |
| mysql-threads                                                        | 4                                                                      |
| mysql-init_connect                                                   |                                                                        |
| mysql-ldap_user_variable                                             |                                                                        |
| mysql-add_ldap_user_comment                                          |                                                                        |
| mysql-default_tx_isolation                                           | READ-COMMITTED                                                         |
| mysql-default_session_track_gtids                                    | OFF                                                                    |
| mysql-connpoll_reset_queue_length                                    | 50                                                                     |
| mysql-min_num_servers_lantency_awareness                             | 1000                                                                   |
| mysql-aurora_max_lag_ms_only_read_from_replicas                      | 2                                                                      |
| mysql-stats_time_backend_query                                       | false                                                                  |
| mysql-stats_time_query_processor                                     | false                                                                  |
| mysql-query_cache_stores_empty_result                                | true                                                                   |
+----------------------------------------------------------------------+------------------------------------------------------------------------+
200 rows in set (0.01 sec)
tsteiner commented 11 months ago

Would this have been resolved by #4306? We don't seem to be experiencing problem anymore, and the patch notes for 2.5.5 sound pretty relevant:

Following an error returned by the backend, COMMIT and ROLLBACK were incorrectly filtered and not sent to the right backend connection because of the unknown transaction status