24
24
Abort logging when we get an error in reading or writing log files
27
#include <drizzled/server_includes.h>
28
#include <drizzled/replication/replication.h>
29
#include <drizzled/replication/filter.h>
30
#include <drizzled/replication/rli.h>
27
#include "mysql_priv.h"
29
#include "rpl_filter.h"
32
32
#include <mysys/my_dir.h>
33
33
#include <stdarg.h>
35
35
#include <drizzled/plugin.h>
36
#include <drizzled/error.h>
37
#include <drizzled/gettext.h>
38
#include <drizzled/data_home.h>
39
#include <drizzled/log_event.h>
41
#include <drizzled/errmsg.h>
36
#include <drizzled/drizzled_error_messages.h>
43
38
/* max size of the log message */
39
#define MAX_LOG_BUFFER_SIZE 1024
40
#define MAX_USER_HOST_SIZE 512
41
#define MAX_TIME_SIZE 32
44
42
#define MY_OFF_T_UNDEF (~(my_off_t)0UL)
44
#define FLAGSTR(V,F) ((V)&(F)?#F" ":"")
48
DRIZZLE_BIN_LOG drizzle_bin_log;
48
MYSQL_BIN_LOG mysql_bin_log;
49
49
ulong sync_binlog_counter= 0;
51
51
static bool test_if_number(const char *str,
52
long *res, bool allow_wildcards);
52
long *res, bool allow_wildcards);
53
53
static int binlog_init(void *p);
54
static int binlog_close_connection(handlerton *hton, Session *session);
55
static int binlog_savepoint_set(handlerton *hton, Session *session, void *sv);
56
static int binlog_savepoint_rollback(handlerton *hton, Session *session, void *sv);
57
static int binlog_commit(handlerton *hton, Session *session, bool all);
58
static int binlog_rollback(handlerton *hton, Session *session, bool all);
59
static int binlog_prepare(handlerton *hton, Session *session, bool all);
54
static int binlog_close_connection(handlerton *hton, THD *thd);
55
static int binlog_savepoint_set(handlerton *hton, THD *thd, void *sv);
56
static int binlog_savepoint_rollback(handlerton *hton, THD *thd, void *sv);
57
static int binlog_commit(handlerton *hton, THD *thd, bool all);
58
static int binlog_rollback(handlerton *hton, THD *thd, bool all);
59
static int binlog_prepare(handlerton *hton, THD *thd, bool all);
62
62
sql_print_message_func sql_print_message_handlers[3] =
202
202
handlerton *binlog_hton;
205
/* Check if a given table is opened log table */
206
int check_if_log_table(uint db_len __attribute__((unused)),
207
const char *db __attribute__((unused)),
208
uint table_name_len __attribute__((unused)),
209
const char *table_name __attribute__((unused)),
210
uint check_if_opened __attribute__((unused)))
215
/* log event handlers */
217
bool Log_to_file_event_handler::
218
log_error(enum loglevel level, const char *format,
221
return vprint_msg_to_log(level, format, args);
224
void Log_to_file_event_handler::init_pthread_objects()
226
mysql_log.init_pthread_objects();
227
mysql_slow_log.init_pthread_objects();
231
/** Wrapper around MYSQL_LOG::write() for slow log. */
233
bool Log_to_file_event_handler::
234
log_slow(THD *thd, time_t current_time, time_t query_start_arg,
235
const char *user_host, uint user_host_len,
236
uint64_t query_utime, uint64_t lock_utime, bool is_command,
237
const char *sql_text, uint sql_text_len)
239
return mysql_slow_log.write(thd, current_time, query_start_arg,
240
user_host, user_host_len,
241
query_utime, lock_utime, is_command,
242
sql_text, sql_text_len);
247
Wrapper around MYSQL_LOG::write() for general log. We need it since we
248
want all log event handlers to have the same signature.
251
bool Log_to_file_event_handler::
252
log_general(THD *thd __attribute__((unused)),
253
time_t event_time, const char *user_host,
254
uint user_host_len, int thread_id,
255
const char *command_type, uint command_type_len,
256
const char *sql_text, uint sql_text_len,
257
CHARSET_INFO *client_cs __attribute__((unused)))
259
return mysql_log.write(event_time, user_host, user_host_len,
260
thread_id, command_type, command_type_len,
261
sql_text, sql_text_len);
265
bool Log_to_file_event_handler::init()
270
mysql_slow_log.open_slow_log(sys_var_slow_log_path.value);
273
mysql_log.open_query_log(sys_var_general_log_path.value);
275
is_initialized= true;
282
void Log_to_file_event_handler::cleanup()
285
mysql_slow_log.cleanup();
288
void Log_to_file_event_handler::flush()
290
/* reopen log files */
292
mysql_log.reopen_file();
294
mysql_slow_log.reopen_file();
206
298
Log error with all enabled log event handlers
272
377
logger.lock_exclusive();
379
/* reopen log files */
380
file_log_handler->flush();
274
382
/* end of log flush */
279
void LOGGER::init_error_log(uint32_t error_log_printer)
389
Log slow query with all enabled log event handlers
394
thd THD of the query being logged
395
query The query being logged
396
query_length The length of the query string
397
current_utime Current time in microseconds (from undefined start)
404
bool LOGGER::slow_log_print(THD *thd, const char *query, uint query_length,
405
uint64_t current_utime)
409
Log_event_handler **current_handler;
410
bool is_command= false;
411
char user_host_buff[MAX_USER_HOST_SIZE];
412
Security_context *sctx= thd->security_ctx;
413
uint user_host_len= 0;
414
uint64_t query_utime, lock_utime;
417
Print the message to the buffer if we have slow log enabled
420
if (*slow_log_handler_list)
424
/* do not log slow queries from replication threads */
425
if (thd->slave_thread && !opt_log_slow_slave_statements)
435
/* fill in user_host value: the format is "%s[%s] @ %s [%s]" */
436
user_host_len= (strxnmov(user_host_buff, MAX_USER_HOST_SIZE,
437
sctx->priv_user ? sctx->priv_user : "", "[",
438
sctx->user ? sctx->user : "", "] @ ",
439
sctx->host ? sctx->host : "", " [",
440
sctx->ip ? sctx->ip : "", "]", NullS) -
443
current_time= my_time_possible_from_micro(current_utime);
444
if (thd->start_utime)
446
query_utime= (current_utime - thd->start_utime);
447
lock_utime= (thd->utime_after_lock - thd->start_utime);
451
query_utime= lock_utime= 0;
457
query= command_name[thd->command].str;
458
query_length= command_name[thd->command].length;
461
for (current_handler= slow_log_handler_list; *current_handler ;)
462
error= (*current_handler++)->log_slow(thd, current_time, thd->start_time,
463
user_host_buff, user_host_len,
464
query_utime, lock_utime, is_command,
465
query, query_length) || error;
472
bool LOGGER::general_log_write(THD *thd, enum enum_server_command command,
473
const char *query, uint query_length)
476
Log_event_handler **current_handler= general_log_handler_list;
477
char user_host_buff[MAX_USER_HOST_SIZE];
478
Security_context *sctx= thd->security_ctx;
480
uint user_host_len= 0;
484
id= thd->thread_id; /* Normal thread */
486
id= 0; /* Log from connect handler */
494
user_host_len= strxnmov(user_host_buff, MAX_USER_HOST_SIZE,
495
sctx->priv_user ? sctx->priv_user : "", "[",
496
sctx->user ? sctx->user : "", "] @ ",
497
sctx->host ? sctx->host : "", " [",
498
sctx->ip ? sctx->ip : "", "]", NullS) -
501
current_time= my_time(0);
503
while (*current_handler)
504
error|= (*current_handler++)->
505
log_general(thd, current_time, user_host_buff,
507
command_name[(uint) command].str,
508
command_name[(uint) command].length,
510
thd->variables.character_set_client) || error;
516
bool LOGGER::general_log_print(THD *thd, enum enum_server_command command,
517
const char *format, va_list args)
519
uint message_buff_len= 0;
520
char message_buff[MAX_LOG_BUFFER_SIZE];
522
/* prepare message */
524
message_buff_len= vsnprintf(message_buff, sizeof(message_buff),
527
message_buff[0]= '\0';
529
return general_log_write(thd, command, message_buff, message_buff_len);
532
void LOGGER::init_error_log(uint error_log_printer)
281
534
if (error_log_printer & LOG_NONE)
289
int LOGGER::set_handlers(uint32_t error_log_printer)
540
switch (error_log_printer) {
542
error_log_handler_list[0]= file_log_handler;
543
error_log_handler_list[1]= 0;
548
void LOGGER::init_slow_log(uint slow_log_printer)
550
if (slow_log_printer & LOG_NONE)
552
slow_log_handler_list[0]= 0;
556
slow_log_handler_list[0]= file_log_handler;
557
slow_log_handler_list[1]= 0;
560
void LOGGER::init_general_log(uint general_log_printer)
562
if (general_log_printer & LOG_NONE)
564
general_log_handler_list[0]= 0;
568
general_log_handler_list[0]= file_log_handler;
569
general_log_handler_list[1]= 0;
573
bool LOGGER::activate_log_handler(THD* thd __attribute__((unused)),
576
MYSQL_QUERY_LOG *file_log;
583
file_log= file_log_handler->get_mysql_slow_log();
585
file_log->open_slow_log(sys_var_slow_log_path.value);
586
init_slow_log(log_output_options);
590
case QUERY_LOG_GENERAL:
593
file_log= file_log_handler->get_mysql_log();
595
file_log->open_query_log(sys_var_general_log_path.value);
596
init_general_log(log_output_options);
608
void LOGGER::deactivate_log_handler(THD *thd __attribute__((unused)),
616
tmp_opt= &opt_slow_log;
617
file_log= file_log_handler->get_mysql_slow_log();
619
case QUERY_LOG_GENERAL:
621
file_log= file_log_handler->get_mysql_log();
624
assert(0); // Impossible
636
int LOGGER::set_handlers(uint error_log_printer,
637
uint slow_log_printer,
638
uint general_log_printer)
291
640
/* error log table is not supported yet */
292
641
lock_exclusive();
294
643
init_error_log(error_log_printer);
644
init_slow_log(slow_log_printer);
645
init_general_log(general_log_printer);
669
1029
that case there is no need to have it in the binlog).
672
static int binlog_savepoint_set(handlerton *, Session *session, void *sv)
1032
static int binlog_savepoint_set(handlerton *hton __attribute__((unused)),
674
binlog_trans_log_savepos(session, (my_off_t*) sv);
1035
binlog_trans_log_savepos(thd, (my_off_t*) sv);
675
1036
/* Write it to the binary log */
677
1038
int const error=
678
session->binlog_query(Session::STMT_QUERY_TYPE,
679
session->query, session->query_length, true, false);
1039
thd->binlog_query(THD::STMT_QUERY_TYPE,
1040
thd->query, thd->query_length, true, false);
683
static int binlog_savepoint_rollback(handlerton *, Session *session, void *sv)
1044
static int binlog_savepoint_rollback(handlerton *hton __attribute__((unused)),
686
1048
Write ROLLBACK TO SAVEPOINT to the binlog cache if we have updated some
687
1049
non-transactional table. Otherwise, truncate the binlog cache starting
688
1050
from the SAVEPOINT command.
690
if (unlikely(session->transaction.all.modified_non_trans_table ||
691
(session->options & OPTION_KEEP_LOG)))
1052
if (unlikely(thd->transaction.all.modified_non_trans_table ||
1053
(thd->options & OPTION_KEEP_LOG)))
694
session->binlog_query(Session::STMT_QUERY_TYPE,
695
session->query, session->query_length, true, false);
1056
thd->binlog_query(THD::STMT_QUERY_TYPE,
1057
thd->query, thd->query_length, true, false);
698
binlog_trans_log_truncate(session, *(my_off_t*)sv);
1060
binlog_trans_log_truncate(thd, *(my_off_t*)sv);
1364
Reopen the log file. The method is used during FLUSH LOGS
1365
and locks LOCK_log mutex
1369
void MYSQL_QUERY_LOG::reopen_file()
1378
pthread_mutex_lock(&LOCK_log);
1381
name= 0; // Don't free name
1382
close(LOG_CLOSE_TO_BE_OPENED);
1385
Note that at this point, log_state != LOG_CLOSED (important for is_open()).
1388
open(save_name, log_type, 0, io_cache_type);
1389
my_free(save_name, MYF(0));
1391
pthread_mutex_unlock(&LOCK_log);
1398
Write a command to traditional general log file
1403
event_time command start timestamp
1404
user_host the pointer to the string with user@host info
1405
user_host_len length of the user_host string. this is computed once
1406
and passed to all general log event handlers
1407
thread_id Id of the thread, issued a query
1408
command_type the type of the command being logged
1409
command_type_len the length of the string above
1410
sql_text the very text of the query being executed
1411
sql_text_len the length of sql_text string
1415
Log given command to to normal (not rotable) log file
1419
TRUE - error occured
1422
bool MYSQL_QUERY_LOG::write(time_t event_time,
1423
const char *user_host __attribute__((unused)),
1424
uint user_host_len __attribute__((unused)),
1426
const char *command_type, uint command_type_len,
1427
const char *sql_text, uint sql_text_len)
1431
char local_time_buff[MAX_TIME_SIZE];
1433
uint time_buff_len= 0;
1435
(void) pthread_mutex_lock(&LOCK_log);
1437
/* Test if someone closed between the is_open test and lock */
1440
/* Note that my_b_write() assumes it knows the length for this */
1441
if (event_time != last_time)
1443
last_time= event_time;
1445
localtime_r(&event_time, &start);
1447
time_buff_len= snprintf(local_time_buff, MAX_TIME_SIZE,
1448
"%02d%02d%02d %2d:%02d:%02d",
1449
start.tm_year % 100, start.tm_mon + 1,
1450
start.tm_mday, start.tm_hour,
1451
start.tm_min, start.tm_sec);
1453
if (my_b_write(&log_file, (uchar*) local_time_buff, time_buff_len))
1457
if (my_b_write(&log_file, (uchar*) "\t\t" ,2) < 0)
1460
/* command_type, thread_id */
1461
length= snprintf(buff, 32, "%5ld ", (long) thread_id);
1463
if (my_b_write(&log_file, (uchar*) buff, length))
1466
if (my_b_write(&log_file, (uchar*) command_type, command_type_len))
1469
if (my_b_write(&log_file, (uchar*) "\t", 1))
1473
if (my_b_write(&log_file, (uchar*) sql_text, sql_text_len))
1476
if (my_b_write(&log_file, (uchar*) "\n", 1) ||
1477
flush_io_cache(&log_file))
1481
(void) pthread_mutex_unlock(&LOCK_log);
1488
sql_print_error(ER(ER_ERROR_ON_WRITE), name, errno);
1490
(void) pthread_mutex_unlock(&LOCK_log);
1496
Log a query to the traditional slow log file
1501
thd THD of the query
1502
current_time current timestamp
1503
query_start_arg command start timestamp
1504
user_host the pointer to the string with user@host info
1505
user_host_len length of the user_host string. this is computed once
1506
and passed to all general log event handlers
1507
query_utime Amount of time the query took to execute (in microseconds)
1508
lock_utime Amount of time the query was locked (in microseconds)
1509
is_command The flag, which determines, whether the sql_text is a
1510
query or an administrator command.
1511
sql_text the very text of the query or administrator command
1513
sql_text_len the length of sql_text string
1517
Log a query to the slow log file.
1521
TRUE - error occured
1524
bool MYSQL_QUERY_LOG::write(THD *thd, time_t current_time,
1525
time_t query_start_arg __attribute__((unused)),
1526
const char *user_host,
1527
uint user_host_len, uint64_t query_utime,
1528
uint64_t lock_utime, bool is_command,
1529
const char *sql_text, uint sql_text_len)
1533
(void) pthread_mutex_lock(&LOCK_log);
1537
(void) pthread_mutex_unlock(&LOCK_log);
1542
{ // Safety agains reopen
1544
char buff[80], *end;
1545
char query_time_buff[22+7], lock_time_buff[22+7];
1549
if (!(specialflag & SPECIAL_SHORT_LOG_FORMAT))
1551
if (current_time != last_time)
1553
last_time= current_time;
1555
localtime_r(¤t_time, &start);
1557
buff_len= snprintf(buff, sizeof buff,
1558
"# Time: %02d%02d%02d %2d:%02d:%02d\n",
1559
start.tm_year % 100, start.tm_mon + 1,
1560
start.tm_mday, start.tm_hour,
1561
start.tm_min, start.tm_sec);
1563
/* Note that my_b_write() assumes it knows the length for this */
1564
if (my_b_write(&log_file, (uchar*) buff, buff_len))
1567
const uchar uh[]= "# User@Host: ";
1568
if (my_b_write(&log_file, uh, sizeof(uh) - 1))
1570
if (my_b_write(&log_file, (uchar*) user_host, user_host_len))
1572
if (my_b_write(&log_file, (uchar*) "\n", 1))
1575
/* For slow query log */
1576
sprintf(query_time_buff, "%.6f", uint64_t2double(query_utime)/1000000.0);
1577
sprintf(lock_time_buff, "%.6f", uint64_t2double(lock_utime)/1000000.0);
1578
if (my_b_printf(&log_file,
1579
"# Query_time: %s Lock_time: %s"
1580
" Rows_sent: %lu Rows_examined: %lu\n",
1581
query_time_buff, lock_time_buff,
1582
(ulong) thd->sent_row_count,
1583
(ulong) thd->examined_row_count) == (uint) -1)
1585
if (thd->db && strcmp(thd->db, db))
1586
{ // Database changed
1587
if (my_b_printf(&log_file,"use %s;\n",thd->db) == (uint) -1)
1591
if (thd->stmt_depends_on_first_successful_insert_id_in_prev_stmt)
1593
end=strmov(end, ",last_insert_id=");
1594
end=int64_t10_to_str((int64_t)
1595
thd->first_successful_insert_id_in_prev_stmt_for_binlog,
1598
// Save value if we do an insert.
1599
if (thd->auto_inc_intervals_in_cur_stmt_for_binlog.nb_elements() > 0)
1601
if (!(specialflag & SPECIAL_SHORT_LOG_FORMAT))
1603
end=strmov(end,",insert_id=");
1604
end=int64_t10_to_str((int64_t)
1605
thd->auto_inc_intervals_in_cur_stmt_for_binlog.minimum(),
1611
This info used to show up randomly, depending on whether the query
1612
checked the query start time or not. now we always write current
1613
timestamp to the slow log
1615
end= strmov(end, ",timestamp=");
1616
end= int10_to_str((long) current_time, end, 10);
1622
if (my_b_write(&log_file, (uchar*) "SET ", 4) ||
1623
my_b_write(&log_file, (uchar*) buff + 1, (uint) (end-buff)))
1628
end= strxmov(buff, "# administrator command: ", NullS);
1629
buff_len= (ulong) (end - buff);
1630
my_b_write(&log_file, (uchar*) buff, buff_len);
1632
if (my_b_write(&log_file, (uchar*) sql_text, sql_text_len) ||
1633
my_b_write(&log_file, (uchar*) ";\n",2) ||
1634
flush_io_cache(&log_file))
1642
sql_print_error(ER(ER_ERROR_ON_WRITE), name, error);
1646
(void) pthread_mutex_unlock(&LOCK_log);
1008
1653
The following should be using fn_format(); We just need to
1009
1654
first change fn_format() to cut the file name if it's too long.
1011
const char *DRIZZLE_LOG::generate_name(const char *log_name,
1656
const char *MYSQL_LOG::generate_name(const char *log_name,
1012
1657
const char *suffix,
1013
1658
bool strip_ext, char *buff)
2572
3287
return logger.error_log_print(level, format, args);
2575
void DRIZZLE_BIN_LOG::rotate_and_purge(uint32_t flags)
3291
bool slow_log_print(THD *thd, const char *query, uint query_length,
3292
uint64_t current_utime)
3294
return logger.slow_log_print(thd, query, query_length, current_utime);
3298
bool LOGGER::log_command(THD *thd, enum enum_server_command command)
3301
Log command if we have at least one log event handler enabled and want
3302
to log this king of commands
3304
if (*general_log_handler_list && (what_to_log & (1L << (uint) command)))
3306
if (thd->options & OPTION_LOG_OFF)
3319
bool general_log_print(THD *thd, enum enum_server_command command,
3320
const char *format, ...)
3325
/* Print the message to the buffer if we want to log this king of commands */
3326
if (! logger.log_command(thd, command))
3329
va_start(args, format);
3330
error= logger.general_log_print(thd, command, format, args);
3336
bool general_log_write(THD *thd, enum enum_server_command command,
3337
const char *query, uint query_length)
3339
/* Write the message to the log if we want to log this king of commands */
3340
if (logger.log_command(thd, command))
3341
return logger.general_log_write(thd, command, query, query_length);
3346
void MYSQL_BIN_LOG::rotate_and_purge(uint flags)
2577
3348
if (!(flags & RP_LOCK_LOG_IS_ALREADY_LOCKED))
2578
3349
pthread_mutex_lock(&LOCK_log);
3054
3829
char err_renamed[FN_REFLEN], *end;
3055
3830
end= strmake(err_renamed,log_error_file,FN_REFLEN-4);
3056
my_stpcpy(end, "-old");
3057
pthread_mutex_lock(&LOCK_error_log);
3831
strmov(end, "-old");
3832
VOID(pthread_mutex_lock(&LOCK_error_log));
3058
3833
char err_temp[FN_REFLEN+4];
3060
3835
On Windows is necessary a temporary file for to rename
3061
3836
the current error file.
3063
strxmov(err_temp, err_renamed,"-tmp",NULL);
3838
strxmov(err_temp, err_renamed,"-tmp",NullS);
3064
3839
(void) my_delete(err_temp, MYF(0));
3065
3840
if (freopen(err_temp,"a+",stdout))
3069
unsigned char buf[IO_SIZE];
3071
if(freopen(err_temp,"a+",stderr)==NULL)
3846
freopen(err_temp,"a+",stderr);
3073
3847
(void) my_delete(err_renamed, MYF(0));
3074
3848
my_rename(log_error_file,err_renamed,MYF(0));
3075
if (freopen(log_error_file,"a+",stdout)==NULL)
3078
if(freopen(log_error_file,"a+",stderr)==NULL)
3849
if (freopen(log_error_file,"a+",stdout))
3850
freopen(log_error_file,"a+",stderr);
3081
3852
if ((fd = my_open(err_temp, O_RDONLY, MYF(0))) >= 0)