Blog 迁移到 http://ikarishinjieva.github.io/tachikoma-blog/.

这个repo留给以前的外链接.

测试一下Mysql 5.6.17对临时表的复制

参考资料

1. Percona这篇08年的blog Can MySQL temporary tables be made safe for statement-based replication?, 是对于Mysql 5.1这方面的测试. 但根据对Mysql 5.6的相关测试, 其结论已经不适用. 其方法可供参考

2. Mysql Manual 对于临时表复制的讨论, 其中一些重要的描述列在下面:

3. Safe slave shutdown when using temporary tables

4. By default, all temporary tables are replicated; this happens whether or not there are any matching --replicate-do-db, --replicate-do-table, or --replicate-wild-do-table options in effect
5. the --replicate-ignore-table and --replicate-wild-ignore-table options are honored for temporary tables

概述

总共做了两个测试:

1. Mysql Manual中”Safe slave shutdown when using temporary tables”一节, 验证为何需要如此安全关闭slave
2. 验证在复制临时表时, master意外crash, 是否会造成slave上的资源泄露

每个测试后都有结论

测试一

针对Mysql Manual提到的”Safe slave shutdown when using temporary tables”, 重现一下:

1
2
3
4
5
6
7
8
9
10
11

#准备环境, 断开复制
mysql-master> select @@binlog_format;
+-----------------+
| @@binlog_format |
+-----------------+
| MIXED           |
+-----------------+
1 row in set (0.02 sec)

mysql-slave> stop slave;
Query OK, 0 rows affected (0.03 sec)

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22

#在master上构造使用临时表的两个transaction
mysql-master> flush logs;
Query OK, 0 rows affected (0.02 sec)

mysql-master> begin;
Query OK, 0 rows affected (0.00 sec)

mysql-master> create temporary table test.t(t int);
Query OK, 0 rows affected (0.01 sec)

mysql-master> commit;
Query OK, 0 rows affected (0.00 sec)

mysql-master> begin;
Query OK, 0 rows affected (0.00 sec)

mysql-master> insert into test.a select t from test.t;
Query OK, 0 rows affected (0.00 sec)
Records: 0  Duplicates: 0  Warnings: 0

mysql-master> commit;
Query OK, 0 rows affected (0.00 sec)

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52

#查看master的binlog
mysql-master> show binlog events in "mysql-bin.000036" \G
*************************** 1. row ***************************
   Log_name: mysql-bin.000036
        Pos: 4
 Event_type: Format_desc
  Server_id: 1
End_log_pos: 120
       Info: Server ver: 5.6.17-debug-log, Binlog ver: 4
*************************** 2. row ***************************
   Log_name: mysql-bin.000036
        Pos: 120
 Event_type: Query
  Server_id: 1
End_log_pos: 195
       Info: BEGIN
*************************** 3. row ***************************
   Log_name: mysql-bin.000036
        Pos: 195
 Event_type: Query
  Server_id: 1
End_log_pos: 301
       Info: create temporary table test.t(t int)
*************************** 4. row ***************************
   Log_name: mysql-bin.000036
        Pos: 301
 Event_type: Query
  Server_id: 1
End_log_pos: 370
       Info: COMMIT
*************************** 5. row ***************************
   Log_name: mysql-bin.000036
        Pos: 370
 Event_type: Query
  Server_id: 1
End_log_pos: 445
       Info: BEGIN
*************************** 6. row ***************************
   Log_name: mysql-bin.000036
        Pos: 445
 Event_type: Query
  Server_id: 1
End_log_pos: 554
       Info: insert into test.a select t from test.t
*************************** 7. row ***************************
   Log_name: mysql-bin.000036
        Pos: 554
 Event_type: Query
  Server_id: 1
End_log_pos: 623
       Info: COMMIT
7 rows in set (0.00 sec)

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19

#开启复制,让复制在两个transaction之间中断

mysql-slave> start slave until master_log_file='mysql-bin.000036', master_log_pos=370;
Query OK, 0 rows affected, 1 warning (0.02 sec)

mysql-slave> show slave status\G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
...
              Master_Log_File: mysql-bin.000036
          Read_Master_Log_Pos: 623
...
        Relay_Master_Log_File: mysql-bin.000036
             Slave_IO_Running: Yes
            Slave_SQL_Running: No
...
          Exec_Master_Log_Pos: 370
...
1 row in set (0.00 sec)

1
2
3
4
5
6
7
8
9
10
11

#查看slave正在使用的临时表, 并重启slave

mysql-slave> show status like '%temp%';                      
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| Slave_open_temp_tables | 1     |
+------------------------+-------+
1 row in set (0.01 sec)

slave> service mysqld restart

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23

#验证slave status


mysql-slave> show slave status\G
*************************** 1. row ***************************
...
              Master_Log_File: mysql-bin.000036
          Read_Master_Log_Pos: 623
...
        Relay_Master_Log_File: mysql-bin.000036
             Slave_IO_Running: Yes
            Slave_SQL_Running: No
...
                   Last_Errno: 1146
                   Last_Error: Error 'Table 'test.t' doesn't exist' on query. Default database: ''. Query: 'insert into test.a select t from test.t'
...
          Exec_Master_Log_Pos: 370
...
               Last_SQL_Errno: 1146
               Last_SQL_Error: Error 'Table 'test.t' doesn't exist' on query. Default database: ''. Query: 'insert into test.a select t from test.t'
  Replicate_Ignore_Server_Ids:
...
1 row in set (0.00 sec)

结论: 使用临时表时, slave并不保证crash-safe, 而且若在连续的transaction中复用同一个临时表, 完全没办法安全修复.

测试2

对于一个create temporary table, 已知drop temporary table会在session结束时写进binlog. 那么如果master意外退出, 是不是会对slave造成资源泄露? 比如不释放文件句柄

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16

#准备master环境
mysql-master> select @@binlog_format;
+-----------------+
| @@binlog_format |
+-----------------+
| MIXED           |
+-----------------+
1 row in set (0.00 sec)

mysql-master> select @@gtid_mode;
+-------------+
| @@gtid_mode |
+-------------+
| OFF         |
+-------------+
1 row in set (0.00 sec)

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18

#检查slave上的资源
mysql-slave> show status like '%open%';
+----------------------------+-------+
| Variable_name              | Value |
+----------------------------+-------+
...
| Innodb_num_open_files      | 6     |
| Open_files                 | 22    |
| Open_streams               | 0     |
| Open_table_definitions     | 70    |
| Open_tables                | 63    |
| Opened_files               | 164   |
| Opened_table_definitions   | 0     |
| Opened_tables              | 0     |
| Slave_open_temp_tables     | 0     |
...
+----------------------------+-------+
14 rows in set (0.00 sec)

1
2
3
4
5
6
7
8
9
10
11

#在master上创建5张临时表
mysql-master> create temporary table test.t1 (t int);create temporary table test.t2 (t int);create temporary table test.t3 (t int);create temporary table test.t4 (t int);create temporary table test.t5 (t int);
Query OK, 0 rows affected (0.02 sec)

Query OK, 0 rows affected (0.00 sec)

Query OK, 0 rows affected (0.01 sec)

Query OK, 0 rows affected (0.01 sec)

Query OK, 0 rows affected (0.01 sec)

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18

#检查slave上的资源
mysql-slave> show status like '%open%';
+----------------------------+-------+
| Variable_name              | Value |
+----------------------------+-------+
...
| Innodb_num_open_files      | 11    |
| Open_files                 | 22    |
| Open_streams               | 0     |
| Open_table_definitions     | 70    |
| Open_tables                | 63    |
| Opened_files               | 179   |
| Opened_table_definitions   | 0     |
| Opened_tables              | 0     |
| Slave_open_temp_tables     | 5     |
...
+----------------------------+-------+
14 rows in set (0.00 sec)

1
2
3

#引发master故障, 重启master库
master> pkill -9 mysqld
master> /opt/mysql/bin/mysqld_safe &

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25

#重启slave复制, 检查slave上的资源

mysql-slave> stop slave io_thread;
Query OK, 0 rows affected (0.02 sec)

mysql-slave> start slave io_thread;
Query OK, 0 rows affected (0.00 sec)

mysql-slave> show status like '%open%';
+----------------------------+-------+
| Variable_name              | Value |
+----------------------------+-------+
...
| Innodb_num_open_files      | 6     |
| Open_files                 | 22    |
| Open_streams               | 0     |
| Open_table_definitions     | 70    |
| Open_tables                | 63    |
| Opened_files               | 209   |
| Opened_table_definitions   | 0     |
| Opened_tables              | 0     |
| Slave_open_temp_tables     | 5     |
...
+----------------------------+-------+
14 rows in set (0.00 sec)

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29

#在master上再次创建5张临时表, 检查slave上的资源
mysql-master> create temporary table test.t1 (t int);create temporary table test.t2 (t int);create temporary table test.t3 (t int);create temporary table test.t4 (t int);create temporary table test.t5 (t int);
Query OK, 0 rows affected (0.09 sec)

Query OK, 0 rows affected (0.00 sec)

Query OK, 0 rows affected (0.02 sec)

Query OK, 0 rows affected (0.00 sec)

Query OK, 0 rows affected (0.00 sec)


mysql-slave> show status like '%open%';
+----------------------------+-------+
| Variable_name              | Value |
+----------------------------+-------+
...
| Innodb_num_open_files      | 11    |
| Open_files                 | 22    |
| Open_streams               | 0     |
| Open_table_definitions     | 70    |
| Open_tables                | 63    |
| Opened_files               | 224   |
| Opened_table_definitions   | 0     |
| Opened_tables              | 0     |
| Slave_open_temp_tables     | 10    |
...
+----------------------------+-------+

结论: 复制临时表时,slave上消耗的资源, Innodb_num_open_files会及时回收,也就是说实际消耗的系统资源被及时回收. 但Slave_open_temp_tables会虚高不下,按照Mysql Manual中”Safe slave shutdown when using temporary tables”的叙述, 用Slave_open_temp_tables来判断关闭server的时机时, 会出现判断失误.

在Mysql 5.6.17上测试临时表生成的binlog

测试用例

(现在用的jekyll对table显示有点问题, 请意会…)

测试结论

1. create temporary table 产生的binlog

结论: 可以看到statement和mixed模式生成的binlog一样. 而row模式中, 因为临时表并没有产生实际影响, 所以没有产生额外的binlog event

2. create temporary table 产生的binlog (mysqlbinlog)

show binlog events 的输出只是摘要了binlog的内容, mysqlbinlog的输出才能精准的显示binlog的内容

重做row模式和statement模式的测试, 可以看到row模式虽然不产生create temporary table, 但是会产生一个drop temporary table if exists; statement模式产生create temporary table, 但不产生drop temporary table

3. 临时表对非临时表数据产生影响时, 产生的binlog

可以看到row模式会产生非临时表的行日志.statement模式会严格记录语句.

4. 临时表对非临时表数据产生影响,并rollback时, 产生的binlog

可以看到row模式下, rollback不会对binlog产生影响. 在statement模式下, 所有的语句都会如实反映在binlog里, 并进行rollback

5. 多session同时创建临时表, 产生的binlog

不同于典型DDL, create temporary table记在transaction中.

由session结束产生的drop temporary table则类似于典型的DDL.

6. 开启enforce-gtid-consistency时, create temporary table

开启enforce-gtid-consistency时, 在transaction内创建临时表会得到warning:

1

ERROR 1787 (HY000): When @@GLOBAL.ENFORCE_GTID_CONSISTENCY = 1, the statements CREATE TEMPORARY TABLE and DROP TEMPORARY TABLE can be executed in a non-transactional context only, and require that AUTOCOMMIT = 1.

元日志

1.1

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22

mysql> select @@gtid_mode;
+-------------+
| @@gtid_mode |
+-------------+
| OFF         |
+-------------+
1 row in set (0.00 sec)

mysql> set @@session.binlog_format="row";
Query OK, 0 rows affected (0.00 sec)

mysql> flush logs;
Query OK, 0 rows affected (0.00 sec)

mysql> begin;
Query OK, 0 rows affected (0.00 sec)

mysql> create temporary table test.t (t int);
Query OK, 0 rows affected (0.01 sec)

mysql> commit;
Query OK, 0 rows affected (0.00 sec)

1
2
3
4
5
6
7
8

mysql> show binlog events in 'mysql-bin.000014' \G
*************************** 1. row ***************************
   Log_name: mysql-bin.000014
        Pos: 4
 Event_type: Format_desc
  Server_id: 1
End_log_pos: 120
       Info: Server ver: 5.6.17-debug-log, Binlog ver: 4

1.2

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23

mysql> select @@gtid_mode;

+-------------+
| @@gtid_mode |
+-------------+
| OFF         |
+-------------+
1 row in set (0.00 sec)

mysql> set @@session.binlog_format="statement";
Query OK, 0 rows affected (0.00 sec)

mysql> flush logs;
Query OK, 0 rows affected (0.00 sec)

mysql> begin;
Query OK, 0 rows affected (0.00 sec)

mysql> create temporary table test.t (t int);
Query OK, 0 rows affected (0.01 sec)

mysql> commit;
Query OK, 0 rows affected (0.00 sec)

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30

mysql> show binlog events in 'mysql-bin.000015' \G
*************************** 1. row ***************************
   Log_name: mysql-bin.000015
        Pos: 4
 Event_type: Format_desc
  Server_id: 1
End_log_pos: 120
       Info: Server ver: 5.6.17-debug-log, Binlog ver: 4
*************************** 2. row ***************************
   Log_name: mysql-bin.000015
        Pos: 120
 Event_type: Query
  Server_id: 1
End_log_pos: 195
       Info: BEGIN
*************************** 3. row ***************************
   Log_name: mysql-bin.000015
        Pos: 195
 Event_type: Query
  Server_id: 1
End_log_pos: 302
       Info: create temporary table test.t (t int)
*************************** 4. row ***************************
   Log_name: mysql-bin.000015
        Pos: 302
 Event_type: Query
  Server_id: 1
End_log_pos: 371
       Info: COMMIT
4 rows in set (0.00 sec)

1.3

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27

mysql> select @@gtid_mode;
+-------------+
| @@gtid_mode |
+-------------+
| OFF         |
+-------------+
1 row in set (0.01 sec)

mysql> select @@binlog_format;
+-----------------+
| @@binlog_format |
+-----------------+
| MIXED           |
+-----------------+
1 row in set (0.01 sec)

mysql> flush logs;
Query OK, 0 rows affected (0.02 sec)

mysql> begin;
Query OK, 0 rows affected (0.00 sec)

mysql> create temporary table test.t (t int);
Query OK, 0 rows affected (0.05 sec)

mysql> commit;
Query OK, 0 rows affected (0.00 sec)

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29

mysql> show binlog events in 'mysql-bin.000011'\G
*************************** 1. row ***************************
   Log_name: mysql-bin.000011
        Pos: 4
 Event_type: Format_desc
  Server_id: 1
End_log_pos: 120
       Info: Server ver: 5.6.17-debug-log, Binlog ver: 4
*************************** 2. row ***************************
   Log_name: mysql-bin.000011
        Pos: 120
 Event_type: Query
  Server_id: 1
End_log_pos: 195
       Info: BEGIN
*************************** 3. row ***************************
   Log_name: mysql-bin.000011
        Pos: 195
 Event_type: Query
  Server_id: 1
End_log_pos: 302
       Info: create temporary table test.t (t int)
*************************** 4. row ***************************
   Log_name: mysql-bin.000011
        Pos: 302
 Event_type: Query
  Server_id: 1
End_log_pos: 371
       Info: COMMIT

2.1

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27

[root@localhost data]# /opt/mysql/bin/mysqlbinlog --base64-output=decode-rows mysql-bin.000014
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#140612  4:38:58 server id 1  end_log_pos 120 CRC32 0xb935033a    Start: binlog v 4, server v 5.6.17-debug-log created 140612  4:38:58
# at 120
#140612  4:42:30 server id 1  end_log_pos 257 CRC32 0x8f9ccf27    Query   thread_id=2 exec_time=0 error_code=0
SET TIMESTAMP=1402548150/*!*/;
SET @@session.pseudo_thread_id=2/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1075838976/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=33/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
DROP TEMPORARY TABLE IF EXISTS `test`.`t` /* generated by server */
/*!*/;
# at 257
#140612  4:42:51 server id 1  end_log_pos 304 CRC32 0x62766a77    Rotate to mysql-bin.000015  pos: 4
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

2.2

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36

[root@localhost data]# /opt/mysql/bin/mysqlbinlog --base64-output=decode-rows mysql-bin.000015
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#140612  4:42:51 server id 1  end_log_pos 120 CRC32 0xc3707cb7    Start: binlog v 4, server v 5.6.17-debug-log created 140612  4:42:51
# Warning: this binlog is either in use or was not closed properly.
# at 120
#140612  4:42:58 server id 1  end_log_pos 195 CRC32 0x2fd0ed95    Query   thread_id=2 exec_time=0 error_code=0
SET TIMESTAMP=1402548178/*!*/;
SET @@session.pseudo_thread_id=2/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1075838976/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=33/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 195
#140612  4:42:58 server id 1  end_log_pos 302 CRC32 0xfc742b50    Query   thread_id=2 exec_time=0 error_code=0
SET TIMESTAMP=1402548178/*!*/;
create temporary table test.t (t int)
/*!*/;
# at 302
#140612  4:43:00 server id 1  end_log_pos 371 CRC32 0x25648832    Query   thread_id=2 exec_time=0 error_code=0
SET TIMESTAMP=1402548180/*!*/;
COMMIT
/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

3.1

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29

mysql> select @@gtid_mode;
+-------------+
| @@gtid_mode |
+-------------+
| OFF         |
+-------------+
1 row in set (0.00 sec)

mysql> set @@session.binlog_format="row";
Query OK, 0 rows affected (0.00 sec)

mysql> flush logs;
Query OK, 0 rows affected (0.01 sec)

mysql> begin;
Query OK, 0 rows affected (0.00 sec)

mysql>  create temporary table test.t (t int);
Query OK, 0 rows affected (0.01 sec)

mysql> insert into test.t values(2);
Query OK, 1 row affected (0.00 sec)

mysql> insert into test.a select t from test.t;
Query OK, 1 row affected (0.00 sec)
Records: 1  Duplicates: 0  Warnings: 0

mysql> commit;
Query OK, 0 rows affected (0.01 sec)

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36

[root@localhost data]# /opt/mysql/bin/mysqlbinlog --base64-output=decode-rows -v mysql-bin.000020
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#140612  6:02:38 server id 1  end_log_pos 120 CRC32 0x31b6357c    Start: binlog v 4, server v 5.6.17-debug-log created 140612  6:02:38
# Warning: this binlog is either in use or was not closed properly.
# at 120
#140612  6:02:53 server id 1  end_log_pos 188 CRC32 0x23bceabc    Query   thread_id=6 exec_time=0 error_code=0
SET TIMESTAMP=1402552973/*!*/;
SET @@session.pseudo_thread_id=6/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1075838976/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=33/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 188
#140612  6:02:53 server id 1  end_log_pos 232 CRC32 0x1a87cc74    Table_map: `test`.`a` mapped to number 70
# at 232
#140612  6:02:53 server id 1  end_log_pos 272 CRC32 0xf0c862fb    Write_rows: table id 70 flags: STMT_END_F
### INSERT INTO `test`.`a`
### SET
###   @1=2
# at 272
#140612  6:02:55 server id 1  end_log_pos 303 CRC32 0xb2f66e82    Xid = 92
COMMIT/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

3.2

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29

mysql> select @@gtid_mode;
+-------------+
| @@gtid_mode |
+-------------+
| OFF         |
+-------------+
1 row in set (0.00 sec)

mysql> set @@session.binlog_format="statement";
Query OK, 0 rows affected (0.00 sec)

mysql> flush logs;
Query OK, 0 rows affected (0.00 sec)

mysql> begin;
Query OK, 0 rows affected (0.00 sec)

mysql> create temporary table test.t (t int);
Query OK, 0 rows affected (0.01 sec)

mysql> insert into test.t values(3);
Query OK, 1 row affected (0.00 sec)

mysql> insert into test.a select t from test.t;
Query OK, 1 row affected (0.00 sec)
Records: 1  Duplicates: 0  Warnings: 0

mysql> commit;
Query OK, 0 rows affected (0.00 sec)

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44

[root@localhost data]# /opt/mysql/bin/mysqlbinlog --base64-output=decode-rows mysql-bin.000021
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#140612  6:07:43 server id 1  end_log_pos 120 CRC32 0xbcd985c3    Start: binlog v 4, server v 5.6.17-debug-log created 140612  6:07:43
# Warning: this binlog is either in use or was not closed properly.
# at 120
#140612  6:07:50 server id 1  end_log_pos 195 CRC32 0xf5ea27f6    Query   thread_id=7 exec_time=0 error_code=0
SET TIMESTAMP=1402553270/*!*/;
SET @@session.pseudo_thread_id=7/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1075838976/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=33/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 195
#140612  6:07:50 server id 1  end_log_pos 302 CRC32 0xa52fbe74    Query   thread_id=7 exec_time=0 error_code=0
SET TIMESTAMP=1402553270/*!*/;
create temporary table test.t (t int)
/*!*/;
# at 302
#140612  6:07:55 server id 1  end_log_pos 400 CRC32 0x037b8754    Query   thread_id=7 exec_time=0 error_code=0
SET TIMESTAMP=1402553275/*!*/;
insert into test.t values(3)
/*!*/;
# at 400
#140612  6:07:59 server id 1  end_log_pos 509 CRC32 0xa1dc2124    Query   thread_id=7 exec_time=0 error_code=0
SET TIMESTAMP=1402553279/*!*/;
insert into test.a select t from test.t
/*!*/;
# at 509
#140612  6:08:01 server id 1  end_log_pos 540 CRC32 0xf7e3aa59    Xid = 102
COMMIT/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

4.1

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37

mysql> select @@gtid_mode;
+-------------+
| @@gtid_mode |
+-------------+
| OFF         |
+-------------+
1 row in set (0.00 sec)

mysql> set @@session.binlog_format="row";
Query OK, 0 rows affected (0.00 sec)

mysql> flush logs;
Query OK, 0 rows affected (0.00 sec)

mysql> begin;
Query OK, 0 rows affected (0.00 sec)

mysql> create temporary table test.t (t int);
Query OK, 0 rows affected (0.01 sec)

mysql> insert into test.t values(5);
Query OK, 1 row affected (0.01 sec)

mysql> insert into test.a select t from test.t;
Query OK, 1 row affected (0.00 sec)
Records: 1  Duplicates: 0  Warnings: 0

mysql> rollback;
Query OK, 0 rows affected, 1 warning (0.00 sec)

mysql> show warnings;
+---------+------+-----------------------------------------------------------------+
| Level   | Code | Message                                                         |
+---------+------+-----------------------------------------------------------------+
| Warning | 1751 | The creation of some temporary tables could not be rolled back. |
+---------+------+-----------------------------------------------------------------+
1 row in set (0.00 sec)

1
2
3
4
5
6
7
8
9
10
11
12
13

[root@localhost data]# /opt/mysql/bin/mysqlbinlog --base64-output=decode-rows mysql-bin.000024
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#140612  6:25:58 server id 1  end_log_pos 120 CRC32 0x8f8f4247    Start: binlog v 4, server v 5.6.17-debug-log created 140612  6:25:58
# Warning: this binlog is either in use or was not closed properly.
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

4.2

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37

mysql> select @@gtid_mode;
+-------------+
| @@gtid_mode |
+-------------+
| OFF         |
+-------------+
1 row in set (0.00 sec)

mysql> set @@session.binlog_format="statement";
Query OK, 0 rows affected (0.00 sec)

mysql> flush logs;
Query OK, 0 rows affected (0.01 sec)

mysql> begin;
Query OK, 0 rows affected (0.00 sec)

mysql> create temporary table test.t (t int);
Query OK, 0 rows affected (0.01 sec)

mysql> insert into test.t values(4);
Query OK, 1 row affected (0.00 sec)

mysql> insert into test.a select t from test.t;
Query OK, 1 row affected (0.00 sec)
Records: 1  Duplicates: 0  Warnings: 0

mysql> rollback;
Query OK, 0 rows affected, 1 warning (0.00 sec)

mysql> show warnings;
+---------+------+-----------------------------------------------------------------+
| Level   | Code | Message                                                         |
+---------+------+-----------------------------------------------------------------+
| Warning | 1751 | The creation of some temporary tables could not be rolled back. |
+---------+------+-----------------------------------------------------------------+
1 row in set (0.00 sec)

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46

[root@localhost data]# /opt/mysql/bin/mysqlbinlog --base64-output=decode-rows mysql-bin.000023
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#140612  6:22:03 server id 1  end_log_pos 120 CRC32 0x8ebd7db6    Start: binlog v 4, server v 5.6.17-debug-log created 140612  6:22:03
# Warning: this binlog is either in use or was not closed properly.
# at 120
#140612  6:22:13 server id 1  end_log_pos 195 CRC32 0x2ef37ea7    Query   thread_id=9 exec_time=0 error_code=0
SET TIMESTAMP=1402554133/*!*/;
SET @@session.pseudo_thread_id=9/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1075838976/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=33/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 195
#140612  6:22:13 server id 1  end_log_pos 302 CRC32 0xc642d4a1    Query   thread_id=9 exec_time=0 error_code=0
SET TIMESTAMP=1402554133/*!*/;
create temporary table test.t (t int)
/*!*/;
# at 302
#140612  6:22:17 server id 1  end_log_pos 400 CRC32 0x076861c4    Query   thread_id=9 exec_time=0 error_code=0
SET TIMESTAMP=1402554137/*!*/;
insert into test.t values(4)
/*!*/;
# at 400
#140612  6:22:21 server id 1  end_log_pos 509 CRC32 0x2e43db50    Query   thread_id=9 exec_time=0 error_code=0
SET TIMESTAMP=1402554141/*!*/;
insert into test.a select t from test.t
/*!*/;
# at 509
#140612  6:22:24 server id 1  end_log_pos 580 CRC32 0xdefa8f3d    Query   thread_id=9 exec_time=0 error_code=0
SET TIMESTAMP=1402554144/*!*/;
ROLLBACK
/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

5.1

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32

mysql-session1> set @@session.binlog_format="statement";
Query OK, 0 rows affected (0.00 sec)

mysql-session2> set @@session.binlog_format="statement";
Query OK, 0 rows affected (0.00 sec)

mysql-session1> flush logs;
Query OK, 0 rows affected (0.00 sec)

mysql-session1> begin;
Query OK, 0 rows affected (0.00 sec)

mysql-session1> create temporary table test.t(t int);
Query OK, 0 rows affected (0.01 sec)

mysql-session2> begin;
Query OK, 0 rows affected (0.00 sec)

mysql-session2> create temporary table test.t(t int);
Query OK, 0 rows affected (0.02 sec)

mysql-session1> commit;
Query OK, 0 rows affected (0.00 sec)

mysql-session2> commit;
Query OK, 0 rows affected (0.00 sec)

mysql-session1> exit;
Bye

mysql-session2> exit;
Bye

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66

[root@localhost data]# /opt/mysql/bin/mysqlbinlog --base64-output=decode-rows mysql-bin.000028
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#140612  6:45:24 server id 1  end_log_pos 120 CRC32 0x0ad8e5a0    Start: binlog v 4, server v 5.6.17-debug-log created 140612  6:45:24
# Warning: this binlog is either in use or was not closed properly.
# at 120
#140612  6:45:58 server id 1  end_log_pos 195 CRC32 0x59b581d0    Query   thread_id=14    exec_time=0 error_code=0
SET TIMESTAMP=1402555558/*!*/;
SET @@session.pseudo_thread_id=14/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1075838976/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=33/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 195
#140612  6:45:58 server id 1  end_log_pos 301 CRC32 0x274004b9    Query   thread_id=14    exec_time=0 error_code=0
SET TIMESTAMP=1402555558/*!*/;
create temporary table test.t(t int)
/*!*/;
# at 301
#140612  6:46:54 server id 1  end_log_pos 370 CRC32 0x9f2ca921    Query   thread_id=14    exec_time=0 error_code=0
SET TIMESTAMP=1402555614/*!*/;
COMMIT
/*!*/;
# at 370
#140612  6:46:17 server id 1  end_log_pos 445 CRC32 0x3f1094c3    Query   thread_id=16    exec_time=0 error_code=0
SET TIMESTAMP=1402555577/*!*/;
SET @@session.pseudo_thread_id=16/*!*/;
BEGIN
/*!*/;
# at 445
#140612  6:46:17 server id 1  end_log_pos 551 CRC32 0x754cae85    Query   thread_id=16    exec_time=0 error_code=0
SET TIMESTAMP=1402555577/*!*/;
create temporary table test.t(t int)
/*!*/;
# at 551
#140612  6:46:58 server id 1  end_log_pos 620 CRC32 0x73eb6f5a    Query   thread_id=16    exec_time=0 error_code=0
SET TIMESTAMP=1402555618/*!*/;
COMMIT
/*!*/;
# at 620
#140612  6:47:22 server id 1  end_log_pos 733 CRC32 0xb4c3b1c0    Query   thread_id=14    exec_time=0 error_code=0
use `test`/*!*/;
SET TIMESTAMP=1402555642/*!*/;
SET @@session.pseudo_thread_id=14/*!*/;
DROP /*!40005 TEMPORARY */ TABLE IF EXISTS `t`
/*!*/;
# at 733
#140612  6:47:38 server id 1  end_log_pos 846 CRC32 0x1287fb24    Query   thread_id=16    exec_time=0 error_code=0
SET TIMESTAMP=1402555658/*!*/;
SET @@session.pseudo_thread_id=16/*!*/;
DROP /*!40005 TEMPORARY */ TABLE IF EXISTS `t`
/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

6.1

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21

mysql> select @@GTID_MODE;
+-------------+
| @@GTID_MODE |
+-------------+
| ON          |
+-------------+
1 row in set (0.00 sec)

mysql> select @@enforce_gtid_consistency;
+----------------------------+
| @@enforce_gtid_consistency |
+----------------------------+
|                          1 |
+----------------------------+
1 row in set (0.00 sec)

mysql> begin;
Query OK, 0 rows affected (0.00 sec)

mysql> create temporary table test.t(t int);
ERROR 1787 (HY000): When @@GLOBAL.ENFORCE_GTID_CONSISTENCY = 1, the statements CREATE TEMPORARY TABLE and DROP TEMPORARY TABLE can be executed in a non-transactional context only, and require that AUTOCOMMIT = 1.

最近读了mysql table_cache部分的一些代码.

首先推荐这篇导读, 写的比较详尽. 不对其中已有的部分进行重复, 仅记录自己的一些理解.

最简单的功能

叫做table_cache, 就是对table做擦车(cache).

其中table是指的mysql打开的表的描述结构(descriptor)(TABLE), 简单理解就是mysql要操作一张表时, 就会先打开其descriptor, 打开后读取其中信息, 然后进行操作.

为了快速访问, cache 往往类似于 Hash. table_cache 的 key 是

db_name + table_name

table_cache 的 value 是 descriptor 的集合, 即 Table_cache_element.

value 是 descriptor 的集合而不是 descriptor, 是因为对于同一张表, 在cache中同时会打开多个 descriptor

额外一提, table_cache是按线程号分桶的, 参看Table_cache_manager

进一步, 留下被回收的元素

传统擦车, 不用的元素就直接回收了. table_cache暂存了不用的元素, 提高命中率.

可以看到Table_cache_element一共两个列表:

• used_tables
• free_tables

进一步, 抽出共同的部分

同一张表的多个 descriptor, 会有公共部分, 抽出这些公共部分, 能有效节省资源.

比如mem_root (个人称之为受管内存区), 此内存区管理着跟某表相关的一些数据结构, 且受mysqld的管制. 如果同一张表的每个 descriptor 都独立管理一篇内存, 会引起不必要的浪费.

抽出的公共部分称为TABLE_SHARE

进一步, 公共部分也得擦车

TABLE_SHARE 也被擦车了, 其被回收的元素跟TABLE一样也被擦车了.

擦车的步骤

简述擦车的步骤

1. 在cache中查找TABLE
2. 如果找到TABLE, 则成功
3. 在cache中查找TABLE_SHARE
4. 如果找不到TABLE_SHARE, 则生成一个
5. 根据TABLE_SHARE, 生成一个TABLE
6. 维护好cache

如果找不到TABLE_SHARE

参看get_table_share_with_discover

如果内存中找不到TABLE_SHARE, 则向存储引擎查询, 如果存储引擎可以提供, 则进行discover

关于死锁

table_cache 里有很多代码是关于死锁的处理, 其一个主要原因是因为 mysql 分为了sql层和存储引擎层, MDL的死锁检测限于sql层, 存储引擎层自带死锁检测, 但一个死锁如果跨过两层, 则需要特殊处理

并没找到特别好的对PREVIOUS_GTIDS_LOG_EVENT格式的描述, 自己写一个

据下面这个例子, 是mysqlbinlog的分析结果

# at 120
#140417 15:50:36 server id 904898000  end_log_pos 311 CRC32 0x311ec069
# Position  Timestamp   Type   Master ID        Size      Master Pos    Flags
#       78 cc 87 4f 53   23   d0 a5 ef 35   bf 00 00 00   37 01 00 00   00 00
#       8b 04 00 00 00 00 00 00 00  7e 23 40 1a c6 03 11 e3 |................|
#       9b 8e 13 5e 10 e6 a0 5c fb  01 00 00 00 00 00 00 00 |................|
#       ab 01 00 00 00 00 00 00 00  06 00 00 00 00 00 00 00 |................|
#       bb 81 86 fc 1e c5 ff 11 e3  8d f9 e6 6c cf 50 db 66 |...........l.P.f|
#       cb 01 00 00 00 00 00 00 00  01 00 00 00 00 00 00 00 |................|
#       db 0c 00 00 00 00 00 00 00  a6 ce 32 8c c6 02 11 e3 |..........2.....|
#       eb 8e 0d e6 6c cf 50 db 66  01 00 00 00 00 00 00 00 |...l.P.f........|
#       fb 01 00 00 00 00 00 00 00  07 00 00 00 00 00 00 00 |................|
#      10b b7 00 99 20 c6 01 11 e3  8e 07 5e 10 e6 a0 5c fb |................|
#      11b 01 00 00 00 00 00 00 00  01 00 00 00 00 00 00 00 |................|
#      12b 07 00 00 00 00 00 00 00  69 c0 1e 31             |........i..1|
#      Previous-GTIDs
# 7e23401a-c603-11e3-8e13-5e10e6a05cfb:1-5,
# 8186fc1e-c5ff-11e3-8df9-e66ccf50db66:1-11,
# a6ce328c-c602-11e3-8e0d-e66ccf50db66:1-6,
# b7009920-c601-11e3-8e07-5e10e6a05cfb:1-6

从78-8a的位置, 是Binlog Event header, 参看这里

最后四个字节, (69 c0 1e 31) 是checksum, 与参数 binlog-checksum 有关

中间的部分, 是gtid的数据区, 格式如下:

在MDL源码中有一段MDL_map_partition中对锁的过渡有点意思, 拿出来分析一下

场景

MDL_map_partition是容纳MDL_lock的一个容器, MDL_lock可以简单的理解为一种锁.

那么场景问题是现在我要从锁容器C中查找一个锁L并加锁L, 怎样做到多线程安全

场景中C上有保护C的锁A (容器锁), L上的锁为B (成员锁) (此处做了简化, 实际上MDL_lock并不是一个锁, 而是类似于条件变量, 而锁B是保护L的锁. 此处将L简化为一把锁)

分析1

最简单的方法, 就是A加锁, B加锁, A解锁. 这种方法肯定不会有错, 但是并发性上会出现问题. 比如以下场景

1. 线程T1持有B
2. 线程T2正在容器中查找B.
3. 线程T3在同一个容器中查找另外一个MDL_lock

T2先将A加锁, 加锁B时, 由于T1持有B, T2被阻塞; T3在同一个容器中查找另一个不相关的成员, 先要加锁A, A被T2持有, T3被阻塞

因此, 这种做法的并发性很差

分析2

提高并发性的关键是将A锁过渡到B锁, 比如这样: A加锁, 查找B, A解锁, B加锁.

这种方法解决了并发性, 但显而易见形成了一个无锁区 (从A解锁到B加锁这个区域). 如果在无锁区另一个线程将B销毁或移出容器, 那么后面的B加锁操作就会悲剧

分析3

面对无锁区的问题, 可以试着加version(版本变量)来解决, 规则如下:

• 任何将成员移入/移出容器的情况, 都需要获得容器锁A和成员锁B, 并在元素version上加1
• 对成员的销毁, 需要先将成员移出容器

这样, 查找成员的流程变为:

1. 线程T1, 对A加锁, 找到B, 记录B的version, 记为v1. 对A解锁
2. 线程T2, B销毁或移出容器, 需要获得A和B锁, 对version加1, 记为v2
3. 线程T1, 等到T2释放B锁后, 可获得B锁, 发现v1 != v2, 意味着成员可能在容器中已经被移出或销毁, 则需要重试整个过程

加入version后, 对于销毁成员的场景, 并发性并没有改变 (因为仍然需要同时获得两把锁), 但对于查找成员的场景, 并发性和分析2一样

不幸的是, 这个场景仍然存在问题, 很容易看到其中一个逻辑问题, T1在T2销毁B锁后, 还获得了B锁. 也就是T2不能即刻销毁B锁, 否则所有等待B锁的线程都会悲剧. 那B锁何时能被安全销毁

分析4

要解决分析3的问题, 可以在B上添加引用计数, 细节如下:

• 在成员未被移出容器时, 持有A锁可以对成员引用计数usage_count进行加1, 即在容器中查找成员时, 容器负责对成员的usage_count加1
• 持有B锁可以对自己的解引用计数release_count进行加1, 即使用者在使用完B后, 对B进行解引用
• 如果usage_count == release_count, 则B可以被安全销毁

可以看到usage_count和release_count在分别在不同锁的保护下, 代入分析3的场景, 发现可以解决分析3的问题

还有一些需要说明的边界情况

• 在成员已经被移出容器后, 成员引用计数usage_count不再受A锁保护, 而是受B锁保护. 相当于容器已经不再管理成员的引用计数
• 如何判断”成员已经被移出容器”, 可以在成员上添加状态量is_removed_from_container, 读取此状态需要A锁或B锁, 修改此状态需要A锁和B锁.

Mysql的实现

Mysql的实现和之前的分析大致相同, 给出映射表

实现锁拆分的函数为MDL_map_partition::move_from_hash_to_lock_mutex, 一看就懂

以下都是个人理解, 如有疏漏请斧正 另, 因为理解不深, 将忽略锁级别以及锁共享的细节

MDL

MDL (Metadata lock), 除了正常的Condition var提供的功能外, 还额外提供了 1. 不同的锁级别. 在不冲突的情况下, 允许共享资源 2. 死锁检查和处理 3. 记录等待状态, 是死锁检查的基础

模型

MDL_lock 表示Mysqld中的一个资源(库/表/…) 存储在全局结构 mdl_locks (MDL_map)中, mdl_locks内有m_partitions (锁的分区), 用来分散查找lock时的竞争

MDL_context 为MDL上下文接口, 表示一个资源竞争者, THD实现了这个接口, 即一个Mysqld的线程可以是MDL_lock的资源竞争者

MDL_ticket 表示MDL_lock的许可或请求, 会同时挂在两处:

1. 挂在所属MDL_Context中, 通过MDL_ticket.next_in_context/prev_in_context组织链表
2. 挂在MDL_lock的队列中, 通过MDL_ticket.next_in_lock/prev_in_lock组织链表. MDL_lock的队列分为两种, 一个MDL_ticket可能会挂在其中之一
   • 挂在MDL_lock的等待队列(MDL_lock.m_waiting)中, 表示MDL_ticket的owner (MDL_context)正在等待该资源(MDL_lock)
   • 挂在MDL_lock的已许可队列(MDL_lock.m_granted)中, 表示MDL_ticket的owner (MDL_context)已经获得该资源(MDL_lock)

总结一下, MDL_context和MDL_ticket的关系是一对多, 一个竞争者可以同时申请/获得多个资源的许可; MDL_ticket和MDL_lock的关系是多对一, 可以同时有多个资源许可在竞争一个资源, 或者多个资源许可可以有条件地共享一个资源

如何获得锁

简单分析MDL_context::acquire_lock方法, 其主要流程是

bool MDL_context::acquire_lock(MDL_request *mdl_request, ulong lock_wait_timeout) {
    ...

    try_acquire_lock_impl(...) 
    //尝试不等待立刻获得资源, 如果成功直接返回
    //以下是等待资源的处理
    ...
    lock->m_waiting.add_ticket(ticket) 
    //将一个资源申请`ticket`挂入资源`lock`的等待队列`m_waiting`
    if (lock->needs_notification(ticket)) {
        //如果等待资源时需要通知状态, 则不断轮询并通知
        //将忽略此处的细节
        ...
    } else {
        //等待资源
        //结果可能是获得资源, 或者超时, 或者异常 (比如被死锁检测机制判定死亡)
        //`timed_wait`中的实现是等待COND(条件变量)`m_wait.m_COND_wait_status`
        wait_status= m_wait.timed_wait(...);
    }
    //收尾处理
    m_tickets[mdl_request->duration].push_front(ticket)
    //将资源申请`ticket`挂入`MDL_Context.m_tickets`
    ...
}

记录等待状态

之前提到了记录等待状态, 在MDL_context::acquire_lock方法中可以看到如下代码 (上一节未列出)

bool MDL_context::acquire_lock(MDL_request *mdl_request, ulong lock_wait_timeout) {
    m_wait.reset_status();
    ...
    will_wait_for(ticket); //其中设置了`m_waiting_for`
    if (lock->needs_notification(ticket)) {
        ...
        //等待资源
        wait_status= m_wait.timed_wait(m_owner, &abs_timeout, TRUE,
                                  mdl_request->key.get_wait_state_name());
    } else {
        //等待资源
        wait_status= m_wait.timed_wait(m_owner, &abs_timeout, TRUE,
                                  mdl_request->key.get_wait_state_name());
    }
    done_waiting_for(); //其中清空了`m_waiting_for`
    ...
}

可以看到MDL_context.m_wait是用来等待资源的工具类, 其中进行等待处理, 并记录等待资源的状态/结果.

还有一个MDL_context.m_waiting_for也在记录MDL_context正在进行的资源申请(MDL_ticket), 其正在等待某个资源. 实际上m_waiting_for是冗余的信息, 至于原因源代码中有解释, 此处不冗余说明…

如何释放锁

释放锁, 需要完成下面几个动作:

1. 将ticket从MDL_lock的数据结构上卸下来
2. 调度选择新的锁占有者
3. 将ticket从MDL_context的数据结构上卸下并回收

入口为MDL_context::release_lock

void MDL_context::release_lock(enum_mdl_duration duration, MDL_ticket *ticket) 
{
    ...
    lock->remove_ticket(&MDL_lock::m_granted, ticket) {
        //将`ticket`从`MDL_lock`的数据结构上卸下来
        (this->*list).remove_ticket(ticket);
        ...
        //调度选择新的锁占有者
        reschedule_waiters();
    }()

    //将`ticket`从`MDL_context`的数据结构上卸下并回收
    m_tickets[duration].remove(ticket);
    MDL_ticket::destroy(ticket);
    ...
}

下面说明调度的细节

释放锁时的调度

调度函数的入口是MDL_lock::reschedule_waiters

最简单的调度就是从MDL_lock.m_waiting队列中取出头元素, 直接将资源调度给头元素即可

Mysqld在此基础上添加了一个退让条件: 如果资源连续被高优先级(比如SNW/SNRW/X锁类型)的ticket获得, 那么退让一步, 允许资源间隔被调度给低优先级的ticket防止其饿死.

用MDL_lock::reschedule_waiters的代码说就是, 如果MDL_lock被连续分配给hog_lock_types_bitmap()中定义的高优先级类型的ticket,连续的次数m_hog_lock_count超过max_write_lock_count, 那么开启退让条件, 批准第一个非高优先级的ticket获得资源

死锁检测

死锁检测的入口是MDL_context::find_deadlock, 本身原理很简单, 但源码写的很复杂= =. 先说明原理, 再对应源码

设当前MDL_context为图的一个节点A, 从节点A出发, 找到A的正在等待的资源L(A.m_waiting_for.m_lock)中的m_granted里的每一个MDL_ticket对应的MDL_context B, 表示A正在等待B释放资源L. 在图中A -> B 添加一条有向边

死锁检查的工作就是遍历这张有向图, 检查其是否存在环路

以MDL_context::find_deadlock入口, 展开一些调用来说明代码

(MDL_context::find_deadlock)
while(1) {
    visit_subgraph(visitor) {
        m_waiting_for->accept_visitor(visitor) {
            m_lock->visit_subgraph(this, visitor) {
                ...
            }()
        }()
    }()
    break if no deadlock
    set deadlock victim
    break if deadlock victim is current context
}

可以看到find_deadlock以MDL_context.m_waiting_for.m_lock为起始点, 不断遍历其有向图, 选出victim. 直到 * 没有发现死锁 * 或自己被选为victim

其使用一个visitor (MDL_wait_for_graph_visitor) 贯穿遍历过程, 其记录了遍历的过程

再来看MDL_lock::visit_subgraph, 此函数是以一个MDL_lock为起点, 来遍历依赖图

MDL_lock::visit_subgraph(MDL_ticket *waiting_ticket, MDL_wait_for_graph_visitor *gvisitor) {

    //此处是因为MDL_context.m_waiting_for是冗余信息, 但无法保证更新同步, 带来的额外操作. 忽略此处细节
    if (src_ctx->m_wait.get_status() != MDL_wait::EMPTY) {...}

    //visitor用来记录遍历层次
    //当遍历层次大于MAX_SEARCH_DEPTH(32), 也认为发现死锁
    if (gvisitor->enter_node(src_ctx)) {...}

    //由于现在是以一个资源(`MDL_lock`)为视角, 之后的检查为了效率, 遍历会从两个方向同时进行, 即检查节点的出度方向(`MDL_lock.m_granted`)和节点的入度方向(`MDL_lock.m_waiting`). 


    //为了效率, 死锁检测会先检测距离为1的临近节点, 而先不深度遍历图

    while ((ticket= granted_it++))
    {
      if (ticket->get_ctx() != src_ctx &&
          ticket->is_incompatible_when_granted(waiting_ticket->get_type()) &&
          gvisitor->inspect_edge(ticket->get_ctx()))
      {
        goto end_leave_node;
      }
    }

    while ((ticket= waiting_it++))
    {
      /* Filter out edges that point to the same node. */
      if (ticket->get_ctx() != src_ctx &&
          ticket->is_incompatible_when_waiting(waiting_ticket->get_type()) &&
          gvisitor->inspect_edge(ticket->get_ctx()))
      {
        goto end_leave_node;
      }
    }

    //此处开始, 深度遍历图

    granted_it.rewind();
    while ((ticket= granted_it++))
    {
      if (ticket->get_ctx() != src_ctx &&
          ticket->is_incompatible_when_granted(waiting_ticket->get_type()) &&
          ticket->get_ctx()->visit_subgraph(gvisitor))
      {
        goto end_leave_node;
      }
    }

    waiting_it.rewind();
    while ((ticket= waiting_it++))
    {
      if (ticket->get_ctx() != src_ctx &&
          ticket->is_incompatible_when_waiting(waiting_ticket->get_type()) &&
          ticket->get_ctx()->visit_subgraph(gvisitor))
      {
        goto end_leave_node;
      }
    }
    ...

    //visitor退栈
    gvisitor->leave_node(src_ctx);
    ...
}

发现死锁后, 会调用Deadlock_detection_visitor::opt_change_victim_to, 其中进行MDL_context权重比较, 来选取一个作为victim, 此处忽略细节

之前对bug #70307有过学习, 苦于阿兹海默状态, 又花了半天在mysql 5.5.33上探查这个场景的原因…

简单记录一下

现象

mysql进行主从复制, 从机上FLUSH TABLES WITH READ LOCK后, 进行STOP SLAVE, 一定概率下 SHOW SLAVE STATUS卡住

重现步骤

其中, START/STOP SLAVE IO_THREAD是为了在FLUSH TABLES WITH READ LOCK时造成slave io_thread有未提交数据

死锁原因

1. FLUSH TABLES WITH READ LOCK 会阻塞IO_THREAD提交数据
2. STOP SLAVE会等待IO_THREAD结束 (mi->stop_cond), 即STOP SLAVE间接被FLUSH TABLES WITH READ LOCK阻塞
3. STOP SLAVE在被阻塞前, 持有了LOCK_active_mi, 独占了master_info
4. SHOW SLAVE STATUS会申请锁LOCK_active_mi, 被STOP SLAVE阻塞
5. 如果SHOW SLAVE STATUS是由之前FLUSH TABLES WITH READ LOCK的slave client 1发出的, 那逻辑上相当于自己在等待自己释放资源
6. 从另外的client上UNLOCK TABLES也解不开

场景

这次想解决的场景是想在一个mysqld实例上重放一些来自于其他实例的binlog, 传统的方法是mysqlbinlog. 但是mysqlbinlog会带来一些问题, 比如这个bug

后同事转给我一种利用复制重放binlog的方法, 其中提到两种方式:

• 第一种是修改relay log的信息, 将binlog作为relay log来放. 这是种很好的方法, 缺点是mysqld需要停机重启. 如果不重启, server中对于relay-log.index和relay-log.info等的缓存不会刷新.
• 第二种是起另外一个mysqld实例, 将binlog作为relay log, 再将此实例作为master, 向目标实例进行复制. 这种方式的缺点是作为中间人的mysqld实例需要消耗资源

于是想办法将第二种方法进行改进, 即制造一个假的master, 实现简单的复制协议, 直接将binlog复制给目标mysqld实例. 与第二种方式相比, 好处在于只使用少量资源 (一个端口, 一点用来读文件的内存).

实现

实现参看我的github

注意: 此实现仅适用于mysql 5.5.33, 其它版本未测试

由于mysql internals 已经将mysql的网络协议写的比较详细, 需要做的只是起一个tcp的server, 同目标mysqld实例进行交互即可.

此处逐层介绍实现, 将忽略不需要特别注意的部分. 为了简单, 将binlog的来源mysqld实例称为A, 目标mysqld实例称为B, 假master称为T.

目标就是讲从A获得的binlog文件, 通过T, 在B上重放出来

从B发起start slave, 到T真正向B复制数据, 需要下面两个阶段

1. Handshake Phase

2. Replication Phase

先介绍Handshake Phase, 有以下步骤

1.1 B执行start slave, 此时B向T建立一个TCP连接

1.2 T向B发送handshake packet

1.3 B向T回复handshake packet response

1.4 T向B发送ok packet

在Replication Phase, 有以下步骤

2.1 B向T查询SELECT UNIX_TIMESTAMP()

2.2 B向T查询SHOW VARIABLES LIKE 'SERVER_ID'

2.3 B向T执行SET @master_heartbeat_period=

2.4 B向T发送COM_REGISTER_SLAVE packet, 得到T回复的ok packet

2.5 B向T发送COM_BINLOG_DUMP packet, T开始向B逐一发送binlog event packet

到目前为止, 所有的packet定义都可以在mysql internals, 逐一实现即可. 这里只简述一些处理packet时需要注意的细节.

处理packet时需要注意的细节

• 所有的packet都会包装一个header, 其中包括packet payload(不包括header)的大小, 和序号
• 对于序号的处理, 比如2.2中B向T查询SHOW VARIABLES LIKE 'SERVER_ID', B向T发送的第一个包序号为0, T向B回复的几个包序号依次递增为1,2,3…
• 注意数据类型, 仅整数, mysql的协议里有定长整数和变长整数(length encoded integer), 需要特别留意packet payload的类型描述
• 说明一下query response packet. 比如B向T做一个查询, T将通过query response packet来返回查询结果. 需要说明的是, 如果查询结果为空 (比如SET @master_heartbeat_period= ?的结果), 仅需返回COM_QUERY_RESPONSE, 后面不需要跟着空的column定义和row数据

对超大packet的支持

当一个packet过大 (超过1<<24-1byte ~= 16 MB) 时, 传输需要对packet进行切割, 参看这里

注意, 在A上生成binlog时, 是可以容纳大于16MB的packet的, 也就是原binlog里存在超大的event, 需要在传输时加以限制

切割packet没什么特别之处, 仅需要注意包格式, 一个20MB的event的传输packet格式举例为 (此处用16MB便于描述, 应为1<<24-1byte):

packet 1
    4字节 packet header
    1字节 值为[00], 是binlog event的特征标志
    16MB-1字节 为第一段数据

packet 2
    4字节 packet header
    20MB-16MB+1字节 为第二段数据

需要注意的是之后的packet时不带有[00]特征位的. 而包的大小计算范围为除去前4字节的全部字节

一些资料

除上文提到的资料, 还推荐MySQL通讯协议研究系列, 会对包格式有个直观感觉

Trouble shooting

在整个过程中, 有时候需要gdb到mysqld里来了解通讯协议的工作机制, 这里记录几个常用的函数入口点

1. slave连接到master时

#0  wait_for_data (fd=21, timeout=3600) at /vagrant/mysql-5.5.35/sql-common/client.c:208
#1  0x00000000007316aa in my_connect (fd=21, name=0x7fa074004fd0, namelen=16, timeout=3600) at /vagrant/mysql-5.5.35/sql-common/client.c:187
#2  0x00000000007363cb in mysql_real_connect (mysql=0x7fa074004960, host=0x3959cc8 "192.168.56.1", user=0x3959d05 "repl", passwd=0x3959d36 "", db=0x0, port=3306, unix_socket=0x0, client_flag=2147483648)
    at /vagrant/mysql-5.5.35/sql-common/client.c:3282
#3  0x000000000057f138 in connect_to_master (thd=0x7fa074000a40, mysql=0x7fa074004960, mi=0x3959640, reconnect=false, suppress_warnings=false) at /vagrant/mysql-5.5.35/sql/slave.cc:4297
#4  0x000000000057edd1 in safe_connect (thd=0x7fa074000a40, mysql=0x7fa074004960, mi=0x3959640) at /vagrant/mysql-5.5.35/sql/slave.cc:4233
#5  0x000000000057b15c in handle_slave_io (arg=0x3959640) at /vagrant/mysql-5.5.35/sql/slave.cc:2851
#6  0x00007fa096751851 in start_thread () from /lib64/libpthread.so.0
#7  0x00007fa0954a690d in clone () from /lib64/libc.so.6

2. handshake phase

#0  send_server_handshake_packet (mpvio=0x7fa0942eb450, data=0x391e5b4 "=!-\\gq$\\%>J8z}'EgVW5", data_len=21) at /vagrant/mysql-5.5.35/sql/sql_acl.cc:8084
#1  0x000000000059a87c in server_mpvio_write_packet (param=0x7fa0942eb450, packet=0x391e5b4 "=!-\\gq$\\%>J8z}'EgVW5", packet_len=21) at /vagrant/mysql-5.5.35/sql/sql_acl.cc:9082
#2  0x000000000059bc99 in native_password_authenticate (vio=0x7fa0942eb450, info=0x7fa0942eb468) at /vagrant/mysql-5.5.35/sql/sql_acl.cc:9713
#3  0x000000000059ad86 in do_auth_once (thd=0x391cc70, auth_plugin_name=0x1026760, mpvio=0x7fa0942eb450) at /vagrant/mysql-5.5.35/sql/sql_acl.cc:9336
#4  0x000000000059b23a in acl_authenticate (thd=0x391cc70, connect_errors=0, com_change_user_pkt_len=0) at /vagrant/mysql-5.5.35/sql/sql_acl.cc:9472
#5  0x00000000006d9eb5 in check_connection (thd=0x391cc70) at /vagrant/mysql-5.5.35/sql/sql_connect.cc:575
#6  0x00000000006d9ffc in login_connection (thd=0x391cc70) at /vagrant/mysql-5.5.35/sql/sql_connect.cc:633
#7  0x00000000006da5ba in thd_prepare_connection (thd=0x391cc70) at /vagrant/mysql-5.5.35/sql/sql_connect.cc:789
#8  0x00000000006daa28 in do_handle_one_connection (thd_arg=0x391cc70) at /vagrant/mysql-5.5.35/sql/sql_connect.cc:855
#9  0x00000000006da583 in handle_one_connection (arg=0x391cc70) at /vagrant/mysql-5.5.35/sql/sql_connect.cc:781
#10 0x00007fa096751851 in start_thread () from /lib64/libpthread.so.0
#11 0x00007fa0954a690d in clone () from /lib64/libc.so.6

3. query时回复column定义

#0  Protocol::send_result_set_metadata (this=0x3767610, list=0x3769328, flags=5)
    at /vagrant/mysql-5.5.35/sql/protocol.cc:677
#1  0x00000000005c6745 in select_send::send_result_set_metadata (this=0x7f350c001658, list=..., flags=5)
    at /vagrant/mysql-5.5.35/sql/sql_class.cc:2132
#2  0x000000000062895a in JOIN::exec (this=0x7f350c001678) at /vagrant/mysql-5.5.35/sql/sql_select.cc:1858
#3  0x000000000062b2a0 in mysql_select (thd=0x37670e0, rref_pointer_array=0x3769400, tables=0x0, wild_num=0,
    fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147748608,
    result=0x7f350c001658, unit=0x3768bf8, select_lex=0x3769218) at /vagrant/mysql-5.5.35/sql/sql_select.cc:2604
#4  0x00000000006232f5 in handle_select (thd=0x37670e0, lex=0x3768b48, result=0x7f350c001658,
    setup_tables_done_option=0) at /vagrant/mysql-5.5.35/sql/sql_select.cc:297
#5  0x00000000005fe82d in execute_sqlcom_select (thd=0x37670e0, all_tables=0x0)
    at /vagrant/mysql-5.5.35/sql/sql_parse.cc:4627
#6  0x00000000005f7379 in mysql_execute_command (thd=0x37670e0) at /vagrant/mysql-5.5.35/sql/sql_parse.cc:2178
#7  0x0000000000600a43 in mysql_parse (thd=0x37670e0, rawbuf=0x7f350c001430 "SELECT UNIX_TIMESTAMP()", length=23,
    parser_state=0x7f35195056f0) at /vagrant/mysql-5.5.35/sql/sql_parse.cc:5664
#8  0x00000000005f490a in dispatch_command (command=COM_QUERY, thd=0x37670e0,
    packet=0x3770e21 "SELECT UNIX_TIMESTAMP()", packet_length=23) at /vagrant/mysql-5.5.35/sql/sql_parse.cc:1040
#9  0x00000000005f3c00 in do_command (thd=0x37670e0) at /vagrant/mysql-5.5.35/sql/sql_parse.cc:773
#10 0x00000000006daa4b in do_handle_one_connection (thd_arg=0x37670e0)
    at /vagrant/mysql-5.5.35/sql/sql_connect.cc:862
#11 0x00000000006da583 in handle_one_connection (arg=0x37670e0) at /vagrant/mysql-5.5.35/sql/sql_connect.cc:781
#12 0x00007f352e043851 in start_thread () from /lib64/libpthread.so.0
#13 0x00007f352cd9890d in clone () from /lib64/libc.so.6

4. query读取数据结果

#0  cli_read_query_result (mysql=0x7f3508004960) at /vagrant/mysql-5.5.35/sql-common/client.c:3829
#1  0x0000000000738016 in mysql_real_query (mysql=0x7f3508004960, query=0xb80e34 "SELECT UNIX_TIMESTAMP()",
    length=23) at /vagrant/mysql-5.5.35/sql-common/client.c:3918
#2  0x00000000005766ec in get_master_version_and_clock (mysql=0x7f3508004960, mi=0x375b400)
    at /vagrant/mysql-5.5.35/sql/slave.cc:1328
#3  0x000000000057b35a in handle_slave_io (arg=0x375b400) at /vagrant/mysql-5.5.35/sql/slave.cc:2881
#4  0x00007f352e043851 in start_thread () from /lib64/libpthread.so.0
#5  0x00007f352cd9890d in clone () from /lib64/libc.so.6

5. slave发送COM_BINLOG_DUMP

#0  request_dump (thd=0x7f35f80008c0, mysql=0x7f35f80076c0, mi=0x3301ac0,
    suppress_warnings=0x7f361c189e2b)
    at /vagrant/mysql-5.5.35/sql/slave.cc:2184
#1  0x000000000057b596 in handle_slave_io (arg=0x3301ac0)
    at /vagrant/mysql-5.5.35/sql/slave.cc:2935
#2  0x00007f3620c66851 in start_thread () from /lib64/libpthread.so.0
#3  0x00007f361f9bb90d in clone () from /lib64/libc.so.6

在go中用cmd生成新的process时, 在某些os中(包括linux的某些版本), 父进程的文件句柄会泄露到子进程中, 参看代码

package main

import (
    "fmt"
    "os"
    "os/exec"
)

func main() {
    a, _ := os.OpenFile("1", os.O_CREATE|os.O_RDWR, 0755)
    defer a.Close()
    cmd := exec.Command("sh", "-c", "lsof +D .; sleep 3")
    output, _ := cmd.CombinedOutput()
    fmt.Printf("%v\n", string(output))
}

得到输出

[root@GroupH-HA-1 tmp]# uname -a
Linux GroupH-HA-1 2.6.18-194.el5xen #1 SMP Tue Mar 16 22:01:26 EDT 2010 x86_64 x86_64 x86_64 GNU/Linux
[root@GroupH-HA-1 tmp]# ./main
COMMAND  PID USER   FD   TYPE DEVICE    SIZE    NODE NAME
bash    4693 root  cwd    DIR  253,0   32768 3506177 .
main    6184 root  cwd    DIR  253,0   32768 3506177 .
main    6184 root  txt    REG  253,0 2250464 3506237 ./main
main    6184 root    3u   REG  253,0       0 3506238 ./1
sh      6189 root  cwd    DIR  253,0   32768 3506177 .
sh      6189 root    3u   REG  253,0       0 3506238 ./1
lsof    6190 root  cwd    DIR  253,0   32768 3506177 .
lsof    6191 root  cwd    DIR  253,0   32768 3506177 .

可以看到./1的文件句柄泄漏到了sh -c中, 目前为止没有特别好的解决方案

参看此处bug描述

直接上代码, LockFile可以获得一个文件的独占权, 或阻塞等待

linux

func LockFile(file *os.File) error {
    return syscall.Flock(int(file.Fd()), syscall.LOCK_EX)
}

windows

func LockFile(file *os.File) error {
    h, err := syscall.LoadLibrary("kernel32.dll")
    if err != nil {
        return err
    }
    defer syscall.FreeLibrary(h)

    addr, err := syscall.GetProcAddress(h, "LockFile")
    if err != nil {
        return err
    }
    for {
        r0, _, _ := syscall.Syscall6(addr, 5, file.Fd(), 0, 0, 0, 1, 0)
        if 0 != int(r0) {
            break
        }
        time.Sleep(100 * time.Millisecond)
    }
    return nil
}

gen是go的代码生成器, 提供类似于underscore的函数集.

尝试将gen用在项目上,发现不太方便,对源码做了如下两个修改, 修改后的代码在这里:

1. 支持条件编译

go提供了条件编译,根据GOOS和GOARCH进行交叉编译,也可以利用build tags自定义条件编译

修改前可能碰到的问题是存在a_linux.go和a_windows.go, 分别定义一个函数A的两个版本. 调用gen时会报错:A不可以重复定义

这个修改已经被merge回原分支

2. 对于import的其它包, 支持分析其源码

设想一个场景, 存在root/A和root/B两个包, root/B import root/A

在root/B上调用gen, gen会分析import关系, 找到并分析root/A

在修改之前, 由于gen只使用了types.Check, 默认只会使用gcimport,只分析root/A编译好的pkg(.a文件), 而不包括root/A的源码.

也就是说对于所有依赖, 必须都保证其跑过go install, 才能在下游模块使用gen. 这个并不方便

做的修改是使用go.tools/importer代替gcimporter, 既可以分析编译好的pkg, 又可以分析源码

不过这个修改的代价是分析的时间会比较长

这个修改尚未被原分支接受

3. types源码分析的一个问题

以下代码在分析源码时报错, 但编译时是通过的

c := make(chan os.Signal, 1)
signal.Notify(c, syscall.SIGTTIN)

分析时报的错是

cannot pass argument c (variable of type chan os.Signal) to parameter of type chan<- os.Signal

目前无解, 但结论是用types包进行的源码分析结果和编译时的略有差异

在GO上发现以下现象

c := exec.Command("sh", "-c", "sleep 100 &")
var b bytes.Buffer
c.Stdout = &b

if e := c.Start(); nil != e {
    fmt.Printf("ERROR: %v\n", e)
}
if e := c.Wait(); nil != e {
    fmt.Printf("ERROR: %v\n", e)
}

这个代码会一直等到sleep 100完成后才退出, 与常识不符.

但去掉Stdout重定向后, 代码就不会等待卡住

c := exec.Command("sh", "-c", "sleep 100 &")
if e := c.Start(); nil != e {
    fmt.Printf("ERROR: %v\n", e)
}
if e := c.Wait(); nil != e {
    fmt.Printf("ERROR: %v\n", e)
}

在运行时打出stacktrace, 再翻翻GO的源代码, 发现GO卡在以下代码

func (c *Cmd) Wait() error {
    ...
    state, err := c.Process.Wait()
    ...
    var copyError error
    for _ = range c.goroutine {
        if err := <-c.errch; err != nil && copyError == nil {
            copyError = err
        }
    }
    ...
}

可以看到Wait()在等待Process结束后, 还等待了所有c.goroutine的c.errch信号. 参看以下代码:

func (c *Cmd) stdout() (f *os.File, err error) {
    return c.writerDescriptor(c.Stdout)
}

func (c *Cmd) writerDescriptor(w io.Writer) (f *os.File, err error) {
    ...
    c.goroutine = append(c.goroutine, func() error {
        _, err := io.Copy(w, pr)
        return err
    })
    ...
}

重定向stdout时, 会添加一个监听任务到goroutine (stderr也是同理)

结论是由于将sleep 100放到后台执行, 其进程stdout并没有关闭, io.Copy()不会返回, 所以会卡住

临时的解决方法就是将后台进程的stdout和stderr重定向出去, 以下代码不会卡住:

c := exec.Command("sh", "-c", "sleep 100 >/dev/null 2>/dev/null &")
var b bytes.Buffer
c.Stdout = &b

if e := c.Start(); nil != e {
    fmt.Printf("ERROR: %v\n", e)
}
if e := c.Wait(); nil != e {
    fmt.Printf("ERROR: %v\n", e)
}

已经报了bug

但想不出好的GO代码的修改方案

这几天在尝试为以下场景制作一个mysql plugin, 但是是一个失败的尝试, 在此记录

一对mysql主从节点 M-S, 节点S执行了RESET SLAVE
后来后悔了
在没有数据通过非replication的渠道写入S的条件下, 想让S和M重新恢复成一对主从

关键点是S能将RESET SLAVE时S的Exec_Master_Log_Pos和S binlog pos记录下来

尝试了以下几种方案:

1. 调用者在RESET SLAVE时手工记录, 不需要制作插件

2. Audit plugin.

Mysql的Audit plugin可以审计大部分mysqld经手的SQL, 包括RESET SLAVE.

但Audit plugin是在每个SQL之后才会调用. 在RESET SLAVE时S上master_info会被清理, 即Exec_Master_Log_Pos的信息在调用Audit plugin已经丢失

3. Replication plugin (after_reset_slave)

Replication plugin (参看mysql semisync的源码), 在slave端提供了Binlog_relay_IO_observer, 贴个Mysql源码方便理解

/**
    Observes and extends the service of slave IO thread.
 */
 typedef struct Binlog_relay_IO_observer {
   uint32 len;

   /**
      This callback is called when slave IO thread starts

      @param param Observer common parameter

      @retval 0 Sucess
      @retval 1 Failure
   */
   int (*thread_start)(Binlog_relay_IO_param *param);

   /**
      This callback is called when slave IO thread stops

      @param param Observer common parameter

      @retval 0 Sucess
      @retval 1 Failure
   */
   int (*thread_stop)(Binlog_relay_IO_param *param);

   /**
      This callback is called before slave requesting binlog transmission from master

      This is called before slave issuing BINLOG_DUMP command to master
      to request binlog.

      @param param Observer common parameter
      @param flags binlog dump flags

      @retval 0 Sucess
      @retval 1 Failure
   */
   int (*before_request_transmit)(Binlog_relay_IO_param *param, uint32 flags);

   /**
      This callback is called after read an event packet from master

      @param param Observer common parameter
      @param packet The event packet read from master
      @param len Length of the event packet read from master
      @param event_buf The event packet return after process
      @param event_len The length of event packet return after process

      @retval 0 Sucess
      @retval 1 Failure
   */
   int (*after_read_event)(Binlog_relay_IO_param *param,
                           const char *packet, unsigned long len,
                           const char **event_buf, unsigned long *event_len);

   /**
      This callback is called after written an event packet to relay log

      @param param Observer common parameter
      @param event_buf Event packet written to relay log
      @param event_len Length of the event packet written to relay log
      @param flags flags for relay log

      @retval 0 Sucess
      @retval 1 Failure
   */
   int (*after_queue_event)(Binlog_relay_IO_param *param,
                            const char *event_buf, unsigned long event_len,
                            uint32 flags);

   /**
      This callback is called after reset slave relay log IO status

      @param param Observer common parameter

      @retval 0 Sucess
      @retval 1 Failure
   */
   int (*after_reset_slave)(Binlog_relay_IO_param *param);
 } Binlog_relay_IO_observer;

首先尝试用after_reset_slave, 从函数名字就可以看到会遇到和Audit Plugin相同的问题: 即Exec_Master_Log_Pos的信息在调用时已经丢失

4. Replication plugin (after_reset_slave再尝试, future_group_master_log_pos)

还不死心, Exec_Master_Log_Pos的数据结构是Relay_log_info.group_master_log_pos, 尽管这个信息在after_reset_slave时已经丢失, 但发现Relay_log_info.future_group_master_log_pos可能是个方向

先解释Relay_log_info.future_group_master_log_pos, 可以参看log_event.cc的这段注释

  /*
    InnoDB internally stores the master log position it has executed so far,
    i.e. the position just after the COMMIT event.
    When InnoDB will want to store, the positions in rli won't have
    been updated yet, so group_master_log_* will point to old BEGIN
    and event_master_log* will point to the beginning of current COMMIT.
    But log_pos of the COMMIT Query event is what we want, i.e. the pos of the
    END of the current log event (COMMIT). We save it in rli so that InnoDB can
    access it.
  */
  const_cast<Relay_log_info*>(rli)->future_group_master_log_pos= log_pos;

future_group_master_log_pos指向了execute的最后一个transaction的COMMIT event之前, 即future_group_master_log_pos 大部分时间等于 group_master_log_pos - 27 (27是COMMIT event的长度)

但仍有例外情况: 如果M执行了FLUSH LOGS, 将log从0001递增到了0002, 此时S上的future_group_master_log_pos会指向0001的最后一个transaction的COMMIT event之前. 但S上的group_master_log_name已经到了0002, 与future_group_master_log_pos不匹配, 会引起异常

(其实此时S上的group_master_log_name也已经置空了, 但可以从内存残片中恢复出文件名)

设想如果对于log_name也有future_group_master_log_name, 那么S可以直接change master到M的future_group_master_log_name和future_group_master_log_pos位置, 可以恢复起M-S主从结构

5. Replication plugin (thread_stop)

Replication plugin的thread_stop是指Slave IO thread停止时调用, 此时可以拿到Exec_Master_Log_Pos和S binlog pos, 但拿到的S binlog pos没有意义, 因为不能保证Slave SQL thread也停下来了

6. Storage Engine plugin

这是我最后一根救命稻草, 阅读Mysql源码时注意到以下片段(做了缩减)

int reset_slave(THD *thd, Master_info* mi)
{
    ...
    ha_reset_slave(thd);
    ... //clean memory data
}

reset_slave在清理内存数据前通知了storage engine插件, 这个插件可以获得所有必要信息

但存在一个问题, 即ha_reset_slave仅在Mysql NDB版本中存在, 不具备通用性, 参看宏定义(做了缩减)

#ifdef HAVE_NDB_BINLOG
...
void ha_reset_slave(THD *thd);
...
#else
...
#define ha_reset_slave(a) do {} while (0)
...
#endif

吐槽和总结

可以看到Mysql plugin不太预留接口, 是仅仅为已知应用场景提供必要接口, 比如Binlog_relay_IO_observer中有after不一定有before. 比较容易控制插件质量, 但插件能做到的非常局限.

以上各种尝试, 归根到底, 只要修改Mysql的一点源码编译一下就可以达到很好的效果, 不需要用插件的方式在Mysql中到处找功能插槽, 但通用性变差.

最近尝试制作了一个mysql的插件. 对c/c++的编译不熟, 又是第一次尝试做mysql插件, 编译过程中碰到些状况

编写好mysql插件后, 编译成功, 在mysql中安装运行报错: 取了threads中的THD, 其中THD->thread_id值为空

由于是mysql内置的数据结构, 一时没了头绪, 只能通过gdb连上去看看

发现plugin打印出来的thread_id距离THD开头的距离为

tmp=0x3661f80
&tmp->thread_id=0x36637b0
delta = 0x1830

而gdb打印出来的距离为

(gdb) p tmp
$1 = (THD *) 0x3661f80
(gdb) p &tmp->thread_id
$2 = (my_thread_id *) 0x3663878
delta = 0x18F8

结论很显然, plugin编译的THD结构和mysqld的THD结构不匹配, 即plugin的编译参数和mysqld的编译参数不一样.

当然mysql的文档上只会说一句大意是 ”编译参数应当设置成一样的“的话

其中比较重要的几个编译选项

1. DBUG_ON
2. SAFE_MUTEX
3. DBUG_OFF (不设置DBUG_ON并不等于DBUG_OFF)

这几个选项会影响当使用mysqld内部数据结构的长度, 不排除还有其他

问题场景

首先有一台tcp server, 模拟一个黑洞

1
2
3
4
5
6
7
8
9

require 'socket'

tcp_server = TCPServer.new("0.0.0.0", 6666)

loop do
     socket = tcp_server.accept
     puts 'got conn']
     #blackhole
end

然后发起一个connection, 从server接受消息(很显然会阻塞在recv上), 并用Timeout::timeout设置一个超时时间

1
2
3
4
5
6
7
8
9
10

require "socket"
require "timeout"

sock = Socket.new(Socket::AF_INET, Socket::SOCK_STREAM, 0)
addr = Socket.sockaddr_in(6666, "127.0.0.1")
sock.connect(addr)

Timeout::timeout(5) {
     sock.recv(1)
}

上面这个场景如果在ruby上跑,5秒后会超时,但如果使用jruby(1.7.6)就会一直处于阻塞

解决方案

使用非阻塞recv,可以在jruby上正常运行

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15

require "socket"
require "timeout"

sock = Socket.new(Socket::AF_INET, Socket::SOCK_STREAM, 0)
addr = Socket.sockaddr_in(6666, "127.0.0.1")
sock.connect(addr)

Timeout::timeout(5) {
    begin
        sock.recv_nonblock(1)
    rescue IO::WaitReadable
        IO.select([sock],nil,nil,5)
        retry
    end
}

猜测

查看一下ruby timeout.rb的源码

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18

  begin
    x = Thread.current
    y = Thread.start {
      begin
        sleep sec
      rescue => e
        x.raise e
      else
        x.raise exception, "execution expired"
      end
    }
    return yield(sec)
  ensure
    if y
      y.kill
      y.join # make sure y is dead.
    end
  end

大概看到timeout是起了一个计时线程,超时时向主线程发起exception

猜测是因为jvm的线程模型导致exception不能向阻塞线程提交,但有待验证

我是万没料到自己栽在了go的for上，说多了都是眼泪

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16

type testStruct struct {
     no int
}

func main() {
     a := []testStruct{testStruct{1}, testStruct{2}, testStruct{3}}
     var p *testStruct
     for _, i := range a {
          if i.no == 2 {
               // o := i
               // p = &o
               p = &i
          }
     }
     fmt.Println(p.no)
}

猜猜看输出是多少？试试看吧

理解起来很容易，p取得是i的地址，而range循环变量i在每个循环之间都是复用同一个地址

证明一下，试试看？

1
2
3
4

a := []int{1, 2, 3, 4, 5}
for _, item := range a {
     fmt.Printf("%p\n", &item)
}

虽然很容易理解，也很容易掉坑，尤其for上用:=，那感觉就像js里连续用var，除了第一下剩下的都不好使…

在阅读之前，请确定已浏览过第一篇，并阅读过以下参考文献[1]（最好是阅读过参考文献[2]）

参考文献

[1]【译】PaxosLease：实现租约的无盘Paxos算法

[2] Keyspace源码

本篇将讨论以下一些实现PaxosLease中的问题和解决：

1. 2PC 两阶段的超时设置
2. 续租困境及解决
3. Proposer对HighestPromisedProposeId的学习
4. 放弃租约

假设读者已经从参考文献[1]中熟悉了PaxosLease算法，在所有讨论之前，我们还是先简述一下整个PaxosLease算法，目的来统一一些术语。其中有一些空白，类似于{1}，后面的讨论中会将这些空白逐一填满：

1 Proposer A 想要获得租约，生成一个新的ProposeId，组装成一个Prepare Request，并广播给所有Accepter

2 Accepter B收到来自Proposer A的PrepareRequest，检查PrepareRequest中的ProposeId
若低于Accepter B的HighestPromisedProposeId，则忽略这一PrepareRequest，{5}
否则

3 Proposer A收到Accepter B的Prepare Response。
若多数派Accepter返回的PrepareRequest中的AcceptedProposeId都为空，{2}，则表示多数派Accepter都可以接受Proposer A的Propose，进入Propose 阶段：

4 {6}

5 Accepter B收到来自Proposer A的ProposeRequest，（再次）检查ProposeRequest中的ProposeId

6 Proposer A收到Accepter B的ProposeResponse。若Proposer A已收到多数派的ProposeReponse，则Proposer A:

这一部分讨论2PC两阶段的超时设置

PaxosLease的过程引自参考[1]中，可以看到Prepare阶段没有计时器，而在Propose阶段，Proposer和Accepter分别启动定时器β和定时器γ，来表示“Propose阶段在当前节点超时，需要重新启动投票”，或者“租约在当前节点过期，当前节点可以参与新一轮投票”

可以看到这个结论与上一篇的描述不符，下面来解释原因

在这种设计下，若Prepare阶段有请求丢失，导致Proposer没法获得多数派的反馈，则Prepare阶段会僵死在那里

参考[1]中使用这种设计的原因是参考[1]中仅讨论了一次投票的情景，并不包括如何长期维护投票秩序。作为一个介绍性的文章，这种情景限定有助于读者理解

而实际应用中，我们必须要解决Prepare阶段的僵死情况，即在Prepare阶段也加入定时器（Keyspace中也是这样做的）：
{1} = “并启动定时器α，时长小于租约时长。α超时时，重新启动Prepare阶段。在节点进入Propose阶段时，取消α计时”

续租困境及解决

在实际应用中，希望长时间维持一个节点master的身份，而不希望master在集群里换来换去，那么当前持有租约的节点就希望能成功续租

先介绍续租的实现，参考[1]中提到“如果多数派响应了空的提案或是 已存在提案 （即这个提案中的该请求者的租约还没有过期），它可以再次提议自己为租约的持有者”，相应的我们在过程中做出修改：
{2} = “或PrepareRequest中的AcceptedProposeId=Proposer A的leaseProposeId”
{3} = “置leaseProposeId为当前的proposeId”
{4} = “置leaseProposeId为0”

续租实现后，测试过程中，就会发现以下续租困境：

1. Proposer A获得租约，proposeId=1（此处我们为了方便，简化ProposeId的结构为提交次数），等待一段时间t后开始续租
2. Proposer B在t的过程中，不断尝试想获取续约，但始终得不到多数派的批准，这个过程中Proposer B发出提案的proposeId会飙升，比如说proposeId=10
3. Accepter们在Proposer B的不断尝试中，Prepare阶段HighestPromisedProposeId也跟着飙升，比如说HighestPromisedProposeId=10
4. Proposer A开始续租，proposeId=2，续租失败

解决续租困境有几种方式：

1. Accepter在定时器γ超时前，不接受新的PrepareRequest
2. Proposer续租时，将Request的ProposeId增加较大的值

我们随机选择第二种方式，那么在时间t（t<租约时长）的过程中，Proposer B能发出的Prepare Request数量，即B的ProposeId增长量Δ一定满足：Δ < ceil(租约时长/定时器α时长)。即，续租时，Proposer A的proposeId += ceil(租约时长/定时器α时长)即可。

额外一提，Keyspace中续租的时间（在获得租约后1s就开始续租）远小于Prepare/Propose阶段的超时时间，不会触发这个困境

Proposer对HighestPromisedProposeId的学习

解决了续租困境后，我们再设定一种困境：

1. Proposer A 持有租约，并一直续租，导致ProposeId变得很大，比如ProposeId = 10000
2. Accepter们的HighestPromisedProposeId也变得很大，比如HighestPromisedProposeId = 10000
3. 此时Proposer A离线
4. Proposer B 闪亮登场（比如在集群中补充了一台server），欲接手，发出PrepareRequest，ProposeId = 0
5. Proposer B 想要持有租约，至少要经过近10000次重试，才能将ProposeId增大到Accepter可接受的大小

这个困境的关键是在Proposer知晓的ProposeId太过落后于集群内最新的ProposeId，导致Proposer无法短时间内获得租约，而是需要长时间的重试

有两种解决方案可供参考：

1. Keyspace用的是这种方法：认为一个节点由Proposer和Accepter构成，即同一个节点Proposer和Accepter可以共享HighestPromisedProposeId。
   这样在上述情况下，只要集群里有任何一个Request被发给Accepter B，那么Proposer B 也可以学习到集群最新的ProposeId
2. 另一种方案是加入PrepareReject消息，在消息中Accpeter加入HighestPromisedProposeId供Promised学习，即
   {5} = 向Proposer A反馈Prepare Reject，其中带有HighestPromisedProposeId
   {6} = 若Proposer A收到Accepter B的Prepare Reject，则学习其中的HighestPromisedProposeId

第二种方案还需考虑网络延迟的情况，即Prepare Reject被长期延迟的情况。不过这种延迟并不会带来影响，因为

1. Proposer较晚学习到HighestPromisedProposeId，不会发生错误，只会延迟产生正确的投票结果
2. Prepare Reject的处理过程中，Proposer也会判断此消息是否是当前Request产生的Response。若Prepare Reject延迟较长，Proposer会发起新一轮的Prepare Request，收到旧的Prepare Reject则会抛弃此消息。

放弃租约

实际应用中，会碰到这种情况：持有租约的服务器同时肩负着其他资源的“敏感角色”，比如数据库集群中的主服务器。此时若此server挂掉，则需要等待租约过期，重新投票产生新的租约持有者，然后再由新的租约持有者裁决出新的数据库主服务器，并进行数据保护迁移。这个过程由于集群租约持有者和数据库主服务器这两种角色同时消失，会带来较大的影响。

为解决以上情况，就希望若两种角色重叠在一台server上，此时server能在运行稳定时放弃租约，做法有两种：

1. 如参考[1]中提到：“请求者可以发送一个特定释放消息给接受者，消息中包含了它要释放租给的投票编号。在发送释放消息之前，请求者把内部状态从“我持有租约”切换到“我没有持有租约”。”。
   
   考虑“释放消息”被长期延迟的情况，最坏的情况是没有Accepter及时收到消息，跟正常租约超时一样，需要等到多数派Accepter的定时器γ都超时，才能选出新的master。看来不会对正确性带来较大影响，只是不能及时释放租约。

2. 懒惰一点，就等到租约超时。为了不让当前Proposer再成为租约持有者，将当前Proposer“冻结” 2倍租约时长，这样既可以等到当前租约超时，又可以避免参与到下一轮投票。
   
   所谓“冻结”，即停掉一切定时器，且不发出新的request

至此，此篇已经描述了在实现PaxosLease中碰到的一切问题和取舍，欢迎各位反馈。

Paxos是分布式解决数据一致性的算法，而PaxosLease是Paxos中的一个子集，用于在集群中选择出一个节点作为master

最近因为项目需要，实现了一下PaxosLease，代码放在Github上

计划用两篇blog，分别记录下自己对PaxosLease的理解，以及对PaxosLease应用时的一些变化。
这篇是我对PaxosLease的个人理解，如有任何bug/改进的建议，欢迎comment

首先，定义一下问题场景：有N个节点组成一个集群，需要从其中选出一个master。（其中可能遇到节点间传输的信息延迟/丢失，节点离线，网络脑裂等等状况）

在这个定义中，先要解决如何定义“选出一个master”，有以下几种可能

1. 仅有master节点知道自己是master，其他节点只知道自己不是master，而不知道谁是master
2. 所有在线节点都知道谁是master，离线节点上线后要等待下次选举
3. 所有节点都知道谁是master，离线节点上线后要立刻学习谁是master

PaxosLease选择的是第一种方式（在此只讨论没有Learner的情况，有Learner的情况可以实现另外两种情况），这种方式满足现在的项目需要

这一个部分的结论：在以上的定义下，PaxosLease需要满足一个不定式：在同一时间，集群内至多有一个节点认为自己是master

要在多个节点达成一致，最通常的想法是二段提交（2-phase commit，2PC），经典2PC步骤是：

1. 某节点A向其他所有节点发起PrepareRequest（准备请求）
2. 某节点B收到节点A的PrepareRequest，经过状态检查，将自己的状态置为PrepareReady（表示可以接受A的PrepareRequest）
   并向A发送PrepareResponse（准备请求的回复）
3. A收到其他节点发来的PrepareResponse，当满足某个条件时，A认为集群整体同意了他得PrepareRequest。
   于是A向其他所有节点发出CommitRequest（提交请求）
4. 节点B收到A的CommitRequest，且检查到当前状态是为A准备的状态，则向A发送CommitResponse（提交回复）
5. A收到其他节点发来的CommitResponse，当满足某个条件时，A认为集群已经完成了提交

但经典的2PC没有以下解决的问题：

1. 如何处理网络脑裂
2. 如何解决master突然离线，比如网络故障
3. 如何面对选举过程中通信可能发生的延迟和中断
4. 是否会发生动态死锁

这一部分先解决网络脑裂的问题。比如有5个节点的集群，分割为[1,2]和[3,4,5]，那么在[1,2]子集群中不能选举出master，而在[3,4,5]子集群中必须要选举出master。若脑裂前master落在[1,2]，那么租约到期后，[1,2]不能选举出master

解决方案是：指定2PC步骤中的某个条件为“收到集群中超过集群节点数一半的节点（多数派）的正反馈”。那么[3,4,5]子集群可能选出master，而[1,2]由于只有2个节点，小于ceil(5/2) = 3，没法选出master

在此，我们称一个集群中，超过集群节点数一半的节点集合为多数派

这一部分将解决master突然离线的问题。根据不变式，除了master本身，没有节点知道谁是master。在这种情况下，如果不做点什么，集群就不会再有master了

解决方案是使用租约，即谁持有租约谁是master。

且整个过程中，租约到期前（多数派定时器超时前），集群不会有两个master同时存在，即满足不定式

以上等到租约过期的做法有一个前提，即所有节点都知道统一的租约时长 （此处是时长，而不是过期时间。PaxosLease并不要求各个节点时钟同步，因此必须使用时长）。这是时长往往是静态配置，而不是动态协商的

这一部分将解决选举过程中通信可能发生延迟。

发生延迟意味着A-B已经进入了下一轮投票，C可能才完成上一轮投票，C的反馈可能影响到这一轮投票结果。

此处PaxosLease引入了投票ID（PaxosLease称ProposeId，后面会统一名称的）的概念，投票ID对于某一节点A，在全局是单调递增的。常用的投票ID结构为<投票轮数 | 重启计数 | 节点ID>（“|”为字符串拼接），这个ID可以被持久化存储，即新一轮投票或节点重启时投票ID都会单调递增。

有了投票ID，那么节点可以只响应本轮的反馈，而不受其他轮的干扰。

这一部分将解决选举过程中通信可能发生中断。

发生中断意味着2PC某阶段会一直等待多数派的反馈，但反馈都丢失了，于是选举可能被无限期拖延下去。很容易得出解决方案：设置超时时间。即在2PC每一个阶段都设置超时时间，若超时，则回退重新开始新一轮的2PC

这一部分将讨论如何解决动态死锁

首先说明何为动态死锁，比如有4个节点的集群[1,2,3,4]，1和4同时请求自己为master，1的request发给2，而4的request发给3，没有任何一方获得多数派，于是进入新的一轮，以上状况重复出现，陷入死循环，没法选出master

观察这个问题的症结在于，2收到1的prepare request后，进入PrepareReady状态，将不再接受4发来的请求。这样[1,2]和[3,4]不断对撞，陷入死锁。

解决方案是PaxosLease引入了“不稳定”的PrepareReady，即2进入为1准备的PrepareReady状态后，如果收到4的PrepareRequest，且这个投票ID大于来自1的PrepareRequest的投票ID，则2转而进入为4准备的PrepareReady

可以看到投票ID代表了优先级，也就能理解之前要求某节点的投票ID单调递增的理由了

需要说明的是，上述做法只是大大降低动态死锁的概率，但仍然可能存在小概率的动态死锁，即两个节点1和4不断增大投票ID且在2和3进入Commit之前不断抢占2和3，形成竞争，可以引入随机的等待来规避这个小概率事件

在此，将上面描述的名词对应到PaxosLease算法的术语上

• 租约 = lease（租约）
• 投票 = propose (提案)
• 发出request的节点 = proposer
• 接受request，发出response的节点 = accepter
• CommitRequest = ProposeRequest
• CommitResponse = ProposeReponse
• 投票ID = ProposeID

之后将使用术语

以上，是出于个人理解，来理解PaxosLease的几个重要元素：

1. lease
2. propose
3. ProposeId
4. 两阶段的超时设置
5. 多数派形成决议

一些实现上的问题会在下一篇blog讨论

再次讨论不变式

在某一时刻，集群中最多存在一个Proposer，知道自己获得了租约。

此时，多数Accepter知道在某一个时刻前某个提案（AcceptedProposeId）是生效的。其他Proposer了解到多数Accepter都有AcceptedProposeId，则其不能获得租约。

这里说明一下上句中的某一时刻。借用参考[1]中的图

可以看到Proposer和Accepter间有时间差，即某一个时刻指的是当前Accepter定时器超时的时刻（可能晚于Proposer上租约到期的时刻），但这并没有影响不变式成立。即在满足当前不变式时，不要求各个节点时钟同步

以上是我个人的理解，如有不妥，烦请看官comment

建议此时参看文末的参考文献和Keyspace源码。之后请期待下一篇：实现PaxosLease中的一些问题和解决

顺便吐个槽，我没有数学天赋和算法天赋，也实在没兴趣下苦工，实在不够进取。罪过罪过。

参考文献

[1]【译】PaxosLease：实现租约的无盘Paxos算法

[2] Keyspace源码

已经是第三遍重写项目主代码了，这几天用主代码和测试框架互相补充。总结下经验值，以期升级

关于测试框架，重写了几遍仍然保留下来的功重要能是：

1. 插桩代码，后面的功能也都依赖插桩。不在主代码中插桩，测试基本靠拜神；

2. 条件池，根据条件池，代码才能沿着需要的分支进行；

3. 签到点（checkpoint），代码要能根据测试要求停得下来，等待状态，之后跑得起来；

4. 外缘测试。比起直接测试变量，还是分析log比较容易维护

测试的难点是：

1. 资源回收。要连续跑测试，资源回收是说说容易的事。tcp server关了，listener停了，关闭的那些connection会不会瞬时占用临时端口；如果某一个connection正在申请二步锁，测试停止时远端锁失败，近端锁如果不释放会不会影响之后的测试；如果系统会自动重启tcp server，tcp server是在测试关闭操作之前停还是之后停还是停两次。想想头就大了。

2. 想停都停不下来，万一断言失败，测试要能停下来。整个flow上都要处理停止中断，用“硬”中断很难掌握资源回收的状况；用“模拟”中断，所有等待/超时/重试的地方都要处理，逐级退栈。比起不测试的代码，主代码花在错误处理的代码量要大很多，但是值得。

3. 测试界限把握不易。测粗了没作用，测细了耗时间而且波动大。插桩的深度，模拟中断的层级，这些都要拿好轻重。否则代码已腐败。

每次跑测试，比起旁边坐个QA的测试，更步步惊心。QA一天才跑十几个case，自动的话2-3分钟就跑十几个简化的case，出错的概率要大很多。

最后反思一下，如果靠人肉测，…