Skip to content

M
MariaDB
Commit b43029f4 authored by serg@serg.mylan's avatar serg@serg.mylan
Browse files
Options

bug#8646 - deadlock if long transaction causes binlog rotate

parent d1be3765
Hide whitespace changes
Inline Side-by-side
Showing with 190 additions and 63 deletions
mysql-test/r/rpl_rotate_logs.result
View file @ b43029f4
......@@ -92,3 +92,120 @@ count(*)
100
unlock tables;
drop table if exists t1,t2,t3,t4;
slave stop;
reset master;
create table t1 (n int) engine=innodb;
begin;
commit;
drop table t1;
show binlog events in 'master-bin.000001';
Log_name Pos Event_type Server_id End_log_pos Info
master-bin.000001 4 Format_desc 1 96 Server ver: 5.0.3-alpha-debug-log, Binlog ver: 4
master-bin.000001 96 Query 1 197 use `test`; create table t1 (n int) engine=innodb
master-bin.000001 197 Query 1 266 use `test`; BEGIN
master-bin.000001 266 Query 1 94 use `test`; insert into t1 values(100 + 4)
master-bin.000001 360 Query 1 187 use `test`; insert into t1 values(99 + 4)
master-bin.000001 453 Query 1 280 use `test`; insert into t1 values(98 + 4)
master-bin.000001 546 Query 1 373 use `test`; insert into t1 values(97 + 4)
master-bin.000001 639 Query 1 466 use `test`; insert into t1 values(96 + 4)
master-bin.000001 732 Query 1 559 use `test`; insert into t1 values(95 + 4)
master-bin.000001 825 Query 1 652 use `test`; insert into t1 values(94 + 4)
master-bin.000001 918 Query 1 745 use `test`; insert into t1 values(93 + 4)
master-bin.000001 1011 Query 1 838 use `test`; insert into t1 values(92 + 4)
master-bin.000001 1104 Query 1 931 use `test`; insert into t1 values(91 + 4)
master-bin.000001 1197 Query 1 1024 use `test`; insert into t1 values(90 + 4)
master-bin.000001 1290 Query 1 1117 use `test`; insert into t1 values(89 + 4)
master-bin.000001 1383 Query 1 1210 use `test`; insert into t1 values(88 + 4)
master-bin.000001 1476 Query 1 1303 use `test`; insert into t1 values(87 + 4)
master-bin.000001 1569 Query 1 1396 use `test`; insert into t1 values(86 + 4)
master-bin.000001 1662 Query 1 1489 use `test`; insert into t1 values(85 + 4)
master-bin.000001 1755 Query 1 1582 use `test`; insert into t1 values(84 + 4)
master-bin.000001 1848 Query 1 1675 use `test`; insert into t1 values(83 + 4)
master-bin.000001 1941 Query 1 1768 use `test`; insert into t1 values(82 + 4)
master-bin.000001 2034 Query 1 1861 use `test`; insert into t1 values(81 + 4)
master-bin.000001 2127 Query 1 1954 use `test`; insert into t1 values(80 + 4)
master-bin.000001 2220 Query 1 2047 use `test`; insert into t1 values(79 + 4)
master-bin.000001 2313 Query 1 2140 use `test`; insert into t1 values(78 + 4)
master-bin.000001 2406 Query 1 2233 use `test`; insert into t1 values(77 + 4)
master-bin.000001 2499 Query 1 2326 use `test`; insert into t1 values(76 + 4)
master-bin.000001 2592 Query 1 2419 use `test`; insert into t1 values(75 + 4)
master-bin.000001 2685 Query 1 2512 use `test`; insert into t1 values(74 + 4)
master-bin.000001 2778 Query 1 2605 use `test`; insert into t1 values(73 + 4)
master-bin.000001 2871 Query 1 2698 use `test`; insert into t1 values(72 + 4)
master-bin.000001 2964 Query 1 2791 use `test`; insert into t1 values(71 + 4)
master-bin.000001 3057 Query 1 2884 use `test`; insert into t1 values(70 + 4)
master-bin.000001 3150 Query 1 2977 use `test`; insert into t1 values(69 + 4)
master-bin.000001 3243 Query 1 3070 use `test`; insert into t1 values(68 + 4)
master-bin.000001 3336 Query 1 3163 use `test`; insert into t1 values(67 + 4)
master-bin.000001 3429 Query 1 3256 use `test`; insert into t1 values(66 + 4)
master-bin.000001 3522 Query 1 3349 use `test`; insert into t1 values(65 + 4)
master-bin.000001 3615 Query 1 3442 use `test`; insert into t1 values(64 + 4)
master-bin.000001 3708 Query 1 3535 use `test`; insert into t1 values(63 + 4)
master-bin.000001 3801 Query 1 3628 use `test`; insert into t1 values(62 + 4)
master-bin.000001 3894 Query 1 3721 use `test`; insert into t1 values(61 + 4)
master-bin.000001 3987 Query 1 3814 use `test`; insert into t1 values(60 + 4)
master-bin.000001 4080 Query 1 3907 use `test`; insert into t1 values(59 + 4)
master-bin.000001 4173 Query 1 4000 use `test`; insert into t1 values(58 + 4)
master-bin.000001 4266 Query 1 4093 use `test`; insert into t1 values(57 + 4)
master-bin.000001 4359 Query 1 4186 use `test`; insert into t1 values(56 + 4)
master-bin.000001 4452 Query 1 4279 use `test`; insert into t1 values(55 + 4)
master-bin.000001 4545 Query 1 4372 use `test`; insert into t1 values(54 + 4)
master-bin.000001 4638 Query 1 4465 use `test`; insert into t1 values(53 + 4)
master-bin.000001 4731 Query 1 4558 use `test`; insert into t1 values(52 + 4)
master-bin.000001 4824 Query 1 4651 use `test`; insert into t1 values(51 + 4)
master-bin.000001 4917 Query 1 4744 use `test`; insert into t1 values(50 + 4)
master-bin.000001 5010 Query 1 4837 use `test`; insert into t1 values(49 + 4)
master-bin.000001 5103 Query 1 4930 use `test`; insert into t1 values(48 + 4)
master-bin.000001 5196 Query 1 5023 use `test`; insert into t1 values(47 + 4)
master-bin.000001 5289 Query 1 5116 use `test`; insert into t1 values(46 + 4)
master-bin.000001 5382 Query 1 5209 use `test`; insert into t1 values(45 + 4)
master-bin.000001 5475 Query 1 5302 use `test`; insert into t1 values(44 + 4)
master-bin.000001 5568 Query 1 5395 use `test`; insert into t1 values(43 + 4)
master-bin.000001 5661 Query 1 5488 use `test`; insert into t1 values(42 + 4)
master-bin.000001 5754 Query 1 5581 use `test`; insert into t1 values(41 + 4)
master-bin.000001 5847 Query 1 5674 use `test`; insert into t1 values(40 + 4)
master-bin.000001 5940 Query 1 5767 use `test`; insert into t1 values(39 + 4)
master-bin.000001 6033 Query 1 5860 use `test`; insert into t1 values(38 + 4)
master-bin.000001 6126 Query 1 5953 use `test`; insert into t1 values(37 + 4)
master-bin.000001 6219 Query 1 6046 use `test`; insert into t1 values(36 + 4)
master-bin.000001 6312 Query 1 6139 use `test`; insert into t1 values(35 + 4)
master-bin.000001 6405 Query 1 6232 use `test`; insert into t1 values(34 + 4)
master-bin.000001 6498 Query 1 6325 use `test`; insert into t1 values(33 + 4)
master-bin.000001 6591 Query 1 6418 use `test`; insert into t1 values(32 + 4)
master-bin.000001 6684 Query 1 6511 use `test`; insert into t1 values(31 + 4)
master-bin.000001 6777 Query 1 6604 use `test`; insert into t1 values(30 + 4)
master-bin.000001 6870 Query 1 6697 use `test`; insert into t1 values(29 + 4)
master-bin.000001 6963 Query 1 6790 use `test`; insert into t1 values(28 + 4)
master-bin.000001 7056 Query 1 6883 use `test`; insert into t1 values(27 + 4)
master-bin.000001 7149 Query 1 6976 use `test`; insert into t1 values(26 + 4)
master-bin.000001 7242 Query 1 7069 use `test`; insert into t1 values(25 + 4)
master-bin.000001 7335 Query 1 7162 use `test`; insert into t1 values(24 + 4)
master-bin.000001 7428 Query 1 7255 use `test`; insert into t1 values(23 + 4)
master-bin.000001 7521 Query 1 7348 use `test`; insert into t1 values(22 + 4)
master-bin.000001 7614 Query 1 7441 use `test`; insert into t1 values(21 + 4)
master-bin.000001 7707 Query 1 7534 use `test`; insert into t1 values(20 + 4)
master-bin.000001 7800 Query 1 7627 use `test`; insert into t1 values(19 + 4)
master-bin.000001 7893 Query 1 7720 use `test`; insert into t1 values(18 + 4)
master-bin.000001 7986 Query 1 7813 use `test`; insert into t1 values(17 + 4)
master-bin.000001 8079 Query 1 7906 use `test`; insert into t1 values(16 + 4)
master-bin.000001 8172 Query 1 7999 use `test`; insert into t1 values(15 + 4)
master-bin.000001 8265 Query 1 8092 use `test`; insert into t1 values(14 + 4)
master-bin.000001 8358 Query 1 8185 use `test`; insert into t1 values(13 + 4)
master-bin.000001 8451 Query 1 8278 use `test`; insert into t1 values(12 + 4)
master-bin.000001 8544 Query 1 8371 use `test`; insert into t1 values(11 + 4)
master-bin.000001 8637 Query 1 8464 use `test`; insert into t1 values(10 + 4)
master-bin.000001 8730 Query 1 8556 use `test`; insert into t1 values(9 + 4)
master-bin.000001 8822 Query 1 8648 use `test`; insert into t1 values(8 + 4)
master-bin.000001 8914 Query 1 8740 use `test`; insert into t1 values(7 + 4)
master-bin.000001 9006 Query 1 8832 use `test`; insert into t1 values(6 + 4)
master-bin.000001 9098 Query 1 8924 use `test`; insert into t1 values(5 + 4)
master-bin.000001 9190 Query 1 9016 use `test`; insert into t1 values(4 + 4)
master-bin.000001 9282 Query 1 9108 use `test`; insert into t1 values(3 + 4)
master-bin.000001 9374 Query 1 9200 use `test`; insert into t1 values(2 + 4)
master-bin.000001 9466 Query 1 9292 use `test`; insert into t1 values(1 + 4)
master-bin.000001 9558 Xid 1 9319 COMMIT /* xid=146 */
master-bin.000001 9585 Rotate 1 9629 master-bin.000002;pos=4
show binlog events in 'master-bin.000002';
Log_name Pos Event_type Server_id End_log_pos Info
master-bin.000002 4 Format_desc 1 96 Server ver: 5.0.3-alpha-debug-log, Binlog ver: 4
master-bin.000002 96 Query 1 173 use `test`; drop table t1
mysql-test/t/rpl_rotate_logs.test
View file @ b43029f4
......@@ -152,3 +152,28 @@ unlock tables;
connection master;
drop table if exists t1,t2,t3,t4;
sync_slave_with_master;
#
# now the same in a transaction
#
slave stop; # we don't need it anymore
connection master;
reset master;
let $1=100;
--disable_warnings
create table t1 (n int) engine=innodb;
--enable_warnings
begin;
--disable_query_log
while ($1)
{
eval insert into t1 values($1 + 4);
dec $1;
}
--enable_query_log
commit;
drop table t1;
show binlog events in 'master-bin.000001';
show binlog events in 'master-bin.000002';
sql/log.cc
View file @ b43029f4
......@@ -1400,7 +1400,7 @@ bool MYSQL_LOG::append(Log_event* ev)
pthread_mutex_unlock(&LOCK_index);
}
err:
err:
pthread_mutex_unlock(&LOCK_log);
signal_update(); // Safe as we don't call close
DBUG_RETURN(error);
......@@ -1548,16 +1548,15 @@ inline bool sync_binlog(IO_CACHE *cache)
Write an event to the binary log
*/
bool MYSQL_LOG::write(Log_event* event_info)
bool MYSQL_LOG::write(Log_event *event_info)
{
THD *thd=event_info->thd;
bool error=1;
bool should_rotate = 0;
DBUG_ENTER("MYSQL_LOG::write(event)");
THD *thd= event_info->thd;
bool error= 1;
DBUG_ENTER("MYSQL_LOG::write(Log_event *)");
pthread_mutex_lock(&LOCK_log);
/*
/*
In most cases this is only called if 'is_open()' is true; in fact this is
mostly called if is_open() *was* true a few instructions before, but it
could have changed since.
......@@ -1567,7 +1566,7 @@ bool MYSQL_LOG::write(Log_event* event_info)
const char *local_db= event_info->get_db();
IO_CACHE *file= &log_file;
#ifdef HAVE_REPLICATION
/*
/*
In the future we need to add to the following if tests like
"do the involved tables match (to be implemented)
binlog_[wild_]{do|ignore}_table?" (WL#1049)"
......@@ -1734,10 +1733,6 @@ COLLATION_CONNECTION=%u,COLLATION_DATABASE=%u,COLLATION_SERVER=%u",
{
if (flush_io_cache(file) || sync_binlog(file))
goto err;
/* check automatic rotation; */
DBUG_PRINT("info",("max_size: %lu",max_size));
should_rotate= (my_b_tell(file) >= (my_off_t) max_size);
}
error=0;
......@@ -1751,28 +1746,39 @@ COLLATION_CONNECTION=%u,COLLATION_DATABASE=%u,COLLATION_SERVER=%u",
write_error=1;
}
if (file == &log_file)
signal_update();
if (should_rotate)
{
pthread_mutex_lock(&LOCK_index);
new_file(0); // inside mutex
pthread_mutex_unlock(&LOCK_index);
signal_update();
rotate_and_purge(RP_LOCK_LOG_IS_ALREADY_LOCKED);
}
}
pthread_mutex_unlock(&LOCK_log);
#ifdef HAVE_REPLICATION
if (should_rotate && expire_logs_days)
{
long purge_time= time(0) - expire_logs_days*24*60*60;
if (purge_time >= 0)
error= purge_logs_before_date(purge_time);
}
#endif
DBUG_RETURN(error);
}
void MYSQL_LOG::rotate_and_purge(uint flags)
{
if (!prepared_xids && // see new_file() for the explanation
((flags & RP_FORCE_ROTATE) ||
(my_b_tell(&log_file) >= (my_off_t) max_size)))
{
if (flags & RP_LOCK_LOG_IS_ALREADY_LOCKED)
pthread_mutex_lock(&LOCK_index);
new_file(!(flags & RP_LOCK_LOG_IS_ALREADY_LOCKED));
if (flags & RP_LOCK_LOG_IS_ALREADY_LOCKED)
pthread_mutex_unlock(&LOCK_index);
#ifdef HAVE_REPLICATION
// QQ why do we need #ifdef here ???
if (expire_logs_days)
{
long purge_time= time(0) - expire_logs_days*24*60*60;
if (purge_time >= 0)
purge_logs_before_date(purge_time);
}
#endif
}
}
uint MYSQL_LOG::next_file_id()
{
......@@ -1797,24 +1803,20 @@ uint MYSQL_LOG::next_file_id()
- The thing in the cache is always a complete transaction
- 'cache' needs to be reinitialized after this functions returns.
TODO
fix it to become atomic - either the complete cache is added to binlog
or nothing (other storage engines rely on this, doing a ROLLBACK)
IMPLEMENTATION
- To support transaction over replication, we wrap the transaction
with BEGIN/COMMIT or BEGIN/ROLLBACK in the binary log.
We want to write a BEGIN/ROLLBACK block when a non-transactional table was
updated in a transaction which was rolled back. This is to ensure that the
same updates are run on the slave.
We want to write a BEGIN/ROLLBACK block when a non-transactional table
was updated in a transaction which was rolled back. This is to ensure
that the same updates are run on the slave.
*/
bool MYSQL_LOG::write(THD *thd, IO_CACHE *cache)
{
bool should_rotate= 0, error= 0;
bool error= 0;
VOID(pthread_mutex_lock(&LOCK_log));
DBUG_ENTER("MYSQL_LOG::write(cache");
DBUG_ENTER("MYSQL_LOG::write(THD *, IO_CACHE *)");
if (likely(is_open())) // Should always be true
{
uint length;
......@@ -1869,25 +1871,10 @@ bool MYSQL_LOG::write(THD *thd, IO_CACHE *cache)
}
signal_update();
DBUG_PRINT("info",("max_size: %lu",max_size));
if (should_rotate= (my_b_tell(&log_file) >= (my_off_t) max_size))
{
pthread_mutex_lock(&LOCK_index);
new_file(0); // inside mutex
pthread_mutex_unlock(&LOCK_index);
}
rotate_and_purge(RP_LOCK_LOG_IS_ALREADY_LOCKED);
}
VOID(pthread_mutex_unlock(&LOCK_log));
#ifdef HAVE_REPLICATION
if (should_rotate && expire_logs_days)
{
long purge_time= time(0) - expire_logs_days*24*60*60;
if (purge_time >= 0)
error= purge_logs_before_date(purge_time);
}
#endif
DBUG_RETURN(error);
err:
......@@ -2993,6 +2980,7 @@ void TC_LOG_BINLOG::unlog(ulong cookie, my_xid xid)
{
if (thread_safe_dec_and_test(prepared_xids, &LOCK_prep_xids))
pthread_cond_signal(&COND_prep_xids);
rotate_and_purge(0); // in case ::write() was not able to rotate
}
int TC_LOG_BINLOG::recover(IO_CACHE *log, Format_description_log_event *fdle)
......
sql/sql_class.h
View file @ b43029f4
......@@ -174,6 +174,9 @@ typedef struct st_user_var_events
uint charset_number;
} BINLOG_USER_VAR_EVENT;
#define RP_LOCK_LOG_IS_ALREADY_LOCKED 1
#define RP_FORCE_ROTATE 2
class Log_event;
/*
......@@ -300,7 +303,7 @@ class MYSQL_LOG: public TC_LOG
}
bool open_index_file(const char *index_file_name_arg,
const char *log_name);
void new_file(bool need_lock= 1);
void new_file(bool need_lock);
bool write(THD *thd, enum enum_server_command command,
const char *format,...);
bool write(THD *thd, const char *query, uint query_length,
......@@ -319,6 +322,7 @@ class MYSQL_LOG: public TC_LOG
void make_log_name(char* buf, const char* log_ident);
bool is_active(const char* log_file_name);
int update_log_index(LOG_INFO* linfo, bool need_update_threads);
void rotate_and_purge(uint flags);
int purge_logs(const char *to_log, bool included,
bool need_mutex, bool need_update_threads,
ulonglong *decrease_log_space);
......
sql/sql_parse.cc
View file @ b43029f4
......@@ -6130,22 +6130,16 @@ bool reload_acl_and_cache(THD *thd, ulong options, TABLE_LIST *tables,
the slow query log, and the relay log (if it exists).
*/
/*
/*
Writing this command to the binlog may result in infinite loops when doing
mysqlbinlog|mysql, and anyway it does not really make sense to log it
automatically (would cause more trouble to users than it would help them)
*/
tmp_write_to_binlog= 0;
mysql_log.new_file(1);
mysql_bin_log.new_file(1);
mysql_slow_log.new_file(1);
mysql_bin_log.rotate_and_purge(RP_FORCE_ROTATE);
#ifdef HAVE_REPLICATION
if (mysql_bin_log.is_open() && expire_logs_days)
{
long purge_time= time(0) - expire_logs_days*24*60*60;
if (purge_time >= 0)
mysql_bin_log.purge_logs_before_date(purge_time);
}
pthread_mutex_lock(&LOCK_active_mi);
rotate_relay_log(active_mi);
pthread_mutex_unlock(&LOCK_active_mi);
......@@ -6159,7 +6153,7 @@ bool reload_acl_and_cache(THD *thd, ulong options, TABLE_LIST *tables,
if (options & REFRESH_QUERY_CACHE_FREE)
{
query_cache.pack(); // FLUSH QUERY CACHE
options &= ~REFRESH_QUERY_CACHE; // Don't flush cache, just free memory
options &= ~REFRESH_QUERY_CACHE; // Don't flush cache, just free memory
}
if (options & (REFRESH_TABLES | REFRESH_QUERY_CACHE))
{
......
sql/sql_yacc.yy
View file @ b43029f4
......@@ -630,7 +630,6 @@ bool my_yyoverflow(short **a, YYSTYPE **b, ulong *yystacksize);
%token VARCHAR
%token VARIABLES
%token VARIANCE_SYM
%token VARIANCE_SYM
%token VARYING
%token VIEW_SYM
%token WARNINGS
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment
GitLab Nexedi Edition | About GitLab | About Nexedi | 沪ICP备2021021310号-2 | 沪ICP备2021021310号-7