Merge pull request #4833 from sysown/v3.0-flush_debug

PROXYSQL FLUSH LOGS forces debug database flush

Author: JavierJF

lib/MySQL_Session.cpp

@@ -4042,6 +4042,17 @@ int MySQL_Session::get_pkts_from_client(bool& wrong_pass, PtrSize_t& pkt) {
 						}
 						switch ((enum_mysql_command)c) {
 							case _MYSQL_COM_QUERY:
+								{
+									const char* schemaname { client_myds->myconn->userinfo->schemaname };
+									const char* recv_query { static_cast<char*>(pkt.ptr) + 5 };
+									const uint32_t recv_query_sz { pkt.size - 5 };
+
+									proxy_debug(PROXY_DEBUG_MYSQL_COM, 5, "Processing received query"
+										"   session=%p session_type=%d schemaname=%s query=%.*s\n",
+										this, session_type, schemaname ? schemaname : "", recv_query_sz, recv_query
+									);
+								}
+
 								__sync_add_and_fetch(&thread->status_variables.stvar[st_var_queries],1);
 								if (session_type == PROXYSQL_SESSION_MYSQL) {
 									bool rc_break=false;
@@ -4849,7 +4860,6 @@ int MySQL_Session::handler() {
 		case PROCESSING_STMT_PREPARE:
 		case PROCESSING_STMT_EXECUTE:
 		case PROCESSING_QUERY:
-			//fprintf(stderr,"PROCESSING_QUERY\n");
 			// Pause Check
 			// It checks if pause_until is greater than the current time (thread->curtime).
 			// If so, it returns handler_ret immediately, indicating that processing should be paused until a later time.

lib/ProxySQL_Admin.cpp

@@ -1117,6 +1117,7 @@ void ProxySQL_Admin::flush_logs() {
 		}
 		free(ssl_keylog_file);
 	}
+	proxy_debug(PROXY_DEBUG_ADMIN, 1, "Running PROXYSQL FLUSH LOGS\n");
 }
 
 

lib/debug.cpp

@@ -43,7 +43,7 @@ struct DebugLogEntry {
 	std::string backtrace;
 };
 
-static const size_t limitSize = 30;
+static const size_t limitSize = 100;
 static std::vector<DebugLogEntry> log_buffer = {};
 
 
@@ -285,7 +285,11 @@ void proxy_debug_func(
 			// but the entries can be read in `log_buffer` in the core dump
 			// note2: also in case of shutdown , `log_buffer` will have entries that won't be saved.
 			// if we really want *all* entries, we could just call sync_log_buffer_to_disk() on shutdown
-			if (log_buffer.size() > limitSize) {
+			if (
+				(log_buffer.size() >= limitSize)
+				||
+				(entry.file == "ProxySQL_Admin.cpp" && entry.funct == "flush_logs")
+			) {
 				sync_log_buffer_to_disk(db);
 			}
 		}

lib/sqlite3db.cpp

@@ -764,7 +764,13 @@ void SQLite3_result::add_column_definition(int a, const char *b) {
  * @return An integer representing the result of the operation (SQLITE_ROW on success).
  */
 int SQLite3_result::add_row(sqlite3_stmt *stmt, bool skip) {
-	int rc=(*proxy_sqlite3_step)(stmt);
+	int rc = 0;
+	do {
+		rc = (*proxy_sqlite3_step)(stmt);
+		if (rc == SQLITE_BUSY || rc == SQLITE_LOCKED) {
+			usleep(USLEEP_SQLITE_LOCKED);
+		}
+	} while (rc == SQLITE_BUSY || rc == SQLITE_LOCKED);
 	if (rc!=SQLITE_ROW) return rc;
 	if (skip==false) {
 		SQLite3_row *row=new SQLite3_row(columns);

test/tap/tap/tap.cpp

@@ -79,21 +79,18 @@ static TEST_DATA g_test = { NO_PLAN, 0, 0, "" };
   @param us True for enabling microseconds in log output.
   @param len Buffer len.
  */
-size_t get_fmt_time(char* tm_buf, size_t len, bool us=false) {
-  time_t __timer;
-  time(&__timer);
+size_t get_fmt_time(char* tm_buf, size_t len, bool us) {
+  struct timeval tv {};
+  gettimeofday(&tv, NULL);
+
   struct tm __tm_info {};
-  localtime_r(&__timer, &__tm_info);
+  localtime_r(&tv.tv_sec, &__tm_info);
+
   size_t rc = strftime(tm_buf, len, "%Y-%m-%d %H:%M:%S", &__tm_info);
 
   if (rc == 0) {
     return rc;
   } else if (us) {
-    struct timeval tv;
-    struct tm *tm_info;
-
-    gettimeofday(&tv, NULL);
-    tm_info = localtime(&tv.tv_sec);
     rc = snprintf(tm_buf + rc, len - rc, ".%06ld", tv.tv_usec);
   }
 

test/tap/tap/tap.h

@@ -20,7 +20,7 @@
 #ifndef TAP_H
 #define TAP_H
 
-//#include "my_global.h"
+#include <unistd.h>
 
 /*
   @defgroup MyTAP MySQL support for performing unit tests according to
@@ -91,6 +91,15 @@ extern volatile int tap_log_us;
   @{
 */
 
+/**
+  @brief Writes current time ("%Y-%m-%d %H:%M:%S") in the supplied buffer.
+
+  @param tm_buf Buffer to be written.
+  @param us True for enabling microseconds in log output.
+  @param len Buffer len.
+ */
+size_t get_fmt_time(char* tm_buf, size_t len, bool us=false);
+
 /**
    Set number of tests that is planned to execute.