Offsets MariaDB 5.5.52 and 10.1.8. Speed improvements in logging.

pull/179/head
Arnold Robbins 2016-10-09 15:41:30 +03:00
parent 97b6031586
commit 6e8e1b16df
3 changed files with 154 additions and 81 deletions

View File

@ -100,10 +100,7 @@ public:
virtual ~IWriter() {}
// return negative on fail
virtual ssize_t write(const char *data, size_t size) = 0;
inline ssize_t write_str(const char *str)
{
return write(str, strlen(str));
}
virtual ssize_t write_no_lock(const char *str, size_t size) = 0;
// return 0 on success
virtual int open(const char *io_dest, bool log_errors) = 0;
virtual void close() = 0;
@ -545,11 +542,11 @@ protected:
// creating additional instances
Audit_handler & operator=(const Audit_handler&);
Audit_handler(const Audit_handler&);
// lock io
pthread_mutex_t LOCK_io;
private:
// bool indicating if to print offset errors to log or not
bool m_print_offset_err;
// lock io
pthread_mutex_t LOCK_io;
bool m_print_offset_err;
// audit (enable) lock
rw_lock_t LOCK_audit;
inline void lock_shared()
@ -585,8 +582,20 @@ public:
* target we write to (socket/file). Public so we update via sysvar
*/
char *m_io_dest;
inline ssize_t write(const char *data, size_t size)
{
pthread_mutex_lock(&LOCK_io);
ssize_t res = write_no_lock(data, size);
pthread_mutex_unlock(&LOCK_io); //release the IO lock
return res;
}
protected:
/**
* Will format using the writer
*/
virtual bool handler_log_audit(ThdSesData *pThdData);
virtual bool handler_start_internal();
virtual void handler_stop_internal();
// used for logging messages
@ -623,7 +632,7 @@ public:
/**
* Write function we pass to formatter
*/
ssize_t write(const char *data, size_t size);
ssize_t write_no_lock(const char *data, size_t size);
void close();
@ -634,11 +643,7 @@ protected:
// additional instances
Audit_file_handler & operator=(const Audit_file_handler&);
Audit_file_handler(const Audit_file_handler&);
/**
* Will acquire locks and call handler_write
*/
virtual bool handler_log_audit(ThdSesData *pThdData);
FILE *m_log_file;
// the period to use for syncing
unsigned int m_sync_counter;
@ -666,7 +671,7 @@ public:
/**
* Write function we pass to formatter
*/
ssize_t write(const char *data, size_t size);
ssize_t write_no_lock(const char *data, size_t size);
void close();
@ -675,11 +680,7 @@ protected:
// override default assignment and copy to protect against creating additional instances
Audit_socket_handler & operator=(const Audit_socket_handler&);
Audit_socket_handler(const Audit_socket_handler&);
/**
* Will acquire locks and call handler_write
*/
virtual bool handler_log_audit(ThdSesData *pThdData);
// Vio we write to
// define as void* so we don't access members directly
void *m_vio;

View File

@ -45,12 +45,59 @@
// initialize static stuff
ThdOffsets Audit_formatter::thd_offsets = { 0 };
Audit_handler *Audit_handler::m_audit_handler_list[Audit_handler::MAX_AUDIT_HANDLERS_NUM];
const char *Audit_json_formatter::DEF_MSG_DELIMITER = "\\n"; // FIXME: This is used ...
#if MYSQL_VERSION_ID < 50709
#define C_STRING_WITH_LEN(X) ((char *) (X)), ((size_t) (sizeof(X) - 1))
#endif
//////////////////////////////////////////////
// Yajl alloc funcs based upon thd_alloc
static void * yajl_thd_malloc(void *ctx, size_t sz)
{
THD *thd = (THD*)ctx;
//we allocate plus sizeof(size_t) and stored the alloced size at the start of the pointer (for support of realloc)
size_t * ptr = (size_t *)thd_alloc(thd, sz + sizeof(size_t));
if(ptr)
{
*ptr = sz; //set the size at the start of the memory
ptr++;
}
return ptr;
}
static void * yajl_thd_realloc(void *ctx, void * previous,
size_t sz)
{
THD *thd = (THD*)ctx;
void *ptr;
if ((ptr= yajl_thd_malloc(thd,sz)))
{
if(previous)
{
//copy only the previous allocated size (which is stored just before the pointer passed in)
size_t prev_sz = *(((size_t *)previous) - 1);
memcpy(ptr,previous, prev_sz);
}
}
return ptr;
}
static void yajl_thd_free(void *ctx, void * ptr)
{
//do nothing as thd_alloc deosn't require free
return;
}
static void yajl_set_thd_alloc_funcs(THD * thd, yajl_alloc_funcs * yaf)
{
yaf->malloc = yajl_thd_malloc;
yaf->free = yajl_thd_free;
yaf->realloc = yajl_thd_realloc;
yaf->ctx = thd;
}
//////////////////////////////////////////////
const char *Audit_formatter::retrieve_object_type(TABLE_LIST *pObj)
{
if (table_is_view(pObj))
@ -148,8 +195,7 @@ void Audit_handler::log_audit(ThdSesData *pThdData)
else
{
// offsets are good
m_print_offset_err = true; // mark to print offset err to log in case we encounter in the future
pthread_mutex_lock(&LOCK_io);
m_print_offset_err = true; // mark to print offset err to log in case we encounter in the future
// check if failed
bool do_log = true;
if (m_failed)
@ -159,18 +205,35 @@ void Audit_handler::log_audit(ThdSesData *pThdData)
difftime(time(NULL), m_last_retry_sec_ts) > m_retry_interval;
if (retry)
{
do_log = handler_start_nolock();
pthread_mutex_lock(&LOCK_io);
//get the io lock. After acquiring the lock do another check that we really need to start (maybe another thread did this already)
if(!m_failed)
{
do_log = true;
}
else if(m_retry_interval > 0 &&
difftime(time(NULL), m_last_retry_sec_ts) > m_retry_interval)
{
do_log = handler_start_nolock();
}
pthread_mutex_unlock(&LOCK_io);
}
}
if (do_log)
{
if (! handler_log_audit(pThdData))
{
set_failed();
handler_stop_internal();
//failure - acquire io lock to set failed and do stop
pthread_mutex_lock(&LOCK_io);
if(!m_failed) //make sure someone else didn't set this already
{
set_failed();
handler_stop_internal();
}
pthread_mutex_unlock(&LOCK_io);
}
}
pthread_mutex_unlock(&LOCK_io);
}
}
unlock();
}
@ -184,13 +247,30 @@ void Audit_file_handler::close()
m_log_file = NULL;
}
ssize_t Audit_file_handler::write(const char *data, size_t size)
{
ssize_t res = my_fwrite(m_log_file, (uchar *) data, size, MYF(0));
if (res < 0) // log the error
ssize_t Audit_file_handler::write_no_lock(const char *data, size_t size)
{
ssize_t res = -1;
if(m_log_file)
{
sql_print_error("%s failed writing to file: %s. Err: %s",
AUDIT_LOG_PREFIX, m_io_dest, strerror(errno));
res = my_fwrite(m_log_file, (uchar *) data, size, MYF(0));
if (res && m_sync_period && ++m_sync_counter >= m_sync_period)
{
m_sync_counter = 0;
// Note fflush() only flushes the user space buffers provided by the C library.
// To ensure that the data is physically stored on disk the kernel buffers must be flushed too,
// e.g. with sync(2) or fsync(2).
res = (fflush(m_log_file) == 0);
if (res)
{
int fd = fileno(m_log_file);
res = (my_sync(fd, MYF(MY_WME)) == 0);
}
}
if (res < 0) // log the error
{
sql_print_error("%s failed writing to file: %s. Err: %s",
AUDIT_LOG_PREFIX, m_io_dest, strerror(errno));
}
}
return res;
}
@ -280,6 +360,10 @@ bool Audit_io_handler::handler_start_internal()
return true;
}
bool Audit_io_handler::handler_log_audit(ThdSesData *pThdData) {
return (m_formatter->event_format(pThdData, this) >= 0);
}
void Audit_io_handler::handler_stop_internal()
{
if (! m_failed)
@ -299,6 +383,7 @@ bool Audit_handler::handler_start_nolock()
else
{
set_failed();
handler_stop_internal();
}
return res;
}
@ -318,25 +403,6 @@ void Audit_handler::handler_stop()
pthread_mutex_unlock(&LOCK_io);
}
bool Audit_file_handler::handler_log_audit(ThdSesData *pThdData)
{
bool res = (m_formatter->event_format(pThdData, this) >= 0);
if (res && m_sync_period && ++m_sync_counter >= m_sync_period)
{
m_sync_counter = 0;
// Note fflush() only flushes the user space buffers provided by the C library.
// To ensure that the data is physically stored on disk the kernel buffers must be flushed too,
// e.g. with sync(2) or fsync(2).
res = (fflush(m_log_file) == 0);
if (res)
{
int fd = fileno(m_log_file);
res = (my_sync(fd, MYF(MY_WME)) == 0);
}
}
return res;
}
/////////////////// Audit_socket_handler //////////////////////////////////
void Audit_socket_handler::close()
@ -349,13 +415,17 @@ void Audit_socket_handler::close()
m_vio = NULL;
}
ssize_t Audit_socket_handler::write(const char *data, size_t size)
{
ssize_t res = vio_write((Vio*)m_vio, (const uchar *) data, size);
if (res < 0) // log the error
ssize_t Audit_socket_handler::write_no_lock(const char *data, size_t size)
{
ssize_t res = -1;
if (m_vio)
{
sql_print_error("%s failed writing to socket: %s. Err: %s",
AUDIT_LOG_PREFIX, m_io_dest, strerror(vio_errno((Vio*)m_vio)));
res = vio_write((Vio*)m_vio, (const uchar *) data, size);
if (res < 0) // log the error
{
sql_print_error("%s failed writing to socket: %s. Err: %s",
AUDIT_LOG_PREFIX, m_io_dest, strerror(vio_errno((Vio*)m_vio)));
}
}
return res;
}
@ -401,11 +471,6 @@ int Audit_socket_handler::open(const char *io_dest, bool log_errors)
return 0;
}
bool Audit_socket_handler::handler_log_audit(ThdSesData *pThdData)
{
return (m_formatter->event_format(pThdData, this) >= 0);
}
//////////////////////// Audit Socket handler end ///////////////////////////////////////////
@ -558,17 +623,13 @@ ssize_t Audit_json_formatter::start_msg_format(IWriter *writer)
yajl_gen_status stat = yajl_gen_map_close(gen); // close the object
if (stat == yajl_gen_status_ok) // all is good write the buffer out
{
//will add the delimiter to the buffer
yajl_gen_reset(gen, "\n");
const unsigned char *text = NULL;
size_t len = 0;
yajl_gen_get_buf(gen, &text, &len);
// print the json
res = writer->write((const char *)text, len);
if (res >= 0)
{
// TODO: use the msg_delimiter
res = writer->write("\n", 1);
}
// my_fwrite(log_file, (uchar *) b.data, json_size(&b), MYF(0));
// no need for lock as it was acquired before as part of the connect
res = writer->write_no_lock((const char *)text, len);
}
yajl_gen_free(gen); // free the generator
return res;
@ -615,7 +676,9 @@ ssize_t Audit_json_formatter::event_format(ThdSesData *pThdData, IWriter *writer
query_id_t qid = thd_inst_query_id(thd);
// initialize yajl
yajl_gen gen = yajl_gen_alloc(NULL);
yajl_alloc_funcs alloc_funcs;
yajl_set_thd_alloc_funcs(thd, &alloc_funcs);
yajl_gen gen = yajl_gen_alloc(&alloc_funcs);
yajl_gen_map_open(gen);
yajl_add_string_val(gen, "msg-type", "activity");
// TODO: get the start date from THD (but it is not in millis. Need to think about how we handle this)
@ -743,17 +806,13 @@ ssize_t Audit_json_formatter::event_format(ThdSesData *pThdData, IWriter *writer
yajl_gen_status stat = yajl_gen_map_close(gen); // close the object
if (stat == yajl_gen_status_ok) // all is good write the buffer out
{
//will add the delimiter to the buffer
yajl_gen_reset(gen, "\n");
const unsigned char *text = NULL;
size_t len = 0;
yajl_gen_get_buf(gen, &text, &len);
// print the json
res = writer->write((const char *)text, len);
if (res >= 0)
{
// TODO: use the msg_delimiter
res = writer->write("\n", 1);
}
// my_fwrite(log_file, (uchar *) b.data, json_size(&b), MYF(0));
res = writer->write((const char *)text, len);
}
yajl_gen_free(gen); // free the generator
return res;
@ -798,8 +857,13 @@ bool ThdSesData::startGetObjects()
return false;
}
// only return query tables if command is COM_QUERY
// TODO: check if other commands can also generate query tables such as "show fields"
if (pLex && command == COM_QUERY && pLex->query_tables)
// TODO: check if other commands can also generate query tables
// such as "show fields"
if ( pLex
&& ( command == COM_QUERY
|| command == COM_STMT_PREPARE
|| command == COM_STMT_EXECUTE)
&& pLex->query_tables)
{
m_tables = pLex->query_tables;
m_objIterType = OBJ_TABLE_LIST;

View File

@ -855,6 +855,10 @@ const ThdOffsets thd_offsets_arr[] =
const ThdOffsets thd_offsets_arr[] =
{
/* +++ MARIADB 64 OFFSETS GO HERE +++ */
//offsets for: /mariadb/10.1.18/bin/mysqld (10.1.18-MariaDB)
{"10.1.18-MariaDB","fa401704df1eabec593f85cdc022d0e4", 13640, 13704, 6416, 8024, 88, 2976, 8, 0, 16, 24, 152, 13796},
//offsets for: /mariadb/5.5.52/bin/mysqld (5.5.52-MariaDB)
{"5.5.52-MariaDB","fa1093ae4a7000c1209f848d155a2eba", 12032, 12096, 5800, 6904, 88, 2920, 8, 0, 16, 24, 152, 12168},
//offsets for: /mariadb/10.1.17/bin/mysqld (10.1.17-MariaDB)
{"10.1.17-MariaDB","f1efa1e5abc9d95de5f06b2ac8e9f94e", 13640, 13704, 6416, 8024, 88, 2976, 8, 0, 16, 24, 152, 13796},
//offsets for: /mariadb/10.0.27/bin/mysqld (10.0.27-MariaDB)
@ -968,6 +972,10 @@ const ThdOffsets thd_offsets_arr[] =
const ThdOffsets thd_offsets_arr[] =
{
/* +++ MARIADB 32 OFFSETS GO HERE +++ */
//offsets for: /mariadb/10.1.18/bin/mysqld (10.1.18-MariaDB)
{"10.1.18-MariaDB","c1f42e4cc9dc7d04dff76566970d584c", 8496, 8532, 3840, 5300, 44, 1892, 4, 0, 8, 12, 84, 8608},
//offsets for: /mariadb/5.5.52/bin/mysqld (5.5.52-MariaDB)
{"5.5.52-MariaDB","0ad2ab91c1723438bff04f5fa41dcb1f", 7276, 7312, 3460, 4468, 44, 1856, 4, 0, 8, 12, 84, 7372},
//offsets for: /mariadb/10.1.17/bin/mysqld (10.1.17-MariaDB)
{"10.1.17-MariaDB","e1a72bffe9bcfd78cbcfc717746c9378", 8496, 8532, 3840, 5300, 44, 1892, 4, 0, 8, 12, 84, 8608},
//offsets for: /mariadb/10.0.27/bin/mysqld (10.0.27-MariaDB)