Percona Server moved to https://jira.percona.com/projects/PS

Merge lp:~sergei.glushchenko/percona-server/5.5-ps-bug1363370 into lp:percona-server/5.5

  1. 5.5-ps-bug1363370
  2. Merge into 5.5
Proposed by Sergei Glushchenko
Status: Merged
Approved by: Laurynas Biveinis
Approved revision: no longer in the source branch.
Merged at revision: 701
Proposed branch: lp:~sergei.glushchenko/percona-server/5.5-ps-bug1363370
Merge into: lp:percona-server/5.5
Diff against target: 235 lines (+78/-26)
8 files modified
mysql-test/r/audit_log_rotate.result (+1/-0)
mysql-test/t/audit_log_rotate-master.opt (+8/-0)
mysql-test/t/audit_log_rotate.test (+29/-0)
plugin/audit_log/audit_file.c (+10/-6)
plugin/audit_log/buffer.c (+7/-8)
plugin/audit_log/buffer.h (+3/-1)
plugin/audit_log/file_logger.c (+14/-10)
plugin/audit_log/logger.h (+6/-1)
To merge this branch: bzr merge lp:~sergei.glushchenko/percona-server/5.5-ps-bug1363370
Reviewer Review Type Date Requested Status
Laurynas Biveinis (community) Approve
Review via email: mp+232842@code.launchpad.net

Description of the change

Bug 1363370: Audit plugin rotates file in middle of audit

Audit record can be split between two files when logging is done to
file with ASYNCHRONOUS strategy and log rotation turned on.

The cause is that logging is done via ring buffer and log record in
the buffer can be wrapped at the end of the buffer. Incomplete
record will be written into log file. If file is exceeded the size
limit, it will be rotated splitting the record into two files.

Fix is to let the log write function to know that record is
incomplete so it will skip log rotation.

http://jenkins.percona.com/view/PS%205.5/job/percona-server-5.5-param/1042/

To post a comment you must log in.
Revision history for this message
Laurynas Biveinis (laurynas-biveinis) wrote :

fprintf(stderr, "debug foo") left in

review: Needs Fixing
Revision history for this message
Sergei Glushchenko (sergei.glushchenko) wrote :

Removed debug fprintf

http://jenkins.percona.com/view/PS%205.5/job/percona-server-5.5-param/1043/

Revision history for this message
Laurynas Biveinis (laurynas-biveinis) wrote :

    - The testcase needs to count that the actual audit files present >= 2, or
      it will pass the same if the log rotate does not happen at all.

review: Needs Fixing
Revision history for this message
Sergei Glushchenko (sergei.glushchenko) wrote :

Hi Laurynas,

Added condition for files count into the test case
http://jenkins.percona.com/view/PS%205.5/job/percona-server-5.5-param/1052/

Revision history for this message
Laurynas Biveinis (laurynas-biveinis) :
review: Approve

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
=== added file 'mysql-test/r/audit_log_rotate.result'
--- mysql-test/r/audit_log_rotate.result 1970-01-01 00:00:00 +0000
+++ mysql-test/r/audit_log_rotate.result 2014-09-26 08:34:49 +0000
@@ -0,0 +1,1 @@
1success
02
=== added file 'mysql-test/t/audit_log_rotate-master.opt'
--- mysql-test/t/audit_log_rotate-master.opt 1970-01-01 00:00:00 +0000
+++ mysql-test/t/audit_log_rotate-master.opt 2014-09-26 08:34:49 +0000
@@ -0,0 +1,8 @@
1$AUDIT_LOG_OPT
2$AUDIT_LOG_LOAD
3--audit_log_file=test_audit.log
4--audit_log_format=JSON
5--audit_log_strategy=ASYNCHRONOUS
6--audit_log_rotate_on_size=4096
7--audit_log_buffer_size=5000
8--audit_log_rotations=10
09
=== added file 'mysql-test/t/audit_log_rotate.test'
--- mysql-test/t/audit_log_rotate.test 1970-01-01 00:00:00 +0000
+++ mysql-test/t/audit_log_rotate.test 2014-09-26 08:34:49 +0000
@@ -0,0 +1,29 @@
1--source include/not_embedded.inc
2
3let $MYSQLD_DATADIR= `select @@datadir`;
4let MYSQLD_DATADIR= $MYSQLD_DATADIR;
5
6--disable_result_log
7--disable_query_log
8--source include/audit_log_events.inc
9--source include/audit_log_events.inc
10--source include/audit_log_events.inc
11--source include/audit_log_events.inc
12--enable_query_log
13--enable_result_log
14
15perl;
16 eval "use JSON qw(decode_json); 1" or exit 0;
17 my @files = glob ($ENV{'MYSQLD_DATADIR'} . "/test_audit.log.*");
18 foreach (@files) {
19 open my $file, $_ or die "Could not open log: $!";
20 while (my $line = <$file>) {
21 decode_json($line);
22 }
23 close $file;
24 }
25 die "Rotation doesn't wrok!" unless scalar(@files) > 1
26EOF
27--remove_files_wildcard $MYSQLD_DATADIR test_audit.log*
28
29--echo success
030
=== modified file 'plugin/audit_log/audit_file.c'
--- plugin/audit_log/audit_file.c 2014-07-30 19:36:26 +0000
+++ plugin/audit_log/audit_file.c 2014-09-26 08:34:49 +0000
@@ -39,7 +39,8 @@
39int audit_handler_file_close(audit_handler_t *handler);39int audit_handler_file_close(audit_handler_t *handler);
40static40static
41int audit_handler_file_write_nobuf(LOGGER_HANDLE *logger,41int audit_handler_file_write_nobuf(LOGGER_HANDLE *logger,
42 const char *buf, size_t len);42 const char *buf, size_t len,
43 log_record_state_t state);
43static44static
44int audit_handler_file_write_buf(audit_log_buffer_t *buffer,45int audit_handler_file_write_buf(audit_log_buffer_t *buffer,
45 const char *buf, size_t len);46 const char *buf, size_t len);
@@ -48,14 +49,15 @@
48 audit_handler_option_t opt, void *val);49 audit_handler_option_t opt, void *val);
4950
50static51static
51int write_callback(void *data, const char *buf, size_t len)52int write_callback(void *data, const char *buf, size_t len,
53 log_record_state_t state)
52{54{
53 audit_handler_t *handler= (audit_handler_t *) data;55 audit_handler_t *handler= (audit_handler_t *) data;
54 audit_handler_file_data_t *hdata= (audit_handler_file_data_t*) handler->data;56 audit_handler_file_data_t *hdata= (audit_handler_file_data_t*) handler->data;
5557
56 DBUG_ASSERT(hdata->struct_size == sizeof(audit_handler_file_data_t));58 DBUG_ASSERT(hdata->struct_size == sizeof(audit_handler_file_data_t));
5759
58 return audit_handler_file_write_nobuf(hdata->logger, buf, len);60 return audit_handler_file_write_nobuf(hdata->logger, buf, len, state);
59}61}
6062
6163
@@ -106,9 +108,10 @@
106108
107static109static
108int audit_handler_file_write_nobuf(LOGGER_HANDLE *logger,110int audit_handler_file_write_nobuf(LOGGER_HANDLE *logger,
109 const char *buf, size_t len)111 const char *buf, size_t len,
112 log_record_state_t state)
110{113{
111 return logger_write(logger, buf, len);114 return logger_write(logger, buf, len, state);
112}115}
113116
114static117static
@@ -135,7 +138,8 @@
135 else138 else
136 {139 {
137 DBUG_ASSERT(data->logger);140 DBUG_ASSERT(data->logger);
138 res= audit_handler_file_write_nobuf(data->logger, buf, len);141 res= audit_handler_file_write_nobuf(data->logger, buf, len,
142 LOG_RECORD_COMPLETE);
139143
140 if (data->sync_on_write)144 if (data->sync_on_write)
141 {145 {
142146
=== modified file 'plugin/audit_log/buffer.c'
--- plugin/audit_log/buffer.c 2014-04-21 12:07:45 +0000
+++ plugin/audit_log/buffer.c 2014-09-26 08:34:49 +0000
@@ -73,26 +73,25 @@
73 mysql_mutex_unlock(&log->mutex);73 mysql_mutex_unlock(&log->mutex);
74 log->write_func(log->write_func_data,74 log->write_func(log->write_func_data,
75 log->buf + log->flush_pos,75 log->buf + log->flush_pos,
76 log->size - log->flush_pos);76 log->size - log->flush_pos,
77 LOG_RECORD_INCOMPLETE);
77 mysql_mutex_lock(&log->mutex);78 mysql_mutex_lock(&log->mutex);
78 log->flush_pos= 0;79 log->flush_pos= 0;
79 log->write_pos%= log->size;80 log->write_pos%= log->size;
80 DBUG_ASSERT(log->write_pos >= log->flush_pos);
81 mysql_cond_broadcast(&log->flushed_cond);
82 mysql_mutex_unlock(&log->mutex);
83 }81 }
84 else82 else
85 {83 {
86 size_t flushlen= log->write_pos - log->flush_pos;84 size_t flushlen= log->write_pos - log->flush_pos;
87 mysql_mutex_unlock(&log->mutex);85 mysql_mutex_unlock(&log->mutex);
88 log->write_func(log->write_func_data,86 log->write_func(log->write_func_data,
89 log->buf + log->flush_pos, flushlen);87 log->buf + log->flush_pos, flushlen,
88 LOG_RECORD_COMPLETE);
90 mysql_mutex_lock(&log->mutex);89 mysql_mutex_lock(&log->mutex);
91 log->flush_pos+= flushlen;90 log->flush_pos+= flushlen;
92 DBUG_ASSERT(log->write_pos >= log->flush_pos);
93 mysql_cond_broadcast(&log->flushed_cond);
94 mysql_mutex_unlock(&log->mutex);
95 }91 }
92 DBUG_ASSERT(log->write_pos >= log->flush_pos);
93 mysql_cond_broadcast(&log->flushed_cond);
94 mysql_mutex_unlock(&log->mutex);
96}95}
9796
9897
9998
=== modified file 'plugin/audit_log/buffer.h'
--- plugin/audit_log/buffer.h 2014-07-30 19:36:26 +0000
+++ plugin/audit_log/buffer.h 2014-09-26 08:34:49 +0000
@@ -19,6 +19,7 @@
19#define AUDIT_LOG_BUFFER_INCLUDED19#define AUDIT_LOG_BUFFER_INCLUDED
2020
21#include <string.h> // for size_t21#include <string.h> // for size_t
22#include "logger.h"
2223
23#ifdef __cplusplus24#ifdef __cplusplus
24extern "C" {25extern "C" {
@@ -26,7 +27,8 @@
2627
27typedef struct audit_log_buffer audit_log_buffer_t;28typedef struct audit_log_buffer audit_log_buffer_t;
2829
29typedef int (*audit_log_write_func)(void *data, const char *buf, size_t len);30typedef int (*audit_log_write_func)(void *data, const char *buf, size_t len,
31 log_record_state_t state);
3032
31audit_log_buffer_t *audit_log_buffer_init(size_t size, int drop_if_full,33audit_log_buffer_t *audit_log_buffer_init(size_t size, int drop_if_full,
32 audit_log_write_func write_func, void *data);34 audit_log_write_func write_func, void *data);
3335
=== modified file 'plugin/audit_log/file_logger.c'
--- plugin/audit_log/file_logger.c 2014-05-23 16:14:27 +0000
+++ plugin/audit_log/file_logger.c 2014-09-26 08:34:49 +0000
@@ -279,24 +279,28 @@
279}279}
280280
281281
282int logger_write(LOGGER_HANDLE *log, const char *buffer, size_t size)282int logger_write(LOGGER_HANDLE *log, const char *buffer, size_t size,
283 log_record_state_t state)
283{284{
284 int result;285 int result;
285 my_off_t filesize;286 my_off_t filesize;
286287
287 flogger_mutex_lock(log);288 flogger_mutex_lock(log);
288 if (log->rotations > 0)
289 if ((filesize= my_tell(log->file, MYF(0))) == (my_off_t) -1 ||
290 ((unsigned long long)filesize >= log->size_limit &&
291 do_rotate(log)))
292 {
293 result= -1;
294 errno= my_errno;
295 goto exit; /* Log rotation needed but failed */
296 }
297289
298 result= my_write(log->file, (uchar *) buffer, size, MYF(0));290 result= my_write(log->file, (uchar *) buffer, size, MYF(0));
299291
292 if (state == LOG_RECORD_COMPLETE && log->rotations > 0)
293 {
294 if ((filesize= my_tell(log->file, MYF(0))) == (my_off_t) -1 ||
295 ((unsigned long long)filesize >= log->size_limit &&
296 do_rotate(log)))
297 {
298 result= -1;
299 errno= my_errno;
300 goto exit; /* Log rotation needed but failed */
301 }
302 }
303
300exit:304exit:
301 flogger_mutex_unlock(log);305 flogger_mutex_unlock(log);
302 return result;306 return result;
303307
=== modified file 'plugin/audit_log/logger.h'
--- plugin/audit_log/logger.h 2014-07-30 19:36:26 +0000
+++ plugin/audit_log/logger.h 2014-09-26 08:34:49 +0000
@@ -62,6 +62,10 @@
62typedef struct logger_handle_st LOGGER_HANDLE;62typedef struct logger_handle_st LOGGER_HANDLE;
63typedef size_t (*logger_prolog_func_t)(MY_STAT *, char *buf, size_t buflen);63typedef size_t (*logger_prolog_func_t)(MY_STAT *, char *buf, size_t buflen);
64typedef size_t (*logger_epilog_func_t)(char *buf, size_t buflen);64typedef size_t (*logger_epilog_func_t)(char *buf, size_t buflen);
65typedef enum {
66 LOG_RECORD_COMPLETE,
67 LOG_RECORD_INCOMPLETE
68} log_record_state_t;
6569
66void logger_init_mutexes();70void logger_init_mutexes();
67LOGGER_HANDLE *logger_open(const char *path,71LOGGER_HANDLE *logger_open(const char *path,
@@ -72,7 +76,8 @@
72int logger_close(LOGGER_HANDLE *log, logger_epilog_func_t footer);76int logger_close(LOGGER_HANDLE *log, logger_epilog_func_t footer);
73int logger_vprintf(LOGGER_HANDLE *log, const char *fmt, va_list argptr);77int logger_vprintf(LOGGER_HANDLE *log, const char *fmt, va_list argptr);
74int logger_printf(LOGGER_HANDLE *log, const char *fmt, ...);78int logger_printf(LOGGER_HANDLE *log, const char *fmt, ...);
75int logger_write(LOGGER_HANDLE *log, const char *buffer, size_t size);79int logger_write(LOGGER_HANDLE *log, const char *buffer, size_t size,
80 log_record_state_t state);
76int logger_rotate(LOGGER_HANDLE *log); 81int logger_rotate(LOGGER_HANDLE *log);
77int logger_sync(LOGGER_HANDLE *log);82int logger_sync(LOGGER_HANDLE *log);
78int logger_reopen(LOGGER_HANDLE *log, logger_prolog_func_t header,83int logger_reopen(LOGGER_HANDLE *log, logger_prolog_func_t header,

Subscribers

People subscribed via source and target branches