Redisにマルチプロセスで接続する時に気をつけたい事
Redis
広告配信やっています@yutakikuchi_です。
Redisの内部処理が1スレッドで受けているようなので、マルチプロセスからRedisに書き込み処理を大量に流した時にどうなるのかを検証してみました。言語はCを、Libraryはhiredisを使います。redis/hiredis
hiredisを使って単一プロセスで実行した場合と、Apache Moduleにhiredisを組み込んでマルチプロセスの実行状態で検証します。検証機はCentOS6.4です。
hiredis
Redisのinstall、version確認、起動
RedisのVersionは2.4.10です。
$ sudo yum install redis -y $ redis-server -v Redis server version 2.4.10 (00000000:0) $ sudo chkconfig --add redis $ sudo /etc/init.d/redis starthiredisのinstallとテストプログラム
hiredisのinstall後に単純にHashをincrbyするプログラムを実行してみます。まずはプロセス内で単純に指定回数incrbyを繰り返します。今回は指定回数を1万としたので、かなり高速に書き込みが完了している事が分かると思います。実行後にはredis-cliで書き込みが出来ているかを確認します。
$ sudo yum install hiredis hiredis-devel -y $ gcc -I/usr/include/hiredis -L/usr/lib64 -lhiredis redis-test.c -o redis-test $ time ./redis-test ./redis-test 0.04s user 0.25s system 48% cpu 0.592 total $ redis-cli HGET foo bar "10000"#include <stdio.h> #include <hiredis.h> #include <assert.h> #define IP "127.0.0.1" #define PORT 6379 #define COUNT 10000 int main(){ redisContext *c = redisConnect(IP, PORT); if (c != NULL && c->err) { printf("Error: %s\n", c->errstr); return 1; } unsigned int i=0; for(; i<COUNT; i++) { redisReply *reply; reply = redisCommand(c,"HINCRBY foo bar 1"); if(reply){ freeReplyObject(reply); } } redisFree(c); return 0; }
Apache Moduleへの組み込み
Moduleを入れる前のPerformance
Redisに接続するApache Moduleを入れる前のPerformanceを見てみます。4,5年前に購入したPCで試しているのでさほどSpeedが出ていませんが、ApacheのSampleページ表示で並列10/合計1万のabベンチマークの場合、2065.80rpsとなりました。
$ cat /proc/meminfo MemTotal: 2327156 kB MemFree: 2058828 kB Buffers: 21396 kB Cached: 94164 kB SwapCached: 0 kB $ ab -n 10000 -c 10 "http://localhost/" Concurrency Level: 10 Time taken for tests: 4.841 seconds Complete requests: 10000 Failed requests: 0 Write errors: 0 Non-2xx responses: 10006 Total transferred: 52401422 bytes HTML transferred: 50420234 bytes Requests per second: 2065.80 [#/sec] (mean) Time per request: 4.841 [ms] (mean) Time per request: 0.484 [ms] (mean, across all concurrent requests) Transfer rate: 10571.35 [Kbytes/sec] received Connection Times (ms) min mean[+/-sd] median max Connect: 0 2 1.4 2 32 Processing: 1 3 1.9 2 64 Waiting: 0 2 1.5 2 36 Total: 2 5 2.4 4 67Apache ModuleからRedisへの書き込み
次にRedisに接続する為のApache Moduleを入れて行きます。まずは接続設定をapacheの設定ファイルに記述します。ここでは新たにredis.confを用意しました。
次にRedisに接続する為のmod_redisという自作Moduleを入れて行きます。apxsコマンドで入れて、apacheをrestartします。
一回curlで接続してみてRedisのPermission deniedで怒られたらhttpd_can_network_connect=1設定して上げましょう。$ sudo vim /etc/httpd/conf.d/redis.conf RedisHost 127.0.0.1 RedisPort 6379 $ sudo apxs -i -a -c -I/usr/include/hiredis -L/usr/lib64 -lhiredis mod_redis.c $ sudo /etc/init.d/httpd restart $ curl "http://localhost/redis" [Fri Dec 06 01:15:43 2013] [error] [client ::1] Redis Connection Error : Permission denied $ sudo /usr/sbin/setsebool httpd_can_network_connect=1#include "httpd.h" #include "http_config.h" #include "http_protocol.h" #include "apr_hash.h" #include "apr_tables.h" #include "apr_strings.h" #include "ap_config.h" #include "util_script.h" #include "http_log.h" #include "hiredis.h" typedef struct { int port; char *host; } redis_env; module AP_MODULE_DECLARE_DATA redis_module; static int redis_handler(request_rec *r) { redis_env *db = ap_get_module_config(r->per_dir_config, &redis_module); redisContext *c = redisConnect(db->host, db->port); if (c != NULL && c->err) { ap_log_rerror(APLOG_MARK, APLOG_ERR, 0, r, "Redis Connection Error : %s", c->errstr); return DECLINED; } redisReply *reply; reply = redisCommand(c,"HINCRBY foo bar 1"); if(reply){ freeReplyObject(reply); } reply = redisCommand(c,"QUIT"); if(reply){ freeReplyObject(reply); } redisFree(c); return OK; } static void *make_redis_dir(apr_pool_t *p, char *d) { redis_env *db; db = (redis_env *) apr_pcalloc(p, sizeof(redis_env)); return db; } static const char *set_redis_host(cmd_parms *cmd, void *mconfig, const char *name) { redis_env *db; db = (redis_env *) mconfig; db->host = ap_getword_conf(cmd->pool, &name); return NULL; } static const char *set_redis_port(cmd_parms *cmd, void *mconfig, const char *port) { redis_env *db; db = (redis_env *) mconfig; char *p; p = ap_getword_conf(cmd->pool, &port); db->port = atoi(p); return NULL; } static const command_rec redis_conf_cmds[] = { AP_INIT_TAKE1("RedisHost", set_redis_host, NULL, OR_FILEINFO, "redis hostname"), AP_INIT_TAKE1("RedisPort", set_redis_port, NULL, OR_FILEINFO, "redis port"), {NULL} }; static void redis_register_hooks(apr_pool_t *p) { ap_hook_handler(redis_handler, NULL, NULL, APR_HOOK_MIDDLE); } module AP_MODULE_DECLARE_DATA redis_module = { STANDARD20_MODULE_STUFF, make_redis_dir, /* create per-dir config structures */ NULL, /* merge per-dir config structures */ NULL, /* create per-server config structures */ NULL, /* merge per-server config structures */ redis_conf_cmds, /* table of config file commands */ redis_register_hooks /* register hooks */ };Moduleを入れた後のPerfomanceテスト
RedisModuleを入れた後のPerformanceテストをしてみます。上と同様に並列10/合計1万のabベンチマークで実行した場合、726.98rpsとなりました。実行後にRedisのHashの値も10000に更新されています。
$ ab -n 10000 -c 10 "http://localhost/redis" Concurrency Level: 10 Time taken for tests: 13.756 seconds Complete requests: 10000 Failed requests: 0 Write errors: 0 Total transferred: 1670000 bytes HTML transferred: 0 bytes Requests per second: 726.98 [#/sec] (mean) Time per request: 13.756 [ms] (mean) Time per request: 1.376 [ms] (mean, across all concurrent requests) Transfer rate: 118.56 [Kbytes/sec] received Connection Times (ms) min mean[+/-sd] median max Connect: 0 3 4.7 2 76 Processing: 1 11 10.3 8 228 Waiting: 0 9 9.2 7 211 Total: 1 14 11.0 11 228 $ redis-cli HGET foo bar "10000"もう少しRedisをいじめてみます。上のabスクリプトを更に繰り返し10回実行してみます。そうするとFailed Requestが多発し226.90rpsまでパフォーマンスが落ちています。この原因はRedisへの接続でTIME_WAITが大量に発生しているので、ApacheがRedisとの接続エラーを返しているためと思われます。Apacheのerror_logを見てもRedis Connection Error : Cannot assign requested addressのように記載されているのでConnectionErrorである事は間違いないと思います。
$ for i in {1..10} do ab -n 10000 -c 10 "http://localhost/redis" done Concurrency Level: 10 Time taken for tests: 44.073 seconds Complete requests: 10000 Failed requests: 2619 (Connect: 0, Receive: 0, Length: 2619, Exceptions: 0) Write errors: 0 Total transferred: 2015708 bytes HTML transferred: 81189 bytes Requests per second: 226.90 [#/sec] (mean) Time per request: 44.073 [ms] (mean) Time per request: 4.407 [ms] (mean, across all concurrent requests) Transfer rate: 44.66 [Kbytes/sec] received Connection Times (ms) min mean[+/-sd] median max Connect: 0 4 8.5 0 75 Processing: 1 40 49.0 18 1188 Waiting: 0 36 46.7 16 1096 Total: 2 44 51.1 21 1188 $ netstat | grep "localhost:6379" tcp 0 0 localhost:37067 localhost:6379 TIME_WAIT tcp 0 0 localhost:37730 localhost:6379 TIME_WAIT tcp 0 0 localhost:45624 localhost:6379 TIME_WAIT tcp 0 0 localhost:52429 localhost:6379 TIME_WAIT $ netstat | grep "localhost:6379" | grep TIME_WAIT | wc -l 19309 $ tail -f /var/log/httpd/error_log [Fri Dec 06 00:42:17 2013] [error] [client ::1] Redis Connection Error : Cannot assign requested address [Fri Dec 06 00:42:17 2013] [error] [client ::1] Redis Connection Error : Cannot assign requested address [Fri Dec 06 00:42:17 2013] [error] [client ::1] Redis Connection Error : Cannot assign requested address [Fri Dec 06 00:42:17 2013] [error] [client ::1] Redis Connection Error : Cannot assign requested address [Fri Dec 06 00:42:17 2013] [error] [client ::1] Redis Connection Error : Cannot assign requested addressCannot assign requested addressの原因を探る
straceを使ってredis-serverの内部処理とCannot assign requested addressが発生している時にどんな処理が行われているのかを見てみます。結論としては良く分からず...。Redisのメモリからbackground saveでdiskに移す時が怪しいと思っていたんですが、どうやらあまり関係無かったようです。同じようにredis-cli slowlog getでslow queryを取得してstraceのlogと照らし合わせてみましたが、これといって変な処理は入っていませんでした。単純にmemoryを大量に消費した時の問題か...この辺り詳しい方教えて頂けると助かります。
$ sudo strace -t -f -p `pgrep redis-server` > redis-log 2>&1 $ tail -f /var/log/httpd/error_log [Fri Dec 06 01:32:15 2013] [error] [client ::1] Redis Connection Error : Cannot assign requested address $ grep "01:32:15" redis-log | vim - [pid 1393] 01:32:15 read(9, "*1\r\n$4\r\nQUIT\r\n", 16384) = 14 [pid 1393] 01:32:15 epoll_ctl(3, EPOLL_CTL_MOD, 9, {EPOLLIN|EPOLLOUT, {u32=9, u64=9}}) = 0 [pid 1393] 01:32:15 write(6, ":932884\r\n", 9) = 9 [pid 1393] 01:32:15 epoll_ctl(3, EPOLL_CTL_MOD, 6, {EPOLLIN, {u32=6, u64=6}}) = 0 [pid 1393] 01:32:15 read(5, "*4\r\n$7\r\nHINCRBY\r\n$3\r\nfoo\r\n$3\r\nba"..., 16384) = 42 [pid 1393] 01:32:15 epoll_ctl(3, EPOLL_CTL_MOD, 5, {EPOLLIN|EPOLLOUT, {u32=5, u64=5}}) = 0 [pid 1393] 01:32:15 epoll_wait(3, {{EPOLLIN, {u32=4, u64=4}}, {EPOLLOUT, {u32=9, u64=9}}, {EPOLLIN, {u32=6, u64=6}}, {EPOLLOUT, {u32=5, u64=5}}, {EPOLLIN, {u32=7, u64=7}}}, 10240, 98) = 5 [pid 1393] 01:32:15 accept(4, {sa_family=AF_INET, sin_port=htons(35569), sin_addr=inet_addr("127.0.0.1")}, [16]) = 8 [pid 1393] 01:32:15 fcntl(8, F_GETFL) = 0x2 (flags O_RDWR) [pid 1393] 01:32:15 fcntl(8, F_SETFL, O_RDWR|O_NONBLOCK) = 0 [pid 1393] 01:32:15 setsockopt(8, SOL_TCP, TCP_NODELAY, [1], 4) = 0 [pid 1393] 01:32:15 epoll_ctl(3, EPOLL_CTL_ADD, 8, {EPOLLIN, {u32=8, u64=8}}) = 0 [pid 1393] 01:32:15 write(9, "+OK\r\n", 5) = 5 [pid 1393] 01:32:15 epoll_ctl(3, EPOLL_CTL_MOD, 9, {EPOLLIN, {u32=9, u64=9}}) = 0 [pid 1393] 01:32:15 epoll_ctl(3, EPOLL_CTL_DEL, 9, {0, {u32=9, u64=9}}) = 0 [pid 1393] 01:32:15 close(9) = 0 $ redis-cli slowlog get 1) 1) (integer) 69 2) (integer) 1386261178 3) (integer) 67530 4) 1) "HINCRBY" 2) "foo" 3) "bar" 4) "1" 2) 1) (integer) 68 2) (integer) 1386261168 3) (integer) 14837 4) 1) "HINCRBY" 2) "foo" 3) "bar" 4) "1"どうやって問題を解決するか？
僕が思いついたのは1.LinuxのKernel設定を修正する、2.Apache Module内でmutexによりConnectionを共有する、3.Redisの設定ファイルを修正してチューニングするの３つです。2.は既にmod_redisがやっています。sneakybeaky/mod_redis
3.はRedisの運用を細かくやってみないとできなそうな気がしたので、ここでは1の例を紹介します。
net.ipv4.tcp_tw_recycleというsysctlのパラメータを1に設定します。このパラメータは高速にSocketのRecycle処理をしてくれます。ただし導入する時は注意してください。同一IPからのアクセスは直ぐにSocketを解放してしまう可能性があるためです。十分なテストをしてから導入しましょう。
今回は導入した結果、Failed requestsが無くなり、Cannot assign requested addressがerror_logに表示されなくなり、更にrpsも1912.64まで上がるという非常に効果の良い設定となりました。実行結果もRequest数に従った登録結果になっています。
今回の件とはあまり関係ありませんが、その他kernel関係の設定でvm.overcommit_memory=1のように設定するとbackground save時にmemoryの問題が回避される等の事例があるので、時間がある時に検証してみたいと思います。Redisを使う時は見積の二倍の容量必要だよね、という話 - Qiita [キータ]
$ sudo vim /etc/sysctl.conf net.ipv4.tcp_tw_recycle = 1 $ sudo sysctl -p $ for i in {1..10} do ab -n 10000 -c 10 "http://localhost/redis" done Concurrency Level: 10 Time taken for tests: 5.228 seconds Complete requests: 10000 Failed requests: 0 Write errors: 0 Total transferred: 1670835 bytes HTML transferred: 0 bytes Requests per second: 1912.64 [#/sec] (mean) Time per request: 5.228 [ms] (mean) Time per request: 0.523 [ms] (mean, across all concurrent requests) Transfer rate: 312.08 [Kbytes/sec] received Connection Times (ms) min mean[+/-sd] median max Connect: 0 2 1.9 2 23 Processing: 1 5 3.6 4 131 Waiting: 0 4 3.3 3 105 Total: 1 7 3.5 7 134 $ redis-cli HGET foo bar "100039"
![はてなブックマーク - Redisを使う時は見積の二倍の容量必要だよね、という話 - Qiita [キータ]](http://b.hatena.ne.jp/entry/image/http://qiita.com/y_matsuwitter/items/4fc43a53d2ac24f7783e)
