2016年5月16日月曜日

MySQL Routerの接続でMySQL Fabricのlogテーブルがあふれた(event_schedulerをOFFにするとあぶない)

MySQL Fabricには /etc/mysql/fabric.cfg の [logging]セクションの他にもログを取る部分が仕込まれていて、


mysql> SELECT * FROM fabric.log;
+---------------------------+----------------------------+------------------------------+-----------------------------------------------------------------------+----------+------+
| subject                   | reported                   | reporter                     | message                                                               | category | type |
+---------------------------+----------------------------+------------------------------+-----------------------------------------------------------------------+----------+------+
| 0                         | 2016-05-16 06:48:47.000000 | mysql.fabric.services.manage | Fabric node version (1.5.6) started.                                  |        0 |    0 |
| manage.ping               | 2016-05-16 06:48:52.000000 | mysql.fabric.command         | Started command (manage, ping).                                       |        1 |    0 |
| manage.ping               | 2016-05-16 06:48:52.000000 | mysql.fabric.command         | Finished command (manage, ping).                                      |        1 |    1 |
..
| dump.servers              | 2016-05-16 06:55:53.000000 | mysql.fabric.command         | Finished command (dump, servers).                                     |        1 |    1 |
| dump.sharding_information | 2016-05-16 06:55:53.000000 | mysql.fabric.command         | Started command (dump, sharding_information).                         |        1 |    0 |
| dump.sharding_information | 2016-05-16 06:55:53.000000 | mysql.fabric.command         | Finished command (dump, sharding_information).                        |        1 |    1 |
+---------------------------+----------------------------+------------------------------+-----------------------------------------------------------------------+----------+------+
1297 rows in set (0.02 sec)

なんというか、どぱーと吐いている。

( ´-`).oO(こんなトランザクションで保護される必要もなさそうな間っ平なログをMySQLに突っ込むとか、何考えてるのか小一時間問い詰めたい。


そしてなんか周辺の流れを見ても、何のフィルターもなく毎回INSERTされてるように見える。マジか(Python詳しい人誰か)

https://github.com/mysql/mysql-fabric/blob/release/1.5.5/lib/mysql/fabric/handler.py#L305-L307



$ mysqlbinlog -R -uroot -h 172.17.0.4 --stop-never -vv --start-position=182893 bin.000001 | grep "^#"
..

# at 285377
#160516 15:55:53 server id 1  end_log_pos 285408 CRC32 0x7f70413b       Xid = 5500
# at 285408
#160516 15:55:53 server id 1  end_log_pos 285473 CRC32 0xb35843f4       Anonymous_GTID  last_committed=772      sequence_number=773
# at 285473
#160516 15:55:53 server id 1  end_log_pos 285555 CRC32 0xd3de3d80       Query   thread_id=4     exec_time=0     error_code=0
# at 285555
#160516 15:55:53 server id 1  end_log_pos 285614 CRC32 0x12ff61e4       Table_map: `fabric`.`log` mapped to number 110
# at 285614
#160516 15:55:53 server id 1  end_log_pos 285734 CRC32 0x3c061fb3       Write_rows: table id 110 flags: STMT_END_F
### INSERT INTO `fabric`.`log`
### SET
###   @1='dump.servers' /* VARSTRING(120) meta=120 nullable=0 is_null=0 */
###   @2=1463349353.000000 /* TIMESTAMP(6) meta=6 nullable=0 is_null=0 */
###   @3='mysql.fabric.command' /* VARSTRING(192) meta=192 nullable=0 is_null=0 */
###   @4='Finished command (dump, servers).' /* BLOB/TEXT meta=2 nullable=1 is_null=0 */
###   @5=1 /* INT meta=0 nullable=0 is_null=0 */
###   @6=1 /* INT meta=0 nullable=0 is_null=0 */
# at 285734
#160516 15:55:53 server id 1  end_log_pos 285765 CRC32 0x39af684e       Xid = 5508
# at 285765
#160516 15:55:53 server id 1  end_log_pos 285830 CRC32 0xe449e1fe       Anonymous_GTID  last_committed=773      sequence_number=774
# at 285830
#160516 15:55:53 server id 1  end_log_pos 285912 CRC32 0x239e9184       Query   thread_id=4     exec_time=0     error_code=0
# at 285912
#160516 15:55:53 server id 1  end_log_pos 285971 CRC32 0xe2235101       Table_map: `fabric`.`log` mapped to number 110
# at 285971
#160516 15:55:53 server id 1  end_log_pos 286116 CRC32 0xf5cc5f55       Write_rows: table id 110 flags: STMT_END_F
### INSERT INTO `fabric`.`log`
### SET
###   @1='dump.sharding_information' /* VARSTRING(120) meta=120 nullable=0 is_null=0 */
###   @2=1463349353.000000 /* TIMESTAMP(6) meta=6 nullable=0 is_null=0 */
###   @3='mysql.fabric.command' /* VARSTRING(192) meta=192 nullable=0 is_null=0 */
###   @4='Started command (dump, sharding_information).' /* BLOB/TEXT meta=2 nullable=1 is_null=0 */
###   @5=1 /* INT meta=0 nullable=0 is_null=0 */
###   @6=0 /* INT meta=0 nullable=0 is_null=0 */

MySQL Routerを起動している間中、ずっとこれが来る。
それぞれのmysqlrouterから1秒に3リクエストずつ来ているらしく、そんな感じで倍々ゲームになっている:(;゙゚'ω゚'):

さてどうしようか。


【2016/05/17 13:46】

event_schedulerをOFFにしてたのがいけなかったのか!!!!

mysql> SELECT * FROM events\G
*************************** 1. row ***************************
       EVENT_CATALOG: def
        EVENT_SCHEMA: fabric
          EVENT_NAME: prune_log
             DEFINER: mikasa_fabric@127.0.0.1
           TIME_ZONE: SYSTEM
          EVENT_BODY: SQL
    EVENT_DEFINITION: DELETE FROM log WHERE TIMEDIFF(UTC_TIMESTAMP(), reported) > MAKETIME(3600,0,0)
          EVENT_TYPE: RECURRING
          EXECUTE_AT: NULL
      INTERVAL_VALUE: 3600
      INTERVAL_FIELD: SECOND
            SQL_MODE: NO_ENGINE_SUBSTITUTION
              STARTS: 2016-04-04 15:49:10
                ENDS: NULL
              STATUS: ENABLED
       ON_COMPLETION: NOT PRESERVE
             CREATED: 2016-04-04 15:49:10
        LAST_ALTERED: 2016-04-04 15:49:10
       LAST_EXECUTED: NULL
       EVENT_COMMENT:
          ORIGINATOR: 33893
CHARACTER_SET_CLIENT: utf8
COLLATION_CONNECTION: utf8_general_ci
  DATABASE_COLLATION: utf8_general_ci
*************************** 2. row ***************************
       EVENT_CATALOG: def
        EVENT_SCHEMA: fabric
          EVENT_NAME: prune_error_log
             DEFINER: mikasa_fabric@127.0.0.1
           TIME_ZONE: SYSTEM
          EVENT_BODY: SQL
    EVENT_DEFINITION: DELETE FROM error_log WHERE TIMEDIFF(UTC_TIMESTAMP(), reported) > MAKETIME(3600,0,0)
          EVENT_TYPE: RECURRING
          EXECUTE_AT: NULL
      INTERVAL_VALUE: 3600
      INTERVAL_FIELD: SECOND
            SQL_MODE: NO_ENGINE_SUBSTITUTION
              STARTS: 2016-04-04 15:49:11
                ENDS: NULL
              STATUS: ENABLED
       ON_COMPLETION: NOT PRESERVE
             CREATED: 2016-04-04 15:49:11
        LAST_ALTERED: 2016-04-04 15:49:11
       LAST_EXECUTED: NULL
       EVENT_COMMENT:
          ORIGINATOR: 33893
CHARACTER_SET_CLIENT: utf8
COLLATION_CONNECTION: utf8_general_ci
  DATABASE_COLLATION: utf8_general_ci
2 rows in set (0.00 sec)

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


MySQL Bugs: #73206: MySQL Fabric should report a warning when MySQL Event Scheduler is disabled




1. logテーブルをBlackhole化する

mysql> use fabric
mysql> ALTER TABLE log Engine= Blackhole;

一番最初にこれが出てくるのもなんだかななんだけど、なんとこれ無事に動く。
mysqlfabricデーモンを再起動してもフツーに動いた。マジか。


2. ロギングをすっ飛ばすようにMySQL Fabric側をゴニョる

$ diff -C1 /usr/lib/python2.6/site-packages/mysql/fabric/handler.py handler.py
*** /usr/lib/python2.6/site-packages/mysql/fabric/handler.py    2015-09-11 14:31:50.000000000 +0900
--- handler.py  2016-05-16 16:51:12.000000000 +0900
***************
*** 209,214 ****
          """
-         persister.exec_stmt(_INSERT_FABRIC_LOG,
-             {"params": (subject, reported, reporter, info, info_category,
-             info_type)}
-         )

--- 209,210 ----

これでももちろんMySQL Routerはちゃんと動く。


3. 定期的にlogテーブルからレコードをパージする

至極当たり前すぎる。
何故かすごくごちゃごちゃとインデックスが張ってあるので、reportedで期間を切って定期的に消すのはそんなに難しくないはずだ。
(最近のMySQLはOPTIMIZE TABLEもオンラインでできるのでー。。)

mysql> SHOW CREATE TABLE log\G
*************************** 1. row ***************************
       Table: log
Create Table: CREATE TABLE `log` (
  `subject` varchar(40) NOT NULL,
  `reported` timestamp(6) NOT NULL DEFAULT CURRENT_TIMESTAMP(6) ON UPDATE CURRENT_TIMESTAMP(6),
  `reporter` varchar(64) NOT NULL,
  `message` text,
  `category` int(11) NOT NULL,
  `type` int(11) NOT NULL,
  KEY `key_subject_reported` (`subject`,`reported`),
  KEY `key_reporter` (`reporter`),
  KEY `key_reported` (`reported`),
  KEY `key_category` (`category`),
  KEY `key_type` (`type`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8
1 row in set (0.00 sec)


これ、実際に運用してる人はどうしてるんでしょうか。
お客様の中にMySQL Fabricを運用している方はいらっしゃいませんか?


…いらっしゃいませんね。

0 件のコメント :

コメントを投稿