Location via proxy:   
[Report a bug]   [Manage cookies]                

GA

2024/11/15

アカウント名を間違った時にも java.sql.SQLNonTransientConnectionException: Public Key Retrieval is not allowed が出る

TL;DR

  • caching_sha2_password で作られたアカウントに初回接続する時は useSSL=true または allowPublicKeyRetrieval=trueが必要

  • にもかかわらず、 default_authentication_plugin=mysql_native_password を指定していて、アカウントにも mysql_native_password を指定しているはずなのに Public Key Retrieval is not allowed のエラーが出たら、接続しようとしているアカウントを間違えているだけかもしれない

  • allowPublicKeyRetrieval=trueは悪意を持ったMySQL Serverに接続すると何を食わされるかわからないけど、自分たちが構築したやつならtrue決め打ちでも良いんじゃないか(通信は平文のままなのでオーバーヘッドはほとんどない)


JavaのコードはChatGPTに生成してもらったものをちょっと編集しただけ。ユーザー名、パスワード、useSSL、allowPublicKeyRetrievalを引数に取ってMySQLに接続するだけ。

MySQL Serverは8.0.40, Connector/Jは9.1.0。

MySQLの環境はこう。パスワードはどっちも “a” の1文字なので、引数の2つ目が “a” の時は正しいパスワードで “b” の時は間違ったパスワード。


mysql80 16> SELECT @@default_authentication_plugin;

+---------------------------------+

| @@default_authentication_plugin |

+---------------------------------+

| mysql_native_password           |

+---------------------------------+

1 row in set, 1 warning (0.00 sec)

mysql80 16> SELECT user, host, plugin FROM mysql.user WHERE host <> 'localhost';
+------------------+------+-----------------------+
| user             | host | plugin                |
+------------------+------+-----------------------+
| caching_password | %    | caching_sha2_password |
| native_password  | %    | mysql_native_password |
+------------------+------+-----------------------+
2 rows in set (0.00 sec)

1. mysql_native_passwordの実在するユーザー + 正しいパスワード

当然useSSL, allowPublicKeyRetrievalの値に関わらず接続に成功する。

$ java -cp .:/usr/share/java/mysql-connector-java.jar MySQLConnectionExample native_password a false false
Connected to the database successfully!

$ java -cp .:/usr/share/java/mysql-connector-java.jar MySQLConnectionExample native_password a true false
Connected to the database successfully!

$ java -cp .:/usr/share/java/mysql-connector-java.jar MySQLConnectionExample native_password a false true
Connected to the database successfully!

$ java -cp .:/usr/share/java/mysql-connector-java.jar MySQLConnectionExample native_password a true true
Connected to the database successfully!

2. mysql_native_passwordの実在するユーザー + 間違ったパスワード

当然全部 Access denied for user ? で失敗する。

$ java -cp .:/usr/share/java/mysql-connector-java.jar MySQLConnectionExample native_password b false false
java.sql.SQLException: Access denied for user 'native_password'@'127.0.0.1' (using password: YES)

..

$ java -cp .:/usr/share/java/mysql-connector-java.jar MySQLConnectionExample native_password b true false
java.sql.SQLException: Access denied for user 'native_password'@'127.0.0.1' (using password: YES)

..

$ java -cp .:/usr/share/java/mysql-connector-java.jar MySQLConnectionExample native_password b false true
java.sql.SQLException: Access denied for user 'native_password'@'127.0.0.1' (using password: YES)

..

$ java -cp .:/usr/share/java/mysql-connector-java.jar MySQLConnectionExample native_password b true true
java.sql.SQLException: Access denied for user 'native_password'@'127.0.0.1' (using password: YES)

..

3. caching_sha2_passwordの実在するユーザー + 正しいパスワード

useSSL=false, allowPublicKeyRetrieval=falseの場合はエラーになる。
ただし、一度でもログインに成功したらその後はfalse, falseでも成功するようになる。

$ java -cp .:/usr/share/java/mysql-connector-java.jar MySQLConnectionExample caching_password a false false
java.sql.SQLNonTransientConnectionException: Public Key Retrieval is not allowed

..

$ java -cp .:/usr/share/java/mysql-connector-java.jar MySQLConnectionExample caching_password a true false
Connected to the database successfully!

$ mysql80 -e "FLUSH PRIVILEGES"

$ java -cp .:/usr/share/java/mysql-connector-java.jar MySQLConnectionExample caching_password a false true
Connected to the database successfully!

$ mysql80 -e "FLUSH PRIVILEGES"

$ java -cp .:/usr/share/java/mysql-connector-java.jar MySQLConnectionExample caching_password a true true
Connected to the database successfully!

### false, falseでも↑の後にFLUSH PRIVILEGESでキャッシュをリセットしないと結果が違う
$ java -cp .:/usr/share/java/mysql-connector-java.jar MySQLConnectionExample caching_password a false false
Connected to the database successfully!

caching_sha2_password のキャッシュをリセットして再び Public Key Retrieval is not allowed を出したい場合は FLUSH PRIVILEGES する。

4. caching_sha2_passwordの実在するユーザー + 間違ったパスワード

当然全部転けるが、false, falseの場合のエラーは Public Key Retrieval is not allowed .

$ java -cp .:/usr/share/java/mysql-connector-java.jar MySQLConnectionExample caching_password b false false
java.sql.SQLNonTransientConnectionException: Public Key Retrieval is not allowed

..

$ java -cp .:/usr/share/java/mysql-connector-java.jar MySQLConnectionExample caching_password b true false
java.sql.SQLException: Access denied for user 'caching_password'@'127.0.0.1' (using password: YES)

..

$ java -cp .:/usr/share/java/mysql-connector-java.jar MySQLConnectionExample caching_password b false true
java.sql.SQLException: Access denied for user 'caching_password'@'127.0.0.1' (using password: YES)

..

$ java -cp .:/usr/share/java/mysql-connector-java.jar MySQLConnectionExample caching_password b true true
java.sql.SQLException: Access denied for user 'caching_password'@'127.0.0.1' (using password: YES)

..

先に一度正しいパスワードで接続してキャッシュを作ってもエラーは相変わらず

$ java -cp .:/usr/share/java/mysql-connector-java.jar MySQLConnectionExample caching_password a true true
Connected to the database successfully!

$ java -cp .:/usr/share/java/mysql-connector-java.jar MySQLConnectionExample caching_password b false false
java.sql.SQLNonTransientConnectionException: Public Key Retrieval is not allowed

..

5. 存在しないアカウントを指定する

存在しないアカウントを指定すると default_authentication_plugin の値に関わらず caching_sha2_password でパスワードを間違った時と同じ組み合わせでエラーになるぽい。

$ java -cp .:/usr/share/java/mysql-connector-java.jar MySQLConnectionExample invalid_user a false false
java.sql.SQLNonTransientConnectionException: Public Key Retrieval is not allowed

..

$ java -cp .:/usr/share/java/mysql-connector-java.jar MySQLConnectionExample invalid_user a true false
java.sql.SQLException: Access denied for user 'invalid_user'@'127.0.0.1' (using password: YES)

..

$ java -cp .:/usr/share/java/mysql-connector-java.jar MySQLConnectionExample invalid_user a false true
java.sql.SQLException: Access denied for user 'invalid_user'@'127.0.0.1' (using password: YES)

..

$ java -cp .:/usr/share/java/mysql-connector-java.jar MySQLConnectionExample invalid_user a true true
java.sql.SQLException: Access denied for user 'invalid_user'@'127.0.0.1' (using password: YES)

..

おまけにmysqlコマンドラインクライアント。バージョンは8.4.2。
すぐquitしてるからエラーが出なければ接続に成功して終わってる。Warningは無視する。
存在しないアカウントを指定した時の動作がConnector/Jとは違う。

$ mysql -h127.0.0.1 -P64080 -unative_password -pa --ssl-mode=DISABLED --skip-get-server-public-key -e quit
mysql: [Warning] Using a password on the command line interface can be insecure.

$ mysql -h127.0.0.1 -P64080 -unative_password -pa --ssl-mode=REQUIRED --skip-get-server-public-key -e quit
mysql: [Warning] Using a password on the command line interface can be insecure.

$ mysql -h127.0.0.1 -P64080 -unative_password -pa --ssl-mode=DISABLED --get-server-public-key -e quit
mysql: [Warning] Using a password on the command line interface can be insecure.

$ mysql -h127.0.0.1 -P64080 -unative_password -pa --ssl-mode=REQUIRED --get-server-public-key -e quit
mysql: [Warning] Using a password on the command line interface can be insecure.

$ mysql80 -e "FLUSH PRIVILEGES"

$ mysql -h127.0.0.1 -P64080 -unative_password -pb --ssl-mode=DISABLED --skip-get-server-public-key -e quit
mysql: [Warning] Using a password on the command line interface can be insecure.
ERROR 1045 (28000): Access denied for user 'native_password'@'127.0.0.1' (using password: YES)

$ mysql -h127.0.0.1 -P64080 -unative_password -pb --ssl-mode=REQUIRED --skip-get-server-public-key -e quit
mysql: [Warning] Using a password on the command line interface can be insecure.
ERROR 1045 (28000): Access denied for user 'native_password'@'127.0.0.1' (using password: YES)

$ mysql -h127.0.0.1 -P64080 -unative_password -pb --ssl-mode=DISABLED --get-server-public-key -e quit
mysql: [Warning] Using a password on the command line interface can be insecure.
ERROR 1045 (28000): Access denied for user 'native_password'@'127.0.0.1' (using password: YES)

$ mysql -h127.0.0.1 -P64080 -unative_password -pb --ssl-mode=REQUIRED --get-server-public-key -e quit
mysql: [Warning] Using a password on the command line interface can be insecure.
ERROR 1045 (28000): Access denied for user 'native_password'@'127.0.0.1' (using password: YES)

$ mysql -h127.0.0.1 -P64080 -ucaching_password -pa --ssl-mode=DISABLED --skip-get-server-public-key -e quit
mysql: [Warning] Using a password on the command line interface can be insecure.
ERROR 2061 (HY000): Authentication plugin 'caching_sha2_password' reported error: Authentication requires secure connection.

$ mysql -h127.0.0.1 -P64080 -ucaching_password -pa --ssl-mode=REQUIRED --skip-get-server-public-key -e quit
mysql: [Warning] Using a password on the command line interface can be insecure.

$ mysql80 -e "FLUSH PRIVILEGES"

$ mysql -h127.0.0.1 -P64080 -ucaching_password -pa --ssl-mode=DISABLED --get-server-public-key -e quit
mysql: [Warning] Using a password on the command line interface can be insecure.

$ mysql80 -e "FLUSH PRIVILEGES"

$ mysql -h127.0.0.1 -P64080 -ucaching_password -pa --ssl-mode=REQUIRED --get-server-public-key -e quit
mysql: [Warning] Using a password on the command line interface can be insecure.

$ mysql80 -e "FLUSH PRIVILEGES"

$ mysql -h127.0.0.1 -P64080 -uinvalid_user -pa --ssl-mode=DISABLED --skip-get-server-public-key -e quit
mysql: [Warning] Using a password on the command line interface can be insecure.
ERROR 1045 (28000): Access denied for user 'invalid_user'@'127.0.0.1' (using password: YES)

$ mysql -h127.0.0.1 -P64080 -uinvalid_user -pa --ssl-mode=REQUIRED --skip-get-server-public-key -e quit
mysql: [Warning] Using a password on the command line interface can be insecure.
ERROR 1045 (28000): Access denied for user 'invalid_user'@'127.0.0.1' (using password: YES)

$ mysql -h127.0.0.1 -P64080 -uinvalid_user -pa --ssl-mode=DISABLED --get-server-public-key -e quit
mysql: [Warning] Using a password on the command line interface can be insecure.
ERROR 1045 (28000): Access denied for user 'invalid_user'@'127.0.0.1' (using password: YES)

$ mysql -h127.0.0.1 -P64080 -uinvalid_user -pa --ssl-mode=REQUIRED --get-server-public-key -e quit
mysql: [Warning] Using a password on the command line interface can be insecure.
ERROR 1045 (28000): Access denied for user 'invalid_user'@'127.0.0.1' (using password: YES)

これ、なんか CHANGE REPLICATION SOURCE TO でもアカウント間違った時に Authentication plugin 'caching_sha2_password' reported error: Authentication requires secure connection. って怒られた気がするんだけど気のせいだったかな…(再現方法がわかっていない…)


【2024/11/15 19:00】

余談。MySQLのエラーログにはこんな風に出る。

2024-11-15T18:26:29.999904+09:00 25 [Note] [MY-010914] [Server] Got an error reading communication packets         <-- 間違ったパスワードで Public Key Retrieval is not allowed 

2024-11-15T18:26:45.095375+09:00 26 [Note] [MY-010926] [Server] Access denied for user 'caching_password'@'127.0.0.1' (using password: YES)

2024-11-15T18:26:58.924712+09:00 27 [Note] [MY-010926] [Server] Access denied for user 'caching_password'@'127.0.0.1' (using password: YES)

2024-11-15T18:27:14.245506+09:00 28 [Note] [MY-010926] [Server] Access denied for user 'caching_password'@'127.0.0.1' (using password: YES)

..

2024-11-15T18:34:32.642543+09:00 39 [Warning] [MY-013360] [Server] Plugin sha256_password reported: ''sha256_password' is deprecated and will be removed in a future release. Please use caching_sha2_password instead'
2024-11-15T18:34:32.652304+09:00 39 [Note] [MY-010914] [Server] Got an error reading communication packets

## ↑ 存在しないアカウントで Public Key Retrieval is not allowed 

2024-11-15T18:34:46.348753+09:00 40 [Warning] [MY-013360] [Server] Plugin sha256_password reported: ''sha256_password' is deprecated and will be removed in a future release. Please use caching_sha2_password instead'
2024-11-15T18:34:46.350837+09:00 40 [Note] [MY-010926] [Server] Access denied for user 'invalid_user'@'127.0.0.1' (using password: YES)

## ↑存在しないアカウントでAcces denied


存在しないアカウントを指定した時はConnector/J側で他のプラグインもネゴシエーションしようとしているぽい。

2024/09/17

Percona XtraBackup 8.0.23 vs MySQL 8.0でバイナリログがパージされずに残り続ける

TL;DR

  • XtraBackupは8.0.23で --lock-ddl がデフォルトでONになった

  • xtrabackup --lock-ddlLOCK INSTANCE FOR BACKUP を呼び出す

  • xtrabackup --backup の最中に FLUSH NO_WRITE_TO_BINLOG BINARY LOGS が実行されるが、 LOCK INSTANCE FOR BACKUP の最中にbinlogがローテーションしてもパージが走らない。

    • よって、バックアップ間隔の間に max_binlog_size 未満のバイナリログしか吐かない = スイッチされるのがxtrabackupのタイミングだけのノードはバイナリログがパージされずに残り続けるように見える

    • max_binlog_size を小さくしてxb以外のタイミングでもローテーションが走るようにしてやればOK

    • それか、バックアップスクリプトの中ででもxbが終了した後に FLUSH BINARY LOGS を呼んでやればOK

  • 前提知識として、「バイナリログのパージはバイナリログがスイッチした時にだけ `binlog_expire_logs_seconds` が評価される

どういうことかというと、


mysql80 8> SET GLOBAL binlog_expire_logs_seconds = 1;

Query OK, 0 rows affected (0.13 sec)

こうやってバイナリログのパージを1秒にしてやっても

$ xtrabackup -S /usr/mysql/8.0.39/data/mysql.sock -uroot --stream=xbstream --backup > /dev/null

$ ll bin.*
-rw-r----- 1 yoku0825 yoku0825 238 Sep 17 15:42 bin.000339
-rw-r----- 1 yoku0825 yoku0825 238 Sep 17 15:43 bin.000340
-rw-r----- 1 yoku0825 yoku0825 197 Sep 17 15:43 bin.000341
-rw-r----- 1 yoku0825 yoku0825  39 Sep 17 15:43 bin.index

バイナリログが消えていないし

$ xtrabackup -S /usr/mysql/8.0.39/data/mysql.sock -uroot --stream=xbstream --backup > /dev/null

$ ll bin.*
-rw-r----- 1 yoku0825 yoku0825 238 Sep 17 15:42 bin.000339
-rw-r----- 1 yoku0825 yoku0825 238 Sep 17 15:43 bin.000340
-rw-r----- 1 yoku0825 yoku0825 238 Sep 17 15:44 bin.000341
-rw-r----- 1 yoku0825 yoku0825 197 Sep 17 15:44 bin.000342
-rw-r----- 1 yoku0825 yoku0825  52 Sep 17 15:44 bin.index

もう一度やっても消えない。むしろ FLUSH BINARY LOGS で新しいのができるのでファイルの数は増える。

手打ちでも再現できる。

$ mysql80

mysql80 15> LOCK INSTANCE FOR BACKUP;
Query OK, 0 rows affected (0.10 sec)

mysql80 15> FLUSH BINARY LOGS;
Query OK, 0 rows affected (0.02 sec)

$ ll bin.*
-rw-r----- 1 yoku0825 yoku0825 238 Sep 17 15:42 bin.000339
-rw-r----- 1 yoku0825 yoku0825 238 Sep 17 15:43 bin.000340
-rw-r----- 1 yoku0825 yoku0825 238 Sep 17 15:44 bin.000341
-rw-r----- 1 yoku0825 yoku0825 238 Sep 17 15:46 bin.000342
-rw-r----- 1 yoku0825 yoku0825 197 Sep 17 15:46 bin.000343
-rw-r----- 1 yoku0825 yoku0825  65 Sep 17 15:46 bin.index

エラーログをよく見るとワーニングが出ているはず。

2024-09-17T15:43:40.409504+09:00 10 [Warning] [MY-014054] [Server] Could not purge binary logs since another session is executing LOCK INSTANCE FOR BACKUP. Wait for that session to release the lock.

LOCK INSTANCE FOR BACKUP の外で FLUSH BINARY LOGS すればすぐに消える。

mysql80 15> UNLOCK INSTANCE;
Query OK, 0 rows affected (0.11 sec)

mysql80 15> FLUSH BINARY LOGS;
Query OK, 0 rows affected (0.22 sec)

$ ll bin.*
-rw-r----- 1 yoku0825 yoku0825 238 Sep 17 15:48 bin.000343
-rw-r----- 1 yoku0825 yoku0825 197 Sep 17 15:48 bin.000344
-rw-r----- 1 yoku0825 yoku0825  26 Sep 17 15:48 bin.index

デフォルトのmax_binlog_sizeは1GBなので、ワーストケース(binlogがパージされずに残り続けて容量が食い切られるケース)では、

  • 今朝のバックアップで binlog.000001 からbinlog.000002にスイッチする
  • 今日いちにちでbinlog.000002が800MBまで書き込まれる
  • 明日の朝のバックアップでbinlog.000002がbinlog.000003にスイッチされる。 LOCK INSTANCE FOR BACKUP で保護されているのでbinlog.000001はexpireしていても削除されない
  • 明日いちにちでbinlog.000003が800MBまで(略

となって、binlogがいつまでもパージされずに残り続ける。

という訳で、

  • max_binlog_size を小さくしてxb以外のタイミングでもローテーションが走るようにしてやればOK(binlog.000003がxtrabackup以外のタイミングでスイッチすれば、binlog.000001~000002はパージ対象になる)

  • それか、バックアップスクリプトの中ででもxbが終了した後に FLUSH BINARY LOGS を呼んでやればOK(xbが終了した後にスイッチすれば過去のbinlogはパージ対象になる)

参考までに。

2024/09/10

今更 素のCentOS7.9でGoを新しくせずにdlvを入れたい

古いところに新しいGoとか入れずにdlvだけ使いたかった。


$ cat /etc/centos-release

CentOS Linux release 7.9.2009 (Core)

$ rpm -q golang
golang-1.18.4-1.el7.x86_64

$ go version

go version go1.18.4 linux/amd64

delve/Documentation/installation at master · go-delve/delve の手順におとなしく従うとgoのバージョンが古いって怒られるので

$ git clone https://github.com/go-delve/delve
Cloning into 'delve'...
remote: Enumerating objects: 28504, done.
remote: Counting objects: 100% (175/175), done.
remote: Compressing objects: 100% (111/111), done.
remote: Total 28504 (delta 83), reused 143 (delta 61), pack-reused 28329 (from 1)
Receiving objects: 100% (28504/28504), 31.27 MiB | 16.54 MiB/s, done.
Resolving deltas: 100% (19460/19460), done.
Checking connectivity... done.

$ cd delve/

$ go install github.com/go-delve/delve/cmd/dlv
# github.com/go-delve/delve/pkg/proc/gdbserial
pkg/proc/gdbserial/rr.go:247:35: undefined: strings.CutPrefix
pkg/proc/gdbserial/rr.go:248:33: undefined: strings.CutPrefix
note: module requires Go 1.21

golang-1.18-4がリリースされたころdlvのタグを探して

$ git checkout v1.20.0
Note: checking out 'v1.20.0'.

You are in 'detached HEAD' state. You can look around, make experimental
changes and commit them, and you can discard any commits you make in this
state without impacting any branches by performing another checkout.

If you want to create a new branch to retain commits you create, you may
do so (now or later) by using -b with the checkout command again. Example:

  git checkout -b <new-branch-name>

HEAD is now at f07be48... *: CHANGELOG and bump to version 1.20.0 (#3209)

$ go install github.com/go-delve/delve/cmd/dlv

エラーは出ない。

$ env | grep GO
GOPATH=/home/yoku0825/go

$ ll /home/yoku0825/go/bin/dlv
-rwxr-xr-x 1 yoku0825 yoku0825 17370208 Sep 10 14:21 /home/yoku0825/go/bin/dlv

入った。

2024/09/02

MySQLだけでファイルシステムフルやMySQLだけでファイルシステムハングを再現するアイディア

TL;DR

  • 障害時の動作を確認するためにファイルシステムをフルにしたり xfs_freeze をかけたいことはままある
  • が、MySQLの動作パーティションが分かれていない場合、本当にやると調査用のシェルまで動けなくなってしまう
  • ループバックデバイスを使ってdatadirだけ起こすのが楽

↑だけで全部言い尽くしてしまった。
取り敢えずdatadirに割り当てる好きなサイズのファイルを切り出す。

[yoku0825@yoku0825-conoha work]$ dd if=/dev/zero of=./datadir bs=1M count=300
300+0 records in
300+0 records out
314572800 bytes (315 MB) copied, 0.26401 s, 1.2 GB/s

[yoku0825@yoku0825-conoha work]$ ll -h
total 301M
-rw-r--r-- 1 yoku0825 yoku0825 300M Sep  2 13:20 datadir

ファイルシステムを作ってから好きなマウントディレクトリに割り当てる。

[yoku0825@yoku0825-conoha work]$ mkfs -t xfs ./datadir
meta-data=./datadir              isize=512    agcount=4, agsize=19200 blks
         =                       sectsz=512   attr=2, projid32bit=1
         =                       crc=1        finobt=0, sparse=0
data     =                       bsize=4096   blocks=76800, imaxpct=25
         =                       sunit=0      swidth=0 blks
naming   =version 2              bsize=4096   ascii-ci=0 ftype=1
log      =internal log           bsize=4096   blocks=855, version=2
         =                       sectsz=512   sunit=0 blks, lazy-count=1
realtime =none                   extsz=4096   blocks=0, rtextents=0

[yoku0825@yoku0825-conoha work]$ sudo mount ./datadir /mnt

[yoku0825@yoku0825-conoha work]$ df -h /mnt
Filesystem      Size  Used Avail Use% Mounted on
/dev/loop1      297M   16M  282M   6% /mnt

既存のdatadirの中身を /mnt に移してシンボリックリンクにするなり、 --datadir=/mnt--initialize するなり、 ラジバンダリ
俺は yoku0825 というOSアカウントで mysqld を起動するので、オーナーを変えてしまっている。

[yoku0825@yoku0825-conoha work]$ sudo chown -R yoku0825. /mnt

[yoku0825@yoku0825-conoha work]$ /usr/mysql/8.4.2/bin/mysqld --no-defaults --datadir=/mnt --initialize-insecure
2024-09-02T04:21:51.223351Z 0 [System] [MY-015017] [Server] MySQL Server Initialization - start.
2024-09-02T04:21:51.223497Z 0 [Warning] [MY-010139] [Server] Changed limits: max_open_files: 1024 (requested 8161)
2024-09-02T04:21:51.223507Z 0 [Warning] [MY-010142] [Server] Changed limits: table_open_cache: 431 (requested 4000)
2024-09-02T04:21:51.225861Z 0 [System] [MY-013169] [Server] /usr/mysql/8.4.2/bin/mysqld (mysqld 8.4.2) initializing of server in progress as process 22201
2024-09-02T04:21:51.235592Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2024-09-02T04:21:51.565478Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2024-09-02T04:21:52.610123Z 5 [Warning] [MY-010453] [Server] root@localhost is created with an empty password ! Please consider switching off the --initialize-insecure option.
2024-09-02T04:21:55.333522Z 0 [System] [MY-015018] [Server] MySQL Server Initialization - end.

[yoku0825@yoku0825-conoha work]$ /usr/mysql/8.4.2/bin/mysqld --no-defaults --datadir=/mnt --daemonize          
mysqld will log errors to /mnt/yoku0825-conoha.err
mysqld is running as pid 22300

テキトーにbinlogを吐きそうな何かをしてやると

[yoku0825@yoku0825-conoha work]$ mysqlslap -S /tmp/mysql.sock -uroot --auto-generate-sql --auto-generate-sql-execute-number=10000000 --auto-generate-sql-load-type=w -c 10

[yoku0825@yoku0825-conoha work]$ df -h /mnt
Filesystem      Size  Used Avail Use% Mounted on
/dev/loop1      297M  297M   20K 100% /mnt

[yoku0825@yoku0825-conoha work]$ tail /mnt/yoku0825-conoha.err 
2024-09-02T04:22:12.892895Z 0 [Warning] [MY-010139] [Server] Changed limits: max_open_files: 1024 (requested 8161)
2024-09-02T04:22:12.892905Z 0 [Warning] [MY-010142] [Server] Changed limits: table_open_cache: 431 (requested 4000)
2024-09-02T04:22:13.150060Z 0 [System] [MY-010116] [Server] /usr/mysql/8.4.2/bin/mysqld (mysqld 8.4.2) starting as process 22298
2024-09-02T04:22:13.177164Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2024-09-02T04:22:13.436646Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2024-09-02T04:22:13.796358Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2024-09-02T04:22:13.796400Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
2024-09-02T04:22:13.821037Z 0 [System] [MY-010931] [Server] /usr/mysql/8.4.2/bin/mysqld: ready for connections. Version: '8.4.2'  socket: '/tmp/mysql.sock'  port: 3306  Source distribution.
2024-09-02T04:22:13.821757Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Bind-address: '::' port: 33060, socket: /tmp/mysqlx.sock
2024-09-02T04:26:29.994586Z 27 [ERROR] [MY-000035] [Server] Disk is full writing './binlog.000001' (OS errno 28 - No space left on device). Waiting for someone to free space... Retry in 60 secs. Message reprinted in 600 secs.     <--- これ
[yoku0825@yoku0825-conoha work]$ mysql -S /tmp/mysql.sock -uroot                                             
mysql> SHOW PROCESSLIST;
+----+-----------------+-----------+-----------+---------+------+----------------------------+------------------------------------------------------------------------------------------------------+
| Id | User            | Host      | db        | Command | Time | State                      | Info                                                                                                 |
+----+-----------------+-----------+-----------+---------+------+----------------------------+------------------------------------------------------------------------------------------------------+
|  5 | event_scheduler | localhost | NULL      | Daemon  |  341 | Waiting on empty queue     | NULL                                                                                                 |
| 19 | root            | localhost | mysqlslap | Sleep   |  115 |                            | NULL                                                                                                 |
| 20 | root            | localhost | mysqlslap | Query   |   85 | waiting for handler commit | INSERT INTO t1 VALUES (1665728802,'8qB5MAR1caTvNFXB00HKShGa1uToGCMP2ZMHjpABFg6fnTioTz8pZGNQAkEJwckr9 |
| 21 | root            | localhost | mysqlslap | Query   |   85 | waiting for handler commit | INSERT INTO t1 VALUES (866596855,'naQuzhMt1IrZIJMkbLAKBNNKKK2sCknzI5uHeGAgQuDd5SLgpN0smODyc7qorTo1Qa |
| 22 | root            | localhost | mysqlslap | Query   |   85 | waiting for handler commit | INSERT INTO t1 VALUES (100669,'qnMdipW5KkXdTjGCh2PNzLoeR0527frpQDQ8uw67Ydk1K06uuNHtkxYBxT5w8plb2Bbpz |
| 23 | root            | localhost | mysqlslap | Query   |   85 | waiting for handler commit | INSERT INTO t1 VALUES (1137990260,'pvYr3YntZ2DoGrwWfL91bW9Epw8iO6vDuR4xrkqOe3Dum1PPEQQpwRvmO3Kg2Ftob |
| 24 | root            | localhost | mysqlslap | Query   |   85 | waiting for handler commit | INSERT INTO t1 VALUES (2010720737,'iLEkea9eOuLJweKJjQ3IJlW1dXTSs6dbJjJpHTRZFgkBJ4XuNQ4iCRchy51r3WQEE |
| 25 | root            | localhost | mysqlslap | Query   |   85 | waiting for handler commit | INSERT INTO t1 VALUES (866596855,'naQuzhMt1IrZIJMkbLAKBNNKKK2sCknzI5uHeGAgQuDd5SLgpN0smODyc7qorTo1Qa |
| 26 | root            | localhost | mysqlslap | Query   |   85 | waiting for handler commit | INSERT INTO t1 VALUES (100669,'qnMdipW5KkXdTjGCh2PNzLoeR0527frpQDQ8uw67Ydk1K06uuNHtkxYBxT5w8plb2Bbpz |
| 27 | root            | localhost | mysqlslap | Query   |   85 | waiting for handler commit | INSERT INTO t1 VALUES (1759592334,'3lkoxjtvgLu5xKHSTTtJuGE5F5QqmCcppCTmvFZScRZQgim93gSxwb24gKmIPEzEQ |
| 28 | root            | localhost | mysqlslap | Query   |   85 | waiting for handler commit | INSERT INTO t1 VALUES (866596855,'naQuzhMt1IrZIJMkbLAKBNNKKK2sCknzI5uHeGAgQuDd5SLgpN0smODyc7qorTo1Qa |
| 29 | root            | localhost | mysqlslap | Query   |   85 | waiting for handler commit | INSERT INTO t1 VALUES (1759592334,'3lkoxjtvgLu5xKHSTTtJuGE5F5QqmCcppCTmvFZScRZQgim93gSxwb24gKmIPEzEQ |
| 30 | root            | localhost | NULL      | Query   |    0 | init                       | SHOW PROCESSLIST                                                                                     |
+----+-----------------+-----------+-----------+---------+------+----------------------------+------------------------------------------------------------------------------------------------------+
13 rows in set, 1 warning (0.01 sec)

とまあファイルシステムが埋まるとbinlogが吐けなくて waiting for handler commit で突き刺さることがわかります。

mysql コマンドラインクライアントでの新規接続には成功するけど SHOW BINARY LOGS が刺さったり (binlogを参照するためのmutexが競合する)、 performance_schema.processlist は読み取れる (MySQL 8.4の SHOW PROCESSLIST はこれを読む)けど information_schema.processlist は読めない (テンポラリーテーブルを作るので失敗した)とか

mysql> SELECT * FROM information_schema.processlist;
ERROR 1114 (HY000): The table '/tmp/#sql571c_22_0' is full

mysql> SELECT * FROM performance_schema.processlist;                                                                       
..
14 rows in set (0.04 sec)

SHUTDOWN ステートメントは刺さるかなと思ったら刺さらずにちゃんと停止したり、 binlog_error_action はファイルシステムフルではトリガーされないのだなあと思ったり、学びはあると思います

2024/09/01

21年の時を経てMySQL 3.23がCentOS7.9にインストールされるはなし

TL;DR


日本MySQLユーザ会会(MyNA会) 2024年8月オフライン! LTSが出たぞ祭り に行ってきました。

本編(?)、幕間(?)、LTと3回も登場してしまってすいません。

LT大会を企画していたけどその前のご歓談タイムにもプロジェクタとマイクを勝手に使って話してる人がいて、

これはその、みんながピザを食べ始めた時に「歓談タイムの間、プロジェクター空いてるなら借りますね!」って勝手に始めた幕間の話です。

もともとやろうとしていたことは、

ずっとMySQLをビルドし続けている自慢(?)のConoHa の環境をお目にかけようと思っていただけなんですが、

[yoku0825@yoku0825-conoha ~]$ ll /usr/mysql
total 32
drwxr-xr-x 10 yoku0825 yoku0825 4096 Jun 18  2021 5.0.96
drwxr-xr-x 11 yoku0825 yoku0825 4096 May  2  2021 5.1.73
drwxr-xr-x 13 yoku0825 yoku0825 4096 May  1 15:37 5.5.62
drwxr-xr-x 13 yoku0825 yoku0825 4096 Sep 15  2021 5.6.51
drwxr-xr-x 11 yoku0825 yoku0825 4096 Jun  4 15:21 5.7.44
drwxrwxr-x 13 yoku0825 yoku0825 4096 Aug 31 22:10 8.0.39
drwxrwxr-x 13 yoku0825 yoku0825 4096 Aug 20 15:43 8.4.2
drwxrwxr-x 13 yoku0825 yoku0825 4096 Jul 25 09:29 9.0.1

おれ「どれでも好きなものを起動しますよ?」
??「あれ、4.0は?」
「やってみますか」
「マジか」

みたいなノリで始まりました。

古いMySQLのバイナリが欲しいとなると頼りになるのは SH2さんMySQL Archives - dbstudy.info

アクセスしてみたら3.23のバイナリまであったので、「折角なら3.23にしましょうか」みたいな感じでスタート。

素直にコンパイルできる自信は無いので、バイナリが欲しくてrpmパッケージを使う。

[yoku0825@yoku0825-conoha ~]$ sudo yum install https://dbstudy.info/mysqlarchives/3.23.58/generic/MySQL-3.23.58-1.i386.rpm
Loaded plugins: auto-update-debuginfo, fastestmirror, langpacks, product-id, search-disabled-repos, subscription-manager

This system is not registered with an entitlement server. You can use subscription-manager to register.

MySQL-3.23.58-1.i386.rpm                                                                                 | 8.2 MB  00:00:00     
Examining /var/tmp/yum-root-lpP0lC/MySQL-3.23.58-1.i386.rpm: MySQL-3.23.58-1.i386
Marking /var/tmp/yum-root-lpP0lC/MySQL-3.23.58-1.i386.rpm to be installed
Resolving Dependencies
--> Running transaction check
---> Package MySQL.i386 0:3.23.58-1 will be installed
--> Finished Dependency Resolution

Dependencies Resolved

================================================================================================================================
 Package                  Arch                    Version                        Repository                                Size
================================================================================================================================
Installing:
 MySQL                    i386                    3.23.58-1                      /MySQL-3.23.58-1.i386                     22 M

Transaction Summary
================================================================================================================================
Install  1 Package

Total size: 22 M
Installed size: 22 M
Is this ok [y/d/N]: y
..

当日ログ取ってなかったなあと思ってもう1回ログを作ろうとしたら、案外一発で入ってしまった。
取り敢えず mysqld を起動してみる。

[yoku0825@yoku0825-conoha ~]$ /usr/sbin/mysqld --no-defaults
/usr/sbin/mysqld: Can't change dir to '/var/lib/mysql/' (Errcode: 13)
240901 18:23:44  Aborting

240901 18:23:44  /usr/sbin/mysqld: Shutdown Complete

/var/lib/mysql が書ける状態になってない。

[yoku0825@yoku0825-conoha ~]$ sudo rm -r /var/lib/mysql
[yoku0825@yoku0825-conoha ~]$ sudo mkdir /var/lib/mysql
[yoku0825@yoku0825-conoha ~]$ sudo chown yoku0825. /var/lib/mysql
[yoku0825@yoku0825-conoha ~]$ /usr/sbin/mysqld --no-defaults
240901 21:35:00  /usr/sbin/mysqld: Table 'mysql.host' doesn't exist

ああ、datadir初期化してなかった。この時代(?) はまだ mysql_install_db だったのはわかる。

[yoku0825@yoku0825-conoha ~]$ /usr/bin/mysql_install_db --no-defaults
Sorry, the host 'yoku0825-conoha' could not be looked up.
Please configure the 'hostname' command to return a correct hostname.
If you want to solve this at a later stage, restart this script with
the --force option

ああ、あった、 /etc/hosts なりで自分自身のホスト名を名前解決できないといけなかったやつ(インストール後にホスト名を変えてるとこうなる)

今回は特に困らないので --force で続行。

[yoku0825@yoku0825-conoha ~]$ /usr/bin/mysql_install_db --no-defaults --force
Preparing db table
Preparing host table
Preparing user table
Preparing func table
Preparing tables_priv table
Preparing columns_priv table
Installing all prepared tables
240901 21:37:34  /usr/sbin/mysqld: Shutdown Complete

To start mysqld at boot time you have to copy support-files/mysql.server
to the right place for your system

PLEASE REMEMBER TO SET A PASSWORD FOR THE MySQL root USER !
This is done with:
/usr/bin/mysqladmin -u root  password 'new-password'
/usr/bin/mysqladmin -u root -h yoku0825-conoha  password 'new-password'
See the manual for more instructions.

You can start the MySQL daemon with:
cd / ; /usr/bin/safe_mysqld &

You can test the MySQL daemon with the benchmarks in the 'sql-bench' directory:
cd sql-bench ; run-all-tests

Please report any problems with the /usr/bin/mysqlbug script!

The latest information about MySQL is available on the web at
http://www.mysql.com
Support MySQL by buying support/licenses at https://order.mysql.com

rootのパスワードを設定しろよ、という当時お決まりの文句と、 mysqld_safe ではなく safe_mysqld (俺はこの時代を知らない!!) で起動しろということを言われる。

まあ気にせず mysqld で直接起動する。

[yoku0825@yoku0825-conoha ~]$ /usr/sbin/mysqld --no-defaults
/usr/sbin/mysqld: ready for connections

なんともあっさりした出力…。
フォアグラウンドで起動するので別のターミナルからアクセスする。

ソケットファイルの場所がわからないので lsof からたどる。

[yoku0825@yoku0825-conoha ~]$ ps auxwww | grep mysqld
yoku0825  1820  0.0  0.0  10696   836 pts/1    S+   21:40   0:00 /usr/sbin/mysqld --no-defaults
yoku0825  1821  0.0  0.0  10696   836 pts/1    S+   21:40   0:00 /usr/sbin/mysqld --no-defaults
yoku0825  1822  0.0  0.0  10696   836 pts/1    S+   21:40   0:00 /usr/sbin/mysqld --no-defaults
yoku0825  1950  0.0  0.0   9092   680 pts/2    S+   21:41   0:00 grep --color=auto mysqld

わーまだマルチスレッドじゃなくてマルチプロセスの頃だ!!!

[yoku0825@yoku0825-conoha ~]$ ps -elf | grep mysqld
0 S yoku0825  1820  1369  0  80   0 -  2674 poll_s 21:40 pts/1    00:00:00 /usr/sbin/mysqld --no-defaults
1 S yoku0825  1821  1820  0  80   0 -  2674 poll_s 21:40 pts/1    00:00:00 /usr/sbin/mysqld --no-defaults
1 S yoku0825  1822  1821  0  80   0 -  2674 sigsus 21:40 pts/1    00:00:00 /usr/sbin/mysqld --no-defaults
0 S yoku0825  2127  1833  0  80   0 -  2273 pipe_w 21:42 pts/2    00:00:00 grep --color=auto mysqld
[yoku0825@yoku0825-conoha ~]$ lsof -p 1820
COMMAND  PID     USER   FD   TYPE             DEVICE SIZE/OFF    NODE NAME
mysqld  1820 yoku0825  cwd    DIR              253,2     4096  286555 /var/lib/mysql
mysqld  1820 yoku0825  rtd    DIR              253,2     4096       2 /
mysqld  1820 yoku0825  txt    REG              253,2  2110756  691929 /usr/sbin/mysqld
mysqld  1820 yoku0825    0u   CHR              136,1      0t0       4 /dev/pts/1
mysqld  1820 yoku0825    1u   CHR              136,1      0t0       4 /dev/pts/1
mysqld  1820 yoku0825    2u   CHR              136,1      0t0       4 /dev/pts/1
mysqld  1820 yoku0825    3u  IPv4            4401525      0t0     TCP *:mysql (LISTEN)
mysqld  1820 yoku0825    4u  unix 0x0000000000000000      0t0 4401526 /var/lib/mysql/mysql.sock
mysqld  1820 yoku0825    5r  FIFO                0,9      0t0 4401527 pipe
mysqld  1820 yoku0825    6w  FIFO                0,9      0t0 4401527 pipe

ソケットファイルは /var/lib/mysql/mysql.sock である、OK。

[yoku0825@yoku0825-conoha ~]$ mysql -uroot -S /var/lib/mysql/mysql.sock
ERROR 2027 (HY000): Malformed packet

ああ、これ mysql コマンドラインクライアントと mysqld の互換性がない時に出る決まり文句だ。

[yoku0825@yoku0825-conoha ~]$ mysql --version
mysql  Ver 8.0.39 for Linux on x86_64 (Source distribution)

mysql コマンドラインクライアントのバージョンが8.0だったから。5.0の mysql コマンドラインクライアントならつなげるかな。

[yoku0825@yoku0825-conoha ~]$ /usr/mysql/5.0.96/bin/mysql -uroot -S /var/lib/mysql/mysql.sock
Warning: /usr/mysql/5.0.96/bin/mysql: unknown variable 'loose-binary-as-hex=0'
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 2
Server version: 3.23.58

Copyright (c) 2000, 2011, 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>

いけた。

mysql> SELECT @@version, NOW();
+-----------+---------------------+
| @@VERSION | NOW()               |
+-----------+---------------------+
| 3.23.58   | 2024-09-01 21:46:57 | 
+-----------+---------------------+
1 row in set (0.00 sec)

当日はrpmインストールした時に俺の秘伝の(?) /etc/my.cnf が消失して他のバージョンを起動できなくなったりとかしたけれど、今回はすんなりいってしまった。

令和6年にもなってMySQL 3.23が使いたくなった時の(?) 参考までに。