库表变更、加锁没审计？PolarDB MySQL 新功能 SQL Detail

Author: 勉仁

PolarDB MySQL最新引入了库表变更、加锁操作的详细审计功能SQL Detail。

背景

在数据库使用过程中，库表的变更，例如删除、创建、增加列和索引等都是非常敏感的。对库表的加锁也会影响整个业务的使用。对应操作的审计日志对于数据库的运维人员就非常重要，需要能够知道操作的用户账号、客户端IP、操作时间、完成时间等详细信息。
以往的审计日志基本都是全局开关，对所有SQL语句都做审计。这样记录的SQL全面，但成本也会很高。同时很多时候需要额外的组件存储信息，维护和信息安全控制的成本也高。而对业务会造成重大影响的很多由库表操作引发，这部分的审计很多时候又不可或缺。
因此PolarDB MySQL内核开发了能够对库表变更、加锁操作的详细审计功能SQL Detail。同时该功能的审计记录存储在用户数据库实例中，用户可以配置审计记录的保存时间，审计记录过期后会自动删除。该功能审计的成本极低，以每条审计记录存储1KB，每天库表变更1024次，审计保存30天算，仅需要30M的存储空间。该功能在相关语句开始执行时就会捕获到，记录到相关系统表中，并会在执行结束时进一步更新相关状态。
下面会对该功能的使用做详细的介绍。

功能介绍

功能开关与相关变量

功能开关

用户可以通过全局参数awr_sqldetail_enabled来开启SQL Detail功能（在阿里云PolarDB实例控制台上搜索参数loose_awr_sqldetail_enabled）。该参数的配置无需重启实例。

审计SQL类型子开关

通过全局参数awr_sqldetail_switch可以控制库表变更或者库表加锁释放锁是否记录。作为一个switch变量，当前有两个子开关，ddl（是否记录DDL变更）和lock_db_table（是否记录库表加锁释放锁）。ddl和lock_db_table默认都是开启的，即默认值为’ddl=on,lock_db_table=on’。
DDL包括的语句类型如下：
create_table、alter_table、drop_table、rename_table、create_index、drop_index、create_db、drop_db、alter_db、create_view、drop_view、create_trigger、drop_trigger、create_event、alter_event、create_function、create_procedure、drop_procedure、drop_function、alter_procedure、alter_function、truncate、alter_tablespace、repair、optimize、install_plugin、uninstall_plugin、install_component、uninstall_component、alter_instance、import、create_spatial_reference_system、drop_spatial_reference_system。
LOCK_DB_TABLE包括的语句类型如下：
lock_tables、unlock_tables。

审计保存时间定义

通过全局参数awr_sqldetail_retention可以配置SQL Detail审计记录的保存时间，其单位是秒。当审计记录保存超过该时候后，内核会通过后台线程自动淘汰该记录。该参数默认值是：2592000（30天）。

审计记录表

SQL Detail功能的记录存储在一张新的PolarDB系统表sys.hist_sqldetail中。该表的定义如下：


1. CREATE TABLE `hist_sqldetail` (
2. `Id` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
3. `State` varchar(16) COLLATE utf8mb4_bin DEFAULT NULL,
4. `Thread_id` bigint(20) unsigned DEFAULT NULL,
5. `Host` varchar(60) COLLATE utf8mb4_bin NOT NULL DEFAULT '',
6. `User` varchar(32) COLLATE utf8mb4_bin NOT NULL DEFAULT '',
7. `Client_ip` varchar(60) COLLATE utf8mb4_bin DEFAULT NULL,
8. `Db` varchar(64) COLLATE utf8mb4_bin DEFAULT NULL,
9. `Sql_text` mediumtext COLLATE utf8mb4_bin NOT NULL,
10. `Server_command` varchar(32) COLLATE utf8mb4_bin DEFAULT NULL,
11. `Sql_command` varchar(64) COLLATE utf8mb4_bin DEFAULT NULL,
12. `Start_time` timestamp(6) NULL DEFAULT NULL,
13. `Exec_time` bigint(20) DEFAULT NULL,
14. `Wait_time` bigint(20) DEFAULT NULL,
15. `Error_code` int(11) DEFAULT NULL,
16. `Rows_sent` bigint(20) DEFAULT NULL,
17. `Rows_examined` bigint(20) DEFAULT NULL,
18. `Rows_affected` bigint(20) DEFAULT NULL,
19. `Logical_read` bigint(20) DEFAULT NULL,
20. `Phy_sync_read` bigint(20) DEFAULT NULL,
21. `Phy_async_read` bigint(20) DEFAULT NULL,
22. `Process_info` text COLLATE utf8mb4_bin,
23. `Extra` text COLLATE utf8mb4_bin,
24. `Create_time` timestamp(6) NOT NULL DEFAULT CURRENT_TIMESTAMP(6),
25. `Update_time` timestamp(6) NOT NULL DEFAULT CURRENT_TIMESTAMP(6) ON UPDATE CURRENT_TIMESTAMP(6),
26. PRIMARY KEY (`Id`),
27. KEY `i_start_time` (`Start_time`),
28. KEY `i_update_time` (`Update_time`)
29. ) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_bin;

该表各个字段表示的意义如下。可以看到该表会详细的记录库表变更、锁操作。

字段	描述
Id	sys.hist_sqldetail表的自增ID。
State	该操作被记录时所处的状态。
Thread_id	执行该SQL会话的线程ID
Host	执行该SQL会话的用户Host
User	执行该SQL会话的用户名
Client_ip	执行该SQL会话的客户端IP
Db	该SQL执行时所在的DB
Sql_text	具体SQL
Server_command	执行该SQL的server命令
Sql_command	命令类型
Start_time	开始执行的时间
Exec_time	执行时间，单位微秒
Wait_time	等待时间，单位微秒
Error_code	错误码
Rows_sent	返回的数据行
Rows_examined	扫描的数据行
Rows_affected	影响的行数
Logical_read	逻辑读次数
Phy_sync_read	物理同步读次数
Phy_async_read	物理异步读次数
Process_info	扩展字段，处理过程信息。
Extra	扩展字段，其他信息。
Create_time	记录写入时间
Update_time	记录更新时间

使用示例

配置awr_sqldetail_enabled为ON后，SQL Detail功能就会自动记录DDL，LOCK DB\TABLE操作，并自动管理这些记录。例如配置awr_sqldetail_enabled为ON后，我们在test库下做如下操作：


1. mysql> create table t(c1 int);
2. Query OK, 0 rows affected (0.02 sec)

4. mysql> create table t(c1 int);
5. ERROR 1050 (42S01): Table 't' already exists

7. mysql>  alter table t add column c2 int;
8. Query OK, 0 rows affected (0.02 sec)
9. Records: 0  Duplicates: 0  Warnings: 0

11. mysql> lock tables t read;
12. Query OK, 0 rows affected (0.00 sec)

14. mysql> unlock tables;
15. Query OK, 0 rows affected (0.00 sec)

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

执行完后，我们可以通过sys.hist_sqldetail查看上述操作中DDL和LOCK DB\TABLE的信息，而DML语句不会被记录。


1. mysql> select * from sys.hist_sqldetail\G
2. *************************** 1. row ***************************
3. Id: 1
4. State: FINISH
5. Thread_id: 18
6. Host: localhost
7. User: root
8. Client_ip: 127.0.0.1
9. Db: test
10. Sql_text: create table t(c1 int)
11. Server_command: Query
12. Sql_command: create_table
13. Start_time: 2023-01-13 16:18:21.840435
14. Exec_time: 17390
15. Wait_time: 318
16. Error_code: 0
17. Rows_sent: 0
18. Rows_examined: 0
19. Rows_affected: 0
20. Logical_read: 420
21. Phy_sync_read: 0
22. Phy_async_read: 0
23. Process_info: NULL
24. Extra: NULL
25. Create_time: 2023-01-13 16:18:22.391407
26. Update_time: 2023-01-13 16:18:22.391407
27. *************************** 2. row ***************************
28. Id: 2
29. State: FINISH
30. Thread_id: 18
31. Host: localhost
32. User: root
33. Client_ip: 127.0.0.1
34. Db: test
35. Sql_text: create table t(c1 int)
36. Server_command: Query
37. Sql_command: create_table
38. Start_time: 2023-01-13 16:18:22.416321
39. Exec_time: 822
40. Wait_time: 229
41. Error_code: 1050
42. Rows_sent: 0
43. Rows_examined: 0
44. Rows_affected: 0
45. Logical_read: 55
46. Phy_sync_read: 0
47. Phy_async_read: 0
48. Process_info: NULL
49. Extra: NULL
50. Create_time: 2023-01-13 16:18:23.393071
51. Update_time: 2023-01-13 16:18:23.393071
52. *************************** 3. row ***************************
53. Id: 3
54. State: FINISH
55. Thread_id: 18
56. Host: localhost
57. User: root
58. Client_ip: 127.0.0.1
59. Db: test
60. Sql_text: alter table t add column c2 int
61. Server_command: Query
62. Sql_command: alter_table
63. Start_time: 2023-01-13 16:18:34.123947
64. Exec_time: 16420
65. Wait_time: 245
66. Error_code: 0
67. Rows_sent: 0
68. Rows_examined: 0
69. Rows_affected: 0
70. Logical_read: 778
71. Phy_sync_read: 0
72. Phy_async_read: 0
73. Process_info: NULL
74. Extra: NULL
75. Create_time: 2023-01-13 16:18:34.394067
76. Update_time: 2023-01-13 16:18:34.394067
77. *************************** 4. row ***************************
78. Id: 4
79. State: FINISH
80. Thread_id: 18
81. Host: localhost
82. User: root
83. Client_ip: 127.0.0.1
84. Db: test
85. Sql_text: lock tables t read
86. Server_command: Query
87. Sql_command: lock_tables
88. Start_time: 2023-01-13 16:19:49.891559
89. Exec_time: 145
90. Wait_time: 129
91. Error_code: 0
92. Rows_sent: 0
93. Rows_examined: 0
94. Rows_affected: 0
95. Logical_read: 0
96. Phy_sync_read: 0
97. Phy_async_read: 0
98. Process_info: NULL
99. Extra: NULL
100. Create_time: 2023-01-13 16:19:50.399585
101. Update_time: 2023-01-13 16:19:50.399585
102. *************************** 5. row ***************************
103. Id: 5
104. State: FINISH
105. Thread_id: 18
106. Host: localhost
107. User: root
108. Client_ip: 127.0.0.1
109. Db: test
110. Sql_text: unlock tables
111. Server_command: Query
112. Sql_command: unlock_tables
113. Start_time: 2023-01-13 16:19:56.924648
114. Exec_time: 98
115. Wait_time: 0
116. Error_code: 0
117. Rows_sent: 0
118. Rows_examined: 0
119. Rows_affected: 0
120. Logical_read: 0
121. Phy_sync_read: 0
122. Phy_async_read: 0
123. Process_info: NULL
124. Extra: NULL
125. Create_time: 2023-01-13 16:19:57.400294
126. Update_time: 2023-01-13 16:19:57.400294

SQL Detail在DDL开始执行时就会被捕获记录到系统表中。我们做如下操作


1. create table t1 as select c1, sleep(10) from t;

在上述DDL执行时，我们用另一个session查看sys.hist_sqldetail，可以看到处理PROCESS状态的审计记录。当该语句执行完，相关状态会被自动更新。


1. select * from sys.hist_sqldetail where state='PROCESS'\G
2. *************************** 1. row ***************************
3. Id: xx
4. State: PROCESS
5. Thread_id: 36
6. Host: localhost
7. User: root
8. Client_ip: 127.0.0.1
9. Db: test
10. Sql_text: create table t1 as select c1, sleep(10) from t
11. Server_command: Query
12. Sql_command: create_table
13. Start_time: 2023-01-19 17:34:42.293752
14. Exec_time: 0
15. Wait_time: 0
16. Error_code: 0
17. Rows_sent: 0
18. Rows_examined: 0
19. Rows_affected: 0
20. Logical_read: 0
21. Phy_sync_read: 0
22. Phy_async_read: 0
23. Process_info: NULL
24. Extra: NULL
25. Create_time: 2023-01-19 17:34:42.641854
26. Update_time: 2023-01-19 17:34:42.641854

总结

PolarDB MySQL新功能SQL Detail可以详细记录用户的各类库表变更操作，并且可以自动淘汰过期记录，帮助用户以极低的成本对库表操作做审计工作。

原文：http://mysql.taobao.org/monthly/2023/01/03/