GA

2012/06/30

straceでthreadの確保するメモリ量を調べてみる

最近straceとtcpdumpがお気に入り。

# strace -ff -tt -o strace -p `pidof mysqld`

-fでforkしたプロセスのシステムコールも拾う、とか書いてあるけれど、
派生したスレッドの情報も拾える(forkとpthreadの違い、メモリコピーするかどうかだけらしいし)

そのまま別のターミナルからmysqlクライアントを立ち上げると、
`Process 1883 attached' みたいなメッセージが上がる。
(スレッドキャッシュ利いてないときだけ。スレッドキャッシュがあればスレッド作らないから、これ出ない)

で、strace止めて、strace.1883ファイルを覗くと色々見られる。
23:55:49.196003 mmap2(NULL, 2097152, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x5cd00000

システムコールはmanpageキーワードと一緒に(mmap manpage、みたいに)
ググれば大体出てくるので、出てきた順に調べていけばなんとなく読める。

取り敢えず、このスレッドは2Mくらい初期状態で確保するのねメモリ。

あと、プロンプトが上がってread()で待ちになるまでは0.5秒くらいだった。
アタッチしてたから体感でもちょっと遅い感じがしたけど。
家の仮想マシン貧弱だしね。。

2012/06/25

スロウログのCSVファイルを--log-output=FILE形式に直す

誰得で書いてみました。

csv2slowlog.pl△スロウログのCSVファイル名 でCSVファイルをパースして標準出力に吐き出します。
リダイレクトすれば--log-output=FILE形式のやつっぽいファイルの出来上がり。

https://gist.github.com/3910570

・USEステートメントはパースしません。無視してます。
・TIMESTAMPステートメントもパースしません。無視です。

手元にCSVしかないけどmysqldumpslowに食わせたいって用途しか考えていないので。。


GPLv2でどうぞ。
逆変換バージョンこそ誰得で作ろう。



【2012/06/26】
逆パターンのスロウログファイルをCSVに直すとか俺得で書いてみました。
mysqldumpslowのSQL集約部分を使っているので、ストリング値が'S'とかに置換されたりします。

https://docs.google.com/open?id=0Bw-FD85aK8GcT2xmUDU0c0VUZjA

これ使ってmysql_slowテーブルに上書いて

SELECT
 DATE_FORMAT(start_time,'%m/%d %H:xx') AS sTime,
 COUNT(start_time) AS c
FROM slow_log
GROUP BY sTime;
とかやるのが夢です。

2012/06/22

mysqladmin pingと/etc/init.d/mysql statusの違い

mysqladminはソケットなりTCP/IPなりを使ってログインした後、
`Command Ping'ってパケットを投げてOKが返ってくればOKと判断する。
なので、Too many connectionsに巻き込まれたりソケットファイルが壊れたりすると転ける。

/etc/init.d/mysql status(MySQLのRPM版)は、pidファイルを探した後に
そのPIDに向かってkill -0を叩く。
なのでプロセスが浮いていれば、たとえクラッシュリカバリ中で実際には接続できなくてもOKが返る。

kill -0なんてあったんだね。
straceで追いかけたけど、実際には何のシグナルも受け取らずにkill側だけで処理が完結してるっぽい。

ゾンビプロセスだとどうなるんだろ。mysqldじゃなくても構わないから、ゾンビプロセスって手軽に再現できないかな。。

killのソースコード読みたくなってきた。。


【2012/09/07 12:32追記】
mysqldではないけど、<defunct>になってるゾンビプロセスを見つけたのでkill -0を叩いてみたら、
終了コード0で返ってきたよ!

あと、gdbでアタッチしてTステートにしたmysqldも普通に終了コード0を返した。

INDEXの功罪(デメリットの方)

よく`INDEXは検索に利くけど更新性能を落とす'のは言われるけれど、
実際どれくらいなのか自分で試してみた。

投げ遣りなテーブルを作る。
 CREATE TABLE t1 ( num bigint unsigned auto_increment primary key,val char(32) );

0,''と100万回かかれたファイルを読み込ませる。
 LOAD DATA INFILE '/tmp/zero' INTO TABLE t1;

100万行更新する。
 UPDATE t1 SET val = MD5(num);

100万行消す。
 DELETE FROM t1;

各3回ずつ測定したら、INDEXを増やす。
 ALTER TABLE t1 ADD INDEX val1(val);

で、これを同じカラムに3本まで増やしながら延々測定。


INDEX LOAD[sec] UPDATE[sec] DELETE[sec]
PKだけ 4.2 17.0 3.3
PK+1つ 5.7 31.3 9.9
PK+2つ 7.7 46.4 18.5
PK+3つ 8.8 61.6 27.0


重複キーだから一概に言い切れないけど、綺麗に線形(ax+bの形で)出てるなぁ。。
かといってUPDATE,DELETEに使うカラムにはINDEX作っておきたいしなぁ。。
INDEXのないカラムでUPDATE,DELETEのWHERE条件を指定すると、InnoDBは全部の行をロックする

功罪あるよね。テーブル設計ムズカシイ。


ところで、Bloggerってファイル名はタイトルから自動生成してるみたいなんだけど、
このタイトルから自動的に生成されたファイル名は`index.html'だった。。

gzip -1オススメ

圧縮によく使うgzip、実は圧縮率が指定できる。
100MBくらいならそこまで気にならないけど、結構違うものです。

[root@cent01 mysql]# ll -h
..
-rw-rw---- 1 mysql mysql 170M  6月 22 12:07 2012 ibdata1
..

これがターゲット。

[root@cent01 ~]# for n in `seq 1 9` ; do
> cp -ip /var/lib/mysql/ibdata1 ./ibdata.$n
> date ; gzip -$n ibdata.$n ; gzip -l ibdata.$n ; date
> echo ""
> done
とやって測定。結果はこんな。


level time[sec] ratio
1 5 57.9%
2 6 56.9%
3 6 56.9%
4 7 58.3%
5 7 58.7%
6 9 58.8%
7 12 58.8%
8 26 58.8%
9 51 59.0%



圧縮率指定せずにやったら10秒間で58.8%の圧縮率だったから、多分デフォルトはレベル6。
レベル1と比べると、1%余計に圧縮率が稼げる(1GBだったら10MB余計に圧縮)けど、
時間が倍近くかかる算段になる(1GBを45秒で圧縮してるんだったら、レベル1なら30秒くらいで済むかも)
時間が短く済むってことはCPU時間もメモリを占有する時間も減るってことで、システムにかける負荷は下がる。

でっかいバックアップを取らないといけない場合に検討すると少し幸せになるかも知れないネタ。



追伸。
このケースだと、どのレベルでも解凍にかかる時間に差はなし。
全部2~3秒のレンジに収まってた。

更に追伸。
gzip -c1 /var/lib/mysql/ibdata1 > ./ibdata1.gz でやると、
cpの分の時間が発生しないので更に速く済んでI/Oも節約できます。
リダイレクトで作るのでパーミッションだけ注意。

再追伸。
レベル2,3の方がレベル1より圧縮率が悪いのは何だ…?;

2012/06/21

Keyのないカラムで迂闊なUPDATE,DELETE

Keyのないカラムを使ってUPDATE,DELETEすると、
当然フルスキャンが発生するので処理にかかる時間は当然延びる。

UPDATE,DELETEの処理が長引くってことは、ロックがかかりっぱなしになる時間が延びる。

さてところで、MyISAMはテーブルロック、InnoDBは行ロックってことになっているので、
`InnoDBならちょっとくらいUPDATEでロックかかってても他のレコードは読み書きできるじゃん'と思うがさにあらず。

 全行いっぺんにロックするよ!
 更新系DML、全部待たされるよ!
 `='演算子でもダメだよ!


技術的な話は公式にお任せとして、`月に1度しかないバッチだから遅くても良いや'くらいのつもりでいると
オンライン系の処理が全滅するのでとても注意。

http://dev.mysql.com/doc/refman/5.5/en/innodb-record-level-locks.html


あ、あとこの現象、`全ての行をロック'なのであって`テーブルロック'ではないです。
一緒といえば一緒なんだけど、InnoDBはロックエスカレーションしませんので(←ここ試験で間違えた)

かといってINDEXをべたべた作ってもなぁ、というのも体感してみた。
 ⇒INDEX作ると更新がどれくらい遅くなるのかという
結構重くなるのね。

2012/06/20

--init-fileオプションを上手く使いたい

init-fileオプションを設定しておくと、mysqldが起動した時にそのファイルを読んでくれる。



制約としては、
・1行じゃなきゃダメ(改行入れちゃいけない。2行目以降無視)
・1ステートメントじゃなきゃダメ(改行入れずにつなげても最初の1つだけ実行して後は無視)
・SOURCEは使えない(SQLステートメントじゃないからか)
・SLEEP関数が一瞬で抜けて返ってくると思う(使うことないけど)
 ⇒SHOW PROCESSLISTで捕まらない。捕まらないだけか?
・SQLを実行し終わるまでconnectionが張れない?(同じ重いクエリをコマンドラインから流しても別termから接続は出来るのに、init-fileで指定すると接続すら出来ない)
最後のはちょっと追いかけてみようかな。


Memoryエンジンを使う時は、init-fileオプション使ってLOADするとかしてねって書いてあるけど、
1つしかSQLが書けない以上、2つ以上Memoryエンジンのテーブルを作るとお手上げ。
(そんなに作るなって話は棚に上げて)



/etc/init.d/mysqlのstart部分にmysql mysql < init.fileて感じでコードするのが良いのかな。。

【2012/06/21追記】
ストアドプロシージャなら利いた。
好きなデータベースにsp_initって作っておいて、--init-fileで指定したSQLにCALL xx.sp_init;
ただ、このプロシージャが流れ終わるまでの間接続できないのかどうかはまだ調べてない。

調べてみた。

120621 15:59:17 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
120621 15:59:17 [Note]   - '0.0.0.0' resolves to '0.0.0.0';
120621 15:59:17 [Note] Server socket created on IP: '0.0.0.0'.
120621 15:59:17 [Warning] Neither --relay-log nor --relay-log-index were used; so replication may break when this MySQL server acts as a slave and has his hostname changed!! Please use '--relay-log=cent01-relay-bin' to avoid this problem.
120621 15:59:17 [Note] Event Scheduler: Loaded 0 events
120621 15:59:22 [Note] /usr/sbin/mysqld: ready for connections.

仕込んだsp_initの中身は、
INSERT INTO t2 VALUES(NOW());
INSERT INTO t1 VALUES(SLEEP(30));
INSERT INTO t2 VALUES(NOW());
t2の中には、15:59:17と15:59:22が記録されてる。
SLEEPはどこかかっ飛ばされたみたいだけど、
--init-fileにSELECT SLEEP(60)でもかっとばされてるっぽいからSLEEPがそもそも上手く利かないか。


sp_initの中身を10億行くらいJOINするSELECT文に変えてみる。


120621 16:11:15 InnoDB: 1.1.8 started; log sequence number 241958172
120621 16:11:15 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
120621 16:11:15 [Note]   - '0.0.0.0' resolves to '0.0.0.0';
120621 16:11:15 [Note] Server socket created on IP: '0.0.0.0'.
120621 16:11:15 [Warning] Neither --relay-log nor --relay-log-index were used; so replication may break when this MySQL server acts as a slave and has his hostname changed!! Please use '--relay-log=cent01-relay-bin' to avoid this problem.
120621 16:11:15 [Note] Event Scheduler: Loaded 0 events
120621 16:40:13 [Note] /usr/sbin/mysqld: ready for connections.

あー、やっぱり--init-fileが流れ終わるまで接続できないんだね。。
/etc/init.d/mysqlの中に、mysql < init.sqlでコーディングするか。。


日付が変わってから、ストアドプロシージャにはLOAD DATAがコーディングできないことに気が付く。
バッファプールあっためる目的だともうスクリプト一択なのかね。。

2012/06/15

英語系用語の読み方って個人差がある

他の会社の人と話してると、`ああ、こう読むんだこの人'というのがよくある。


InnoDB .. `いんのでぃーびー'、周りに多いのは`いのでぃーびー'。

ALTER .. `あるたー'。英語発音だと`おるたー'だけど、`あるたー'もままいる。

halt .. 英語発音だと`ほると'。`はると'って読む人も。ただ、ドイツ語でもhaltenって単語があって命令形はhalt(こっちは`はると')

my.cnf .. `まい こんふ'(`.'の部分でちょっとためる)。`まいてんこんふ'って人がいた。感染りそうな予感。

mintty .. `みんてぃーてぃーわい'。`みんてぃてぃ'って人がいた。その人にとってはPuTTYは`ぷってぃてぃー'になるんだろうか?

EVA .. 読み方というか、`いーぶいえー'と言ったときと`えヴぁ'と言ったときで指す対象が違うよねきっと。

XP .. `ぺけぴー'。世間的には`えっくすぴー'。直す気はない。。

mv .. `むーぶ'が多い気が。cp `しーぴー'やrm `あーるえむ'に比べて、これだけ元の英単語読みするのね。

gif .. `じふ'。`ぎふ'派と分かれるのはよくある話。

git .. `じっと'。正式には`ぎっと'。gifと同じノリで`じっと'と憶えてしまった。。_| ̄|○ 直らない

SQL .. `えすきゅーえる'。たまーに`しーくうぇる'って人がいたりするけれど、それはSEQUELの読み方なのでは。

comma .. `こんま'。`かんま'の方が多いかな? 発音記号的には`かーま'または`こーま'って感じっぽい。

CentOS .. `せんとおーえす'。`せんとす'って呼ぶ人も。



なんか面白いのないかなぁ。。

2012/06/13

Too many connectionsとレプリケーション

ここ数日、Too many connectionsに関してやたら書いているけど。

MySQLのレプリケーションも当然コネクションを使うので、下手をするとこれに引っかかる。
たまたま151本のコネクションが飽和した時にレプリケーションの接続がちょっと切れて…なんてことがあると…((((;゚д゚))))

基本的にmax_connectionsはそんなに増やさないで、アプリケーション側でERR: 1040をハンドルしてリトライしてよって思ってたけど、
こう考えると、たとえレスポンスの低下を招くとしてもある程度max_connectionsに余裕を持たせた方が良いのかなぁ。。

Too many connectionsのエラーが出たからmax_connectionを増やす

アプリケーションのトラフィックが多くなってきたから、という。
よく聞く話ですが、多分あんまり効果ないです。

テストテーブルはこんな。

CREATE TABLE t1 (num serial,val char(32) not null);
numには1~1,000,000の整数値が、valにはMD5(num)の値が入ってます。

投げるクエリはこんな。
SELECT sql_no_cache * FROM t1 ORDER BY val LIMIT 1;
INDEXを全然使わない`重い'クエリ。転送量がネックになってほしくないのでLIMIT 1。
mysqlクライアントから直接叩いても2秒ちょいかかる。

これをPerlにしてapache越しに呼ぶ様にする。
MySQLのmax_connectionsを10に設定して、いざ測定。



ab -n 20 -c 10 http://localhost/cgi-bin/test.cgi &
ab -n 20 -c 10 http://localhost/cgi-bin/test.cgi &
abをバックグラウンドで2つ動かしてやって、10コネクション * 2回繰り返し * 2クライアントから、とする。

...

Time taken for tests:   33.176 seconds

Complete requests:      20
Failed requests:        1
...
Time taken for tests:   38.575 seconds
Complete requests:      20
Failed requests:        11



$ tail -f /var/log/httpd/error_log
...

[Tue Jun 12 23:15:38 2012] [error] [client ::1] DBI connect('d1','root',...) failed: Too many connections at /var/www/cgi-bin/test.cgi line 12
[Tue Jun 12 23:15:38 2012] [error] [client ::1] Can't call method "prepare" on an undefined value at /var/www/cgi-bin/test.cgi line 13.
...


都合12回Too many connectionsで失敗したのかな。
合計40のリクエストなんで、30%の失敗。



対比としてテーブルにINDEXをつけて`軽い'クエリに仕立て上げる。
ALTER TABLE t1 ADD INDEX (val);
mysqlクライアントから直接叩くと0.00秒で結果が返ってくる様になった。
これ以外は何も変えない。
apacheを再起動してから同じabを試す。

ab -n 20 -c 10 http://localhost/cgi-bin/test.cgi &
ab -n 20 -c 10 http://localhost/cgi-bin/test.cgi &
...
Time taken for tests:   8.606 seconds
Complete requests:      20
Failed requests:        0
...
Time taken for tests:   8.765 seconds
Complete requests:      20
Failed requests:        0
...

error_logにも何も出ない。
スクリプトもデータもパラメータもいじらず、ALTER TABLEだけで事情が解決することもあるってことで。


ちなみに、INDEX作る前の状態で、max_connections = 100にして測定しようとしたら、


ab -n 20 -c 10 http://localhost/cgi-bin/test.cgi &
ab -n 20 -c 10 http://localhost/cgi-bin/test.cgi &
...
Benchmarking localhost (be patient)...apr_poll: The timeout specified has expired (70007)
Benchmarking localhost (be patient)...apr_poll: The timeout specified has expired (70007)

abがタイムアウトして結果すら出なくなった。
タイムアウト値いくつか知らないけど、予想通り性能は劣化するよね。。

2012/06/08

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

5/28にPrimary KeyがなくてもINSERTの速度はそこまで落ちなかったし、
普通のKeyがあればUPDATEもDELETEもそこまで問題なかった話を書いたけれど。

Primary Keyがないテーブルで複数行のUPDATEやDELETEをして、
それをレプリケーションしていたりすると大問題になるケースがあったりする。

http://lists.mysql.com/mysql/227217

…もともとこの話書きたかった気がするんだけどなぁ。。


ざっくり要約すると、binlog_formatがROWまたはMIXEDの場合、
Primary Keyが設定されていないとテーブルを全スキャンする必要があるので
とんでもなくレプリケーションが遅れる、という感じ。

Primary Key設定漏れがないかどうか確認するのはこんな感じ。



SELECT
 db,
 name
FROM (
 SELECT
  t.table_schema AS db,
  t.table_name AS name,
  constraint_name,
  table_type
 FROM information_schema.tables AS t
 LEFT JOIN information_schema.table_constraints AS tc ON
  t.table_name = tc.table_name AND
  constraint_name = 'PRIMARY'
) AS tmp
WHERE
 constraint_name IS NULL AND
 table_type = 'BASE TABLE' AND
 db NOT IN ('mysql','information_schema','performance_schema');

気を付けよう。


【2013/02/14 16:46】
こんなことを言いながら綺麗に自分でハマった!

ちゃんとエラーログに吐いてくれるんですね。すてき。

MySQLのSUPERユーザーはmax_connectionsでも1コネクションだけセッションを張れる

タイトルのこと自体はMySQLのリファレンスにも載ってることなんですが。
http://dev.mysql.com/doc/refman/5.1-olh/ja/grant.html

ここでいう余分な1コネクションは、本当に1コネクションしかないです。
rootとadminというユーザーがそれぞれSUPER権限を持っていたとして、
`too many connections'状態でrootユーザーがログインすると、adminユーザーはログインできません。

普段バッチでステータス監視をしてて、そのバッチの中でログインするユーザーがSUPER権限だったりすると、
`too many connections'で巻き込まれて動きが遅くなった時、手でログインしようにも既にSUPER権限ユーザーがログインしてるから
肝心のDBAがログインできないとか(mysqladminも使えない)


ふと思ったので。

2012/06/04

tpcc-mysqlとtpcemysqlのデータ量メモ

tpcc-mysqlの場合、可変パラメータは-wのみ。
 - 500,000 * w rows
 - 80 * w Mbytes

tpcemysqlの場合、可変パラメータが結構あって相関するので合ってるかどうか判らない。
以下、c/t <= 1のときk=1、c/t > 1のときk=c/tとおく。
 - 400,000 * w * k * 500/f rows
 - 15 * w * k * 500/f Mbytes

tpcemysqlを最小データのつもりで-w 1 -t 1000 -c 1000 -f 1とかやると、
fの値に反比例するからひどい目に遭うんだZE。