Merge lp:~laurynas-biveinis/percona-server/bug1193332-5.5 into lp:percona-server/5.5

Proposed by Laurynas Biveinis on 2014-06-11
Status: Merged
Approved by: Sergei Glushchenko on 2014-07-14
Approved revision: 662
Merged at revision: 679
Proposed branch: lp:~laurynas-biveinis/percona-server/bug1193332-5.5
Merge into: lp:percona-server/5.5
Diff against target: 221 lines (+120/-19)
7 files modified
mysql-test/suite/innodb/r/percona_changed_page_bmp_debug.result (+16/-0)
mysql-test/suite/innodb/t/percona_changed_page_bmp_debug.test (+56/-0)
storage/innobase/handler/i_s.cc (+12/-0)
storage/innobase/include/log0log.h (+12/-0)
storage/innobase/include/log0log.ic (+21/-0)
storage/innobase/log/log0log.c (+0/-19)
storage/innobase/log/log0online.c (+3/-0)
To merge this branch: bzr merge lp:~laurynas-biveinis/percona-server/bug1193332-5.5
Reviewer Review Type Date Requested Status
Sergei Glushchenko (community) g2 2014-06-11 Approve on 2014-07-14
Review via email: mp+222799@code.launchpad.net

Description of the change

Fix bug 1193332 ([Warning] InnoDB: changed page bitmap file
'./ib_modified_log_11_951286349.xdb' does not contain a complete run
at the end.)

The problem is bitmap writer thread working in parallel with bitmap
reader that processes an INFORMATION_SCHEMA.INNODB_CHANGED_PAGES
query, causing the latter to see partial data in the middle of the
write. The fix is, if the log tracker is running, to limit any
maximum LSN value for a query with an actual tracked LSN value.

Add a testcase to percona_changed_page_bmp_debug.

    http://jenkins.percona.com/job/percona-server-5.5-param/1009/

To post a comment you must log in.

Approve

review: Approve (g2)

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
1=== modified file 'mysql-test/suite/innodb/r/percona_changed_page_bmp_debug.result'
2--- mysql-test/suite/innodb/r/percona_changed_page_bmp_debug.result 2013-09-25 05:52:09 +0000
3+++ mysql-test/suite/innodb/r/percona_changed_page_bmp_debug.result 2014-06-11 13:20:55 +0000
4@@ -42,3 +42,19 @@
5 ERROR HY000: Can't read record in system table
6 SET DEBUG_SYNC="RESET";
7 DROP TABLE t2;
8+RESET CHANGED_PAGE_BITMAPS;
9+4th restart
10+SET DEBUG_SYNC="i_s_innodb_changed_pages_range_ready SIGNAL ready WAIT_FOR finish";
11+SELECT COUNT(*) FROM INFORMATION_SCHEMA.INNODB_CHANGED_PAGES;
12+SET DEBUG_SYNC="now WAIT_FOR ready";
13+SET @@GLOBAL.innodb_track_changed_pages=FALSE;
14+SET @@GLOBAL.innodb_log_checkpoint_now=TRUE;
15+CREATE TABLE t1 (a INT)ENGINE=InnoDB;
16+INSERT INTO t1 VALUES (1);
17+CREATE TABLE t2 (a INT) ENGINE=InnoDB;
18+INSERT INTO t2 VALUES (2);
19+SET @@GLOBAL.innodb_log_checkpoint_now=TRUE;
20+SET @@GLOBAL.innodb_track_changed_pages=TRUE;
21+SET @@GLOBAL.innodb_track_redo_log_now=TRUE;
22+SET DEBUG_SYNC="now SIGNAL finish";
23+DROP TABLE t1, t2;
24
25=== modified file 'mysql-test/suite/innodb/t/percona_changed_page_bmp_debug.test'
26--- mysql-test/suite/innodb/t/percona_changed_page_bmp_debug.test 2013-09-25 05:52:09 +0000
27+++ mysql-test/suite/innodb/t/percona_changed_page_bmp_debug.test 2014-06-11 13:20:55 +0000
28@@ -130,5 +130,61 @@
29 disconnect con2;
30
31 DROP TABLE t2;
32+RESET CHANGED_PAGE_BITMAPS;
33+
34+--source include/wait_until_count_sessions.inc
35+
36+#
37+# Test for bug 1193332 ([Warning] InnoDB: changed page bitmap file
38+# './ib_modified_log_11_951286349.xdb' does not contain a complete run at the end.)
39+#
40+
41+# Setup an error on the 2nd bitmap page write, so that bitmap contains an incomplete run
42+--echo 4th restart
43+--exec echo "wait" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
44+--shutdown_server 10
45+--source include/wait_until_disconnected.inc
46+--enable_reconnect
47+--exec echo "restart:-#d,bitmap_page_2_write_error" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
48+--source include/wait_until_connected_again.inc
49+
50+--source include/count_sessions.inc
51+
52+--connect(con2,localhost,root,,)
53+
54+SET DEBUG_SYNC="i_s_innodb_changed_pages_range_ready SIGNAL ready WAIT_FOR finish";
55+send SELECT COUNT(*) FROM INFORMATION_SCHEMA.INNODB_CHANGED_PAGES;
56+
57+--connection default
58+
59+SET DEBUG_SYNC="now WAIT_FOR ready";
60+
61+# Pause the log tracker
62+SET @@GLOBAL.innodb_track_changed_pages=FALSE;
63+SET @@GLOBAL.innodb_log_checkpoint_now=TRUE;
64+
65+# Prepare two pages of bitmap data
66+CREATE TABLE t1 (a INT)ENGINE=InnoDB;
67+INSERT INTO t1 VALUES (1);
68+CREATE TABLE t2 (a INT) ENGINE=InnoDB;
69+INSERT INTO t2 VALUES (2);
70+
71+# Resume the log tracker so it crashes after writing one page
72+SET @@GLOBAL.innodb_log_checkpoint_now=TRUE;
73+SET @@GLOBAL.innodb_track_changed_pages=TRUE;
74+SET @@GLOBAL.innodb_track_redo_log_now=TRUE;
75+
76+SET DEBUG_SYNC="now SIGNAL finish";
77+
78+--connection con2
79+# With the bug present the query will fail with ER_CANT_FIND_SYSTEM_REC
80+--disable_result_log
81+reap;
82+--enable_result_log
83+
84+--disconnect con2
85+--connection default
86+
87+DROP TABLE t1, t2;
88
89 --source include/wait_until_count_sessions.inc
90
91=== modified file 'storage/innobase/handler/i_s.cc'
92--- storage/innobase/handler/i_s.cc 2013-10-31 11:50:31 +0000
93+++ storage/innobase/handler/i_s.cc 2014-06-11 13:20:55 +0000
94@@ -42,6 +42,7 @@
95 #include "i_s.h"
96 #include <sql_plugin.h>
97 #include <mysql/innodb_priv.h>
98+#include <debug_sync.h>
99
100 extern "C" {
101 #include "btr0pcur.h" /* for file sys_tables related info. */
102@@ -7511,12 +7512,23 @@
103 limit_lsn_range_from_condition(table, cond, &min_lsn,
104 &max_lsn);
105 }
106+
107+ /* If the log tracker is running and our max_lsn > current tracked LSN,
108+ cap the max lsn so that we don't try to read any partial runs as the
109+ tracked LSN advances. */
110+ if (srv_track_changed_pages) {
111+ ib_uint64_t tracked_lsn = log_get_tracked_lsn();
112+ if (max_lsn > tracked_lsn)
113+ max_lsn = tracked_lsn;
114+ }
115
116 if (!log_online_bitmap_iterator_init(&i, min_lsn, max_lsn)) {
117 my_error(ER_CANT_FIND_SYSTEM_REC, MYF(0));
118 DBUG_RETURN(1);
119 }
120
121+ DEBUG_SYNC(thd, "i_s_innodb_changed_pages_range_ready");
122+
123 while(log_online_bitmap_iterator_next(&i) &&
124 (!srv_max_changed_pages ||
125 output_rows_num < srv_max_changed_pages) &&
126
127=== modified file 'storage/innobase/include/log0log.h'
128--- storage/innobase/include/log0log.h 2013-12-05 08:07:26 +0000
129+++ storage/innobase/include/log0log.h 2014-06-11 13:20:55 +0000
130@@ -581,6 +581,18 @@
131 log_mem_free(void);
132 /*==============*/
133
134+/****************************************************************//**
135+Safely reads the log_sys->tracked_lsn value. Uses atomic operations
136+if available, otherwise this field is protected with the log system
137+mutex. The writer counterpart function is log_set_tracked_lsn() in
138+log0online.c.
139+
140+@return log_sys->tracked_lsn value. */
141+UNIV_INLINE
142+ib_uint64_t
143+log_get_tracked_lsn(void);
144+/*=====================*/
145+
146 extern log_t* log_sys;
147
148 /* Values used as flags */
149
150=== modified file 'storage/innobase/include/log0log.ic'
151--- storage/innobase/include/log0log.ic 2013-08-02 09:40:55 +0000
152+++ storage/innobase/include/log0log.ic 2014-06-11 13:20:55 +0000
153@@ -459,3 +459,24 @@
154 }
155 }
156 #endif /* !UNIV_HOTBACKUP */
157+
158+/****************************************************************//**
159+Safely reads the log_sys->tracked_lsn value. Uses atomic operations
160+if available, otherwise this field is protected with the log system
161+mutex. The writer counterpart function is log_set_tracked_lsn() in
162+log0online.c.
163+
164+@return log_sys->tracked_lsn value. */
165+UNIV_INLINE
166+ib_uint64_t
167+log_get_tracked_lsn(void)
168+/*=====================*/
169+{
170+#ifdef HAVE_ATOMIC_BUILTINS_64
171+ return os_atomic_increment_uint64(&log_sys->tracked_lsn, 0);
172+#else
173+ ut_ad(mutex_own(&(log_sys->mutex)));
174+ return log_sys->tracked_lsn;
175+#endif
176+}
177+
178
179=== modified file 'storage/innobase/log/log0log.c'
180--- storage/innobase/log/log0log.c 2013-12-05 08:07:26 +0000
181+++ storage/innobase/log/log0log.c 2014-06-11 13:20:55 +0000
182@@ -215,25 +215,6 @@
183 }
184
185 /****************************************************************//**
186-Safely reads the log_sys->tracked_lsn value. Uses atomic operations
187-if available, otherwise this field is protected with the log system
188-mutex. The writer counterpart function is log_set_tracked_lsn() in
189-log0online.c.
190-
191-@return log_sys->tracked_lsn value. */
192-UNIV_INLINE
193-ib_uint64_t
194-log_get_tracked_lsn()
195-{
196-#ifdef HAVE_ATOMIC_BUILTINS_64
197- return os_atomic_increment_uint64(&log_sys->tracked_lsn, 0);
198-#else
199- ut_ad(mutex_own(&(log_sys->mutex)));
200- return log_sys->tracked_lsn;
201-#endif
202-}
203-
204-/****************************************************************//**
205 Checks if the log groups have a big enough margin of free space in
206 so that a new log entry can be written without overwriting log data
207 that is not read by the changed page bitmap thread.
208
209=== modified file 'storage/innobase/log/log0online.c'
210--- storage/innobase/log/log0online.c 2014-02-14 07:44:36 +0000
211+++ storage/innobase/log/log0online.c 2014-06-11 13:20:55 +0000
212@@ -1202,6 +1202,9 @@
213
214 bmp_tree_node = (ib_rbt_node_t*)
215 rbt_next(log_bmp_sys->modified_pages, bmp_tree_node);
216+
217+ DBUG_EXECUTE_IF("bitmap_page_2_write_error",
218+ DBUG_SET("+d,bitmap_page_write_error"););
219 }
220
221 rbt_reset(log_bmp_sys->modified_pages);

Subscribers

People subscribed via source and target branches