追蹤mysql操作記錄時間1.

bestone0213發表於2015-03-16
MySql
測試環境莫名其妙有幾條重要資料被刪除了，由於在binlog裡面只看到是公用賬號刪除的，無法查詢是那個誰在那個時間段登入的，就考慮怎麼記錄每一個MYSQL賬號的登入資訊，在MYSQL中，每個連線都會先執行init-connect，進行連線的初始化，我們可以在這裡獲取使用者的登入名稱和thread的ID值。然後配合binlog，就可以追蹤到每個操作語句的操作時間，操作人以及客戶端的連線程式資訊等。實現審計。


1，在mysql伺服器db中建立單獨的記錄訪問資訊的庫
set names utf8;
create database access_log;
CREATE TABLE `access_log` 
(
  `id` int(11) NOT NULL AUTO_INCREMENT,
  `thread_id` int(11) DEFAULT NULL, -- 執行緒ID，這個值很重要
  `log_time` timestamp NOT NULL DEF AULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP, -- 登入時間
  `localname` varchar(30) DEFAULT NULL, -- 登入名稱
  `matchname` varchar(30) DEFAULT NULL, -- 登入使用者
  PRIMARY KEY (`id`)
) ENGINE=InnoDB AUTO_INCREMENT=1 DEFAULT CHARSET=utf8 comment '錄入使用者登入資訊';



2，在配置檔案中配置init-connect引數。登入時插入日誌表。如果這個引數是個錯誤的SQL語句，登入就會失敗。
vim /usr/local/mysql/my.cnf
init-connect='INSERT INTO access_log.access_log VALUES(NULL,CONNECTION_ID(),NOW(),USER(),CURRENT_USER());'
然後重啟資料庫

3，建立普通使用者，不能有super許可權，而且使用者必須有對access_log庫的access_log表的insert許可權，否則會登入失敗。
給登入使用者賦予insert許可權，但是不賦予access_log的insert、select許可權，
GRANT INSERT,DELETE,UPDATE,SELECT ON test.* TO audit_user@'%' IDENTIFIED BY 'cacti_user1603';
mysql> GRANT CREATE,DROP,ALTER,INSERT,DELETE,UPDATE,SELECT ON test.* TO audit_user@'%' IDENTIFIED BY 'cacti_user1603';
Query OK, 0 rows affected (0.00 sec)
mysql> exit
然後去用新的audit_user登入操作
[root@db_server ~]# /usr/local/mysql/bin/mysql  -uaudit_user -p -S /usr/local/mysql/mysql.sock
Enter password: 
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 25
Server version: 5.6.12-log

Copyright (c) 2000, 2013, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> lect * from access_log.access_log;
ERROR 2006 (HY000): MySQL server has gone away
No connection. Trying to reconnect...
Connection id:    26
Current database: *** NONE ***


ERROR 1184 (08S01): Aborted connection 26 to db: 'unconnected' user: 'audit_user' host: 'localhost' (init_connect command failed)
mysql> 
看到報錯資訊 (init_connect command failed)，再去錯誤日誌error log驗證一下：
tail -fn 5 /usr/local/mysql/mysqld.log 
2014-07-28 16:03:31 23743 [Warning] Aborted connection 25 to db: 'unconnected' user: 'audit_user' host: 'localhost' (init_connect command failed)
2014-07-28 16:03:31 23743 [Warning] INSERT command denied to user ''@'localhost' for table 'access_log'
2014-07-28 16:04:04 23743 [Warning] Aborted connection 26 to db: 'unconnected' user: 'audit_user' host: 'localhost' (init_connect command failed)
2014-07-28 16:04:04 23743 [Warning] INSERT command denied to user ''@'localhost' for table 'access_log'
看到必須要有對access_log庫的access_log表的insert許可權才行。


4，賦予使用者access_log的insert、select許可權，然後重新賦予許可權：
GRANT SELECT,INSERT ON access_log.* TO audit_user@'%';
mysql> 
mysql> GRANT SELECT,INSERT ON access_log.* TO audit_user@'%';
Query OK, 0 rows affected (0.00 sec)

mysql> exit
Bye

再登入，報錯如下：
[root@db_server ~]# /usr/local/mysql/bin/mysql  -uaudit_user -p -S /usr/local/mysql/mysql.sock
Enter password: 
ERROR 1045 (28000): Access denied for user 'audit_user'@'localhost' (using password: YES)
[root@db_server ~]# 

去檢視error日誌：
2014-07-28 16:15:29 23743 [Warning] INSERT command denied to user ''@'localhost' for table 'access_log'
2014-07-28 16:15:41 23743 [Warning] Aborted connection 37 to db: 'unconnected' user: 'audit_user' host: 'localhost' (init_connect command failed)
2014-07-28 16:15:41 23743 [Warning] INSERT command denied to user ''@'localhost' for table 'access_log'
2014-07-28 16:15:50 23743 [Warning] Aborted connection 38 to db: 'unconnected' user: 'audit_user' host: 'localhost' (init_connect command failed)
2014-07-28 16:15:50 23743 [Warning] INSERT command denied to user ''@'localhost' for table 'access_log'

需要用root使用者登入進去，清空掉使用者為''的使用者記錄。
 mysql> select user,host,password from mysql.user;
+----------------+-----------+-------------------------------------------+
| user           | host      | password                                  |
+----------------+-----------+-------------------------------------------+
| root           | localhost |                                           |
| root           | db_server   |                                           |
| root           | 127.0.0.1 |                                           |
| root           | ::1       |                                           |
|                | localhost |                                           |
|                | db_server   |                                           |
| cacti_user     | %         | *EB9E3195E443D577879101A35EF64A701B35F949 |
| cacti_user     | 1         | *D5FF9B53A78232DA13D3643965A5961449B387DB |
| cacti_user     | 2         | *D5FF9B53A78232DA13D3643965A5961449B387DB |
| test_user      | 192.%     | *8A447777509932F0ED07ADB033562027D95A0F17 |
| test_user      | 1         | *8A447777509932F0ED07ADB033562027D95A0F17 |
| weakpwd_user_1 | 10.%      | *6BB4837EB74329105EE4568DDA7DC67ED2CA2AD9 |
| weakpwd_user_2 | 10.%      | *B1461C9C68AFA1129A5F968C343636192A084ADB |
| weakpwd_user_3 | 10.%      | *DCB7DF5FFC82C441503300FFF165257BC551A598 |
| audit_user     | %         | *AEAB1915B137FAFDE9B949D67A9A42DDB68DD8A2 |
+----------------+-----------+-------------------------------------------+
15 rows in set (0.00 sec)

mysql> drop user ''@'localhost';
Query OK, 0 rows affected (0.00 sec)

mysql> drop user ''@'db_server';
Query OK, 0 rows affected (0.00 sec)

mysql> 

再用已經分配了access_log表的Insert許可權的audit_user登入
mysql> select * from access_log.access_log;
+----+-----------+---------------------+---------------------------+--------------+
| id | thread_id | log_time            | localname                 | matchname    |
+----+-----------+---------------------+---------------------------+--------------+
|  4 |        41 | 2014-07-28 16:19:37 | audit_user@localhost      | audit_user@% |
|  5 |        42 | 2014-07-28 16:20:32 | audit_user@localhost      | audit_user@% |
|  6 |        45 | 2014-07-28 16:21:11 | audit_user@localhost      | audit_user@% |
+----+-----------+---------------------+---------------------------+--------------+
6 rows in set (0.00 sec)

mysql> show full processlist;
+----+------------+-----------+------+---------+------+-------+-----------------------+
| Id | User       | Host      | db   | Command | Time | State | Info                  |
+----+------------+-----------+------+---------+------+-------+-----------------------+
| 45 | audit_user | localhost | NULL | Query   |    0 | init  | show full processlist |
+----+------------+-----------+------+---------+------+-------+-----------------------+
1 row in set (0.00 sec)

mysql> 

5，再用另外一個使用者登入建表，錄入測試資料。
建表錄入資料記錄
mysql> use test;
Database changed
mysql> create table t1 select 1 as a, 'wa' as b;
Query OK, 1 row affected (0.01 sec)
Records: 1  Duplicates: 0  Warnings: 0

檢視跟蹤使用者行為記錄。
mysql> select * from access_log.access_log;
+----+-----------+---------------------+---------------------------+--------------+
| id | thread_id | log_time            | localname                 | matchname    |
+----+-----------+---------------------+---------------------------+--------------+
|  4 |        41 | 2014-07-28 16:19:37 | audit_user@localhost      | audit_user@% |
|  5 |        42 | 2014-07-28 16:20:32 | audit_user@localhost      | audit_user@% |
|  6 |        45 | 2014-07-28 16:21:11 | audit_user@localhost      | audit_user@% |
|  7 |        48 | 2014-07-28 16:30:42 | audit_user@192.168.3.62    | audit_user@% |
|  8 |        50 | 2014-07-28 16:46:11 | audit_user@192.168.3.62    | audit_user@% |
+----+-----------+---------------------+---------------------------+--------------+
8 rows in set (0.00 sec)

去mysql db伺服器上檢視binlog 內容，解析完後，沒有insert語句，怎麼回事，去看my.cnf
#binlog-ignore-db=mysql                         # No sync databases
#binlog-ignore-db=test                          # No sync databases
#binlog-ignore-db=information_schema            # No sync databases
#binlog-ignore-db=performance_schema

原來是對test庫有binlog過濾設定，全部註釋掉。重啟mysql庫，重新來一遍，可以在看到binlog
在MySQL客戶端上重新執行。
mysql> use test;
Database changed
mysql> insert into test.t1 select 5,'t5';
Query OK, 1 row affected (0.00 sec)
Records: 1  Duplicates: 0  Warnings: 0

mysql> select * from access_log.access_log;
+----+-----------+---------------------+---------------------------+--------------+
| id | thread_id | log_time            | localname                 | matchname    |
+----+-----------+---------------------+---------------------------+--------------+
|  1 |        17 | 2014-07-28 15:41:04 | cacti_user@192.168.171.71 | cacti_user@% |
|  2 |        18 | 2014-07-28 15:41:05 | cacti_user@192.168.171.71 | cacti_user@% |
|  3 |        19 | 2014-07-28 15:41:05 | cacti_user@192.168.171.71 | cacti_user@% |
|  4 |        41 | 2014-07-28 16:19:37 | audit_user@localhost      | audit_user@% |
|  5 |        42 | 2014-07-28 16:20:32 | audit_user@localhost      | audit_user@% |
|  6 |        45 | 2014-07-28 16:21:11 | audit_user@localhost      | audit_user@% |
|  7 |        48 | 2014-07-28 16:30:42 | audit_user@192.168.3.62    | audit_user@% |
|  8 |        50 | 2014-07-28 16:46:11 | audit_user@192.168.3.62    | audit_user@% |
|  9 |        56 | 2014-07-28 19:32:12 | audit_user@192.168.1.12    | audit_user@% |
| 10 |         1 | 2014-07-28 20:02:56 | audit_user@192.168.3.62    | audit_user@% |
+----+-----------+---------------------+---------------------------+--------------+
10 rows in set (0.00 sec)
看到thread_id為1


6，如何檢視何跟蹤使用者行為記錄。
去mysql資料庫伺服器上檢視binlog，應該thread_id=1的binlog記錄。
[root@db_server binlog]# /usr/local/mysql/bin/mysqlbinlog  --base64-output=DECODE-ROWS  mysql-bin.000018 -v>3.log
[root@db_server binlog]# vim 3.log
# at 1103
#140728 20:12:48 server id 72  end_log_pos 1175 CRC32 0xa323c00e        Query   thread_id=1     exec_time=0     error_code=0
SET TIMESTAMP=1406549568/*!*/;
BEGIN
/*!*/;
# at 1175
#140728 20:12:48 server id 72  end_log_pos 1229 CRC32 0xbb8ca914        Table_map: `access_log`.`t1` mapped to number 72
# at 1229
#140728 20:12:48 server id 72  end_log_pos 1272 CRC32 0x8eed1450        Write_rows: table id 72 flags: STMT_END_F
### INSERT INTO `access_log`.`t1`
### SET
###   @1=10
###   @2='w0'
# at 1272
#140728 20:12:48 server id 72  end_log_pos 1303 CRC32 0x72b26336        Xid = 14
COMMIT/*!*/;

看到thread_id=1，然後，就可以根據thread_id=1來判斷執行這條insert命令的來源，還可以在mysql伺服器上執行show full processlist;來得到MySQL客戶端的請求埠，
mysql> show full processlist;
+----+------------+-------------------+------+---------+------+-------+-----------------------+
| Id | User       | Host              | db   | Command | Time | State | Info                  |
+----+------------+-------------------+------+---------+------+-------+-----------------------+
|  1 | audit_user | 192.168.3.62:44657 | test | Sleep   |  162 |       | NULL                  |
|  3 | root       | localhost         | NULL | Query   |    0 | init  | show full processlist |
+----+------------+-------------------+------+---------+------+-------+-----------------------+
2 rows in set (0.00 sec)


mysql> 
看到Id為1的執行緒，埠是44657。

我們切換回mysql客戶端，去檢視埠是44657的是什麼程式，如下所示：
[tim@db_client ~]$ netstat -antlp |grep 44657
(Not all processes could be identified, non-owned process info
 will not be shown, you would have to be root to see it all.)
tcp        0      0 192.168.3.62:44657           192.168.1.12:3307            ESTABLISHED 6335/mysql          
[tim@db_client ~]$ 

獲取到該程式的PID 6335，再通過ps -eaf得到該程式所執行的命令，如下所示：
[tim@db_client ~]$ ps -eaf|grep 6335
tim   6335 25497  0 19:59 pts/1    00:00:00 mysql -uaudit_user -p -h 192.168.1.12 -P3307
tim   6993  6906  0 20:16 pts/2    00:00:00 grep 6335
[tim@db_client ~]$

最後查到是通過mysql客戶端登陸連線的。加入這個6335是某個web工程的，那麼，也可以根據ps -eaf命令查詢得到web工程的程式資訊。



參考文章地址：http://blog.chinaunix.net/uid-24086995-id-168445.html

相關文章