From fd11e6a7f52d4b71dde8cabbdb8d58ce55435365 Mon Sep 17 00:00:00 2001 From: VilhoRaatikka Date: Wed, 19 Nov 2014 00:08:59 +0200 Subject: [PATCH] Session-specific logging. Added functions void session_enable_log(SESSION* ses, logfile_id_t id) and void session_disable_log(SESSION* ses, logfile_id_t id) Which switch specific log type on/off if the log type in question is not generally enabled. Each thread carries a thread-specific struct log_info_t which includes members for current session id and bitfield for enabled log types for the current session. That information is checked before actual log write functions are called. Each file where session-specific logging is used, must include the following exports: /** Defined in log_manager.cc */ extern int lm_enabled_logfiles_bitmask; extern size_t log_ses_count[]; extern __thread log_info_t tls_log_info; --- log_manager/log_manager.cc | 81 ++++++++++--------- log_manager/log_manager.h | 48 +++++++++-- query_classifier/query_classifier.cc | 4 +- server/core/adminusers.c | 5 +- server/core/buffer.c | 5 +- server/core/config.c | 5 +- server/core/dbusers.c | 5 +- server/core/dcb.c | 62 ++++++++++++-- server/core/filter.c | 5 +- server/core/gateway.c | 5 +- server/core/gw_utils.c | 5 +- server/core/load_utils.c | 5 +- server/core/monitor.c | 5 +- server/core/poll.c | 66 ++++++++------- server/core/secrets.c | 5 +- server/core/server.c | 5 +- server/core/service.c | 5 +- server/core/session.c | 55 +++++++++++-- server/core/utils.c | 5 +- server/include/dcb.h | 4 +- server/include/session.h | 31 ++++--- server/modules/filter/hint/hintparser.c | 5 +- server/modules/filter/qlafilter.c | 5 +- server/modules/filter/regexfilter.c | 5 +- server/modules/filter/tee.c | 5 +- server/modules/filter/topfilter.c | 5 +- server/modules/monitor/galera_mon.c | 5 +- server/modules/monitor/mysql_mon.c | 5 +- server/modules/monitor/ndbcluster_mon.c | 5 +- server/modules/protocol/httpd.c | 5 +- server/modules/protocol/maxscaled.c | 5 +- server/modules/protocol/mysql_backend.c | 5 +- server/modules/protocol/mysql_client.c | 5 +- server/modules/protocol/mysql_common.c | 5 +- server/modules/protocol/telnetd.c | 5 +- server/modules/routing/cli.c | 5 +- server/modules/routing/debugcli.c | 5 +- server/modules/routing/readconnroute.c | 5 +- .../routing/readwritesplit/readwritesplit.c | 11 +-- 39 files changed, 379 insertions(+), 133 deletions(-) diff --git a/log_manager/log_manager.cc b/log_manager/log_manager.cc index 04c96b353..c7175daf0 100644 --- a/log_manager/log_manager.cc +++ b/log_manager/log_manager.cc @@ -57,10 +57,18 @@ static simple_mutex_t msg_mutex; * actual library calls such as skygw_log_write. */ int lm_enabled_logfiles_bitmask = 0; + /** - * Thread-specific variable for session id which is used in trace logging. + * Thread-specific struct variable for storing current session id and currently + * enabled log files for the session. */ -__thread size_t tls_sesid = 0; +__thread log_info_t tls_log_info = {0, 0}; + +/** + * Global counter for each log file type. It indicates for how many sessions + * each log type is currently enabled. + */ +ssize_t log_ses_count[LOGFILE_LAST] = {0}; /** * BUFSIZ comes from the system. It equals with block size or @@ -68,13 +76,6 @@ __thread size_t tls_sesid = 0; */ #define MAX_LOGSTRLEN BUFSIZ -#if defined(SS_PROF) -/** - * These counters may be inaccurate but give some idea of how - * things are going. - */ - -#endif /** * Path to directory in which all files are stored to shared memory * by the OS. @@ -726,20 +727,19 @@ static int logmanager_write_log( int safe_str_len; /** Length of session id */ int sesid_str_len; - + /** 2 braces and 2 spaces */ - if (id == LOGFILE_TRACE && tls_sesid > 0) + if (id == LOGFILE_TRACE && tls_log_info.li_sesid != 0) { - sesid_str_len = 2+2+get_decimal_len(tls_sesid); + sesid_str_len = 2+2+get_decimal_len(tls_log_info.li_sesid); } else { sesid_str_len = 0; - } - + } timestamp_len = get_timestamp_len(); - /** Findout how much can be safely written with current block size */ + /** Find out how much can be safely written with current block size */ if (timestamp_len-1+sesid_str_len-1+str_len > lf->lf_buf_size) { safe_str_len = lf->lf_buf_size; @@ -799,12 +799,15 @@ static int logmanager_write_log( */ timestamp_len = snprint_timestamp(wp, timestamp_len); - if (id == LOGFILE_TRACE) + if (sesid_str_len != 0) { /** * Write session id */ - snprintf(wp+timestamp_len, sesid_str_len, "[%lu] ", tls_sesid); + snprintf(wp+timestamp_len, + sesid_str_len, + "[%lu] ", + tls_log_info.li_sesid); sesid_str_len -= 1; /*< remove terminating char */ } /** @@ -1234,10 +1237,10 @@ int skygw_log_enable( { bool err = 0; - if (!logmanager_register(true)) { - //fprintf(stderr, "ERROR: Can't register to logmanager\n"); - err = -1; - goto return_err; + if (!logmanager_register(true)) + { + err = -1; + goto return_err; } CHK_LOGMANAGER(lm); @@ -1369,19 +1372,21 @@ int skygw_log_write_flush( va_list valist; size_t len; - if (!logmanager_register(true)) { - //fprintf(stderr, "ERROR: Can't register to logmanager\n"); - err = -1; - goto return_err; + if (!logmanager_register(true)) + { + err = -1; + goto return_err; } CHK_LOGMANAGER(lm); - /** - * If particular log is disabled only unregister and return. - */ - if (!(lm->lm_enabled_logfiles & id)) { - err = 1; - goto return_unregister; + /** + * If particular log is disabled in general and it is not enabled for + * the current session, then unregister and return. + */ + if (!LOG_IS_ENABLED(id)) + { + err = 1; + goto return_unregister; } /** * Find out the length of log string (to be formatted str). @@ -1422,17 +1427,19 @@ int skygw_log_write( va_list valist; size_t len; - if (!logmanager_register(true)) { - //fprintf(stderr, "ERROR: Can't register to logmanager\n"); - err = -1; - goto return_err; + if (!logmanager_register(true)) + { + err = -1; + goto return_err; } CHK_LOGMANAGER(lm); /** - * If particular log is disabled only unregister and return. + * If particular log is disabled in general and it is not enabled for + * the current session, then unregister and return. */ - if (!(lm->lm_enabled_logfiles & id)) { + if (!LOG_IS_ENABLED(id)) + { err = 1; goto return_unregister; } diff --git a/log_manager/log_manager.h b/log_manager/log_manager.h index 9266e865e..af11d3a86 100644 --- a/log_manager/log_manager.h +++ b/log_manager/log_manager.h @@ -42,17 +42,55 @@ typedef enum { typedef enum { FILEWRITER_INIT, FILEWRITER_RUN, FILEWRITER_DONE } filewriter_state_t; +/** +* Thread-specific logging information. +*/ +typedef struct log_info_st +{ + size_t li_sesid; + int li_enabled_logs; +} log_info_t; + #define LE LOGFILE_ERROR #define LM LOGFILE_MESSAGE #define LT LOGFILE_TRACE #define LD LOGFILE_DEBUG +/** + * Check if specified log type is enabled in general or if it is enabled + * for the current session. + */ +#define LOG_IS_ENABLED(id) (((lm_enabled_logfiles_bitmask & id) || \ + (log_ses_count[id] > 0 && \ + tls_log_info.li_enabled_logs & id)) ? true : false) + + +#define LOG_MAY_BE_ENABLED(id) (((lm_enabled_logfiles_bitmask & id) || \ + log_ses_count[id] > 0) ? true : false) +/** + * Execute the given command if specified log is enabled in general or + * if there is at least one session for whom the log is enabled. + */ +#define LOGIF_MAYBE(id,cmd) if (LOG_MAY_BE_ENABLED(id)) \ + { \ + cmd; \ + } + +/** + * Execute the given command if specified log is enabled in general or + * if the log is enabled for the current session. + */ +#define LOGIF(id,cmd) if (LOG_IS_ENABLED(id)) \ + { \ + cmd; \ + } + +#if !defined(LOGIF) #define LOGIF(id,cmd) if (lm_enabled_logfiles_bitmask & id) \ - { \ - cmd; \ - } \ - -#define LOG_IS_ENABLED(id) ((lm_enabled_logfiles_bitmask & id) ? true : false) + { \ + cmd; \ + } +#endif /** * UNINIT means zeroed memory buffer allocated for the struct. diff --git a/query_classifier/query_classifier.cc b/query_classifier/query_classifier.cc index c10d78a48..109269252 100644 --- a/query_classifier/query_classifier.cc +++ b/query_classifier/query_classifier.cc @@ -61,7 +61,9 @@ #include #include -extern int lm_enabled_logfiles_bitmask; +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; #define QTYPE_LESS_RESTRICTIVE_THAN_WRITE(t) (t #include -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; /** * @file adminusers.c - Administration user account management diff --git a/server/core/buffer.c b/server/core/buffer.c index 8cbac2d65..8f4989a7e 100644 --- a/server/core/buffer.c +++ b/server/core/buffer.c @@ -47,7 +47,10 @@ #include #include -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; static buffer_object_t* gwbuf_remove_buffer_object( GWBUF* buf, diff --git a/server/core/config.c b/server/core/config.c index 153bf1640..cc5886c03 100644 --- a/server/core/config.c +++ b/server/core/config.c @@ -58,7 +58,10 @@ #include #include -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; extern int setipaddress(struct in_addr *, char *); static int process_config_context(CONFIG_CONTEXT *); diff --git a/server/core/dbusers.c b/server/core/dbusers.c index 7d6acfd98..8404bd7ba 100644 --- a/server/core/dbusers.c +++ b/server/core/dbusers.c @@ -63,7 +63,10 @@ #define LOAD_MYSQL_DATABASE_NAMES "SELECT * FROM ( (SELECT COUNT(1) AS ndbs FROM INFORMATION_SCHEMA.SCHEMATA) AS tbl1, (SELECT GRANTEE,PRIVILEGE_TYPE from INFORMATION_SCHEMA.USER_PRIVILEGES WHERE privilege_type='SHOW DATABASES' AND REPLACE(GRANTEE, \"\'\",\"\")=CURRENT_USER()) AS tbl2)" -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; static int getUsers(SERVICE *service, USERS *users); static int uh_cmpfun( void* v1, void* v2); diff --git a/server/core/dcb.c b/server/core/dcb.c index 641691e72..a4037eaa5 100644 --- a/server/core/dcb.c +++ b/server/core/dcb.c @@ -71,7 +71,10 @@ #include #include -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; static DCB *allDCBs = NULL; /* Diagnostics need a list of DCBs */ static DCB *zombies = NULL; @@ -85,10 +88,10 @@ static bool dcb_set_state_nomutex( dcb_state_t* old_state); static void dcb_call_callback(DCB *dcb, DCB_REASON reason); static DCB* dcb_get_next (DCB* dcb); -static int dcb_null_write(DCB *dcb, GWBUF *buf); -static int dcb_null_close(DCB *dcb); -static int dcb_null_auth(DCB *dcb, SERVER *server, SESSION *session, GWBUF *buf); -static int dcb_isvalid_nolock(DCB *dcb); +static int dcb_null_write(DCB *dcb, GWBUF *buf); +static int dcb_null_close(DCB *dcb); +static int dcb_null_auth(DCB *dcb, SERVER *server, SESSION *session, GWBUF *buf); +static int dcb_isvalid_nolock(DCB *dcb); size_t dcb_get_session_id( DCB* dcb) @@ -105,8 +108,45 @@ size_t dcb_get_session_id( } return rval; } + /** - * Return the pointer to the lsit of zombie DCB's + * Read log info from session through DCB and store values to memory locations + * passed as parameters. + * + * @param dcb DCB + * @param sesid location where session id is to be copied + * @param enabled_logs bit field indicating which log types are enabled for the + * session + * + *@return true if call arguments included memory addresses, false if any of the + *parameters was NULL. + */ +bool dcb_get_ses_log_info( + DCB* dcb, + size_t* sesid, + int* enabled_logs) +{ + bool succp; + + if (dcb == NULL || + dcb->session == NULL || + sesid == NULL || + enabled_logs == NULL) + { + succp = false; + } + else + { + *sesid = dcb->session->ses_id; + *enabled_logs = dcb->session->ses_enabled_logs; + succp = true; + } + + return succp; +} + +/** + * Return the pointer to the list of zombie DCB's * * @return Zombies DCB list */ @@ -455,6 +495,7 @@ bool succp = false; zombies = tptr; else lptr->memdata.next = tptr; + LOGIF(LD, (skygw_log_write_flush( LOGFILE_DEBUG, "%lu [dcb_process_zombies] Remove dcb " @@ -498,6 +539,7 @@ bool succp = false; while (dcb != NULL) { DCB* dcb_next = NULL; int rc = 0; + /*< * Close file descriptor and move to clean-up phase. */ @@ -532,12 +574,20 @@ bool succp = false; ss_debug(dcb->fd = -1;) } #endif /* SS_DEBUG */ + LOGIF_MAYBE(LT, (dcb_get_ses_log_info( + dcb, + &tls_log_info.li_sesid, + &tls_log_info.li_enabled_logs))); + succp = dcb_set_state(dcb, DCB_STATE_DISCONNECTED, NULL); ss_dassert(succp); dcb_next = dcb->memdata.next; dcb_final_free(dcb); dcb = dcb_next; } + /** Reset threads session data */ + LOGIF(LT, tls_log_info.li_sesid = 0); + return zombies; } diff --git a/server/core/filter.c b/server/core/filter.c index b14f23a87..975386f2b 100644 --- a/server/core/filter.c +++ b/server/core/filter.c @@ -38,7 +38,10 @@ #include #include -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; static SPINLOCK filter_spin = SPINLOCK_INIT; /**< Protects the list of all filters */ static FILTER_DEF *allFilters = NULL; /**< The list of all filters */ diff --git a/server/core/gateway.c b/server/core/gateway.c index 7e2e49dcd..60dbbb692 100644 --- a/server/core/gateway.c +++ b/server/core/gateway.c @@ -85,7 +85,10 @@ extern char *program_invocation_short_name; * Used from log users to check enabled logs prior calling * actual library calls such as skygw_log_write. */ -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; /* * Server options are passed to the mysql_server_init. Each gateway must have a unique diff --git a/server/core/gw_utils.c b/server/core/gw_utils.c index f76fb583b..1b8836ba6 100644 --- a/server/core/gw_utils.c +++ b/server/core/gw_utils.c @@ -48,7 +48,10 @@ SPINLOCK tmplock = SPINLOCK_INIT; -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; /* * Set IP address in socket structure in_addr diff --git a/server/core/load_utils.c b/server/core/load_utils.c index b7edef9e9..2d1f5ecd8 100644 --- a/server/core/load_utils.c +++ b/server/core/load_utils.c @@ -43,7 +43,10 @@ #include #include -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; static MODULES *registered = NULL; diff --git a/server/core/monitor.c b/server/core/monitor.c index b2b348e5e..23b8ee4ef 100644 --- a/server/core/monitor.c +++ b/server/core/monitor.c @@ -40,7 +40,10 @@ #include #include -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; static MONITOR *allMonitors = NULL; static SPINLOCK monLock = SPINLOCK_INIT; diff --git a/server/core/poll.c b/server/core/poll.c index 378147ac4..7a5b31d85 100644 --- a/server/core/poll.c +++ b/server/core/poll.c @@ -39,9 +39,10 @@ #include #endif -extern int lm_enabled_logfiles_bitmask; - -extern __thread size_t tls_sesid; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; /** * @file poll.c - Abstraction of the epoll functionality @@ -662,24 +663,21 @@ uint32_t ev; if (eno == 0) { #if MUTEX_BLOCK - simple_mutex_lock( - &dcb->dcb_write_lock, - true); - ss_info_dassert( - !dcb->dcb_write_active, - "Write already active"); + simple_mutex_lock(&dcb->dcb_write_lock, true); + ss_info_dassert(!dcb->dcb_write_active, + "Write already active"); dcb->dcb_write_active = TRUE; - atomic_add( - &pollStats.n_write, - 1); + atomic_add(&pollStats.n_write, 1); dcb->func.write_ready(dcb); dcb->dcb_write_active = FALSE; - simple_mutex_unlock( - &dcb->dcb_write_lock); + simple_mutex_unlock(&dcb->dcb_write_lock); #else - atomic_add(&pollStats.n_write, - 1); - LOGIF(LT, (tls_sesid = dcb_get_session_id(dcb))); + atomic_add(&pollStats.n_write, 1); + + LOGIF_MAYBE(LT, (dcb_get_ses_log_info( + dcb, + &tls_log_info.li_sesid, + &tls_log_info.li_enabled_logs))); dcb->func.write_ready(dcb); #endif } else { @@ -698,10 +696,8 @@ uint32_t ev; if (ev & EPOLLIN) { #if MUTEX_BLOCK - simple_mutex_lock(&dcb->dcb_read_lock, - true); - ss_info_dassert(!dcb->dcb_read_active, - "Read already active"); + simple_mutex_lock(&dcb->dcb_read_lock, true); + ss_info_dassert(!dcb->dcb_read_active, "Read already active"); dcb->dcb_read_active = TRUE; #endif @@ -715,7 +711,10 @@ uint32_t ev; dcb->fd))); atomic_add( &pollStats.n_accept, 1); - LOGIF(LT, (tls_sesid = dcb_get_session_id(dcb))); + LOGIF_MAYBE(LT, (dcb_get_ses_log_info( + dcb, + &tls_log_info.li_sesid, + &tls_log_info.li_enabled_logs))); dcb->func.accept(dcb); } else @@ -728,7 +727,10 @@ uint32_t ev; dcb, dcb->fd))); atomic_add(&pollStats.n_read, 1); - LOGIF(LT, (tls_sesid = dcb_get_session_id(dcb))); + LOGIF_MAYBE(LT, (dcb_get_ses_log_info( + dcb, + &tls_log_info.li_sesid, + &tls_log_info.li_enabled_logs))); dcb->func.read(dcb); } #if MUTEX_BLOCK @@ -764,7 +766,10 @@ uint32_t ev; strerror(eno)))); } atomic_add(&pollStats.n_error, 1); - LOGIF(LT, (tls_sesid = dcb_get_session_id(dcb))); + LOGIF_MAYBE(LT, (dcb_get_ses_log_info( + dcb, + &tls_log_info.li_sesid, + &tls_log_info.li_enabled_logs))); dcb->func.error(dcb); } @@ -789,7 +794,10 @@ uint32_t ev; { dcb->flags |= DCBF_HUNG; spinlock_release(&dcb->dcb_initlock); - LOGIF(LT, (tls_sesid = dcb_get_session_id(dcb))); + LOGIF_MAYBE(LT, (dcb_get_ses_log_info( + dcb, + &tls_log_info.li_sesid, + &tls_log_info.li_enabled_logs))); dcb->func.hangup(dcb); } else @@ -818,15 +826,16 @@ uint32_t ev; { dcb->flags |= DCBF_HUNG; spinlock_release(&dcb->dcb_initlock); - LOGIF(LT, (tls_sesid = dcb_get_session_id(dcb))); + LOGIF_MAYBE(LT, (dcb_get_ses_log_info( + dcb, + &tls_log_info.li_sesid, + &tls_log_info.li_enabled_logs))); dcb->func.hangup(dcb); } else spinlock_release(&dcb->dcb_initlock); } #endif - LOGIF(LT, tls_sesid = 0); - spinlock_acquire(&pollqlock); if (dcb->evq.pending_events == 0) { @@ -871,6 +880,7 @@ uint32_t ev; } } dcb->evq.processing = 0; + LOGIF(LT, tls_log_info.li_sesid = 0); spinlock_release(&pollqlock); return 1; diff --git a/server/core/secrets.c b/server/core/secrets.c index a27ee0d3b..b05f47ebe 100644 --- a/server/core/secrets.c +++ b/server/core/secrets.c @@ -23,7 +23,10 @@ #include #include -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; /** * Generate a random printable character * diff --git a/server/core/server.c b/server/core/server.c index dd0e8819d..e4cb0e114 100644 --- a/server/core/server.c +++ b/server/core/server.c @@ -45,7 +45,10 @@ #include #include -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; static SPINLOCK server_spin = SPINLOCK_INIT; static SERVER *allServers = NULL; diff --git a/server/core/service.c b/server/core/service.c index b9294bd27..1263c0ee1 100644 --- a/server/core/service.c +++ b/server/core/service.c @@ -55,7 +55,10 @@ #include #include -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; /** To be used with configuration type checks */ typedef struct typelib_st { diff --git a/server/core/session.c b/server/core/session.c index 9283fffa8..f056be95d 100644 --- a/server/core/session.c +++ b/server/core/session.c @@ -44,7 +44,10 @@ #include /** Defined in log_manager.cc */ -extern int lm_enabled_logfiles_bitmask; +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; + /** Global session id; updated safely by holding session_spin */ static size_t session_id; @@ -74,15 +77,14 @@ session_alloc(SERVICE *service, DCB *client_dcb) ss_info_dassert(session != NULL, "Allocating memory for session failed."); - if (session == NULL) { - int eno = errno; - errno = 0; + if (session == NULL) + { LOGIF(LE, (skygw_log_write_flush( LOGFILE_ERROR, "Error : Failed to allocate memory for " "session object due error %d, %s.", - eno, - strerror(eno)))); + errno, + strerror(errno)))); goto return_session; } #if defined(SS_DEBUG) @@ -219,7 +221,8 @@ session_alloc(SERVICE *service, DCB *client_dcb) session->state = SESSION_STATE_ROUTER_READY; spinlock_release(&session->ses_lock); spinlock_acquire(&session_spin); - session->ses_id = ++session_id; /*< assign an id and increase */ + /** Assign a session id and increase */ + session->ses_id = ++session_id; session->next = allSessions; allSessions = session; spinlock_release(&session_spin); @@ -250,6 +253,41 @@ return_session: return session; } +/** + * Enable specified logging for the current session and increase logger + * counter. + * Generic logging setting has precedence over session-specific setting. + * + * @param ses session + * @param id logfile identifier + */ +void session_enable_log( + SESSION* ses, + logfile_id_t id) +{ + ses->ses_enabled_logs |= id; + atomic_add((int *)&log_ses_count[id], 1); +} + +/** + * Disable specified logging for the current session and decrease logger + * counter. + * Generic logging setting has precedence over session-specific setting. + * + * @param ses session + * @param id logfile identifier + */ +void session_disable_log( + SESSION* ses, + logfile_id_t id) +{ + if (ses->ses_enabled_logs & id) + { + ses->ses_enabled_logs &= ~id; + atomic_add((int *)&log_ses_count[id], -1); + } +} + /** * Link a session to a DCB. * @@ -381,6 +419,9 @@ bool session_free( session->service->name, session->ses_id))); + /** Disable trace and decrease trace logger counter */ + session_disable_log(session, LT); + free(session); succp = true; diff --git a/server/core/utils.c b/server/core/utils.c index 937341f26..da9378867 100644 --- a/server/core/utils.c +++ b/server/core/utils.c @@ -43,7 +43,10 @@ #include #include -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; /* used in the hex2bin function */ #define char_val(X) (X >= '0' && X <= '9' ? X-'0' :\ diff --git a/server/include/dcb.h b/server/include/dcb.h index 0695a6e57..66d18bcf7 100644 --- a/server/include/dcb.h +++ b/server/include/dcb.h @@ -309,7 +309,9 @@ int dcb_isvalid(DCB *); /* Check the DCB is in the linked list */ bool dcb_set_state(DCB* dcb, dcb_state_t new_state, dcb_state_t* old_state); void dcb_call_foreach (DCB_REASON reason); -size_t dcb_get_session_id(DCB* dcb);; +size_t dcb_get_session_id(DCB* dcb); +bool dcb_get_ses_log_info(DCB* dcb, size_t* sesid, int* enabled_logs); + /** diff --git a/server/include/session.h b/server/include/session.h index a1733c873..ae1210bcb 100644 --- a/server/include/session.h +++ b/server/include/session.h @@ -41,6 +41,7 @@ #include #include #include +#include struct dcb; struct service; @@ -109,19 +110,20 @@ typedef struct session { skygw_chk_t ses_chk_top; #endif SPINLOCK ses_lock; - session_state_t state; /**< Current descriptor state */ - size_t ses_id; /**< unique session identifier */ - struct dcb *client; /**< The client connection */ - void *data; /**< The session data */ - void *router_session;/**< The router instance data */ - SESSION_STATS stats; /**< Session statistics */ - struct service *service; /**< The service this session is using */ - int n_filters; /**< Number of filter sessions */ - SESSION_FILTER *filters; /**< The filters in use within this session */ - DOWNSTREAM head; /**< Head of the filter chain */ - UPSTREAM tail; /**< The tail of the filter chain */ - struct session *next; /**< Linked list of all sessions */ - int refcount; /**< Reference count on the session */ + session_state_t state; /*< Current descriptor state */ + size_t ses_id; /*< Unique session identifier */ + int ses_enabled_logs; /*< Bitfield of enabled logs */ + struct dcb *client; /*< The client connection */ + void *data; /*< The session data */ + void *router_session; /*< The router instance data */ + SESSION_STATS stats; /*< Session statistics */ + struct service *service; /*< The service this session is using */ + int n_filters; /*< Number of filter sessions */ + SESSION_FILTER *filters; /*< The filters in use within this session */ + DOWNSTREAM head; /*< Head of the filter chain */ + UPSTREAM tail; /*< The tail of the filter chain */ + struct session *next; /*< Linked list of all sessions */ + int refcount; /*< Reference count on the session */ #if defined(SS_DEBUG) skygw_chk_t ses_chk_tail; #endif @@ -160,4 +162,7 @@ void dListSessions(struct dcb *); char *session_state(int); bool session_link_dcb(SESSION *, struct dcb *); SESSION* get_session_by_router_ses(void* rses); +void session_enable_log(SESSION* ses, logfile_id_t id); +void session_disable_log(SESSION* ses, logfile_id_t id); + #endif diff --git a/server/modules/filter/hint/hintparser.c b/server/modules/filter/hint/hintparser.c index 0d0e47dcb..91140ed97 100644 --- a/server/modules/filter/hint/hintparser.c +++ b/server/modules/filter/hint/hintparser.c @@ -25,7 +25,10 @@ #include #include -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; /** * hintparser.c - Find any comment in the SQL packet and look for MAXSCALE diff --git a/server/modules/filter/qlafilter.c b/server/modules/filter/qlafilter.c index 2f25ba1fb..301f8d3e5 100644 --- a/server/modules/filter/qlafilter.c +++ b/server/modules/filter/qlafilter.c @@ -51,7 +51,10 @@ #include #include -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; MODULE_INFO info = { MODULE_API_FILTER, diff --git a/server/modules/filter/regexfilter.c b/server/modules/filter/regexfilter.c index 4ca20563e..a280c79b3 100644 --- a/server/modules/filter/regexfilter.c +++ b/server/modules/filter/regexfilter.c @@ -24,7 +24,10 @@ #include #include -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; /** * @file regexfilter.c - a very simple regular expression rewrite filter. diff --git a/server/modules/filter/tee.c b/server/modules/filter/tee.c index 43f7075c5..3d9be06a9 100644 --- a/server/modules/filter/tee.c +++ b/server/modules/filter/tee.c @@ -58,7 +58,10 @@ #include #include -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; MODULE_INFO info = { MODULE_API_FILTER, diff --git a/server/modules/filter/topfilter.c b/server/modules/filter/topfilter.c index eaf471910..0afcb836c 100644 --- a/server/modules/filter/topfilter.c +++ b/server/modules/filter/topfilter.c @@ -48,7 +48,10 @@ #include #include -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; MODULE_INFO info = { MODULE_API_FILTER, diff --git a/server/modules/monitor/galera_mon.c b/server/modules/monitor/galera_mon.c index 274b6a30d..7da08839f 100644 --- a/server/modules/monitor/galera_mon.c +++ b/server/modules/monitor/galera_mon.c @@ -50,7 +50,10 @@ #include #include -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; static void monitorMain(void *); diff --git a/server/modules/monitor/mysql_mon.c b/server/modules/monitor/mysql_mon.c index 957866b30..d6e756159 100644 --- a/server/modules/monitor/mysql_mon.c +++ b/server/modules/monitor/mysql_mon.c @@ -62,7 +62,10 @@ #include #include -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; static void monitorMain(void *); diff --git a/server/modules/monitor/ndbcluster_mon.c b/server/modules/monitor/ndbcluster_mon.c index d273fe32f..b022e02cc 100644 --- a/server/modules/monitor/ndbcluster_mon.c +++ b/server/modules/monitor/ndbcluster_mon.c @@ -42,7 +42,10 @@ #include #include -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; static void monitorMain(void *); diff --git a/server/modules/protocol/httpd.c b/server/modules/protocol/httpd.c index 4b4588b16..92887f154 100644 --- a/server/modules/protocol/httpd.c +++ b/server/modules/protocol/httpd.c @@ -49,7 +49,10 @@ MODULE_INFO info = { "An experimental HTTPD implementation for use in admnistration" }; -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; #define ISspace(x) isspace((int)(x)) #define HTTP_SERVER_STRING "MaxScale(c) v.1.0.0" diff --git a/server/modules/protocol/maxscaled.c b/server/modules/protocol/maxscaled.c index 5623fcad6..89fd19535 100644 --- a/server/modules/protocol/maxscaled.c +++ b/server/modules/protocol/maxscaled.c @@ -45,7 +45,10 @@ MODULE_INFO info = { "A maxscale protocol for the administration interface" }; -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; /** * @file maxscaled.c - MaxScale administration protocol diff --git a/server/modules/protocol/mysql_backend.c b/server/modules/protocol/mysql_backend.c index 96fe9377f..fe6c47ea7 100644 --- a/server/modules/protocol/mysql_backend.c +++ b/server/modules/protocol/mysql_backend.c @@ -56,7 +56,10 @@ MODULE_INFO info = { "The MySQL to backend server protocol" }; -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; static char *version_str = "V2.0.0"; static int gw_create_backend_connection(DCB *backend, SERVER *server, SESSION *in_session); diff --git a/server/modules/protocol/mysql_client.c b/server/modules/protocol/mysql_client.c index 2366ca39f..26822cbdc 100644 --- a/server/modules/protocol/mysql_client.c +++ b/server/modules/protocol/mysql_client.c @@ -54,7 +54,10 @@ MODULE_INFO info = { "The client to MaxScale MySQL protocol implementation" }; -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; static char *version_str = "V1.0.0"; diff --git a/server/modules/protocol/mysql_common.c b/server/modules/protocol/mysql_common.c index 9ca3617b5..27159dc21 100644 --- a/server/modules/protocol/mysql_common.c +++ b/server/modules/protocol/mysql_common.c @@ -45,7 +45,10 @@ #include #include -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; extern int gw_read_backend_event(DCB* dcb); extern int gw_write_backend_event(DCB *dcb); diff --git a/server/modules/protocol/telnetd.c b/server/modules/protocol/telnetd.c index f78a8e0d3..b079a3679 100644 --- a/server/modules/protocol/telnetd.c +++ b/server/modules/protocol/telnetd.c @@ -45,7 +45,10 @@ MODULE_INFO info = { "A telnet deamon protocol for simple administration interface" }; -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; /** * @file telnetd.c - telnet daemon protocol module diff --git a/server/modules/routing/cli.c b/server/modules/routing/cli.c index eb581f4c7..263e5a434 100644 --- a/server/modules/routing/cli.c +++ b/server/modules/routing/cli.c @@ -53,7 +53,10 @@ MODULE_INFO info = { "The admin user interface" }; -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; static char *version_str = "V1.0.0"; diff --git a/server/modules/routing/debugcli.c b/server/modules/routing/debugcli.c index 2e5a79381..2312808ae 100644 --- a/server/modules/routing/debugcli.c +++ b/server/modules/routing/debugcli.c @@ -52,7 +52,10 @@ MODULE_INFO info = { "The debug user interface" }; -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; static char *version_str = "V1.1.1"; diff --git a/server/modules/routing/readconnroute.c b/server/modules/routing/readconnroute.c index f5d15ee5d..b79583999 100644 --- a/server/modules/routing/readconnroute.c +++ b/server/modules/routing/readconnroute.c @@ -89,7 +89,10 @@ #include -extern int lm_enabled_logfiles_bitmask; +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; MODULE_INFO info = { MODULE_API_ROUTER, diff --git a/server/modules/routing/readwritesplit/readwritesplit.c b/server/modules/routing/readwritesplit/readwritesplit.c index 9352fe650..106df0fdf 100644 --- a/server/modules/routing/readwritesplit/readwritesplit.c +++ b/server/modules/routing/readwritesplit/readwritesplit.c @@ -45,9 +45,10 @@ MODULE_INFO info = { # include #endif - -extern int lm_enabled_logfiles_bitmask; - +/** Defined in log_manager.cc */ +extern int lm_enabled_logfiles_bitmask; +extern size_t log_ses_count[]; +extern __thread log_info_t tls_log_info; /** * @file readwritesplit.c The entry points for the read/write query splitting * router module. @@ -1946,7 +1947,7 @@ static int routeQuery( char* contentstr = strndup(data, len); char* qtypestr = skygw_get_qtype_str(qtype); - LOGIF(LT, (skygw_log_write( + skygw_log_write( LOGFILE_TRACE, "> Autocommit: %s, trx is %s, cmd: %s, type: %s, " "stmt: %s%s %s", @@ -1956,7 +1957,7 @@ static int routeQuery( (qtypestr==NULL ? "N/A" : qtypestr), contentstr, (querybuf->hint == NULL ? "" : ", Hint:"), - (querybuf->hint == NULL ? "" : STRHINTTYPE(querybuf->hint->type))))); + (querybuf->hint == NULL ? "" : STRHINTTYPE(querybuf->hint->type))); free(contentstr); free(qtypestr);