aherman
/
proxysql
mirror of https://github.com/sysown/proxysql
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

Adding debug_filters

Browse Source
pull/2993/head
René Cannaò 6 years ago
parent 9f02f4800c
commit 449f4eb659
5 changed files with 250 additions and 39 deletions
Show Stats Download Patch File Download Diff File

38
doc/internal/debug_filters.md
Unescape View File

@ -0,0 +1,38 @@
# Debug Filters
When ProxySQL is compiled with debug option, debugging information are dumped onto standard error.
Because debugging can be very verbose, in 2.0.13 we introduced debug filters.
The new table created is `debug_filters` , present both in `main` and `disk`.
There is no equivalent `runtime_debug_filters`.
The commands responsible for handling with `debug_levels` are also used for `debug_filters`:
* `(LOAD|SAVE) DEBUG (FROM|TO) (RUNTIME|MEMORY|DISK)`
Table definition:
```
Admin> SHOW CREATE TABLE debug_filters\G
*************************** 1. row ***************************
table: debug_filters
Create Table: CREATE TABLE debug_filters (
filename VARCHAR NOT NULL,
line INT NOT NULL,
funct VARCHAR NOT NULL,
PRIMARY KEY (filename, line, funct) )
1 row in set (0.00 sec)
```
Columns:
* `filename`: the source code filename, for example `MySQL_Thread.cpp`
* `line` : the line number in the source file, for example `1234` . `0` means any line.
* `funct` : the function name without parenthesis, for example `run` . Empty value is allowed.
When debug is writing a new debugging entry, if first checks what was loaded at runtime from `debug_filters`.
The debugging information is filtered if:
* an entry for `filename`+`line`+`funct` exists
* an entry for `filename`+`line` exists (empty `funct`)
* an entry for `filename`+`0`+`funct` exists (line `0` means any line in the given `funct`)
* an entry for `filename`+`0` exists (empty `funct`, any line)

3
include/proxysql.h
Unescape View File

@ -3,6 +3,7 @@
#include <stack>
#include <algorithm>
#include <set>
#ifndef EZOPTION
#define EZOPTION
@ -111,6 +112,8 @@ void proxy_info_(const char* msg, ...);
void init_debug_struct();
void init_debug_struct_from_cmdline();
void proxy_debug_func(enum debug_module, int, int, const char *, int, const char *, const char *, ...);
void proxy_debug_get_filters(std::set<std::string>&);
void proxy_debug_load_filters(std::set<std::string>&);
#endif
#ifdef __cplusplus

12
include/proxysql_admin.h
Unescape View File

@ -192,6 +192,8 @@ class ProxySQL_Admin {
#ifdef DEBUG
void flush_debug_levels_runtime_to_database(SQLite3DB *db, bool replace);
int flush_debug_levels_database_to_runtime(SQLite3DB *db);
void flush_debug_filters_runtime_to_database(SQLite3DB *db);
void flush_debug_filters_database_to_runtime(SQLite3DB *db);
#endif /* DEBUG */
void __insert_or_ignore_maintable_select_disktable();
@ -284,9 +286,13 @@ class ProxySQL_Admin {
void send_MySQL_OK(MySQL_Protocol *myprot, char *msg, int rows=0);
void send_MySQL_ERR(MySQL_Protocol *myprot, char *msg);
#ifdef DEBUG
int load_debug_to_runtime() { return flush_debug_levels_database_to_runtime(admindb); }
void save_debug_from_runtime() { return flush_debug_levels_runtime_to_database(admindb, true); }
#endif /* DEBUG */
// these two following functions used to just call and return one function each
// this approach was replaced when we introduced debug filters
//int load_debug_to_runtime() { return flush_debug_levels_database_to_runtime(admindb); }
//void save_debug_from_runtime() { return flush_debug_levels_runtime_to_database(admindb, true); }
int load_debug_to_runtime();
void save_debug_from_runtime();
#endif // DEBUG
void flush_mysql_users__from_memory_to_disk();
void flush_mysql_users__from_disk_to_memory();
void flush_mysql_servers__from_memory_to_disk();

136
lib/ProxySQL_Admin.cpp
Unescape View File

@ -444,6 +444,7 @@ static int http_handler(void *cls, struct MHD_Connection *connection, const char
#ifdef DEBUG
#define ADMIN_SQLITE_TABLE_DEBUG_LEVELS "CREATE TABLE debug_levels (module VARCHAR NOT NULL PRIMARY KEY , verbosity INT NOT NULL DEFAULT 0)"
#define ADMIN_SQLITE_TABLE_DEBUG_FILTERS "CREATE TABLE debug_filters (filename VARCHAR NOT NULL , line INT NOT NULL , funct VARCHAR NOT NULL , PRIMARY KEY (filename, line, funct) )"
#endif /* DEBUG */
#define ADMIN_SQLITE_TABLE_MYSQL_GROUP_REPLICATION_HOSTGROUPS_V1_4 "CREATE TABLE mysql_group_replication_hostgroups (writer_hostgroup INT CHECK (writer_hostgroup>=0) NOT NULL PRIMARY KEY , backup_writer_hostgroup INT CHECK (backup_writer_hostgroup>=0 AND backup_writer_hostgroup<>writer_hostgroup) NOT NULL , reader_hostgroup INT NOT NULL CHECK (reader_hostgroup<>writer_hostgroup AND backup_writer_hostgroup<>reader_hostgroup AND reader_hostgroup>0) , offline_hostgroup INT NOT NULL CHECK (offline_hostgroup<>writer_hostgroup AND offline_hostgroup<>reader_hostgroup AND backup_writer_hostgroup<>offline_hostgroup AND offline_hostgroup>=0) , active INT CHECK (active IN (0,1)) NOT NULL DEFAULT 1 , max_writers INT NOT NULL CHECK (max_writers >= 0) DEFAULT 1 , writer_is_also_reader INT CHECK (writer_is_also_reader IN (0,1)) NOT NULL DEFAULT 0 , max_transactions_behind INT CHECK (max_transactions_behind>=0) NOT NULL DEFAULT 0 , comment VARCHAR , UNIQUE (reader_hostgroup) , UNIQUE (offline_hostgroup) , UNIQUE (backup_writer_hostgroup))"
@ -1456,10 +1457,20 @@ bool admin_handler_command_load_or_save(char *query_no_space, unsigned int query
(query_no_space_length==strlen("LOAD DEBUG FROM DISK") && !strncasecmp("LOAD DEBUG FROM DISK",query_no_space, query_no_space_length))
) {
proxy_info("Received %s command\n", query_no_space);
l_free(*ql,*q);
*q=l_strdup("INSERT OR REPLACE INTO main.debug_levels SELECT * FROM disk.debug_levels");
*ql=strlen(*q)+1;
return true;
// we are now copying the data from memory to disk
// tables involved are:
// * debug_levels
// * debug_filters
// We only delete from filters and not from levels because the
// levels are hardcoded and fixed in number, while filters can
// be arbitrary
ProxySQL_Admin *SPA=(ProxySQL_Admin *)pa;
SPA->admindb->execute("DELETE FROM main.debug_filters");
SPA->admindb->execute("INSERT OR REPLACE INTO main.debug_levels SELECT * FROM disk.debug_levels");
SPA->admindb->execute("INSERT INTO main.debug_filters SELECT * FROM disk.debug_filters");
proxy_debug(PROXY_DEBUG_ADMIN, 4, "Loaded debug levels/filters to MEMORY\n");
SPA->send_MySQL_OK(&sess->client_myds->myprot, NULL);
return false;
}
if (
@ -1470,10 +1481,20 @@ bool admin_handler_command_load_or_save(char *query_no_space, unsigned int query
(query_no_space_length==strlen("SAVE DEBUG TO DISK") && !strncasecmp("SAVE DEBUG TO DISK",query_no_space, query_no_space_length))
) {
proxy_info("Received %s command\n", query_no_space);
l_free(*ql,*q);
*q=l_strdup("INSERT OR REPLACE INTO disk.debug_levels SELECT * FROM main.debug_levels");
*ql=strlen(*q)+1;
return true;
// we are now copying the data from disk to memory
// tables involved are:
// * debug_levels
// * debug_filters
// We only delete from filters and not from levels because the
// levels are hardcoded and fixed in number, while filters can
// be arbitrary
ProxySQL_Admin *SPA=(ProxySQL_Admin *)pa;
SPA->admindb->execute("DELETE FROM disk.debug_filters");
SPA->admindb->execute("INSERT OR REPLACE INTO disk.debug_levels SELECT * FROM main.debug_levels");
SPA->admindb->execute("INSERT INTO disk.debug_filters SELECT * FROM main.debug_filters");
proxy_debug(PROXY_DEBUG_ADMIN, 4, "Saved debug levels/filters to DISK\n");
SPA->send_MySQL_OK(&sess->client_myds->myprot, NULL);
return false;
}
if (
@ -1489,11 +1510,11 @@ bool admin_handler_command_load_or_save(char *query_no_space, unsigned int query
ProxySQL_Admin *SPA=(ProxySQL_Admin *)pa;
int rc=SPA->load_debug_to_runtime();
if (rc) {
proxy_debug(PROXY_DEBUG_ADMIN, 4, "Loaded debug levels to RUNTIME\n");
proxy_debug(PROXY_DEBUG_ADMIN, 4, "Loaded debug levels/filters to RUNTIME\n");
SPA->send_MySQL_OK(&sess->client_myds->myprot, NULL);
} else {
proxy_debug(PROXY_DEBUG_ADMIN, 1, "Error while loading debug levels to RUNTIME\n");
SPA->send_MySQL_ERR(&sess->client_myds->myprot, (char *)"Error while loading debug levels to RUNTIME");
proxy_debug(PROXY_DEBUG_ADMIN, 1, "Error while loading debug levels/filters to RUNTIME\n");
SPA->send_MySQL_ERR(&sess->client_myds->myprot, (char *)"Error while loading debug levels/filters to RUNTIME");
}
return false;
}
@ -1510,7 +1531,7 @@ bool admin_handler_command_load_or_save(char *query_no_space, unsigned int query
proxy_info("Received %s command\n", query_no_space);
ProxySQL_Admin *SPA=(ProxySQL_Admin *)pa;
SPA->save_debug_from_runtime();
proxy_debug(PROXY_DEBUG_ADMIN, 4, "Saved debug levels from RUNTIME\n");
proxy_debug(PROXY_DEBUG_ADMIN, 4, "Saved debug levels/filters from RUNTIME\n");
SPA->send_MySQL_OK(&sess->client_myds->myprot, NULL);
return false;
}
@ -5241,6 +5262,7 @@ bool ProxySQL_Admin::init() {
insert_into_tables_defs(tables_defs_admin, "runtime_restapi_routes", ADMIN_SQLITE_TABLE_RUNTIME_RESTAPI_ROUTES);
#ifdef DEBUG
insert_into_tables_defs(tables_defs_admin,"debug_levels", ADMIN_SQLITE_TABLE_DEBUG_LEVELS);
insert_into_tables_defs(tables_defs_admin,"debug_filters", ADMIN_SQLITE_TABLE_DEBUG_FILTERS);
#endif /* DEBUG */
#ifdef PROXYSQLCLICKHOUSE
// ClickHouse
@ -5268,6 +5290,7 @@ bool ProxySQL_Admin::init() {
insert_into_tables_defs(tables_defs_config, "restapi_routes", ADMIN_SQLITE_TABLE_RESTAPI_ROUTES);
#ifdef DEBUG
insert_into_tables_defs(tables_defs_config,"debug_levels", ADMIN_SQLITE_TABLE_DEBUG_LEVELS);
insert_into_tables_defs(tables_defs_config,"debug_filters", ADMIN_SQLITE_TABLE_DEBUG_FILTERS);
#endif /* DEBUG */
#ifdef PROXYSQLCLICKHOUSE
// ClickHouse
@ -8959,6 +8982,91 @@ void ProxySQL_Admin::flush_debug_levels_runtime_to_database(SQLite3DB *db, bool
#endif /* DEBUG */
#ifdef DEBUG
int ProxySQL_Admin::load_debug_to_runtime() {
int numrows = flush_debug_levels_database_to_runtime(admindb);
if (numrows) { // so far so good
// we now load filters
flush_debug_filters_database_to_runtime(admindb);
}
return numrows;
}
// because debug_mutex is static in debug.cpp
// we get a list of filters debug, where a copy constructor is called
// it is not optimal in term of performance, but this is not critical
void ProxySQL_Admin::flush_debug_filters_runtime_to_database(SQLite3DB *db) {
std::set<std::string> filters;
proxy_debug_get_filters(filters);
admindb->execute((char *)"DELETE FROM debug_filters");
for (std::set<std::string>::iterator it = filters.begin(); it != filters.end(); ++it) {
// we are splitting each key in 3 parts, separated by :
// we call c_split_2 twice
char *a = NULL;
char *b = NULL;
char *c = NULL;
std::string s = *it;
char *key = strdup(s.c_str());
c_split_2(key, (const char *)":", &a, &b);
assert(a);
assert(b);
free(b);
b = NULL;
c_split_2(index(key,':')+1, (const char *)":", &b, &c);
assert(b);
assert(c);
std::string query = "INSERT INTO debug_filters VALUES ('";
query += a;
query += "',";
query += b; // line
query += ",'";
query += c; // funct
query += "')";
admindb->execute(query.c_str());
free(a);
free(b);
free(c);
free(key);
}
}
void ProxySQL_Admin::save_debug_from_runtime() {
flush_debug_levels_runtime_to_database(admindb, true);
flush_debug_filters_runtime_to_database(admindb);
}
// because debug_mutex is static in debug.cpp
// we generate a set and sent it to debug, where a copy constructor is called
// it is not optimal in term of performance, but this is not critical
void ProxySQL_Admin::flush_debug_filters_database_to_runtime(SQLite3DB *db) {
char *error=NULL;
int cols=0;
int affected_rows=0;
SQLite3_result *resultset=NULL;
std::string query = "SELECT filename, line, funct FROM debug_filters";
admindb->execute_statement(query.c_str(), &error , &cols , &affected_rows , &resultset);
if (error) {
proxy_error("Error on %s : %s\n", query, error);
assert(0);
} else {
std::set<std::string> filters;
for (std::vector<SQLite3_row *>::iterator it = resultset->rows.begin() ; it != resultset->rows.end(); ++it) {
SQLite3_row *r=*it;
std::string key; // we create a string with the row
// remember the format is filename:line:funct
// no column can be null
key = r->fields[0];
key += ":";
key += r->fields[1];
key += ":";
key += r->fields[2];
filters.emplace(key);
}
proxy_debug_load_filters(filters);
}
if (resultset) delete resultset;
}
int ProxySQL_Admin::flush_debug_levels_database_to_runtime(SQLite3DB *db) {
int i;
char *query=(char *)"SELECT verbosity FROM debug_levels WHERE module=\"%s\"";
@ -9006,6 +9114,7 @@ void ProxySQL_Admin::__insert_or_ignore_maintable_select_disktable() {
admindb->execute("INSERT OR IGNORE INTO main.proxysql_servers SELECT * FROM disk.proxysql_servers");
#ifdef DEBUG
admindb->execute("INSERT OR IGNORE INTO main.debug_levels SELECT * FROM disk.debug_levels");
admindb->execute("INSERT OR IGNORE INTO main.debug_filters SELECT * FROM disk.debug_filters");
#endif /* DEBUG */
#ifdef PROXYSQLCLICKHOUSE
if ( GloVars.global.clickhouse_server == true ) {
@ -9037,6 +9146,7 @@ void ProxySQL_Admin::__insert_or_replace_maintable_select_disktable() {
admindb->execute("INSERT OR REPLACE INTO main.proxysql_servers SELECT * FROM disk.proxysql_servers");
#ifdef DEBUG
admindb->execute("INSERT OR REPLACE INTO main.debug_levels SELECT * FROM disk.debug_levels");
admindb->execute("INSERT OR REPLACE INTO main.debug_filters SELECT * FROM disk.debug_filters");
#endif /* DEBUG */
#ifdef PROXYSQLCLICKHOUSE
if ( GloVars.global.clickhouse_server == true ) {
@ -9066,6 +9176,7 @@ void ProxySQL_Admin::__delete_disktable() {
admindb->execute("DELETE FROM disk.proxysql_servers");
#ifdef DEBUG
admindb->execute("DELETE FROM disk.debug_levels");
admindb->execute("DELETE FROM disk.debug_filters");
#endif /* DEBUG */
#ifdef PROXYSQLCLICKHOUSE
if ( GloVars.global.clickhouse_server == true ) {
@ -9094,6 +9205,7 @@ void ProxySQL_Admin::__insert_or_replace_disktable_select_maintable() {
admindb->execute("INSERT OR REPLACE INTO disk.proxysql_servers SELECT * FROM main.proxysql_servers");
#ifdef DEBUG
admindb->execute("INSERT OR REPLACE INTO disk.debug_levels SELECT * FROM main.debug_levels");
admindb->execute("INSERT OR REPLACE INTO disk.debug_filters SELECT * FROM main.debug_filters");
#endif /* DEBUG */
#ifdef PROXYSQLCLICKHOUSE
if ( GloVars.global.clickhouse_server == true ) {

100
lib/debug.cpp
Unescape View File

@ -1,27 +1,21 @@
#include <set>
#include "proxysql.h"
#include "proxysql_atomic.h"
#include <cxxabi.h>
#ifdef DEBUG
#ifdef DEBUG_EXTERN
#undef DEBUG_EXTERN
#endif /* DEBUG_EXTERN */
#endif /* DEBUG */
#define PROXYSQL_DEBUG_PTHREAD_MUTEX
#ifndef CLOCK_MONOTONIC
#define CLOCK_MONOTONIC SYSTEM_CLOCK
#endif // CLOCK_MONOTONIC
#ifdef DEBUG
static unsigned long long pretime=0;
#ifdef PROXYSQL_DEBUG_PTHREAD_MUTEX
static pthread_mutex_t debug_mutex;
#else
static spinlock debug_spinlock;
#endif
#endif /* DEBUG */
static inline unsigned long long debug_monotonic_time() {
@ -35,9 +29,82 @@ static inline unsigned long long debug_monotonic_time() {
#ifdef DEBUG
// this set will have all the filters related to debug
// for convention, the key is:
// filename:line:function
// this key structure applies also if line is 0 or function is empty
// filename is mandatory
std::set<std::string> debug_filters;
static bool filter_debug_entry(const char *__file, int __line, const char *__func) {
pthread_mutex_lock(&debug_mutex);
bool to_filter = false;
if (debug_filters.size()) { // if the set is empty we aren't performing any filter, so we won't search
std::string key(__file);
key += ":" + std::to_string(__line);
key += ":";
key += __func;
// we start with a full search
if (debug_filters.find(key) != debug_filters.end()) {
to_filter = true;
} else {
// we now search filename + line
key = __file;
key += ":" + std::to_string(__line);
// remember to add the final ":"
key += ":";
if (debug_filters.find(key) != debug_filters.end()) {
to_filter = true;
} else {
// we now search filename + function
key = __file;
// no line = 0
key += ":0:";
key += __func;
if (debug_filters.find(key) != debug_filters.end()) {
to_filter = true;
} else {
// we now search filename only
key = __file;
// remember to add ":" even if no line
key += ":0:";
if (debug_filters.find(key) != debug_filters.end()) {
to_filter = true;
} else {
// if we reached here, we couldn't find any filter
}
}
}
}
}
pthread_mutex_unlock(&debug_mutex);
return to_filter;
}
// we use this function to sent the filters to Admin
// we hold here the mutex on debug_mutex
void proxy_debug_get_filters(std::set<std::string>& f) {
pthread_mutex_lock(&debug_mutex);
f = debug_filters;
pthread_mutex_unlock(&debug_mutex);
}
// we use this function to get the filters from Admin
// we hold here the mutex on debug_mutex
void proxy_debug_load_filters(std::set<std::string>& f) {
pthread_mutex_lock(&debug_mutex);
debug_filters.erase(debug_filters.begin(), debug_filters.end());
debug_filters = f;
pthread_mutex_unlock(&debug_mutex);
}
void proxy_debug_func(enum debug_module module, int verbosity, int thr, const char *__file, int __line, const char *__func, const char *fmt, ...) {
assert(module<PROXY_DEBUG_UNKNOWN);
if (GloVars.global.gdbg_lvl[module].verbosity < verbosity) return;
if (GloVars.global.gdbg_lvl[module].verbosity < verbosity)
return;
if (filter_debug_entry(__file, __line, __func)) // check if the entry must be filtered
return;
char debugbuff[DEBUG_MSG_MAXSIZE];
char longdebugbuff[DEBUG_MSG_MAXSIZE*8];
longdebugbuff[0]=0;
@ -46,11 +113,7 @@ void proxy_debug_func(enum debug_module module, int verbosity, int thr, const ch
va_start(ap, fmt);
vsnprintf(debugbuff, DEBUG_MSG_MAXSIZE,fmt,ap);
va_end(ap);
#ifdef PROXYSQL_DEBUG_PTHREAD_MUTEX
pthread_mutex_lock(&debug_mutex);
#else
spin_lock(&debug_spinlock);
#endif
unsigned long long curtime=debug_monotonic_time();
//fprintf(stderr, "%d:%s:%d:%s(): MOD#%d LVL#%d : %s" , thr, __file, __line, __func, module, verbosity, debugbuff);
sprintf(longdebugbuff, "%llu(%llu): %d:%s:%d:%s(): MOD#%d#%s LVL#%d : %s" , curtime, curtime-pretime, thr, __file, __line, __func, module, GloVars.global.gdbg_lvl[module].name, verbosity, debugbuff);
@ -88,14 +151,7 @@ void proxy_debug_func(enum debug_module module, int verbosity, int thr, const ch
}
#endif
if (strlen(longdebugbuff)) fprintf(stderr, "%s", longdebugbuff);
#ifdef PROXYSQL_DEBUG_PTHREAD_MUTEX
pthread_mutex_unlock(&debug_mutex);
#else
spin_unlock(&debug_spinlock);
#endif
if (GloVars.global.foreground) {
return;
}
};
#endif
@ -144,11 +200,7 @@ void print_backtrace(void)
#ifdef DEBUG
void init_debug_struct() {
int i;
#ifdef PROXYSQL_DEBUG_PTHREAD_MUTEX
pthread_mutex_init(&debug_mutex,NULL);
#else
spinlock_init(&debug_spinlock);
#endif
pthread_mutex_init(&debug_mutex,NULL);
pretime=debug_monotonic_time();
GloVars.global.gdbg_lvl= (debug_level *) malloc(PROXY_DEBUG_UNKNOWN*sizeof(debug_level));
for (i=0;i<PROXY_DEBUG_UNKNOWN;i++) {

Write Preview
Loading…
Cancel
Save