Primary Keyが無いテーブル + Galera Clusterで悲惨な目に

自分でこんな記事書いてたのに。。

　Primary Keyがないテーブル その２

binlog_format=ROWの時(MIXEDでも、結果が一意にならない関数使ったりしてROWモードでバイナリログ出力された時)に
Primary Keyの無いテーブルだと無茶苦茶テーブルスキャンしてレプリケーションが遅延しまくった話があったから、
Primary Keyは取り敢えず付けておこう！ と思った話。


で。

最近Galera Cluster for MySQLの実装をいくつか試してるんですが、
これって必須でbinlog_format=ROWを設定しなきゃいけない。

…テーブルにpkey付けるの忘れて100万行INSERTしたら終わらない終わらない。。。_|￣|○

エラーログに吐いて教えてくれました。
このcommitでlog_event.ccに追加されたのかな？


130129 22:24:07 [Note] The slave is applying a ROW event on behalf of an UPDATE statement on table t2 and is currently taking a considerable amount of time (61 seconds). This is due to the fact that it is scanning the table while looking up records to be processed. Consider adding a primary key (or unique key) to the table to improve performance.


_|￣|○ 油断していたよ。。でもありがとうエラーログに吐いてくれて。。

MySQL 5.6.9のmysqlクライアントがujis, sjis, cp932で落ちる(5.6.12で修正)

たまたまujisで試したいことがあってログインしたらいきなり落ちました。。


$ mysql56 --default-character-set=ujis
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 4
Server version: 5.6.9-rc-log Source distribution

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

mysql56>
mysql56> show databases;
Segmentation fault (core dumped)


(´･ω･｀) 。。。
backtrace見ると、どうも.my_historyに書き込むところで落ちているような気がする。




(gdb) bt
#0  0x0000000000000000 in ?? ()
#1  0x0000000000488346 in my_wildcmp_mb_impl (cs=0x919e60, str=<value optimized out>, str_end=0x1b7ce97 "",
    wildstr=0x1b4d661 "IDENTIFIED*", wildend=0x1b4d649 "ibution", escape=0, w_one=63, w_many=42, recurse_level=1)
    at /home/yoku/mysql-5.6.9-rc/strings/ctype-mb.c:326
#2  0x0000000000488512 in my_wildcmp_mb (cs=<value optimized out>, str=<value optimized out>, str_end=<value optimized out>,
    wildstr=<value optimized out>, wildend=<value optimized out>, escape=<value optimized out>, w_one=63, w_many=42)
    at /home/yoku/mysql-5.6.9-rc/strings/ctype-mb.c:370
#3  0x000000000040be11 in check_histignore (string=0x1b7ce80 "use performanse_schema;")
    at /home/yoku/mysql-5.6.9-rc/client/mysql.cc:2995
#4  add_filtered_history (string=0x1b7ce80 "use performanse_schema;") at /home/yoku/mysql-5.6.9-rc/client/mysql.cc:2966
#5  0x00000000004136f8 in add_line (interactive=true) at /home/yoku/mysql-5.6.9-rc/client/mysql.cc:2324
#6  read_and_execute (interactive=true) at /home/yoku/mysql-5.6.9-rc/client/mysql.cc:2166
#7  0x000000000041477e in main (argc=11, argv=0x1b2f328) at /home/yoku/mysql-5.6.9-rc/client/mysql.cc:1395


sjisとcp932でも落ちるのは確認した。
5.5.29のクライアント使えば大丈夫。

Bugs投稿済み。。



【2013/02/06 10:12】
5.6.10 GAになってもまだ直ってません。
回避方法は、character setにujis, sjis, cp932を指定しない(latin1やutf8でつなぐ)してから
SET NAMES ujis; で変更する。


【2013/03/21 09:36】
5.6.12で修正されたそうです！

http://bugs.mysql.com/bug.php?id=68107

redis 2.6のaofファイルを覗いてみた

最近ちょこちょこredis触ってます。

この前、`redisに載ってる全KEYをダンプしたい！'とかふと思い付いてやろうと思ったんですが、
redis-cliから叩くにも良さそうなものがないので、ダンプファイルから抜こうと思いました。

dump.rdbはこんなデータ。



$ od -c dump.rdb
0000000   R   E   D   I   S   0   0   0   6 376  \0  \n 003   b   b   b
0000020 032 032  \0  \0  \0 022  \0  \0  \0 002  \0  \0 006   s   e   c
0000040   o   n   d  \b 005   f   i   r   s   t 377  \0 003   a   b   c
0000060 300  \n  \0 002   a   a 003   n   i   c 377   y   6 210   q 365
0000100   `   t 177
0000103


bbbというリストに"second", "first"の2要素、abcというキーに"10"、aaというキーに"nic"が入ってる。
先頭12バイト(\0\nまで)がヘッダっぽい感じで、1バイトでキーの名前の長さ、キー名、
キー名の終端はよく判らない、1バイトで値の長さ、値、の順？

よし、あきらめる。
マニュアル読めば書いてあるのかも知れないけど、
こんなものを俺のPerl力でパースさせていたら多分redisの新バージョンが出てしまう。


折り良く（？）aofファイルも出力（というかこっちがメインで運用してた）させていたので、
そっちを何とか解析できないかと思って覗いてみる。



$ od -c appendonly.aof
0000000   *   2  \r  \n   $   6  \r  \n   S   E   L   E   C   T  \r  \n
0000020   $   1  \r  \n   0  \r  \n   *   3  \r  \n   $   3  \r  \n   s
0000040   e   t  \r  \n   $   2  \r  \n   a   a  \r  \n   $   3  \r  \n
0000060   n   i   c  \r  \n   *   3  \r  \n   $   3  \r  \n   s   e   t
0000100  \r  \n   $   3  \r  \n   a   b   c  \r  \n   $   2  \r  \n   1
0000120   0  \r  \n   *   3  \r  \n   $   5  \r  \n   l   p   u   s   h
0000140  \r  \n   $   3  \r  \n   b   b   b  \r  \n   $   5  \r  \n   f
0000160   i   r   s   t  \r  \n   *   3  \r  \n   $   5  \r  \n   l   p
0000200   u   s   h  \r  \n   $   3  \r  \n   b   b   b  \r  \n   $   6
0000220  \r  \n   s   e   c   o   n   d  \r  \n   *   1  \r  \n   $   4
0000240  \r  \n   s   a   v   e  \r  \n
0000250

…ん？； なんかすごくASCII文字だなこれ。



$ head appendonly.aof
*2
$6
SELECT
$1
0
*3
$3
set
$2
aa



…ほう！
レスポンスが間に入って読みにくいけど、これredisの生コマンドっぽい。
というか、まさにこれだった。プロトコル仕様。すてき。

欲しいのはキーの名前とキーの長さだったので、レスポンスの部分は省くことに決定。
キーの名前に英大文字は使っていないという噂だったので、/^[A-Z]+$/をリクエストとして扱うことに大決定。
取り敢えず書いてみる。



$ cat appendonly.pl
#!/usr/bin/perl

use strict;
use warnings;
use Fcntl;

my $sBuff = "";
my $sTmp = "";

sysopen(IN, "/usr/redis/appendonly.aof", O_RDONLY);
sysopen(OUT, "/usr/redis/tmp.aof", O_WRONLY | O_CREAT);

while ($sBuff = <IN>) {
        chomp $sBuff;
        if ($sBuff =~ /^[A-Z]+$/) {
                if ($sTmp ne "") {
                        printf(OUT "%s\n", $sTmp);
                        $sTmp = "";
                }
        } elsif ($sBuff =~ /^(\*|\$)/) {
                next;
        }

        $sBuff =~ s/[\r\n]/ /g;
        $sTmp .= $sBuff;
}

printf(OUT "%s\n", $sTmp);

__END__


我ながらやっつけ仕事。。
ともあれこれで、
`SET key value\n'
の列挙されたテキストファイルが/usr/redis/tmp.aofにどばーと吐き出される。

これを適当にawk '{print $2,length($3)}' とかで切って集計したりしていて気付いたんだけど、
aofファイルにはタイムスタンプが無いのでちょっと不便。

そこで、redis-cli set mymark `date "%Y/%m/%d %H:%M:%S"`とかするようにcronに仕込んでおくと、
awk '{if ($2 == "mymark") {print $3} else if ($2 == "keyname") {print $2,length($3)}}' ..
とやった時に特定のキーが時間経過とともにめりめり大きくなっていくのが確認できたり。

意外とredisが楽しくなってきた今日この頃なのでした。

Percona Serverのmysql_configが変？

XtraDB Cluster 5.5.28だけを積んだマシンでtpcc-mysqlをコンパイルしようとしたら、
-lmysqlclient_rが見つからないと何度も怒られた。




$ bin/mysql_config
Usage: bin/mysql_config [OPTIONS]
Options:
        --cflags         [-I/xtra/include -fPIC -g -static-libgcc -fno-omit-frame-pointer -DPERCONA_INNODB_VERSION=rel29.1    -DWITH_WSREP -DWSREP_PROC_INFO -DMYSQL_MAX_VARIABLE_VALUE_LEN=2048 -DWITH_INNODB_DISALLOW_WRITES -fPIC -g -static-libgcc -fno-omit-frame-pointer -fno-strict-aliasing -DMY_PTHREAD_FASTMUTEX=1]
        --include        [-I/xtra/include]
        --libs           [-L/xtra/lib/mysql -lmysqlclient -lpthread -lm -lrt -ldl]
        --libs_r         [-L/xtra/lib/mysql -lmysqlclient_r -lpthread -lm -lrt -ldl]
        --plugindir      [/xtra/lib/mysql/plugin]
        --socket         [/tmp/mysql.sock]
        --port           [0]
        --version        [5.5.28]
        --libmysqld-libs [-L/xtra/lib/mysql -lmysqld]
        --variable=VAR   VAR is one of:
                pkgincludedir [/xtra/include]
                pkglibdir     [/xtra/lib/mysql]
                plugindir     [/xtra/lib/mysql/plugin]



$ ls -l lib lib/mysql
lib:
合計 50544
-rwxr-xr-x 1 xtra xtra 26612459 11月 17 05:38 2012 libgalera_smm.so
-rw-r--r-- 1 xtra xtra 17309456 11月 17 05:39 2012 libmysqlclient.a
lrwxrwxrwx 1 xtra xtra       20  1月 11 13:43 2013 libmysqlclient.so -> libmysqlclient.so.18
lrwxrwxrwx 1 xtra xtra       24  1月 11 13:43 2013 libmysqlclient.so.18 -> libmysqlclient.so.18.0.0
-rwxr-xr-x 1 xtra xtra  7811970 11月 17 05:39 2012 libmysqlclient.so.18.0.0
lrwxrwxrwx 1 xtra xtra       16  1月 11 13:43 2013 libmysqlclient_r.a -> libmysqlclient.a
lrwxrwxrwx 1 xtra xtra       17  1月 11 13:43 2013 libmysqlclient_r.so -> libmysqlclient.so
lrwxrwxrwx 1 xtra xtra       17  1月 11 13:43 2013 libmysqlclient_r.so.18 -> libmysqlclient.so
lrwxrwxrwx 1 xtra xtra       17  1月 11 13:43 2013 libmysqlclient_r.so.18.0.0 -> libmysqlclient.so
-rw-r--r-- 1 xtra xtra    10288 11月 17 05:38 2012 libmysqlservices.a
drwxr-xr-x 3 xtra xtra     4096 11月 17 05:41 2012 mysql

lib/mysql:
合計 4
drwxr-xr-x 3 xtra xtra 4096 11月 17 05:41 2012 plugin


なんかどうも、mysql_config --libsと--libs_rは/xtra/libを返さないといけない気がするんだけども。
lib/mysqlの中何も入ってナイヨ。。
（同じ5.5.28の本家MySQLとMariaDBのmysql_configは$basedir/libを返してくれる）

バグかなー。。

rpmインストール時にmy.cnfをおいておく

Oracleビルドのrpmの話です。
独自リポジトリ(remiとかepelとか)の話はちょっと違います。

rpm -iを叩く前に/etc/my.cnf (/etcでなくても、自動的に読み込まれるパスならOK)をおいておくと、
mysql_install_db (rpmインストールの一番最後に流れる)が流れる辺りで
勝手に/etc/my.cnfを食ってくれる。

インストールしたあとにinnodb_log_file_sizeを変えて、
InnoDBログファイルと共有テーブルスペースを毎度作り直しているような方（半年前の俺）にはオススメ。


ところで/etc/my.cnfを読んでくれることは知っていたけれど、
何が、なぜ/etc/my.cnfを読むのかに気付いたのでその記録。

mysql_install_dbはシステムテーブルを作るときに、
"mysqld --bootstrap .." にmysql_system_tables.sqlとmysql_system_tables_data.sqlを標準入力から食わせていて、
このときのmysqldプロセスが起動する時に/etc/my.cnfを食ってくれるからこうなる。

道理でlog-bin指定した/etc/my.cnf置いておくとバイナリログにmysqlデータベースへのINSERTがごそごそ書いてある訳だ。。


今まで知らなかったのが逆に恥ずかしいくらいだけど、一応メモ。

pt-ioprofileでMySQLのテンポラリテーブルのサイズを測る

Percona-Toolkitのうちの1つにpt-ioprofileというやつがあって、
straceでwriteやread, fsyncのシステムコール呼び出し状況を記録して、
lsofでファイルディスクリプタ番号と紐付けて、集計して出してくれたりする。

一番単純な使い方は多分こんな感じ。



# pt-ioprofile --cell sizes --run-time 60
2013年  1月  6日 日曜日 17:08:03 JST
Tracing process ID 1824
     total       read    pread64   pwrite64      write       open    _llseek filename
      2191          0       1024       1167          0          0          0 /var/lib/mysql/mysql/user.MYI
      1386          0       1386          0          0          0          0 /var/lib/mysql/mysql/proxies_priv.MYD
      1320          0       1320          0          0          0          0 /var/lib/mysql/mysql/db.MYD
       564        512         24         28          0          0          0 /var/lib/mysql/mysql/user.MYD
        81          0          0          0         81          0          0 /var/lib/mysql/bin.000056
         0          0          0          0          0          0          0 /var/lib/mysql/mysql/db.opt


デフォルトの計測時間は30秒。--run-timeで上書き。
デフォルトの集計はI/O`回数'。--cellでsizesを指定するとバイト単位のオペレーション量になる。

1分間でこれらのファイルにこれだけのread, writeが発生してた…というのが測れる。


さてさてさて。
pt-ioprofileを走らせて、おもむろに`converting HEAP to MyISAM'が走る様なクエリを流す。
（tmp_table_sizeを1024に設定して、DISK上に出させる）



# pt-ioprofile --cell sizes --run-time 10

2013年  1月  6日 日曜日 17:22:17 JST
Tracing process ID 4904
     total       read     pwrite      write       open      close      lseek filename
     80400      20100          0      20100          0          0      40200 /tmp/#sql_1328_0.MYD
      1782        328        126       1024          0          0        304 /tmp/#sql_1328_0.MYI



おお、取れた…んだけど、この値合ってんのかな。。
なんか違う気がする。



mysql> DESC t1;
+-------+---------------------+------+-----+---------+----------------+
| Field | Type                | Null | Key | Default | Extra          |
+-------+---------------------+------+-----+---------+----------------+
| num   | bigint(20) unsigned | NO   | PRI | NULL    | auto_increment |
| val   | char(32)            | YES  |     | NULL    |                |
+-------+---------------------+------+-----+---------+----------------+
2 rows in set (0.01 sec)

mysql> DESC t2;
+-------+---------------------+------+-----+---------+----------------+
| Field | Type                | Null | Key | Default | Extra          |
+-------+---------------------+------+-----+---------+----------------+
| num   | bigint(20) unsigned | NO   | PRI | NULL    | auto_increment |
| val   | char(32)            | YES  |     | NULL    |                |
+-------+---------------------+------+-----+---------+----------------+
2 rows in set (0.00 sec)


mysql> SELECT * FROM t2 LEFT JOIN t1 USING(num) ORDER BY t2.val DESC, t1.val ASC;
+-----+----------------------------------+----------------------------------+
| num | val                              | val                              |
+-----+----------------------------------+----------------------------------+
|  83 | fe9fc289c3ff0af142b6d3bead98a923 | fe9fc289c3ff0af142b6d3bead98a923 |
..
|  27 | 02e74f10e0327ad868d138f2b4fdd6f0 | 02e74f10e0327ad868d138f2b4fdd6f0 |
+-----+----------------------------------+----------------------------------+
100 rows in set (0.05 sec)

mysql> SHOW PROFILE;
+--------------------------------+----------+
| Status                         | Duration |
+--------------------------------+----------+
| starting                       | 0.001830 |
| Waiting for query cache lock   | 0.000587 |
| checking query cache for query | 0.000904 |
| checking permissions           | 0.000647 |
| checking permissions           | 0.000546 |
| Opening tables                 | 0.001298 |
| System lock                    | 0.000778 |
| init                           | 0.000812 |
| optimizing                     | 0.004460 |
| statistics                     | 0.000866 |
| preparing                      | 0.000701 |
| Creating tmp table             | 0.001023 |
| executing                      | 0.000597 |
| Copying to tmp table           | 0.003121 |
| converting HEAP to MyISAM      | 0.015940 |
| Copying to tmp table on disk   | 0.005196 |
| Sorting result                 | 0.001541 |
| Sending data                   | 0.000519 |
| end                            | 0.000314 |
| removing tmp table             | 0.001926 |
| end                            | 0.000363 |
| query end                      | 0.000301 |
| closing tables                 | 0.000289 |
| freeing items                  | 0.006751 |
| logging slow query             | 0.000266 |
| cleaning up                    | 0.000558 |
+--------------------------------+----------+
26 rows in set (0.05 sec)

(BIGINT 4バイト + CHAR 32バイト) * 2テーブル結合 * 100行だから、
1行ごとのオーバーヘッド入れても20KiB近くも行かなそうなんだけどな。。

でもtmp_table_sizeを上げながら確認すると、
16KiBだとまだMyISAM変換されて、20KiBだとなくなる。

そんなものなのかぁ。


なおpt-ioprofileはstraceとlsofとpidof（だと思う。動き的に。中身は読んでない）を使ってるだけの
シェルスクリプトなので、


# pt-ioprofile --cell sizes --run-time 10 --profile-process rsyslogd
2013年  1月  6日 日曜日 17:25:44 JST
Tracing process ID 1227
     total      write filename
        46         46 /var/log/messages

こんな真似も可能だったりする。

ただし、
tpcc-mysqlで負荷かけながらmysqldにアタッチしてたら、
スレッドが何本かState: Tでハングって
mysqldが動かなくなったことがあるので、
絶対に本番でやってはダメです。



言われなくてもやりませんね、はい。。