GA

2016/05/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を運用している方はいらっしゃいませんか?


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

2016/05/09

innotopが最近息してないなーと思ったんだ

使っている人口がどれくらいいるかわからないですが、 innotop というtopライクにMySQLの状況を表示してくれる便利スクリプトが世の中には存在しています。

日々の覚書: innotopがすごく便利

もともとGoogle Codeにホスティングされてたんだけど、Google Codeはサービス終了しちゃったから(いつからか知らないけど)GitHubに移行してて、ひょっとしたらこのまま(移行だけしてメンテナンスされなくなって)息を引き取るんじゃないか疑惑が当時から俺の中にあったりなかったり。


原因がそれかどうかは全く知らないけれど、 innotopは5.6までは問題なく使える(5.6で使えなくなった時にちゃんと対応された)んだけど、5.7だと `SHOW ENGINE INNODB STATUS` をパースできなくなっていて(それ以外は何とか使える)、随分前からこれはIssueに上がってるんだけど、全然直される気配がない。

App crash on the "T" and "L" pages · Issue #109 · innotop/innotop


というか、 "Support MySQL 5.7" と銘打たれたコミットがひどすぎて、テストすら通らない(何故マージされたし)

Support MySQL 5.7 by potto007 · Pull Request #114 · innotop/innotop


ちまちま直してったら、こんな転け方もした。日付が違う? 馬鹿な。

$ perl t/InnoDBParser.t
1..5
ok 1 - /home/yoku0825/git/innotop/t/innodb-status-007
ok 2 - /home/yoku0825/git/innotop/t/innodb-status-001
ok 3 - /home/yoku0825/git/innotop/t/innodb-status-002
not ok 4 - /home/yoku0825/git/innotop/t/innodb-status-009
#   Failed test '/home/yoku0825/git/innotop/t/innodb-status-009'
#   at InnoDBParser.t line 2193.
#     Structures begin differing at:
#          $got->{IB_timestring} = '2015-06-09 13:52:05'
#     $expected->{IB_timestring} = '2013-06-19 13:47:37'
ok 5 - /home/yoku0825/git/innotop/t/innodb-status-008
ok 6 - /home/yoku0825/git/innotop/t/innodb-status-006
# Looks like you planned 5 tests but ran 6.
# Looks like you failed 1 test of 6 run.


という訳でまずテストを直すPRした。これがマージされれば Issue #109のやつも頑張るかも知れない。これがマージされないようなら、 innotop は死んだんであろう(というか、死んだと思ってForkしてゴニョったやつをrpmbuildしたらテストが通らないのに気が付いた。。)

Fix broken test for 5.7 by yoku0825 · Pull Request #135 · innotop/innotop


出来れば死なずにメンテナンスされ続けて欲しいなーと思いつつ、今後どうなるかなぁ。。
(多少なら自分で使う分くらいは頑張れると思うんだけど、全面的にメンテナンスは無理だなきっと。。)


【2016/05/11 00:20】

2016/05/02

はじめてのMySQLへのPull-Request体験談

の前に、いくつかMySQLへのContributeの前提を。

MySQLへのコードの寄贈は

1. Oracleプロファイルを持っていないといけない。ダウンロードする時に "No thanks" に気付かないと作らされるアレ。
2. Oracle Contributor Agreement にサインしないといけない(OCAにサインしたかどうかがOracleプロファイルに紐付けられる…ので、Oracleプロファイルが必要みたい)

が前提になる。


【2016/05/06 23:35】

ちなみにMariaDBの場合も似たようなもので

If you want the code to be part of the main MariaDB tree, you also have to give the MariaDB Foundation a shared copyright to your code. This is needed so that the foundation can offer the code to other projects (like MySQL).

You do this by either:

1. Signing the MariaDB Contributor Agreement (MCA) and then scanning and sending it to the foundation.
2. Sending an email to maria-developers where you say that your patch and all fixes to it are provided to the MariaDB Foundation under the MCA.
3. Licensing your code using the BSD license.
Contributing Code - MariaDB Knowledge Base

MCAにサインするか、パッチのライセンスを明示的にBSDにする必要がある。


これなしでいきなりPull-Requestしても多分蹴られる(ってか手違いで蹴られた)


前提について詳しくはこのへんの記事が読みやすくて良いと思う。




で、取り敢えず バグレポート を上げて、GitHubでも Pull-Request を出してみた。

予想としては
Hi, thank you for your contribution. Please confirm this code is submitted under the terms of the OCA (Oracle's Contribution Agreement) you have previously signed by cutting and pasting the following text as a comment:
"I confirm the code being submitted is offered under the terms of the OCA, and that I am authorized to contribute it."
Thanks

bug 79747: crc32 optimizations by grooverdan · Pull Request #68 · mysql/mysql-server

こんな感じで、「これコピペしてね」って言われると思ってたんだけどさにあらず。



Hi, thank you for submitting this pull request. In order to consider your code we need you to sign the Oracle Contribution Agreement (OCA). Please review the details and follow the instructions at http://www.oracle.com/technetwork/community/oca-486395.html
Please make sure to include your MySQL bug system user (email) in the returned form.
Thanks

Fix Bug#80833 by yoku0825 · Pull Request #102 · mysql/mysql-sys


(;・3・) アルェー、コピペしようにもコピペするべき文章が見当たらないぞー。

mysql/mysql-server と mysql/mysql-sys でbotが違うのかなぁと思いつつ、かるーく 梅ッシュ 最近のVerifiedおじさんことUmeshに「GitHubでPull-Request出したけど大丈夫ですかね?」的なジャブをかましてみるも、「大丈夫じゃね?」的な返答。

そして待つことしばし。


Hi, there was no response to our request to sign an OCA or confirm the code is submitted under the terms of the OCA. As such this request will be closed.
Thanks

Fix Bug#80833 by yoku0825 · Pull Request #102 · mysql/mysql-sys


Σ(゚д゚lll) confirm用のメッセージが表示されないまま「お前がconfirmしないからcloseするわー」ってなった!!!1


困った時の Lenkaちゃん 。
bugs.mysql.comにパッチを送り付けると、Lenkaちゃんから「受け取ったよ!」ってメールが来る(Lenkaちゃん宛てにbugs.mysql.comからメールが飛んでるっぽく、それを転送してくれるんだけど、どうもその時間差から察するに、自動転送ってわけではなさそう)ので、きっと彼女なら詳しいはず。

待つことしばし。


it looks like that for some reason I have not added (or it was somehow removed…) your GitHub name.
As a result the script did not know that you signed OCA.

( д ) ゚ ゚ ホワッ!?

そしてmysql-oca-botと同じアイコンの mysql-admin というアカウントによってreopenされるPull-Request。
https://github.com/mysql/mysql-sys/pull/102#issuecomment-215091765


その後は無事にbotによってbugs.mysql.comがアップデートされました。

Lenkaちゃんありがとう。



…ところでついさっき気付いたんだけど、俺、今まで一度も○racleさんにGitHubアカウント提出したことなかったや。。(今はOCAの段階で聞かれるのかしらん? 体験談求む)

取り敢えず困った時はLenkaちゃん。ありがとうございました(*-人-)

2016/04/26

epelからyumでCactiをインストールするとcacti.sqlがない

久々にCactiをインストールしようとしたらハマった。
ハマったところは Cactiをインストール via yum - CentOS@さくらVPSで構築するサーバ管理・運用メモ を見て解決したんだけれど(ビバインターネット)2016年にもなってまだcacti.sql入ってないの馬鹿なの? とか思ってたらなんか変な動作してる。


なんだこれ。

# cat /etc/centos-release
CentOS release 6.6 (Final)

# yum install -y epel-release

# yum install -y cacti
..

# rpm -ql cacti | grep cacti.sql
/usr/share/doc/cacti-0.8.8b/cacti.sql

# ll /usr/share/doc/cacti-0.8.8b/cacti.sql
ls: cannot access /usr/share/doc/cacti-0.8.8b/cacti.sql: No such file or directory

# rpm -Vv cacti | grep cacti.sql
.........  d /usr/share/doc/cacti-0.8.8b/cacti.sql

epelからyumで突っ込むとcacti.sqlは無い。
でもrpm -Vでもmissingとも言われない。


# yum install -y epel-release yum-utils

# yumdownloader cacti

# yum install -y crontabs httpd mysql net-snmp net-snmp-utils php php-mysql php-snmp rrdtool perl
# rpm -i cacti-0.8.8b-7.el6.noarch.rpm

# rpm -ql cacti | grep cacti.sql
/usr/share/doc/cacti-0.8.8b/cacti.sql

# ll /usr/share/doc/cacti-0.8.8b/cacti.sql
-rw-r--r-- 1 root root 178349 Aug  7  2013 /usr/share/doc/cacti-0.8.8b/cacti.sql

# rpm -Vv cacti | grep cacti.sql
.........  d /usr/share/doc/cacti-0.8.8b/cacti.sql

yumdownloaderからのrpmでインストールするとフツーにあった(コンテナーは新しく立ち上げ直した)
えー、なにこれ。


# yum install -y epel-release yum-utils

# yumdownloader cacti
# yum install -y ./cacti-0.8.8b-7.el6.noarch.rpm

# rpm -ql cacti | grep cacti.sql
/usr/share/doc/cacti-0.8.8b/cacti.sql

# ll /usr/share/doc/cacti-0.8.8b/cacti.sql
ls: cannot access /usr/share/doc/cacti-0.8.8b/cacti.sql: No such file or directory

# rpm -Vv cacti | grep cacti.sql
.........  d /usr/share/doc/cacti-0.8.8b/cacti.sql

yumdownloaderからのyumコマンドだと消えるので、yumコマンドが悪さをしてるのはそうなんだろうけど。。
ナニコレ。

CentOS 6.6とCentOS 7.2(の吊るしのDockerイメージ)で確認。


【2016/04/26 13:42】

教えてもらいました! ビバインターネット!





# yum install -y epel-release

# diff -C1 /etc/yum.conf{.orig,}
*** /etc/yum.conf.orig  2016-04-26 04:44:45.807999999 +0000
--- /etc/yum.conf       2016-04-26 04:44:55.390999997 +0000
***************
*** 12,14 ****
  distroverpkg=centos-release
! tsflags=nodocs

--- 12,14 ----
  distroverpkg=centos-release
! #tsflags=nodocs

# yum install -y cacti

# rpm -ql cacti | grep cacti.sql
/usr/share/doc/cacti-0.8.8b/cacti.sql

# ll /usr/share/doc/cacti-0.8.8b/cacti.sql
-rw-r--r-- 1 root root 178349 Aug  7  2013 /usr/share/doc/cacti-0.8.8b/cacti.sql

やった!! ありがとうございます!!

2016/04/01

舞奈たんとは何なのか

4/1ですが大真面目なはなし(?)


俺が最初に言い出したのは多分この時。



日本MySQLユーザ会  略称MyNA(まいな)と日本MySQLユーザ会MariaDB分科会 略称MariNA(まりな)、擬人化されてないのおかしくね? みたいなネタでした(誰だったか忘れたけれど誰かが言ってたのをネタにしたと記憶している)


【2016/04/27 12:42】
代表えもんだったようです。







それ以降は割としょっちゅう言ってた気がします。




あれから2年が経ち…カッとしてクラウドワークスで発注しました。
今でもなんであんなにムキになって舞奈たんを擬人化したかったのか良くわかりません。
なお、舞奈たんは「マイナくん(仮)」の擬人化であってMySQLの擬人化ではないので、緑色です。

最初は 第2回 MySQL・PostgreSQLユーザーグループ(MyNA・JPUG)合同DB勉強会 に間に合うようなスケジュールを考えていたんですが(「MySQLといかMyNAのPostgreSQLというかJPUGに対する優位点? 萌えキャラがいることですよ!」って言いたかった)、依頼してたデザイナーさんと連絡が取れなくなるなどクラウドソーシングの闇をいくつか見たあとで、最終的に キヨイチ さんに受注していただきました(*-人-)





( ´-`).oO(現在もう候補画像は見られませんが、当時1案と呼ばれていたものが僅差で勝ちました。というわけでこれが舞奈たん。




この手のネタは人によって好き嫌い分かれそうですが、まあかつて↓こんなことやってた人たちなので大丈夫だろうとか思ってましたし思ってます。

萌え萌えなMySQL互換オープンソースデータベース「MoSQL」 - GIGAZINE


もともと、俺が会社目的でも個人目的でもスライドなりステッカーなりサイトなり好きなように使えるように発注したものなので、ライセンスはとてもゆるい です。
値段ぶんくらいは使い倒したいと思っているのでみなさんも協力してくだしあ。

ちなみに「どこからその予算出てるの?」と聞かれることが何度かありましたが、俺のお小遣いです


何が言いたいかと言うと今月のクレジットカードの引き落としがくぁwせdrftgyふじこlp


【2016/06/29 10:56】

うん、「また」なんだ。済まない。
(妻にバレるまでは)謝って許してもらおうとも思っていない。





ファイルとライセンスはこちら!

https://github.com/yoku0825/MyNA/tree/master/unofficial_myna_girl2


【2020/08/24 18:44】



30過ぎても反省しないとこうなる。
ファイルとライセンスはこちら!

2016/03/30

SHOW TABLE STATUSのData_lengthとかIndex_lengthとかData_freeの値をぼんやり考える

InnoDBの場合。MyISAMは全くアテにならなかった(少なくとも5.7.11では)
InnoDBでも所詮統計情報なので完全にアテになる訳じゃないのはお約束。

テスト。


mysql57> CREATE TABLE t1 (val char(250));
Query OK, 0 rows affected (0.02 sec)

mysql57> INSERT INTO t1 SET val= '';
Query OK, 1 row affected (0.00 sec)

mysql57> INSERT INTO t1 SELECT * FROM t1;
Query OK, 1 row affected (0.00 sec)
Records: 1  Duplicates: 0  Warnings: 0

..

mysql57> INSERT INTO t1 SELECT * FROM t1;
Query OK, 131072 rows affected (1.67 sec)
Records: 131072  Duplicates: 0  Warnings: 0

ysql57> ANALYZE TABLE t1;
+-------+---------+----------+----------+
| Table | Op      | Msg_type | Msg_text |
+-------+---------+----------+----------+
| d1.t1 | analyze | status   | OK       |
+-------+---------+----------+----------+
1 row in set (0.00 sec)

mysql57> SHOW TABLE STATUS\G
*************************** 1. row ***************************
           Name: t1
         Engine: InnoDB
        Version: 10
     Row_format: Compact
           Rows: 257368
 Avg_row_length: 312
    Data_length: 80330752
Max_data_length: 0
   Index_length: 0
      Data_free: 4194304
 Auto_increment: NULL
    Create_time: 2016-03-30 19:14:45
    Update_time: 2016-03-30 19:24:46
     Check_time: NULL
      Collation: utf8mb4_general_ci
       Checksum: NULL
 Create_options: row_format=Dynamic
        Comment:
1 row in set (0.01 sec)

mysql57> SELECT table_rows, sys.format_bytes(data_length) AS data_length, sys.format_bytes(index_length) AS index_length, sys.format_bytes(data_free) AS data_free FROM information_schema.tables WHERE (table_schema, table_name)= ('d1', 't1');
+------------+-------------+--------------+-----------+
| table_rows | data_length | index_length | data_free |
+------------+-------------+--------------+-----------+
|     257368 | 76.61 MiB   | 0 bytes      | 4.00 MiB  |
+------------+-------------+--------------+-----------+
1 row in set (0.01 sec)

SHOW TABLE STATUSだと見にくいのでi_s使って取ってみる。
innodb_autoextend_incrementはシステムテーブルスペース(ibdata1)の自動拡張単位で、.ibdファイルの場合は最大で4MB(らしい)

https://dev.mysql.com/doc/refman/5.6/ja/innodb-parameters.html#sysvar_innodb_autoextend_increment

100行ずつINSERTしながら100万行くらいまで様子を見てみたけど、Data_freeはだいたい4MB~7MBの間を彷徨っている様子。4MBまでは利用可能領域を使って、それを割るとautoextendするっぽい。

行を半分くらい消してみる。


mysql57> DELETE FROM t1 WHERE rand() < 0.5;
Query OK, 130891 rows affected (1.00 sec)

mysql57> ANALYZE TABLE t1;
+-------+---------+----------+----------+
| Table | Op      | Msg_type | Msg_text |
+-------+---------+----------+----------+
| d1.t1 | analyze | status   | OK       |
+-------+---------+----------+----------+
1 row in set (0.00 sec)

mysql57> SELECT table_rows, sys.format_bytes(data_length) AS data_length, sys.format_bytes(index_length) AS index_length, sys.format_bytes(data_free) AS data_free FROM information_schema.tables WHERE (table_schema, table_name)= ('d1', 't1');
+------------+-------------+--------------+-----------+
| table_rows | data_length | index_length | data_free |
+------------+-------------+--------------+-----------+
|     131354 | 76.61 MiB   | 0 bytes      | 4.00 MiB  |
+------------+-------------+--------------+-----------+
1 row in set (0.00 sec)

Data_lengthは変わらず、Data_freeも変わらず。.ibdファイルのサイズももちろん変わらない。


mysql57> INSERT INTO t1 SELECT * FROM t1 WHERE rand() < 0.5;
Query OK, 65675 rows affected (0.77 sec)
Records: 65675  Duplicates: 0  Warnings: 0

mysql57> ANALYZE TABLE t1;
+-------+---------+----------+----------+
| Table | Op      | Msg_type | Msg_text |
+-------+---------+----------+----------+
| d1.t1 | analyze | status   | OK       |
+-------+---------+----------+----------+
1 row in set (0.00 sec)

mysql57> SELECT table_rows, sys.format_bytes(data_length) AS data_length, sys.format_bytes(index_length) AS index_length, sys.format_bytes(data_free) AS data_free FROM information_schema.tables WHERE (table_schema, table_name)= ('d1', 't1');
+------------+-------------+--------------+-----------+
| table_rows | data_length | index_length | data_free |
+------------+-------------+--------------+-----------+
|     193161 | 76.42 MiB   | 0 bytes      | 4.00 MiB  |
+------------+-------------+--------------+-----------+
1 row in set (0.00 sec)

消したぶんより少ない行をINSERTすると、Data_lengthは伸びない(= 空きページが再利用されている)けどData_freeも変わらない。謎い(deleteした時にdata_freeをインクリメントしてた気がするんだけど見付けられない。気のせいだったのか)
パージスレッドのご機嫌なのかなぁと思ってinnodb_fast_shutdown= 0にして再起動してみたけど変わらない。WHEREなしのDELETEでどかんと行くとData_freeに全部計上されるんだけどなぁ。


mysql57> SET GLOBAL innodb_fast_shutdown= 0;
Query OK, 0 rows affected (0.00 sec)

mysql57> SHUTDOWN;
Query OK, 0 rows affected (0.00 sec)

$ mysqld_multi start 57


Index_lengthも同じ様子。

mysql57> ALTER TABLE t1 ADD KEY (val);
Query OK, 0 rows affected (9.73 sec)
Records: 0  Duplicates: 0  Warnings: 0

mysql57> ANALYZE TABLE t1;
+-------+---------+----------+----------+
| Table | Op      | Msg_type | Msg_text |
+-------+---------+----------+----------+
| d1.t1 | analyze | status   | OK       |
+-------+---------+----------+----------+
1 row in set (0.01 sec)

mysql57> SELECT table_rows, sys.format_bytes(data_length) AS data_length, sys.format_bytes(index_length) AS index_length, sys.format_bytes(data_free) AS data_free FROM information_schema.tables WHERE (table_schema, table_name)= ('d1', 't1');
+------------+-------------+--------------+-----------+
| table_rows | data_length | index_length | data_free |
+------------+-------------+--------------+-----------+
|     191498 | 76.44 MiB   | 58.98 MiB    | 4.00 MiB  |
+------------+-------------+--------------+-----------+
1 row in set (0.00 sec)

mysql57> DELETE FROM t1 WHERE rand() < 0.5;
Query OK, 98257 rows affected (1.94 sec)

mysql57> ANALYZE TABLE t1;
+-------+---------+----------+----------+
| Table | Op      | Msg_type | Msg_text |
+-------+---------+----------+----------+
| d1.t1 | analyze | status   | OK       |
+-------+---------+----------+----------+
1 row in set (0.02 sec)

mysql57> SELECT table_rows, sys.format_bytes(data_length) AS data_length, sys.format_bytes(index_length) AS index_length, sys.format_bytes(data_free) AS data_free FROM information_schema.tables WHERE (table_schema, table_name)= ('d1', 't1');
+------------+-------------+--------------+-----------+
| table_rows | data_length | index_length | data_free |
+------------+-------------+--------------+-----------+
|      92680 | 76.44 MiB   | 58.98 MiB    | 4.00 MiB  |
+------------+-------------+--------------+-----------+
1 row in set (0.00 sec)


大体、storage/innobase/handler/i_s.ccから上手く見つけられないんだけどどこから見つければいいんだっけ。。:(;゙゚'ω゚'):

2016/03/08

MySQL <= 5.7.10からMySQL >= 5.7.11に乗り換えるだけでdefault_password_lifetimeの呪縛から逃れられる理由

見直したらほぼ 日々の覚書: MySQL 5.7.4で導入されたdefault_password_lifetimeがじわじわくる(MySQL 5.7.11でFIX!!) に書いてあったんだけど、



default_password_lifetime はユーザー作成時には何もせず、ユーザーがログインするたびにpassword_last_changedと比較するので、default_password_lifetime= 360でユーザーを作っちゃっても今の値が0なら特に何もする必要はないです

文字コードの話でいうと、character_set_serverのデフォルトにあたるものが置き換わっただけで、テーブル単位で既に指定されている文字コードは変わらない、というのと同じ感じ。

default_password_lifetimeは「ユーザーを作ってからn日後にEXPIREする」ではなくて(変数の名前からするとそんな動作しそうなんだけど)、「ログイン試行時にpassword_lifetimeが明示的に決められていない場合、password_last_changedと現在時刻を比較して、n日以上経過してたらエラーを返す」ためのパラメーター。


mysql57> SELECT user, host, password_expired, password_last_changed, password_lifetime FROM user;
+-----------+-----------+------------------+-----------------------+-------------------+
| user      | host      | password_expired | password_last_changed | password_lifetime |
+-----------+-----------+------------------+-----------------------+-------------------+
| root      | localhost | N                | 2016-02-07 21:31:49   |              NULL |
| mysql.sys | localhost | N                | 2016-02-07 21:31:49   |              NULL |
+-----------+-----------+------------------+-----------------------+-------------------+
2 rows in set (0.00 sec)

関係してくるカラムはこのへん。

まず、password_lifetimeが NULLならuse_default_password_lifetimeのフラグが立つ。NULL以外の場合(EXPIREする日付が入る)はuse_default_password_lifetimeのフラグは降りる。これはacl_loadの中なので、mysqldが起動した時やFLUSH PRIVILEGESの時にこの処理を通る。

https://github.com/mysql/mysql-server/blob/7ef2156f065d388f2c7ba2e0a69b3610e417f4d6/sql/auth/sql_auth_cache.cc#L1764-L1798


それから認証時のcheck_password_lifetime。

1) password_expiredが'Y'ならreturn false
2) use_default_password_lifetimeフラグが降りてたらpassword_lifetimeと現在時刻を比較。過ぎてたらtrue
3) フラグが降りてなかったらpassword_last_changedと現在時刻とdefault_password_lifetimeで比較。過ぎてたらtrue

https://github.com/mysql/mysql-server/blob/7ef2156f065d388f2c7ba2e0a69b3610e417f4d6/sql/auth/sql_authentication.cc#L1988-L2028


check_password_lifetimeの呼び出し元では、password_expiredが'Y'またはcheck_password_lifetimeの戻り値がtrueならEXPIREされているとしてER_MUST_CHANGE_PASSWORD_LOGIN。

https://github.com/mysql/mysql-server/blob/7ef2156f065d388f2c7ba2e0a69b3610e417f4d6/sql/auth/sql_authentication.cc#L2358-L2381


CREATE USER時に通るのはmysql_create_userだけれど、ここは特にdefault_password_lifetimeはチェックしてない。ALTER USERとSET PASSWORDの時だけ変数を参照してるくらい。

https://github.com/mysql/mysql-server/blob/7ef2156f065d388f2c7ba2e0a69b3610e417f4d6/sql/auth/sql_user.cc#L1232


5.7.11の時点で、という感じなので、5.8以降で再び仕掛けてくる時はどうなるか知らない。