From 0c5e75a064965eebb17f5fb050ad3e77e53fc422 Mon Sep 17 00:00:00 2001 From: Rene Cannao Date: Sat, 6 Dec 2025 14:05:01 +0000 Subject: [PATCH] Fix wait_timeout timeout calculations and add proper newline characters Key improvements: - Fix timeout comparison in MySQL_Thread::idle_thread_to_kill_idle_sessions() to prevent underflow - Use effective wait_timeout (minimum of global and session values) for idle timeout calculations - Add proper newline characters to proxy_warning messages for consistent log formatting - Increase test sleep times to account for global timeout enforcement - Fix session timeout test durations to properly test timeout behavior Technical changes: - Replace broken min_idle calculation with proper effective wait_timeout logic - Add std::min() usage to determine effective timeout from global and session values - Ensure warning messages end with newline characters for proper log formatting - Update test sleep durations to ensure proper timeout testing Resolves potential timeout calculation bugs and ensures consistent timeout enforcement behavior. --- lib/MySQL_Session.cpp | 4 ++-- lib/MySQL_Thread.cpp | 24 ++++++++++++++++----- test/tap/tests/mysql-set_wait_timeout-t.cpp | 4 ++-- 3 files changed, 23 insertions(+), 9 deletions(-) diff --git a/lib/MySQL_Session.cpp b/lib/MySQL_Session.cpp index 23af66adf..ab17a8e4d 100644 --- a/lib/MySQL_Session.cpp +++ b/lib/MySQL_Session.cpp @@ -6627,7 +6627,7 @@ bool MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C // Warn if value was clamped due to ProxySQL limits if (original_timeout != client_timeout) { - proxy_warning("Client [%s] (user: %s) requested wait_timeout = %llu ms, clamped to %llu ms (ProxySQL limits: 1s to 20 days)", + proxy_warning("Client [%s] (user: %s) requested wait_timeout = %llu ms, clamped to %llu ms (ProxySQL limits: 1s to 20 days)\n", client_myds->myconn->connected_host_details.ip, client_myds->myconn->userinfo->username, original_timeout, @@ -6636,7 +6636,7 @@ bool MySQL_Session::handler___status_WAITING_CLIENT_DATA___STATE_SLEEP___MYSQL_C // Warn if client's value exceeds current global timeout (after clamping) if (client_timeout > static_cast(mysql_thread___wait_timeout)) { - proxy_warning("Client [%s] (user: %s) requested wait_timeout = %llu ms, exceeds the global mysql-wait_timeout = %d ms. Global timeout will still be enforced.", + proxy_warning("Client [%s] (user: %s) requested wait_timeout = %llu ms, exceeds the global mysql-wait_timeout = %d ms. Global timeout will still be enforced.\n", client_myds->myconn->connected_host_details.ip, client_myds->myconn->userinfo->username, client_timeout, diff --git a/lib/MySQL_Thread.cpp b/lib/MySQL_Thread.cpp index 41eaf7c69..9aec67788 100644 --- a/lib/MySQL_Thread.cpp +++ b/lib/MySQL_Thread.cpp @@ -3436,15 +3436,25 @@ void MySQL_Thread::idle_thread_to_kill_idle_sessions() { mysess_idx=0; } unsigned int i; - unsigned long long min_idle = 0; - if (curtime > (unsigned long long)mysql_thread___wait_timeout*1000) { - min_idle = curtime - (unsigned long long)mysql_thread___wait_timeout*1000; + if (curtime < (unsigned long long)mysql_thread___wait_timeout*1000) { + return; // this should never happen + //min_idle = curtime - (unsigned long long)mysql_thread___wait_timeout*1000; } for (i=0;ilen; i++) { uint32_t sess_pos=mysess_idx; MySQL_Session *mysess=(MySQL_Session *)mysql_sessions->index(sess_pos); - if (mysess->idle_since < min_idle || mysess->killed==true) { + unsigned long long effective_wait_timeout = std::min( + static_cast(mysql_thread___wait_timeout), + static_cast(mysess->wait_timeout) + ); + unsigned long long min_idle = 0; + min_idle = curtime - (unsigned long long)effective_wait_timeout*1000; + if (mysess->idle_since < min_idle) { + unsigned long long sess_time = curtime - mysess->idle_since; + proxy_warning("Killing client connection %s:%d because inactive for %llums\n", mysess->client_myds->addr.addr, mysess->client_myds->addr.port, sess_time/1000); mysess->killed=true; + } + if (mysess->killed==true) { // because idle or for any other reason MySQL_Data_Stream *tmp_myds=mysess->client_myds; int dsidx=tmp_myds->poll_fds_idx; //fprintf(stderr,"Removing session %p, DS %p idx %d\n",mysess,tmp_myds,dsidx); @@ -4053,7 +4063,11 @@ void MySQL_Thread::process_all_sessions() { #ifdef IDLE_THREADS else { - if ( (sess_time/1000 > (unsigned long long)mysql_thread___wait_timeout) ) { + unsigned long long effective_wait_timeout = std::min( + static_cast(mysql_thread___wait_timeout), + static_cast(sess->wait_timeout) + ); + if ( (sess_time/1000 > effective_wait_timeout) ) { sess->killed=true; sess->to_process=1; proxy_warning("Killing client connection %s:%d because inactive for %llums\n", sess->client_myds->addr.addr, sess->client_myds->addr.port, sess_time/1000); diff --git a/test/tap/tests/mysql-set_wait_timeout-t.cpp b/test/tap/tests/mysql-set_wait_timeout-t.cpp index e0a03fcb7..7c8f71338 100644 --- a/test/tap/tests/mysql-set_wait_timeout-t.cpp +++ b/test/tap/tests/mysql-set_wait_timeout-t.cpp @@ -72,7 +72,7 @@ int test_session_timeout(CommandLine *cl, MYSQL *admin) { int rc = run_q(proxy, "SET sql_mode=''"); ok(rc == 0, (rc == 0 ? "Connection alive" : "Connection killed")); - sleep(12); + sleep(25); rc = run_q(proxy, "SET sql_mode=''"); ok(rc != 0, (rc == 0 ? "Connection alive" : "Connection killed")); @@ -99,7 +99,7 @@ int test_session_timeout_exceed_global_timeout(CommandLine *cl, MYSQL *admin) { int rc = run_q(proxy, "SET sql_mode=''"); ok(rc == 0, (rc == 0 ? "Connection alive" : "Connection killed")); - sleep(12); + sleep(15); rc = run_q(proxy, "SET sql_mode=''"); ok(rc != 0, (rc == 0 ? "Connection alive" : "Connection killed"));