2013年5月31日金曜日

MariaDB5.5.30の--crash-scriptオプションとか

MariaDBの追加オプション。
--crash-script=FILE        Script to call when mysqld crashes
--no-auto-restart          Exit after starting mysqld
--nowatch                  Exit after starting mysqld
--crash-scriptに何かを指定しておくと、mysqldが落ちた時に指定したファイルを実行してくれて
その標準出力と標準エラー出力をmysqld_safeのログファイル(つまりエラーログ)に書き出してくれる。
何か通知スクリプト入れておくと良いかも知れない。

--no-auto-restart, --nowatch(と、usageには出てこないけど--no-watchも)を指定しておくと、
mysqldを起動した後にmysqld_safeがexitするように指定される。
なので、mysqldが落ちても自動で再起動してくれなくなる。


すごく関係なさそうだけど、
MySQLは--datadirだけがdatadir、MariaDBは--data, --datadirがdatadirに格納される。

あと、MariaDBのmysqld_safeはmy_print_defaultsに--mysqldオプションをつけていて、
これはMySQLのmy_print_defaultsには無いオプションなので、
MariaDBのmysqld_safeではMySQLのmysqldは起動できない。

my_print_defaultsの差分は細かいところを除けばそれくらいぽかった。


--crash-scriptでへーと思って調べ始めたらむしろ、MariaDBのmysqld_safeでMySQLのmysqldが起動できないことに吃驚した。

2013年5月30日木曜日

MariaDBが{basedir}/etc/my.cnfを読んでくれないらしい

風邪でぼんやりしてる中、ITOHさんのつぶやきで現実に戻ってみる。



…ん? {basedir}/etc/my.cnf、そもそも読んだっけ?

http://dev.mysql.com/doc/refman/5.5/en/option-files.html

ここを読んでも読む気配はなさげ。
そういえば前に調べたな。。

http://yoku0825.blogspot.jp/2012/11/mycnf.html

うーん、{basedir}/etc/my.cnfってのは/usr/local/mysql/etc/my.cnfのことかな?
cmakeするときにデフォルトをいじらなければ、basedirは/usr/local/mysql, sysconfdirは/usr/local/mysql/etcだから結果としては{basedir}/etc/my.cnfになるけど。

でも違いそうだな。。
MySQL5.5.30, MariaDB5.5.30とも、mysys/default.cはこんな感じ。
 140   - Unix:        /etc/
 141   - Unix:        /etc/mysql/
 142   - Unix:        --sysconfdir=<path> (compile-time option)
 143   - ALL:         getenv("MYSQL_HOME")
 144   - ALL:         --defaults-extra-file=<path> (run-time option)
 145   - Unix:        ~/
..
1225   errors += add_directory(alloc, "/etc/", dirs);
1226   errors += add_directory(alloc, "/etc/mysql/", dirs);
1227
1228 #if defined(DEFAULT_SYSCONFDIR)
1229   if (DEFAULT_SYSCONFDIR[0])
1230     errors += add_directory(alloc, DEFAULT_SYSCONFDIR, dirs);
1231 #endif /* DEFAULT_SYSCONFDIR */
1232
1233 #endif
1234
1235   if ((env= getenv("MYSQL_HOME")))
1236     errors += add_directory(alloc, env, dirs);
1237
1238   /* Placeholder for --defaults-extra-file=<path> */
1239   errors += add_directory(alloc, "", dirs);
1240
1241 #if !defined(__WIN__)
1242   errors += add_directory(alloc, "~/", dirs);
1243 #endif
順番的には/mnt/s3700/mysql-5.6.11/etcは$MYSQL_HOMEに当たりそうな気がする。
$MYSQL_HOMEってmysqld_safeの中であちゃこちゃいじっててよくわかんなくなるんだよな。。

gdbで順番に追ってみる。
まずはMariaDB 5.5.30。

# gdb bin/mysqld
..
(gdb) b add_directory
Breakpoint 1 at 0xa6bc78: file /home/yoku0825/mariadb-5.5.30/mysys/default.c, line 1117.
(gdb) r
Starting program: /usr/maria/5.5.30/bin/mysqld
..
Breakpoint 1, add_directory (alloc=0x7fffffffe340, dir=0xbff585 "/etc/", dirs=0x19c0458)
    at /home/yoku0825/mariadb-5.5.30/mysys/default.c:1117
1117      len= normalize_dirname(buf, dir);

まず/etc/を取った。

(gdb) c
Continuing.

Breakpoint 1, add_directory (alloc=0x7fffffffe340, dir=0xbff58b "/etc/mysql/", dirs=0x19c0458)
    at /home/yoku0825/mariadb-5.5.30/mysys/default.c:1117
1117      len= normalize_dirname(buf, dir);

次に/etc/mysql/、ここまではハードコードされてる通り。

(gdb) c

Breakpoint 1, add_directory (alloc=0x7fffffffe340, dir=0xae3a77 "", dirs=0x19c0458)
    at /home/yoku0825/mariadb-5.5.30/mysys/default.c:1117
1117      len= normalize_dirname(buf, dir);

あ、sysconfdirとMYSQL_HOME飛ばしてdefaults-extra-fileに行ったぽい。
ああ、MYSQL_HOMEが飛んでるのは多分mysqld_safeを通さずに直接mysqldを叩いてるからか。

(gdb) c
Continuing.

Breakpoint 1, add_directory (alloc=0x7fffffffe340, dir=0xbff5a2 "~/", dirs=0x19c0458)
    at /home/yoku0825/mariadb-5.5.30/mysys/default.c:1117
1117      len= normalize_dirname(buf, dir);

でホームディレクトリの.my.cnfを取ると。

(gdb) c
Continuing.
..

ここで起動終了。
sysconfdirって定義されてないのね。。

続いてMySQL 5.5.30。

# gdb bin/mysqld
..
(gdb) b add_directory
Breakpoint 1 at 0x746fa0: file /home/yoku0825/mysql-5.5.30/mysys/default.c, line 1111.
(gdb) r
Starting program: /usr/mysql/5.5.30/bin/mysqld
..
Breakpoint 1, add_directory (alloc=0x7fffffffe2e0, dir=0x9bef03 "/etc/", dirs=0xf68c00)
    at /home/yoku0825/mysql-5.5.30/mysys/default.c:1111
1111    {
(gdb) c
Continuing.

Breakpoint 1, add_directory (alloc=0x7fffffffe2e0, dir=0x9bef09 "/etc/mysql/", dirs=0xf68c00)
    at /home/yoku0825/mysql-5.5.30/mysys/default.c:1111
1111    {
(gdb) c
Continuing.

Breakpoint 1, add_directory (alloc=0x7fffffffe2e0, dir=0x9bef15 "/usr/local/mysql/etc", dirs=0xf68c00)
    at /home/yoku0825/mysql-5.5.30/mysys/default.c:1111
1111    {
(gdb) c
Continuing.

Breakpoint 1, add_directory (alloc=0x7fffffffe2e0, dir=0x90931f "", dirs=0xf68c00)
    at /home/yoku0825/mysql-5.5.30/mysys/default.c:1111
1111    {
(gdb) c
Continuing.

Breakpoint 1, add_directory (alloc=0x7fffffffe2e0, dir=0x9bef35 "~/", dirs=0xf68c00)
    at /home/yoku0825/mysql-5.5.30/mysys/default.c:1111
1111    {
(gdb) c
Continuing.

こっちはsysconfdirが定義されてるぽい。

$ cmake -i mysql-5.5.30/
..
Variable Name: SYSCONFDIR
Description: config directory (for my.cnf)
Current Value: /usr/local/mysql/etc
New Value (Enter to keep current value):
..

$ cmake -i mariadb-5.5.30/
..

やっぱSYSCONFDIRがないね。

いやでもSYSCONFDIRじゃなくてMYSQL_HOMEっぽいんだよな。。

$ diff mysql-5.5.30/scripts/mysqld_safe.sh mariadb-5.5.30/scripts/mysqld_safe.sh
..

ばらばら違い出てくるけど、熱あるしよくわかんない。。
余力があったらまたこんど。。今日はもうだめだ。。

2013年5月24日金曜日

Amazon RDSのinnodbってデータベースの正体

この前初めてRDSにログインしたんですが、


mysql> SHOW DATABASES;
+--------------------+
| Database           |
+--------------------+
| information_schema |
| innodb             |
| mysql              |
| performance_schema |
+--------------------+
4 rows in set (0.00 sec)

なにこれ。


mysql> DROP DATABASE innodb;
ERROR 1010 (HY000): Error dropping database (can't rmdir './innodb/', errno: 17)

$ perror 17
OS error code  17:  File exists

あれ消せない。

mysql-5.5.31/sql/sql_db.ccによると、DROP DATABASEはそのデータベースに紐付いている
(とMySQLが認識している)ファイルを全部消しつつ、
他にファイルが無いか数えて、他にファイルが無ければそのディレクトリに向かってrmdirを呼ぶ。

ここで消さなかった(MySQLがテーブルだと認識してない)ファイルが残ってた場合、
Error:1010がコールされると。

つまりが、コイツの実体はデータベースじゃなくて単なるディレクトリなのね。
と思ってたら


mysql> show variables like 'datadir';
+----------------------+----------------------+
| Variable_name        | Value                |
+----------------------+----------------------+
| datadir              | /rdsdbdata/db/       |
+----------------------+----------------------+
1 rows in set (0.00 sec)

mysql> SELECT * FROM information_schema.global_variables WHERE variable_value LIKE '%innodb%';
+---------------------------+-----------------------+
| VARIABLE_NAME             | VARIABLE_VALUE        |
+---------------------------+-----------------------+
| INNODB_DATA_HOME_DIR      | /rdsdbdata/db/innodb  |
| DEFAULT_STORAGE_ENGINE    | InnoDB                |
| STORAGE_ENGINE            | InnoDB                |
| INNODB_LOG_GROUP_HOME_DIR | /rdsdbdata/log/innodb |
+---------------------------+-----------------------+
4 rows in set (0.00 sec)

ああ、datadirの下にinnodbディレクトリを掘って、そこにibdata1があるのか。。納得。
ib_logfileと同じように/rdsdbdata/data/innodbとかにすれば良かったのにね。。


↓という訳で、「権限の関連で」削除できないんじゃなくて、そもそもデータベースじゃない気がするんですよ。
https://forums.aws.amazon.com/thread.jspa?messageID=422607

mysql> SHOW GRANTS\G
*************************** 1. row ***************************
Grants for root@%: GRANT SELECT, INSERT, UPDATE, DELETE, CREATE, DROP, RELOAD, PROCESS, REFERENCES, INDEX, ALTER, SHOW DATABASES, CREATE TEMPORARY TABLES, LOCK TABLES, EXECUTE, REPLICATION CLIENT, CREATE VIEW, SHOW VIEW, CREATE ROUTINE, ALTER ROUTINE, CREATE USER, EVENT, TRIGGER ON *.* TO 'root'@'%' IDENTIFIED BY PASSWORD 'xxx' WITH GRANT OPTION
1 row in set (0.00 sec)


2013年5月22日水曜日

/usr/bin/gcoreのバグ(gdb-7.2-56.el6, gdb-7.2-60.el6で確認)

gdbには/usr/bin/gcoreというシェルスクリプトが入っていて、PIDを引数で渡すと、
そのプロセスにアタッチ -> coreファイル作成 -> デタッチ を流してやってくれるというもの。

PIDを複数渡した場合はそれら全てのプロセスに対してこれをやってくれるはずなんだけど、
ちょっとバグがあって上手く行かない。

..
 62 # Loop through pids
 63 for pid in $*
 64 do
 65         # Write gdb script for pid $pid.
 66         cat >>$tmpfile <<EOF
 67 set pagination off
 68 set width 0
 69 set height 0
 70 attach $pid
 71 gcore $name.$pid
 72 detach
 73 quit
 74 EOF
 75
 76         # `</dev/null' to avoid touching interactive terminal if it is
 77         # available but not accessible (SIGTTIN risk)
 78         gdb -x $tmpfile -batch </dev/null
..


テンポラリファイルにgdbコマンドを詰め込んでgdb -xで非対話に食わせるわけだけれども、
これに2つ以上のPIDを渡すと、

1) 1つめのPIDについてgdbコマンドを$tmpfileに書き込む
2) gdb非対話モードで$tmpfileを実行
 2-1) 表示を整えて
 2-2) 1つめのPIDにアタッチして
 2-3) core吐かせて
 2-4) デタッチして
 2-5) gdbを終了
3) 2つめのPIDについて、gdbコマンドを$tmpfileに追記する
4) gdb非対話モードで$tmpfileを実行
 4-1) 2-1~2-5をやる
 4-2) gdbが既に終了しているので2つ目のPIDについて$tmpfileに追記された部分は読み取られない
5) 3つ目のPIDについて..


Σ(゚д゚lll) ダメじゃん!?

66行目の>>を>に書き換えたらちゃんと動きました。
bug-gdbでも誰も何も言わないというのは、まあ誰も使わないってことだろうか。

https://lists.gnu.org/mailman/listinfo/bug-gdb/


MySQL Bugs、簡単に投稿出来て良いなぁとか思った。
でもMySQLのバグメーリングリストは死んでるよね。
もともとはBugsに上げたらMLにも投げよう、とかそういう感じだった気がするんだけども。

2013年5月17日金曜日

RESET SLAVEでリセットされる範囲

RESET SLAVEだけの場合、master_log_name, master_log_pos, ssl_verify_server_cert, heartbeat_periodのクリア。
RESET SLAVE ALLの場合、↑に加えてhost[0] = 0; user[0] = 0; password[0] = 0; される。

gtid周りの情報はhiroi10さんの gtidを使用した環境でのmysqldump が詳しい。


【2013/05/20 12:07】
MASTER_SSL_*は?
⇒「メモリ上からは」クリアされない。

RESET SLAVEだけでもMySQL再起動したら消える気がするけど?
⇒RESET SLAVEは「メモリ上の」↑の情報と、master.infoファイルを消す。
再起動するとメモリ上の情報は全て吹っ飛ぶ && master.infoから読もうにもmaster.infoは消されてるから、全部消える。
⇒master_info_repository = 'table'でも、mysql.slave_master_infoの中身が吹っ飛ばされるので動作は一緒。



# ll master*
ls: cannot access master*: そのようなファイルやディレクトリはありません

mysql55> CHANGE MASTER TO master_host = 'localhost';
Query OK, 0 rows affected (0.02 sec)

# ll master*
-rw-rw---- 1 mysql mysql 47  5月 20 12:15 2013 master.info

mysql55> SHOW SLAVE STATUS\G
*************************** 1. row ***************************
               Slave_IO_State:
                  Master_Host: localhost
                  Master_User:
                  Master_Port: 3306
                Connect_Retry: 60
              Master_Log_File:
          Read_Master_Log_Pos: 4
               Relay_Log_File: relay.000001
                Relay_Log_Pos: 4
        Relay_Master_Log_File:
             Slave_IO_Running: No
            Slave_SQL_Running: No
              Replicate_Do_DB:
          Replicate_Ignore_DB:
           Replicate_Do_Table:
       Replicate_Ignore_Table:
      Replicate_Wild_Do_Table:
  Replicate_Wild_Ignore_Table:
                   Last_Errno: 0
                   Last_Error:
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 0
              Relay_Log_Space: 107
              Until_Condition: None
               Until_Log_File:
                Until_Log_Pos: 0
           Master_SSL_Allowed: No
           Master_SSL_CA_File:
           Master_SSL_CA_Path:
              Master_SSL_Cert:
            Master_SSL_Cipher:
               Master_SSL_Key:
        Seconds_Behind_Master: NULL
Master_SSL_Verify_Server_Cert: No
                Last_IO_Errno: 0
                Last_IO_Error:
               Last_SQL_Errno: 0
               Last_SQL_Error:
  Replicate_Ignore_Server_Ids:
             Master_Server_Id: 0
1 row in set (0.00 sec)

mysql55> RESET SLAVE;
Query OK, 0 rows affected (0.02 sec)

# ll master*
ls: cannot access master*: そのようなファイルやディレクトリはありません

mysql55> SHOW SLAVE STATUS\G
*************************** 1. row ***************************
               Slave_IO_State:
                  Master_Host: localhost
                  Master_User:
                  Master_Port: 3306
                Connect_Retry: 60
              Master_Log_File:
          Read_Master_Log_Pos: 4
               Relay_Log_File: relay.000001
                Relay_Log_Pos: 4
        Relay_Master_Log_File:
             Slave_IO_Running: No
            Slave_SQL_Running: No
              Replicate_Do_DB:
          Replicate_Ignore_DB:
           Replicate_Do_Table:
       Replicate_Ignore_Table:
      Replicate_Wild_Do_Table:
  Replicate_Wild_Ignore_Table:
                   Last_Errno: 0
                   Last_Error:
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 0
              Relay_Log_Space: 126
              Until_Condition: None
               Until_Log_File:
                Until_Log_Pos: 0
           Master_SSL_Allowed: No
           Master_SSL_CA_File:
           Master_SSL_CA_Path:
              Master_SSL_Cert:
            Master_SSL_Cipher:
               Master_SSL_Key:
        Seconds_Behind_Master: NULL
Master_SSL_Verify_Server_Cert: No
                Last_IO_Errno: 0
                Last_IO_Error:
               Last_SQL_Errno: 0
               Last_SQL_Error:
  Replicate_Ignore_Server_Ids:
             Master_Server_Id: 0
1 row in set (0.00 sec)


【2013/05/20 12:39】
おまけ。
master.infoはCHANGE MASTER TOまたはSTART SLAVEのタイミングで作られるので、
RESET SLAVE -> (再起動をはさまずに) START SLAVE(または中途半端なCHANGE MASTER TO)で残った情報が記録されてしまうので注意、という感じ?

2013年5月15日水曜日

linux-fincoreを使ってページキャッシュを覗く

ページキャッシュにどれだけページが載っているかを調べたいなーと思うと、
ファイルがページキャッシュに乗っているかどうかを調べる というのがよく引っかかって、
そもそもfincoreってどっから出てきた名前なんだと思ったらlinux-ftoolsというところに行き着いた。

linux-ftoolsはApacheライセンスで、PerlとINLINE Cで書かれたfincoreはGPLv2なんだけど、
どっちが本家なんだかもともとオリジナルがあるのかよく判らない。


取り敢えずlinux-ftoolsを落としてきてコンパイル。
ダウンロード可能なtarballが存在しないので、hgとやらでcloneするしかなさそう。
hgコマンドが入ってなかったので、mercurialパッケージを突っ込んでから(恥ずかしながらこれ知らなかった。。)

$ sudo yum install -y mercurial
$ hg clone https://code.google.com/p/linux-ftools/
$ cd linux-fincore
$ ./configure && make

makeさえすればバイナリ単品で使い回せそうなので、make installはしない前提でconfigureオプションなし。

$ ./linux-fincore /tmp/*

filename                                                                                       size        total_pages    min_cached page       cached_pages        cached_size        cached_perc
--------                                                                                       ----        -----------    ---------------       ------------        -----------        -----------
/tmp/access.log                                                                             191,010                 47                 -1                  0                  0               0.00
/tmp/logs.sql.201305091141.gz                                                                 8,908                  3                 -1                  0                  0               0.00
/tmp/logs.sql.201305131834                                                                   72,382                 18                 -1                  0                  0               0.00
---
total cached size: 0

うむ。-Lつけて縦表示にした方が見やすいかも。

$ ./linux-fincore -L -s /tmp/*
filename                                                                                       size        total_pages    min_cached page       cached_pages        cached_size        cached_perc
--------                                                                                       ----        -----------    ---------------       ------------        -----------        -----------
/tmp/access.log
size: 191,010
total_pages: 47
min_cached_page: -1
cached: 0
cached_size: 0
cached_perc: 0.00
/tmp/logs.sql.201305091141.gz
size: 8,908
total_pages: 3
min_cached_page: -1
cached: 0
cached_size: 0
cached_perc: 0.00
/tmp/logs.sql.201305131834
size: 72,382
total_pages: 18
min_cached_page: -1
cached: 0
cached_size: 0
cached_perc: 0.00
---
total cached size: 0

さあ、これでmroonga載っててswapが鬼の様なサーバー覗いてこよう。

2013年5月14日火曜日

redis sentinelの動きを軽く追ってみる

redis-2.6.7のソースから。

redis.c: serverCronから100ミリ秒ごとにsentinel.c: sentinelTimerが呼ばれる。
まずはマスターから。
 ⇒マスターが終わったら、マスターからスレーブの情報を引っ張ってきてそいつらをチェック。
 ⇒次にマスターからsentinelの情報を引っ張ってきて、そいつらを。
  ⇒マスター、自分に接続してるsentinelの情報なんて持ってるんだね。

sentinel.c: sentinelHandleRedisInstanceの中で
 1) コネクションが切れてたら再接続(sentinel.c: sentinelReconnectInstance)
 2) INFOやPINGの打ち込み(sentinel.c: sentinelPingInstance)
 3) PINGの戻りがPONG, LOADING, MASTERDOWNだったらlast_avail_timeを更新。
 4) チェックしているマスターのステータスがSDOWN, FAILOVER_IN_PROGRESSだったら、他のsentinelにis-master-down-by-addrを投げて問い合わせる。これ、「このsentinelは自分のマスターがダウンしていると認識しているかどうか(=MASTERDOWN)」を判定して格納してるように見える(sentinel.c: sentinelAskMasterStateToOtherSentinels)
 5) ここでSDOWNしているかどうかの判定関数を呼ぶ(sentinel.c: sentinelCheckSubjectivelyDown)
 6) last_avail_timeと現在時刻の差がdown_after_millisecondsを超えていたらSDOWN判定。
 7) 自分がSDOWNとしている場合、他のsentinelがSDOWNと判定しているかどうか問い合わせる。quorumの値を超えたらODOWNのステータスをつける(sentinel.c: sentinelCheckObjectivelyDown)


http://redis.io/topics/sentinel

PONG, LOADING, MASTERDOWN以外のレスポンスは無効でSDOWNに叩き落とされるのかと思ったら、
無効で無視されてlast_avail_timeが更新されない、という動作だった。

なんでSDOWN判定されたのかをログに吐かせたくて色々読んだんだけれども、
そもそもSDOWN判定ではlast_avail_timeと現在時刻の差しか見てなくて、
PINGのレスポンスを受け取るところは結構前の段階なのでどうしようか考えちゅう。

2013年5月10日金曜日

MySQL 5.6より前のマスターにMySQL 5.6のスレーブをぶら下げるとワーニングが出る(Err: 1193)

知らなかったのでメモる。
ネタ提供は @kenjiskywalker さん。

今日もありがとうございます(*-人-)


5.5, 5.1, 5.0のマスターに5.6のスレーブをぶら下げてSTART SLAVEすると、こんなワーニングが出る。

2013-05-10 12:45:45 15820 [Warning] Slave I/O: Notifying master by SET @master_binlog_checksum= @@global.binlog_checksum faile
d with error: Unknown system variable 'binlog_checksum', Error_code: 1193
2013-05-10 12:45:45 15820 [Warning] Slave I/O: Unknown system variable 'SERVER_UUID' on master. A probable cause is that the v
ariable is not supported on the master (version: 5.5.31-log), even though it is on the slave (version: 5.6.11-log), Error_code
: 1193

これ自体はWarningで動作に問題はないけど、なんでMySQL 5.6で追加されたbinlog_checksumと
SERVER_UUIDが`MySQL 5.6のエラーログ'に出るんだろうとふと思って調べてみる。

取り敢えず覗いてみると、sql/rpl_slave.cc:get_master_version_and_clock にこんなところを発見。

2047     const char query[]= "SET @master_binlog_checksum= @@global.binlog_checksum";
2048     master_res= NULL;
2049     mi->checksum_alg_before_fd= BINLOG_CHECKSUM_ALG_UNDEF; //initially undefined
..
2056     rc= mysql_real_query(mysql, query, strlen(query));
2057     if (rc != 0)
..
2063       if (mysql_errno(mysql) == ER_UNKNOWN_SYSTEM_VARIABLE)
2064       {
2065         // this is tolerable as OM -> NS is supported
2066         mi->report(WARNING_LEVEL, mysql_errno(mysql),
2067                    "Notifying master by %s failed with "
2068                    "error: %s", query, mysql_error(mysql));

マスターに向かって、"SET @master_binlog_checksum= @@global.binlog_checksum"を放って、
リターンコードでものによってはワーニングにしたりFatalでI/Oスレッドとめたり。

MySQL 5.5以前はbinlog_checksum変数がないから、ER_UNKNOWN_SYSTEM_VARIABLEで必ずエラーになるはず。


SERVER_UUIDのところは sql/rpl_slave.cc:get_master_uuid から

1541   if (!mysql_real_query(mysql,
1542                         STRING_WITH_LEN("SHOW VARIABLES LIKE 'SERVER_UUID'")) &&
1543       (master_res= mysql_store_result(mysql)) &&
1544       (master_row= mysql_fetch_row(master_res)))
1545   {
..

1587   else if (!master_row && master_res)
1588   {
1589     mi->report(WARNING_LEVEL, ER_UNKNOWN_SYSTEM_VARIABLE,
1590                "Unknown system variable 'SERVER_UUID' on master. "
1591                "A probable cause is that the variable is not supported on the "
1592                "master (version: %s), even though it is on the slave (version: %s)",
1593                mysql->server_version, server_version);
1594   }

マスターに向かって"SHOW VARIABLES LIKE 'SERVER_UUID'"を放って、結果セットを空っぽでもらってこのワーニングになる、と。


で、この2つの関数は sql/rpl_slave.cc:handle_slave_ioからこんな風に

4056 connected:
..
4067   mysql_mutex_lock(&mi->run_lock);
4068   mi->slave_running= MYSQL_SLAVE_RUN_CONNECT;
4069   mysql_mutex_unlock(&mi->run_lock);
4070
4071   thd->slave_net = &mysql->net;
4072   THD_STAGE_INFO(thd, stage_checking_master_version);
4073   ret= get_master_version_and_clock(mysql, mi);
4074   if (!ret)
4075     ret= get_master_uuid(mysql, mi);
4076   if (!ret)
4077     ret= io_thread_init_commands(mysql, mi);

呼ばれていて、呼び出し元をたどっていくと sql/rpl_slave.cc:start_slave_threads にたどり着く。

OK、START SLAVEすると毎回出るのね。
しかしこんな処理追加になってたのか。。
楽しかった。

2013年5月9日木曜日

Last_SQL_Errno: 1677 にであった

珍しいエラーでSQLスレッドが止まっていた。

mysql> SHOW SLAVE STATUS\G
..

               Last_SQL_Errno: 1677
               Last_SQL_Error: Column 0 of table 'd1.t1' cannot be converted from type 'int' to type 'bigint(20)'
..

なにこれ。初めて見た。
mysqlbinlogで止まっているリレーログのエントリを当たると、ROWフォーマットで記録されたUPDATEステートメントに遭遇。
binlog_format = MIXEDなので、ORDER BYなしのLIMIT使ったUPDATEでも投げたのかな。。


で、まあ、非決定性のクエリ投げるなよは置いておいて。
INT型をBIGINT型に変換できないとか言ってるけど、なんだよ変換って。。

原因はマスターとスレーブのテーブルで、データ型が違うカラムがあったからorz
STATEMENTベースのレプリケーションだと問題にならないけど、
ROWベースのレプリケーションだとこのエラーに遭遇する。

ちなみに、マスター側テーブルのカラムをVARCHAR(100)、
スレーブ側をVARCHAR(50)にしてもこのエラーにぶち当たった。

ただ、エラーメッセージにtype 'varchar(300) to type 'varchar(50)'って書いてあったんだけど、
UTF-8だから1文字3byteで、バイナリログにはバイト数で情報書いてるんだろうなとか思うだけ思って調べなかった。


教訓: バッチ用スレーブだからって無茶はいけない。

2013年5月1日水曜日

MariaDB 10.0.2にinformation_schema.QUERY_CACHE_INFOが入ってる

最近、クエリキャッシュの中身を見るinformation_schemaプラグイン作りたいとか思って
試行錯誤してた訳なんですが、まあやっぱり他の誰かも思いつきますよね。

http://lists.askmonty.org/pipermail/commits/2013-March/004459.html



MariaDB [d1]> SELECT * FROM t1;
+-----+------+
| num | val  |
+-----+------+
|   1 | one  |
|   2 | two  |
+-----+------+
2 rows in set (0.00 sec)


MariaDB [d1]> SELECT * FROM t1 LIMIT 3;
+-----+------+
| num | val  |
+-----+------+
|   1 | one  |
|   2 | two  |
+-----+------+
2 rows in set (0.00 sec)


MariaDB [d1]> SELECT * FROM information_schema.QUERY_CACHE_INFO;
+------------------+--------------------------+---------------------+--------------------+-------------------------+
| STATEMENT_SCHEMA | STATEMENT_TEXT           | RESULT_BLOCKS_COUNT | RESULT_BLOCKS_SIZE | RESULT_BLOCKS_SIZE_USED |
+------------------+--------------------------+---------------------+--------------------+-------------------------+
| d1               | SELECT * FROM t1 LIMIT 3 |                   1 |                512 |                     183 |
| d1               | SELECT * FROM t1         |                   1 |                512 |                     183 |
+------------------+--------------------------+---------------------+--------------------+-------------------------+
2 rows in set (0.00 sec)


デフォルトではsoファイルとしてmakeされて、information_schemaプラグインとして使える。
-DWITH_QUERY_CACHE_INFO=ONにすると、プラグインではなくサーバー本体に組み込まれる。

$ cmake -i
..
Variable Name: WITH_QUERY_CACHE_INFO
Description: Link QUERY_CACHE_INFO statically to the server
Current Value: OFF
New Value (Enter to keep current value): OFF
..

ちょっとCMakeFile.txtいじってやれば本家でも使えるかな? まだ試してない。。


【2013/06/21 10:44】
MySQL5.5で動くようにqc_info.ccを書き換えるパッチ作ったよ!

https://github.com/yoku0825/qc_info

MySQL5.6とMySQL5.0のレプリケーションでI/OスレッドがError: 2049

MySQL5.6をスレーブに、old_passwords = 1なMySQL5.0をマスターにしてレプリケーションを組もうとすると、

mysql56> show slave status\G
*************************** 1. row ***************************
               Slave_IO_State: Connecting to master
                  Master_Host: localhost
                  Master_User: replicator
                  Master_Port: 64050
                Connect_Retry: 60
              Master_Log_File: bin.000019
          Read_Master_Log_Pos: 820
               Relay_Log_File: relay.000001
                Relay_Log_Pos: 4
        Relay_Master_Log_File: bin.000019
             Slave_IO_Running: Connecting
            Slave_SQL_Running: Yes
              Replicate_Do_DB:
          Replicate_Ignore_DB:
           Replicate_Do_Table:
       Replicate_Ignore_Table:
      Replicate_Wild_Do_Table:
  Replicate_Wild_Ignore_Table:
                   Last_Errno: 0
                   Last_Error:
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 820
              Relay_Log_Space: 120
              Until_Condition: None
               Until_Log_File:
                Until_Log_Pos: 0
           Master_SSL_Allowed: No
           Master_SSL_CA_File:
           Master_SSL_CA_Path:
              Master_SSL_Cert:
            Master_SSL_Cipher:
               Master_SSL_Key:
        Seconds_Behind_Master: NULL
Master_SSL_Verify_Server_Cert: No
                Last_IO_Errno: 2049
                Last_IO_Error: error connecting to master 'replicator@localhost:64050' - retry-time: 60  retries: 1
               Last_SQL_Errno: 0
               Last_SQL_Error:
  Replicate_Ignore_Server_Ids:
             Master_Server_Id: 1050
                  Master_UUID:
             Master_Info_File: /usr/mysql/5.6.11/data/master.info
                    SQL_Delay: 0
          SQL_Remaining_Delay: NULL
      Slave_SQL_Running_State: Slave has read all relay log; waiting for the slave I/O thread to update it
           Master_Retry_Count: 86400
                  Master_Bind:
      Last_IO_Error_Timestamp: 130501 13:24:13
     Last_SQL_Error_Timestamp:
               Master_SSL_Crl:
           Master_SSL_Crlpath:
           Retrieved_Gtid_Set:
            Executed_Gtid_Set:
                Auto_Position: 0
1 row in set (0.00 sec)

エラる。

$ perror 2049
Illegal error code: 2049

あれ、perrorが2049レポートしてくれない(´・ω・`)
マニュアルには記載ある。
http://dev.mysql.com/doc/refman/5.6/en/error-messages-client.html#error_cr_secure_auth

クライアントオプションのsecure_authが有効だから、
サーバーに格納されてるユーザーのパスワードが古い16桁形式だと接続できない。
というか、クライアントが接続を拒否する。

取り敢えずマスター側のサーバーで

mysql50> SET SESSION old_passwords = 0;
Query OK, 0 rows affected (0.00 sec)

mysql50> SET PASSWORD FOR replicator = PASSWORD('replicator');
Query OK, 0 rows affected (0.00 sec)

mysql50> SELECT user, host, password FROM mysql.user;
+--------------+-----------------+-------------------------------------------+
| user         | host            | password                                  |
+--------------+-----------------+-------------------------------------------+
| root         | localhost       |                                           |
| root         | dev-personal-04 |                                           |
| root         | 127.0.0.1       |                                           |
| mysqld_multi | localhost       | *25538D365EF36670224773C86161F9D7EEAC49F9 |
| replicator   | %               | *E6FA4B5E283079702D46597DFCD2766E7BF96B0E |
+--------------+-----------------+-------------------------------------------+
5 rows in set (0.00 sec)

これで接続できる。
いきなり上書きがアレなら、

mysql50> set session old_passwords = 0;
Query OK, 0 rows affected (0.00 sec)

mysql50> GRANT REPLICATION SLAVE ON *.* TO replicator56 IDENTIFIED BY 'replicator';
Query OK, 0 rows affected (0.00 sec)

mysql50> SELECT user, host, password FROM mysql.user;
+--------------+-----------------+-------------------------------------------+
| user         | host            | password                                  |
+--------------+-----------------+-------------------------------------------+
| root         | localhost       |                                           |
| root         | dev-personal-04 |                                           |
| root         | 127.0.0.1       |                                           |
| replicator56 | %               | *E6FA4B5E283079702D46597DFCD2766E7BF96B0E |
| mysqld_multi | localhost       | *25538D365EF36670224773C86161F9D7EEAC49F9 |
| replicator   | %               | 755c4ac71c32381e                          |
+--------------+-----------------+-------------------------------------------+
6 rows in set (0.00 sec)

5.6接続用に新しくREPLICATION SLAVE権限持ちのユーザーを作る。

ちなみに、↑のSELECT見ると判る感じで、古いパスワードは16桁、
新しい(といっても随分昔からだけど)パスワードは41桁で先頭が*です。

gdbでちょこちょこ調べてみたけど、
I/Oスレッドはサーバーのsecure-authもmy.cnfのsecure-authも見てくれなくて、
暗黙のデフォルト値(secure-auth=1)を使っているぽいので、
あとで暗黙のデフォルト値書き換えて試してみますかね。

ネタ提供のけんじおじさん++
今日もごちそうさまです(*-人-)


【2013/05/01 14:48】
今更になって気付いたんですが、タイトルに反してMySQL5.1だろうと5.5だろうと5.6だろうと
レプリケーション用のユーザーが16桁パスワードで設定されている場合は同じエラーになります。

名が体を現さないエントリになってしまった。。

あと、mysql_initがデフォルトでsecure_auth = TRUEを押し込んでいたので、
ここを直したら16桁パスワードでもスレーブになれるようになりました。ビバ。


$ diff -c sql-common/client.c sql-common/client.c.org
*** sql-common/client.c 2013-05-01 14:08:10.810764039 +0900
--- sql-common/client.c.org     2013-04-05 21:27:18.000000000 +0900
***************
*** 1687,1694 ****
    */
    mysql->reconnect= 0;

! //  mysql->options.secure_auth= TRUE;
!   mysql->options.secure_auth= FALSE;

    return mysql;
  }
--- 1687,1693 ----
    */
    mysql->reconnect= 0;

!   mysql->options.secure_auth= TRUE;

    return mysql;
  }

mysql50> select user, host, password from user;
+--------------+-----------------+-------------------------------------------+
| user         | host            | password                                  |
+--------------+-----------------+-------------------------------------------+
| root         | localhost       |                                           |
| root         | dev-personal-04 |                                           |
| root         | 127.0.0.1       |                                           |
| mysqld_multi | localhost       | *25538D365EF36670224773C86161F9D7EEAC49F9 |
| replicator   | %               | 755c4ac71c32381e                          |
+--------------+-----------------+-------------------------------------------+
5 rows in set (0.00 sec)

mysql> change master to master_host='localhost', master_port = 64050, master_user='replicator', master_password='replicator', master_log_file='bin.000022', master_log_pos = 591;
Query OK, 0 rows affected, 2 warnings (0.05 sec)

mysql> start slave;
Query OK, 0 rows affected (0.01 sec)

mysql> show slave status\G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: localhost
                  Master_User: replicator
                  Master_Port: 64050
                Connect_Retry: 60
              Master_Log_File: bin.000022
          Read_Master_Log_Pos: 591
               Relay_Log_File: relay.000002
                Relay_Log_Pos: 251
        Relay_Master_Log_File: bin.000022
             Slave_IO_Running: Yes
            Slave_SQL_Running: Yes
              Replicate_Do_DB:
          Replicate_Ignore_DB:
           Replicate_Do_Table:
       Replicate_Ignore_Table:
      Replicate_Wild_Do_Table:
  Replicate_Wild_Ignore_Table:
                   Last_Errno: 0
                   Last_Error:
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 591
              Relay_Log_Space: 410
              Until_Condition: None
               Until_Log_File:
                Until_Log_Pos: 0
           Master_SSL_Allowed: No
           Master_SSL_CA_File:
           Master_SSL_CA_Path:
              Master_SSL_Cert:
            Master_SSL_Cipher:
               Master_SSL_Key:
        Seconds_Behind_Master: 0
Master_SSL_Verify_Server_Cert: No
                Last_IO_Errno: 0
                Last_IO_Error:
               Last_SQL_Errno: 0
               Last_SQL_Error:
  Replicate_Ignore_Server_Ids:
             Master_Server_Id: 1050
                  Master_UUID:
             Master_Info_File: /usr/mysql/nosecure_5.6.11/data/master.info
                    SQL_Delay: 0
          SQL_Remaining_Delay: NULL
      Slave_SQL_Running_State: Slave has read all relay log; waiting for the slave I/O thread to update it
           Master_Retry_Count: 86400
                  Master_Bind:
      Last_IO_Error_Timestamp:
     Last_SQL_Error_Timestamp:
               Master_SSL_Crl:
           Master_SSL_Crlpath:
           Retrieved_Gtid_Set:
            Executed_Gtid_Set:
                Auto_Position: 0
1 row in set (0.00 sec)


【2013/05/21 12:04】
そっか、perrorはサーバー側のエラーコードを解釈してくれるやつで、
エラーコード2000番台はクライアント側のエラーコードだからperrorがInvalidって言うんだ。。