GA

2021/06/17

MySQLはCREATE USERの生パスワードをハッシュに書き換えてバイナリログに吐くけどそれどこでやってるのか

いつから入ったか忘れたけど、5.6の途中くらいだった気がする。

mysql80 8> CREATE USER yoku0825 IDENTIFIED BY 'abc';
Query OK, 0 rows affected (0.01 sec)

$ mysqlbinlog bin.000002
..
CREATE USER 'yoku0825'@'%' IDENTIFIED WITH 'mysql_native_password' AS '*0D3CED9BEC10A777AEC23CCC353A8C08A633045E'
/*!*/;
..

こんな感じで、平文でパスワードを指定するようなクエリーを実行させると、バイナリログでは互換性のあるハッシュ形式に書き換えて記録してくれるやつ。

mysql80 8> CREATE USER yoku0824 IDENTIFIED BY 'c';

(gdb) bt
+bt
#0  Rewriter_create_user::append_user_auth_info (this=0x7f89a00c8cc0, user=0x7f89a000c1e0, comma=false, str=0x7f89f7334c00) at /home/yoku0825/mysql-8.0.25/sql/sql_rewrite.cc:774
#1  0x0000000000dd7fbf in Rewriter_user::rewrite_users (this=this@entry=0x7f89a00c8cc0, lex=lex@entry=0x7f89a00cf940, str=str@entry=0x7f89f7334c00)
    at /home/yoku0825/mysql-8.0.25/sql/sql_rewrite.cc:714
#2  0x0000000000dd824a in Rewriter_user::rewrite (this=this@entry=0x7f89a00c8cc0, rlb=
      @0x7f89f7334c00: {m_ptr = 0x7f89a000d750 "CREATE USER ", m_length = 12, m_charset = 0x38294c0 <my_charset_bin>, m_alloced_length = 16, m_is_alloced = true})
    at /home/yoku0825/mysql-8.0.25/sql/sql_rewrite.cc:419
#3  0x0000000000dd8338 in Rewriter_create_user::rewrite (this=0x7f89a00c8cc0, rlb=
      @0x7f89f7334c00: {m_ptr = 0x7f89a000d750 "CREATE USER ", m_length = 12, m_charset = 0x38294c0 <my_charset_bin>, m_alloced_length = 16, m_is_alloced = true})
    at /home/yoku0825/mysql-8.0.25/sql/sql_rewrite.cc:758
#4  0x0000000000dd8bbd in (anonymous namespace)::rewrite_query(THD*, Consumer_type, Rewrite_params*, String&) () at /home/yoku0825/mysql-8.0.25/sql/sql_rewrite.cc:297
#5  0x0000000000dd8e3f in mysql_rewrite_query(THD*, Consumer_type, Rewrite_params*) () at /home/yoku0825/mysql-8.0.25/sql/sql_rewrite.cc:344
#6  0x0000000000d8bc7a in dispatch_sql_command (thd=0x7f89a000fdf0, parser_state=<optimized out>) at /home/yoku0825/mysql-8.0.25/sql/sql_parse.cc:4920
#7  0x0000000000d8ce6a in dispatch_command(THD*, COM_DATA const*, enum_server_command) () at /home/yoku0825/mysql-8.0.25/sql/sql_parse.cc:1841
#8  0x0000000000d8ed04 in do_command (thd=0x7f89a000fdf0) at /home/yoku0825/mysql-8.0.25/sql/sql_parse.cc:1320
#9  0x0000000000eb3b88 in handle_connection (arg=arg@entry=0x78589f0) at /home/yoku0825/mysql-8.0.25/sql/conn_handler/connection_handler_per_thread.cc:301
#10 0x000000000234101e in pfs_spawn_thread (arg=0x79cd080) at /home/yoku0825/mysql-8.0.25/storage/perfschema/pfs.cc:2898
#11 0x00007f8a08141ea5 in start_thread (arg=0x7f89f7336700) at pthread_create.c:307
#12 0x00007f8a065249fd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

(gdb) p *user
+p *user
$4 = {
  user = {
    str = 0x7f89a000c1c0 "yoku0824",
    length = 8
  },
  host = {
    str = 0x25c3a9c "%",
    length = 1
  },
  plugin = {
    str = 0x25be139 "",
    length = 0
  },
  auth = {
    str = 0x7f89a000c268 "c",
    length = 1
  },
  current_auth = {
    str = 0x0,
    length = 0
  },
  uses_identified_by_clause = true,
  uses_identified_with_clause = false,
  uses_authentication_string_clause = false,
  uses_replace_clause = false,
  retain_current_password = false,
  discard_old_password = false,
  has_password_generator = false,
  alter_status = {
    update_password_expired_fields = false,
    update_password_expired_column = false,
    use_default_password_lifetime = true,
    expire_after_days = 0,
    update_account_locked_column = false,
    account_locked = false,
    password_history_length = 0,
    use_default_password_history = true,
    update_password_history = false,
    password_reuse_interval = 0,
    use_default_password_reuse_interval = false,
    update_password_reuse_interval = false,
    failed_login_attempts = 0,
    update_failed_login_attempts = false,
    password_lock_time = 0,
    update_password_lock_time = false,
    update_password_require_current = UNCHANGED
  }
}

割と汎用的な mysql_rewrite_query という名前の関数の割に

https://github.com/mysql/mysql-server/blob/mysql-8.0.25/sql/sql_rewrite.cc#L303-L348

そこから呼び出しているやっぱり汎用的な名前の rewrite_query 関数は、アカウント系DDLの操作に特化したリライトしかしてない。

https://github.com/mysql/mysql-server/blob/mysql-8.0.25/sql/sql_rewrite.cc#L216-L300

ジェネラルログも書き換えてた。

2021-06-17T14:47:18.332134+09:00            8 Query     CREATE USER 'yoku0824'@'%' IDENTIFIED BY <secret>

ところで、 CREATE USER を1回さばく間に Rewriter_create_user::append_user_auth_info を3回通ったんだけど、最初の dispatch_sql_command から呼ばれる時点で書き換えはは完了しているっぽい。

(gdb) b Rewriter_create_user::append_user_auth_info
+b Rewriter_create_user::append_user_auth_info
Breakpoint 1 at 0xdd7ad0: file /home/yoku0825/mysql-8.0.25/sql/sql_rewrite.cc, line 774.

(gdb) p *user
+p *user
$4 = {
  user = {
    str = 0x7f89a000c1c0 "yoku0824",
    length = 8
  },
  host = {
    str = 0x25c3a9c "%",
    length = 1
  },
  plugin = {
    str = 0x25be139 "",
    length = 0
  },
  auth = {
    str = 0x7f89a000c268 "c",
    length = 1
  },
  current_auth = {
    str = 0x0,
    length = 0
  },
  uses_identified_by_clause = true,
  uses_identified_with_clause = false,
  uses_authentication_string_clause = false,
  uses_replace_clause = false,
  retain_current_password = false,
  discard_old_password = false,
  has_password_generator = false,
  alter_status = {
    update_password_expired_fields = false,
    update_password_expired_column = false,
    use_default_password_lifetime = true,
    expire_after_days = 0,
    update_account_locked_column = false,
    account_locked = false,
    password_history_length = 0,
    use_default_password_history = true,
    update_password_history = false,
    password_reuse_interval = 0,
    use_default_password_reuse_interval = false,
    update_password_reuse_interval = false,
    failed_login_attempts = 0,
    update_failed_login_attempts = false,
    password_lock_time = 0,
    update_password_lock_time = false,
    update_password_require_current = UNCHANGED
  }
}

$ strings ib_logfile0  | grep yoku0824

1回目はまだ1回もリライトしてないので生パスワードのまま。

(gdb) c
+c
Continuing.

Breakpoint 1, Rewriter_create_user::append_user_auth_info (this=0x7f89a00c8cc0, user=0x7f89a000c1e0, comma=false, str=0x7f89f7334c00)
    at /home/yoku0825/mysql-8.0.25/sql/sql_rewrite.cc:774
774       append_auth_id(m_thd, user, comma, str);

(gdb) p *user
+p *user
$6 = {
  user = {
    str = 0x7f89a000c1c0 "yoku0824",
    length = 8
  },
  host = {
    str = 0x25c3a9c "%",
    length = 1
  },
  plugin = {
    str = 0x25d023d "mysql_native_password",
    length = 21
  },
  auth = {
    str = 0x7f89a01e6690 "*FDD369C6B7C3C64C7C07EDE4DC5C01BF8970B24D",
    length = 41
  },
  current_auth = {
    str = 0x0,
    length = 0
  },
  uses_identified_by_clause = true,
  uses_identified_with_clause = false,
  uses_authentication_string_clause = false,
  uses_replace_clause = false,
  retain_current_password = false,
  discard_old_password = false,
  has_password_generator = false,
  alter_status = {
    update_password_expired_fields = false,
    update_password_expired_column = false,
    use_default_password_lifetime = true,
    expire_after_days = 0,
    update_account_locked_column = false,
    account_locked = false,
    password_history_length = 0,
    use_default_password_history = true,
    update_password_history = false,
    password_reuse_interval = 0,
    use_default_password_reuse_interval = true,
    update_password_reuse_interval = false,
    failed_login_attempts = 0,
    update_failed_login_attempts = false,
    password_lock_time = 0,
    update_password_lock_time = false,
    update_password_require_current = UNCHANGED
  }
}

$ strings ib_logfile0  | grep yoku0824

2回目の時点では既にLEX_USER自体がハッシュを使ったものに書き換えられている。

(gdb) c
+c
Continuing.

Breakpoint 1, Rewriter_create_user::append_user_auth_info (this=0x7f89a0086610, user=0x7f89a000c1e0, comma=false, str=0x7f89f732ff80)
    at /home/yoku0825/mysql-8.0.25/sql/sql_rewrite.cc:774
774       append_auth_id(m_thd, user, comma, str);

$ strings ib_logfile0  | grep yoku0824
                                                                           yoku0824
yoku0824

3回目に差し掛かった時点で ib_logfile0 の中に書き込まれている。

Lossless-semisyncではない環境なので、1回目がgeneral_log/SHOW PROCESSLIST用の書き換え、2回目が ib_logfile0 への書き込み、3回目がbinlogへの書き込みとかなのかな。

2021/06/09

Percona Toolkitのテスト環境を整える

TL;DR

  • Setting up the development environment の通りに ~やるつもりがない人または~ やっても上手くいかなかった人向け
    • ほら、テストしたいバージョンがいろいろある人とかさ

Setting up the development environment は一通り目を通しておいた方が良い気がします。

Percona Toolkitのテストは MySQL::Sandbox っぽいスクリプトを内包していて、バイナリをポンと置いて環境変数をセットするだけで、3つくらいの mysqld を起動してそれに対してテストを走らせてくれます。

というわけでまずは mysqld 実行ファイルが必要。PXCのテストをするつもりでないなら吊るしのMySQLでも良い。ただし INSTALL_LAYOUT=STANDALONE を想定しているので、rpmでインストールするのはダメ。Linux - Genericのtarボールを解凍するのが良いんではないか。

$ wget https://dev.mysql.com/get/Downloads/MySQL-8.0/mysql-8.0.25-linux-glibc2.12-x86_64.tar.xz
$ tar -C /tmp -xf mysql-8.0.25-linux-glibc2.12-x86_64.tar.xz
$ ll -d /tmp/mysql-8.0.25-linux-glibc2.12-x86_64
$ export PERCONA_TOOLKIT_SANDBOX=/tmp/mysql-8.0.25-linux-glibc2.12-x86_64

展開した先のディレクトリを PERCONA_TOOLKIT_SANDBOX 環境変数に詰めておく。

次はPercona Toolkitのソースコードを持ってくる。

$ git clone https://github.com/percona/percona-toolkit.git
$ cd percona-toolkit
$ pwd  ### まあどこでもいいんだけど
/root/git/percona-toolkit
$ export PERCONA_TOOLKIT_BRANCH="$PWD"   ### percona-toolkitディレクトリが PERCONA_TOOLKIT_BRANCH環境変数
$ export PERL5LIB=${PERCONA_TOOLKIT_BRANCH}/lib ### percona-toolkit/lib をPERL5LIBに追加

percona-toolkitのトップディレクトリとlibディレクトリをそれぞれ環境変数で指定。
全部設定が通ってれば、sandboxディレクトリの test-env スクリプトでテスト用のインスタンスが立ち上げられる。

$ ./sandbox/test-env checkconfig
PERCONA_TOOLKIT_BRANCH=/root/git/percona-toolkit - ok
PERCONA_TOOLKIT_SANDBOX=/tmp/mysql-8.0.25-linux-glibc2.12-x86_64 - ok
Percona Toolkit test environment config is ok!

$ ./sandbox/test-env stop
MySQL test server on port 12349 does not exist.
MySQL test server on port 12348 does not exist.
Stopping MySQL test server on port 12347... OK (1s)
Stopping MySQL test server on port 12346... OK (11s)
Stopping MySQL test server on port 12345... OK (12s)
MySQL test server on port 2903 does not exist.
MySQL test server on port 2902 does not exist.
MySQL test server on port 2901 does not exist.
MySQL test server on port 2900 does not exist.
Percona Toolkit test environment stopped.
[root@81dc970554a2 percona-toolkit]$ ./sandbox/test-env start
Creating default databases ...
Starting MySQL test server on port 12345... return 0
OK (1s)
Creating default databases ...
Starting MySQL test server on port 12346... return 0
OK (2s)
Creating default databases ...
Starting MySQL test server on port 12347... return 0
OK (9s)
Loading sakila database... OK
LOAD DATA LOCAL INFILE is enabled
Waiting for replication to finish... OK
Percona Toolkit test environment started with MySQL v8.0.

こいつらが起動している状態でテストを実行してやればOK。
t ディレクトリの真下ではなくて、コマンドごとにさらにディレクトリが掘ってあるのでその単位で prove してやる。

$ ps auxwww | grep mysqld
root      2358  4.1  8.5 1636704 86304 pts/0   Sl   09:52   0:08 /tmp/mysql-8.0.25-linux-glibc2.12-x86_64/bin/mysqld --defaults-file=/tmp/12346/my.sandbox.cnf -u root --init-file /tmp/12346/mysql-init
root      2510  4.7 28.6 1635464 290640 pts/0  Sl   09:52   0:09 /tmp/mysql-8.0.25-linux-glibc2.12-x86_64/bin/mysqld --defaults-file=/tmp/12347/my.sandbox.cnf -u root --init-file /tmp/12347/mysql-init
root      2703  5.0 33.9 1634624 344132 pts/0  Sl   09:55   0:02 /tmp/mysql-8.0.25-linux-glibc2.12-x86_64/bin/mysqld --defaults-file=/tmp/12345/my.sandbox.cnf -u root --init-file /tmp/12345/mysql-init
root      2986  0.0  0.0   9092   672 pts/0    S+   09:56   0:00 grep --color=auto mysqld

$ prove t/pt-table-usage/
t/pt-table-usage/basics.t .................... ok
t/pt-table-usage/create_table_definitions.t .. ok
t/pt-table-usage/explain_extended.t .......... ok
All tests successful.
Files=3, Tests=21,  5 wallclock secs ( 0.03 usr  0.01 sys +  0.91 cusr  0.44 csys =  1.39 CPU)
Result: PASS

ちなみにMySQL::Sandboxっぽいので、 /tmp/ポート番号/use とか起動すると中に入れる。

$ ll /tmp/12345/
total 28
drwxr-x--- 8 root root 4096 Jun  9 09:55 data
-rw-r--r-- 1 root root 1475 Jun  9 09:52 my.sandbox.cnf
-rw-r--r-- 1 root root  529 Jun  9 09:52 mysql-init
srwxrwxrwx 1 root root    0 Jun  9 09:55 mysql_sandbox12345.sock
-rw------- 1 root root    5 Jun  9 09:55 mysql_sandbox12345.sock.lock
-rwxr-xr-x 1 root root 2589 Jun  9 09:52 start
-rwxr-xr-x 1 root root 1537 Jun  9 09:52 stop
-rwxr-xr-x 1 root root  135 Jun  9 09:52 use

8.0.25だと t/pt-show-grants が転けたとか、5.6ベースでも t/pt-online-schema-change が転けるとかいろいろあるけど取り敢えずここまで

2021/06/07

mysqldumpからのリストアがERROR 3185 (HY000): Can't find master key from keyring で転ける

TL;DR


暗号化したテーブルをmysqldumpすると、 ENCRYPTION = 'Y' がテーブルオプションにくっついてくる。

--
-- Table structure for table `t1`
--

DROP TABLE IF EXISTS `t1`;
/*!40101 SET @saved_cs_client     = @@character_set_client */;
/*!50503 SET character_set_client = utf8mb4 */;
CREATE TABLE `t1` (
  `num` int DEFAULT NULL
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_0900_ai_ci ENCRYPTION='Y';
/*!40101 SET character_set_client = @saved_cs_client */;

こいつを early_plugin_load=keyring_file.so していないmysqldで実行すると転ける。

mysql> CREATE TABLE `t1` (   `num` int DEFAULT NULL ) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_0900_ai_ci ENCRYPTION='Y';
ERROR 3185 (HY000): Can't find master key from keyring, please check in the server log if a keyring is loaded and initialized successfully.

おとなしく my.cnfearly_plugin_load を書くと成功するようになる。

「Can't find ..」にばかり目がいくけれど、「keyringがロードされて初期化に成功してるか確認しろ」とも書いてあるし。


とまあここまでは良いんだけども。

keyring_file プラグインって「 early_plugin_load で読ませろよ!」って ドキュメント に書いてある割に、(earlyでない) plugin_loadINSTALL PLUGIN でも利用できる。

特に INSTALL PLUGIN で有効にしていた場合、「バックアップ元の my.cnf には early_plugin_load の記述はなかったよ?」ということになりがちな気がする。

mysql.plugin テーブルのリストアそれ自体はプラグインをロードしてくれないので、「 my.cnf に書いた記憶もないし、リストアがこのエラーで途中までで転けたけどmysqldを再起動(=再起動すると mysql.plugin テーブルから読んで keyring_file プラグインがロードされるから)してからもう一度やったら上手くいったよ?」みたいなのはこのケースに該当する気がする。

ストレージエンジンの場合と仕組み(?)はいっしょ。

まあ、忘れがちですが忘れないようにしましょう