diff --git a/log_manager/log_manager.cc b/log_manager/log_manager.cc index 24288e986..9dc2a0f87 100644 --- a/log_manager/log_manager.cc +++ b/log_manager/log_manager.cc @@ -75,7 +75,7 @@ int lm_enabled_logfiles_bitmask = 0; * Path to directory in which all files are stored to shared memory * by the OS. */ -const char* shm_pathname = "/dev/shm"; +const char* shm_pathname_prefix = "/dev/shm/"; /** Logfile ids from call argument '-s' */ char* shmem_id_str = NULL; @@ -2063,11 +2063,34 @@ static bool logfile_init( * pointing to shm file is created and located to the file * directory. */ - if (store_shmem) { - logfile->lf_filepath = strdup(shm_pathname); + if (store_shmem) + { + char* c; + pid_t pid = getpid(); + int len = strlen(shm_pathname_prefix)+ + get_decimal_len((size_t)pid); + + c = (char *)calloc(len, sizeof(char)); + + if (c == NULL) + { + succp = false; + goto file_create_fail; + } + sprintf(c, "%s%d", shm_pathname_prefix, pid); + logfile->lf_filepath = c; + + if (mkdir(c, S_IRWXU | S_IRWXG) != 0 && + errno != EEXIST) + { + succp = false; + goto file_create_fail; + } logfile->lf_linkpath = strdup(fn->fn_logpath); logfile->lf_linkpath = add_slash(logfile->lf_linkpath); - } else { + } + else + { logfile->lf_filepath = strdup(fn->fn_logpath); } logfile->lf_filepath = add_slash(logfile->lf_filepath); @@ -2146,7 +2169,7 @@ static bool logfile_init( } } } - file_create_fail: +file_create_fail: if (namecreatefail || nameconflicts) { logfile->lf_name_seqno += 1; @@ -2161,7 +2184,7 @@ static bool logfile_init( free(logfile->lf_full_link_name); logfile->lf_full_link_name = NULL; } - + goto return_with_succp; } } while (namecreatefail || nameconflicts); /** diff --git a/query_classifier/query_classifier.cc b/query_classifier/query_classifier.cc index 2b9f2c5c2..6eea51cdb 100644 --- a/query_classifier/query_classifier.cc +++ b/query_classifier/query_classifier.cc @@ -639,7 +639,17 @@ static skygw_query_type_t resolve_query_type( type |= QUERY_TYPE_PREPARE_NAMED_STMT; goto return_qtype; break; - + + case SQLCOM_SHOW_DATABASES: + type |= QUERY_TYPE_SHOW_DATABASES; + goto return_qtype; + break; + + case SQLCOM_SHOW_TABLES: + type |= QUERY_TYPE_SHOW_TABLES; + goto return_qtype; + break; + default: break; } @@ -823,8 +833,7 @@ static skygw_query_type_t resolve_query_type( LOGIF(LD, (skygw_log_write( LOGFILE_DEBUG, "%lu [resolve_query_type] " - "Unknown functype %d. Something " - "has gone wrong.", + "Functype %d.", pthread_self(), ftype))); break; @@ -1375,3 +1384,49 @@ static void parsing_info_set_plain_str( pi->pi_query_plain_str = str; } + +/** + * Generate a string of query type value. + * Caller must free the memory of the resulting string. + * + * @param qtype Query type value, combination of values listed in + * query_classifier.h + * + * @return string representing the query type value + */ +char* skygw_get_qtype_str( + skygw_query_type_t qtype) +{ + int t1 = (int)qtype; + int t2 = 1; + skygw_query_type_t t = QUERY_TYPE_UNKNOWN; + char* qtype_str = NULL; + + /** + * Test values (bits) and clear matching bits from t1 one by one until + * t1 is completely cleared. + */ + while (t1 != 0) + { + if (t1&t2) + { + t = (skygw_query_type_t)t2; + + if (qtype_str == NULL) + { + qtype_str = strdup(STRQTYPE(t)); + } + else + { + size_t len = strlen(STRQTYPE(t)); + /** reallocate space for delimiter, new string and termination */ + qtype_str = (char *)realloc(qtype_str, strlen(qtype_str)+1+len+1); + snprintf(qtype_str+strlen(qtype_str), 1+len+1, "|%s", STRQTYPE(t)); + } + /** Remove found value from t1 */ + t1 &= ~t2; + } + t2 <<= 1; + } + return qtype_str; +} diff --git a/query_classifier/query_classifier.h b/query_classifier/query_classifier.h index 95e9694f6..db2011642 100644 --- a/query_classifier/query_classifier.h +++ b/query_classifier/query_classifier.h @@ -54,7 +54,9 @@ typedef enum { QUERY_TYPE_PREPARE_STMT = 0x020000, /*< Prepared stmt with id provided by server:all */ QUERY_TYPE_EXEC_STMT = 0x040000, /*< Execute prepared statement:master or any */ QUERY_TYPE_CREATE_TMP_TABLE = 0x080000, /*< Create temporary table:master (could be all) */ - QUERY_TYPE_READ_TMP_TABLE = 0x100000 /*< Read temporary table:master (could be any) */ + QUERY_TYPE_READ_TMP_TABLE = 0x100000, /*< Read temporary table:master (could be any) */ + QUERY_TYPE_SHOW_DATABASES = 0x200000, /*< Show list of databases */ + QUERY_TYPE_SHOW_TABLES = 0x400000 /*< Show list of tables */ } skygw_query_type_t; @@ -91,6 +93,7 @@ bool parse_query (GWBUF* querybuf); parsing_info_t* parsing_info_init(void (*donefun)(void *)); void parsing_info_done(void* ptr); bool query_is_parsed(GWBUF* buf); +char* skygw_get_qtype_str(skygw_query_type_t qtype); EXTERN_C_BLOCK_END diff --git a/server/modules/protocol/mysql_common.c b/server/modules/protocol/mysql_common.c index 1b2719cb1..89ffd890e 100644 --- a/server/modules/protocol/mysql_common.c +++ b/server/modules/protocol/mysql_common.c @@ -1653,9 +1653,11 @@ void protocol_archive_srv_command( s1 = &p->protocol_command; - LOGIF(LT, (skygw_log_write( - LOGFILE_TRACE, - "Move command %s from fd %d to command history.", + LOGIF(LD, (skygw_log_write( + LOGFILE_DEBUG, + "%lu [protocol_archive_srv_command] Move command %s from fd %d " + "to command history.", + pthread_self(), STRPACKETTYPE(s1->scom_cmd), p->owner_dcb->fd))); @@ -1727,8 +1729,8 @@ void protocol_add_srv_command( p->protocol_command.scom_next = server_command_init(NULL, cmd); } - LOGIF(LT, (skygw_log_write( - LOGFILE_TRACE, + LOGIF(LD, (skygw_log_write( + LOGFILE_DEBUG, "Added command %s to fd %d.", STRPACKETTYPE(cmd), p->owner_dcb->fd))); @@ -1738,8 +1740,8 @@ void protocol_add_srv_command( while (c != NULL && c->scom_cmd != MYSQL_COM_UNDEFINED) { - LOGIF(LT, (skygw_log_write( - LOGFILE_TRACE, + LOGIF(LD, (skygw_log_write( + LOGFILE_DEBUG, "fd %d : %d %s", p->owner_dcb->fd, c->scom_cmd, diff --git a/server/modules/routing/readwritesplit/readwritesplit.c b/server/modules/routing/readwritesplit/readwritesplit.c index 6c9200de7..e08386089 100644 --- a/server/modules/routing/readwritesplit/readwritesplit.c +++ b/server/modules/routing/readwritesplit/readwritesplit.c @@ -1282,9 +1282,10 @@ static route_target_t get_route_target ( if (hint->type == HINT_ROUTE_TO_MASTER) { target = TARGET_MASTER; /*< override */ - LOGIF(LT, (skygw_log_write( - LOGFILE_TRACE, - "Hint: route to master."))); + LOGIF(LD, (skygw_log_write( + LOGFILE_DEBUG, + "%lu [get_route_target] Hint: route to master.", + pthread_self()))); break; } else if (hint->type == HINT_ROUTE_TO_NAMED_SERVER) @@ -1294,9 +1295,11 @@ static route_target_t get_route_target ( * found, the oroginal target is chosen. */ target |= TARGET_NAMED_SERVER; - LOGIF(LT, (skygw_log_write( - LOGFILE_TRACE, - "Hint: route to named server : "))); + LOGIF(LD, (skygw_log_write( + LOGFILE_DEBUG, + "%lu [get_route_target] Hint: route to " + "named server : ", + pthread_self()))); } else if (hint->type == HINT_ROUTE_TO_UPTODATE_SERVER) { @@ -1334,9 +1337,11 @@ static route_target_t get_route_target ( else if (hint->type == HINT_ROUTE_TO_SLAVE) { target = TARGET_SLAVE; - LOGIF(LT, (skygw_log_write( - LOGFILE_TRACE, - "Hint: route to slave."))); + LOGIF(LD, (skygw_log_write( + LOGFILE_DEBUG, + "%lu [get_route_target] Hint: route to " + "slave.", + pthread_self()))); } hint = hint->next; } /*< while (hint != NULL) */ @@ -1653,7 +1658,6 @@ static int routeQuery( GWBUF* querybuf) { skygw_query_type_t qtype = QUERY_TYPE_UNKNOWN; - char* querystr = NULL; mysql_server_cmd_t packet_type; uint8_t* packet; int ret = 0; @@ -1793,8 +1797,33 @@ static int routeQuery( { router_cli_ses->rses_autocommit_enabled = true; router_cli_ses->rses_transaction_active = false; - } + } + if (LOG_IS_ENABLED(LOGFILE_TRACE)) + { + uint8_t* packet = GWBUF_DATA(querybuf); + unsigned char ptype = packet[4]; + size_t len = MIN(GWBUF_LENGTH(querybuf), + MYSQL_GET_PACKET_LEN((unsigned char *)querybuf->start)-1); + char* data = (char*)&packet[5]; + char* contentstr = strndup(data, len); + char* qtypestr = skygw_get_qtype_str(qtype); + + LOGIF(LT, (skygw_log_write( + LOGFILE_TRACE, + "> Autocommit: %s, trx is %s, cmd: %s, type: %s, " + "stmt: %s%s %s", + (router_cli_ses->rses_autocommit_enabled ? "[enabled]" : "[disabled]"), + (router_cli_ses->rses_transaction_active ? "[open]" : "[not open]"), + STRPACKETTYPE(ptype), + (qtypestr==NULL ? "N/A" : qtypestr), + contentstr, + (querybuf->hint == NULL ? "" : ", Hint:"), + (querybuf->hint == NULL ? "" : STRHINTTYPE(querybuf->hint->type))))); + + free(contentstr); + free(qtypestr); + } /** * Find out where to route the query. Result may not be clear; it is * possible to have a hint for routing to a named server which can @@ -1911,6 +1940,27 @@ static int routeQuery( btype, named_server, rlag_max); + if (!succp) + { + if (TARGET_IS_NAMED_SERVER(route_target)) + { + LOGIF(LT, (skygw_log_write( + LOGFILE_TRACE, + "Was supposed to route to named server " + "%s but couldn't find the server in a " + "suitable state.", + named_server))); + } + else if (TARGET_IS_RLAG_MAX(route_target)) + { + LOGIF(LT, (skygw_log_write( + LOGFILE_TRACE, + "Was supposed to route to server with " + "replication lag at most %d but couldn't " + "find such a slave.", + rlag_max))); + } + } } if (!succp && TARGET_IS_SLAVE(route_target)) @@ -1930,9 +1980,16 @@ static int routeQuery( NULL, rlag_max); if (succp) - { + { atomic_add(&inst->stats.n_slave, 1); } + else + { + LOGIF(LT, (skygw_log_write(LOGFILE_TRACE, + "Was supposed to route to slave" + "but finding suitable one " + "failed."))); + } } if (!succp && TARGET_IS_MASTER(route_target)) @@ -1944,6 +2001,16 @@ static int routeQuery( BE_MASTER, NULL, MAX_RLAG_UNDEFINED); + if (!succp) + { + LOGIF(LT, (skygw_log_write(LOGFILE_TRACE, + "Was supposed to " + "route to master " + "but couldn't find " + "master in a " + "suitable state " + "failed."))); + } } else { @@ -1951,9 +2018,7 @@ static int routeQuery( } atomic_add(&inst->stats.n_master, 1); target_dcb = master_dcb; - } - ss_dassert(succp); - + } if (succp) /*< Have DCB of the target backend */ { @@ -1962,6 +2027,14 @@ static int routeQuery( bref = get_bref_from_dcb(router_cli_ses, target_dcb); scur = &bref->bref_sescmd_cur; + + LOGIF(LT, (skygw_log_write( + LOGFILE_TRACE, + "Route query to %s\t%s:%d <", + (SERVER_IS_MASTER(bref->bref_backend->backend_server) ? + "master" : "slave"), + bref->bref_backend->backend_server->name, + bref->bref_backend->backend_server->port))); /** * Store current stmt if execution of previous session command * haven't completed yet. Note that according to MySQL protocol @@ -1993,8 +2066,7 @@ static int routeQuery( { LOGIF(LE, (skygw_log_write_flush( LOGFILE_ERROR, - "Error : Routing query \"%s\" failed.", - querystr))); + "Error : Routing query failed."))); } } rses_end_locked_router_action(router_cli_ses); @@ -3441,12 +3513,6 @@ static bool execute_sescmd_in_backend( sescmd_cursor_clone_querybuf(scur)); break; } - LOGIF(LT, (skygw_log_write_flush( - LOGFILE_TRACE, - "%lu [execute_sescmd_in_backend] Routed %s cmd %p.", - pthread_self(), - STRPACKETTYPE(scur->scmd_cur_cmd->my_sescmd_packet_type), - scur->scmd_cur_cmd))); if (rc == 1) { @@ -3573,8 +3639,8 @@ static void tracelog_routed_query( querystr = (char *)malloc(len); memcpy(querystr, startpos, len-1); querystr[len-1] = '\0'; - LOGIF(LT, (skygw_log_write_flush( - LOGFILE_TRACE, + LOGIF(LD, (skygw_log_write_flush( + LOGFILE_DEBUG, "%lu [%s] %d bytes long buf, \"%s\" -> %s:%d %s dcb %p", pthread_self(), funcname, @@ -3595,8 +3661,8 @@ static void tracelog_routed_query( querystr = (char *)malloc(len); memcpy(querystr, startpos, len-1); querystr[len-1] = '\0'; - LOGIF(LT, (skygw_log_write_flush( - LOGFILE_TRACE, + LOGIF(LD, (skygw_log_write_flush( + LOGFILE_DEBUG, "%lu [%s] %d bytes long buf, \"%s\" -> %s:%d %s dcb %p", pthread_self(), funcname, @@ -3663,10 +3729,7 @@ static bool route_session_write( LOGIF(LT, (skygw_log_write( LOGFILE_TRACE, - "Session write, query type\t%s, packet type %s, " - "routing to all servers.", - STRQTYPE(qtype), - STRPACKETTYPE(packet_type)))); + "Session write, routing to all servers."))); backend_ref = router_cli_ses->rses_backend_ref; @@ -3693,7 +3756,19 @@ static bool route_session_write( for (i=0; irses_nbackends; i++) { - DCB* dcb = backend_ref[i].bref_dcb; + DCB* dcb = backend_ref[i].bref_dcb; + + if (LOG_IS_ENABLED(LOGFILE_TRACE)) + { + LOGIF(LT, (skygw_log_write( + LOGFILE_TRACE, + "Route query to %s\t%s:%d%s", + (SERVER_IS_MASTER(backend_ref[i].bref_backend->backend_server) ? + "master" : "slave"), + backend_ref[i].bref_backend->backend_server->name, + backend_ref[i].bref_backend->backend_server->port, + (i+1==router_cli_ses->rses_nbackends ? " <" : "")))); + } if (BREF_IS_IN_USE((&backend_ref[i]))) { @@ -3703,14 +3778,7 @@ static bool route_session_write( { succp = false; } - else if (LOG_IS_ENABLED(LOGFILE_TRACE)) - { - LOGIF(LT, (skygw_log_write( - LOGFILE_TRACE, - "Wrote to %s:%d", - backend_ref[i].bref_backend->backend_server->name, - backend_ref[i].bref_backend->backend_server->port))); - } + } } rses_end_locked_router_action(router_cli_ses); @@ -3740,6 +3808,18 @@ static bool route_session_write( { sescmd_cursor_t* scur; + if (LOG_IS_ENABLED(LOGFILE_TRACE)) + { + LOGIF(LT, (skygw_log_write( + LOGFILE_TRACE, + "Route query to %s\t%s:%d%s", + (SERVER_IS_MASTER(backend_ref[i].bref_backend->backend_server) ? + "master" : "slave"), + backend_ref[i].bref_backend->backend_server->name, + backend_ref[i].bref_backend->backend_server->port, + (i+1==router_cli_ses->rses_nbackends ? " <" : "")))); + } + scur = backend_ref_get_sescmd_cursor(&backend_ref[i]); /** @@ -3747,7 +3827,7 @@ static bool route_session_write( */ bref_set_state(get_bref_from_dcb(router_cli_ses, backend_ref[i].bref_dcb), - BREF_WAITING_RESULT); + BREF_WAITING_RESULT); /** * Start execution if cursor is not already executing. * Otherwise, cursor will execute pending commands diff --git a/utils/skygw_debug.h b/utils/skygw_debug.h index 56b399710..7c070cd6f 100644 --- a/utils/skygw_debug.h +++ b/utils/skygw_debug.h @@ -129,13 +129,29 @@ typedef enum skygw_chk_t { # define STRBOOL(b) ((b) ? "true" : "false") -# define STRQTYPE(t) ((t) == QUERY_TYPE_WRITE ? "QUERY_TYPE_WRITE" : \ - ((t) == QUERY_TYPE_READ ? "QUERY_TYPE_READ" : \ - ((t) == QUERY_TYPE_SESSION_WRITE ? "QUERY_TYPE_SESSION_WRITE" : \ - ((t) == QUERY_TYPE_UNKNOWN ? "QUERY_TYPE_UNKNOWN" : \ - ((t) == QUERY_TYPE_LOCAL_READ ? "QUERY_TYPE_LOCAL_READ" : \ - ((t) == QUERY_TYPE_EXEC_STMT ? "QUERY_TYPE_EXEC_STMT" : \ - "Unknown query type")))))) +# define STRQTYPE(t) ((t) == QUERY_TYPE_WRITE ? "QUERY_TYPE_WRITE" : \ + ((t) == QUERY_TYPE_READ ? "QUERY_TYPE_READ" : \ + ((t) == QUERY_TYPE_SESSION_WRITE ? "QUERY_TYPE_SESSION_WRITE" : \ + ((t) == QUERY_TYPE_UNKNOWN ? "QUERY_TYPE_UNKNOWN" : \ + ((t) == QUERY_TYPE_LOCAL_READ ? "QUERY_TYPE_LOCAL_READ" : \ + ((t) == QUERY_TYPE_MASTER_READ ? "QUERY_TYPE_MASTER_READ" : \ + ((t) == QUERY_TYPE_USERVAR_READ ? "QUERY_TYPE_USERVAR_READ" : \ + ((t) == QUERY_TYPE_SYSVAR_READ ? "QUERY_TYPE_SYSVAR_READ" : \ + ((t) == QUERY_TYPE_GSYSVAR_READ ? "QUERY_TYPE_GSYSVAR_READ" : \ + ((t) == QUERY_TYPE_GSYSVAR_WRITE ? "QUERY_TYPE_GSYSVAR_WRITE" : \ + ((t) == QUERY_TYPE_BEGIN_TRX ? "QUERY_TYPE_BEGIN_TRX" : \ + ((t) == QUERY_TYPE_ENABLE_AUTOCOMMIT ? "QUERY_TYPE_ENABLE_AUTOCOMMIT" : \ + ((t) == QUERY_TYPE_DISABLE_AUTOCOMMIT ? "QUERY_TYPE_DISABLE_AUTOCOMMIT" : \ + ((t) == QUERY_TYPE_ROLLBACK ? "QUERY_TYPE_ROLLBACK" : \ + ((t) == QUERY_TYPE_COMMIT ? "QUERY_TYPE_COMMIT" : \ + ((t) == QUERY_TYPE_PREPARE_NAMED_STMT ? "QUERY_TYPE_PREPARE_NAMED_STMT" : \ + ((t) == QUERY_TYPE_PREPARE_STMT ? "QUERY_TYPE_PREPARE_STMT" : \ + ((t) == QUERY_TYPE_EXEC_STMT ? "QUERY_TYPE_EXEC_STMT" : \ + ((t) == QUERY_TYPE_CREATE_TMP_TABLE ? "QUERY_TYPE_CREATE_TMP_TABLE" : \ + ((t) == QUERY_TYPE_READ_TMP_TABLE ? "QUERY_TYPE_READ_TMP_TABLE" : \ + ((t) == QUERY_TYPE_SHOW_DATABASES ? "QUERY_TYPE_SHOW_DATABASES" : \ + ((t) == QUERY_TYPE_SHOW_TABLES ? "QUERY_TYPE_SHOW_TABLES" : \ + "Unknown query type")))))))))))))))))))))) #define STRLOGID(i) ((i) == LOGFILE_TRACE ? "LOGFILE_TRACE" : \ ((i) == LOGFILE_MESSAGE ? "LOGFILE_MESSAGE" : \ @@ -247,6 +263,14 @@ typedef enum skygw_chk_t { (SERVER_IS_RELAY_SERVER(s) ? "RUNNING RELAY" : \ (SERVER_IS_RUNNING(s) ? "RUNNING (only)" : "NO STATUS"))))))) +#define STRHINTTYPE(t) (t == HINT_ROUTE_TO_MASTER ? "HINT_ROUTE_TO_MASTER" : \ + ((t) == HINT_ROUTE_TO_SLAVE ? "HINT_ROUTE_TO_SLAVE" : \ + ((t) == HINT_ROUTE_TO_NAMED_SERVER ? "HINT_ROUTE_TO_NAMED_SERVER" : \ + ((t) == HINT_ROUTE_TO_UPTODATE_SERVER ? "HINT_ROUTE_TO_UPTODATE_SERVER" : \ + ((t) == HINT_ROUTE_TO_ALL ? "HINT_ROUTE_TO_ALL" : \ + ((t) == HINT_PARAMETER ? "HINT_PARAMETER" : "UNKNOWN HINT TYPE")))))) + + #define CHK_MLIST(l) { \ ss_info_dassert((l->mlist_chk_top == CHK_NUM_MLIST && \ l->mlist_chk_tail == CHK_NUM_MLIST), \ diff --git a/utils/skygw_utils.cc b/utils/skygw_utils.cc index 0975b6a10..30b7ae8a9 100644 --- a/utils/skygw_utils.cc +++ b/utils/skygw_utils.cc @@ -1955,7 +1955,19 @@ retblock: return newstr; } - +/** + * Calculate the number of decimal numbers from a size_t value. + * + * @param value value + * + * @return number of decimal numbers of which the value consists of + * value==123 returns 3, for example. + */ +size_t get_decimal_len( + size_t value) +{ + return value > 0 ? (size_t) log10 ((double) value) + 1 : 1; +} diff --git a/utils/skygw_utils.h b/utils/skygw_utils.h index a54859392..80793fbca 100644 --- a/utils/skygw_utils.h +++ b/utils/skygw_utils.h @@ -192,6 +192,7 @@ int skygw_rwlock_unlock(skygw_rwlock_t* rwlock); int skygw_rwlock_init(skygw_rwlock_t** rwlock); int atomic_add(int *variable, int value); +size_t get_decimal_len(size_t s); EXTERN_C_BLOCK_BEGIN