熟悉mysql的朋友应该都知道,error日志只记录数据库层的报错,binlog只记录增/删/改的记录,但是没记录谁执行,只记录执行用户名,slowlog虽然详细,但是只记录超过设定值的慢查询sql信息.
只有general-log才是记录所有的操作日志,不过他会耗费数据库5%-10%的性能,所以一般没什么特别需要,大多数情况是不开的,例如一些sql审计和不知名的排错等,那就是打开来使用了.
开启的方法
开启方法很简单,
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
|
#先查看当前状态
mysql> show variables like
'general%'
;
+------------------+--------------------------------+
| Variable_name | Value |
+------------------+--------------------------------+
| general_log | OFF |
| general_log_file |
/data/mysql/data/localhost
.log |
+------------------+--------------------------------+
2 rows
in
set
(0.00 sec)
#可以在my.cnf里添加,1开启(0关闭),当然了,这样要重启才能生效,有点多余了
general-log = 1
log =
/log/mysql_query
.log路径
#也可以设置变量那样更改,1开启(0关闭),即时生效,不用重启,首选当然是这样的了
set
global general_log=1
#这个日志对于操作频繁的库,产生的数据量会很快增长,出于对硬盘的保护,可以设置其他存放路径
set
global general_log_file=
/tmp/general_log
.log
|
然后就开启完了,看看是否有这个文件存在并产生了日志,我们看到localhost.log已经生成了,因为我是默认的,所以名字就是这样的.
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
|
#ll
总用量 3215528
-rw-rw----. 1 mysql mysql 56 9月 5 11:32 auto.cnf
drwx------ 2 mysql mysql 4096 9月 17 14:09 gw
-rw-rw---- 1 mysql mysql 25666 9月 8 17:07 ib_buffer_pool
-rw-rw----. 1 mysql mysql 1073741824 9月 19 10:21 ibdata1
-rw-rw----. 1 mysql mysql 1073741824 9月 19 10:21 ib_logfile0
-rw-rw----. 1 mysql mysql 1073741824 9月 5 11:27 ib_logfile1
-rw-rw---- 1 mysql mysql 5 9月 8 17:11 localhost.localdomain.pid
-rw-rw---- 1 mysql mysql 6699602 9月 19 09:50 localhost.log
-rw-rw---- 1 mysql mysql 5 9月 14 09:16 localhost.pid
drwx------. 2 mysql mysql 4096 9月 5 11:27 mysql
-rw-rw---- 1 mysql mysql 34539 9月 7 14:57 mysql-bin.000006
-rw-rw---- 1 mysql mysql 13746613 9月 8 17:07 mysql-bin.000007
-rw-rw---- 1 mysql mysql 498989 9月 14 09:16 mysql-bin.000008
-rw-rw---- 1 mysql mysql 48302055 9月 19 10:20 mysql-bin.000009
-rw-rw---- 1 mysql mysql 136 9月 14 09:16 mysql-bin.index
-rw-rw----. 1 mysql mysql 57569 9月 14 09:16 mysql.err
drwx------. 2 mysql mysql 4096 9月 5 11:27 performance_schema
drwx------ 2 mysql mysql 4096 9月 17 14:35
test
|
开启完了,就看怎么分析了.
分析日志
其实也比较直观,只是容易混淆,下面来看例子.
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
|
/usr/local/mysql/bin/mysqld
, Version: 5.6.32-78.0-log (Percona Server (GPL), Release 78.0, Revision 8a8e016). started with:
Tcp port: 3306 Unix socket:
/tmp/mysql
.sock
Time Id Command Argument
160919 9:28:19 30722 Connect root@192.168.1.252 on
test
30722 Query SET SESSION sql_mode =
REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(
@@sql_mode,
"STRICT_ALL_TABLES,"
,
""
),
",STRICT_ALL_TABLES"
,
""
),
"STRICT_ALL_TABLES"
,
""
),
"STRICT_TRANS_TABLES,"
,
""
),
",STRICT_TRANS_TABLES"
,
""
),
"STRICT_TRANS_TABLES"
,
""
)
30722 Query SET NAMES utf8
30722 Query SELECT *
FROM `
type
`
WHERE `pid` = 30
30722 Quit
160919 9:28:38 29975 Query SHOW GLOBAL STATUS
160919 9:28:39 30728 Connect root@192.168.1.95 on
test
30728 Query SET SESSION sql_mode =
REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(
@@sql_mode,
"STRICT_ALL_TABLES,"
,
""
),
",STRICT_ALL_TABLES"
,
""
),
"STRICT_ALL_TABLES"
,
""
),
"STRICT_TRANS_TABLES,"
,
""
),
",STRICT_TRANS_TABLES"
,
""
),
"STRICT_TRANS_TABLES"
,
""
)
30728 Query SET NAMES utf8
30728 Query SELECT `a`.*, `b`.`clientname`, `b`.`deptname`, `b`.`receiveprovince`, `b`.`carriers`, `b`.`receivecity`
FROM `repri` as `a`
LEFT JOIN `illmain` as `b` ON `a`.`illid` = `b`.`illID`
WHERE `a`.`
id
` =
'21'
30728 Query SELECT `typename`
FROM `
type
`
WHERE `
id
` =
'8'
30728 Query SELECT `typename`
FROM `
type
`
WHERE `
id
` =
'9'
30728 Query SELECT *
FROM `handlepri`
WHERE `
id
` =
'21'
30728 Query SELECT *
FROM `low_re`
WHERE `low` =
'21'
AND `
type
` =0
ORDER BY `
id
` desc
30728 Query SELECT *
FROM `guide`
WHERE `ll_type` =
'9'
30728 Query SELECT *
FROM `illmain`
WHERE `illid` =
'0992016'
OR `orderid` =
'0992016'
30728 Quit
|
我们来按列来解析
第一列:时间列,前面一个是日期,后面一个是小时和分钟,有一些不显示的原因是因为这些sql语句几乎是同时执行的,所以就不另外记录时间了.
第二列:ID列,就是show processlist出来的第一列的线程ID,对于长连接和一些比较耗时的sql语句,你可以精确找出究竟是那一条那一个线程在运行.
第三列:操作类型,Connect就是连接数据库,Query就是查询数据库(增删查改都显示为查询),可以特定过虑一些操作.
第四列:详细信息,例如上面例子Connect的详细信息就是root@192.168.1.95 on test,意思就是root@192.168.1.95连上test库,如此类推,下面的意思就是30728这个线程号连上数据库之后,做了什么查询的操作.
还有其他一些grant/drop/create/alter等的操作,general_log都回全部记录下来,不过这里就不细细演示了,各位可以尝试一下.
最后,也正如我开始说的,有了这些信息,做sql语句审计就变得可能了,找到责任人也是没有压力的,而对于一些疑难杂症的sql分析也是很简单了.
本文转自arthur376 51CTO博客,原文链接:http://blog.51cto.com/arthur376/1853924,如需转载请自行联系原作者