Cache::Memcached 1.21が突如クラッシュした

お仕事で使っているサーバが突如落ちた。データセンターまで 30 分ほどかかるのでリモートハンドサービスってのでリブートして頂いてますが、それでも 20 分くらいかかります。正直不便。まぁその話はおいておいて、どうにも腑に落ちないのですがログを見る限りエラーを吐いているのは Cache::Memcached らしい。

ってか半年ほど前にこの業務アプリに Cache::Memcached を入れて実装した機能があるんですがその間安定して動いていた。

が、突如としてこんなエラーを吐きやがった。 

Use of uninitialized value in vec at /usr/local/lib/perl5/site_perl/5.8.6/Cache/Memcached.pm line 722.
Use of uninitialized value in vec at /usr/local/lib/perl5/site_perl/5.8.6/Cache/Memcached.pm line 737.
send() on closed socket $sock at /usr/local/lib/perl5/site_perl/5.8.6/Cache/Memcached.pm line 688.
Use of uninitialized value in numeric gt (>) at /usr/local/lib/perl5/site_perl/5.8.6/Cache/Memcached.pm line 692.
Use of uninitialized value in vec at /usr/local/lib/perl5/site_perl/5.8.6/Cache/Memcached.pm line 360.
Use of uninitialized value in vec at /usr/local/lib/perl5/site_perl/5.8.6/Cache/Memcached.pm line 367.
send() on closed socket $sock at /usr/local/lib/perl5/site_perl/5.8.6/Cache/Memcached.pm line 368.
Use of uninitialized value in numeric gt (>) at /usr/local/lib/perl5/site_perl/5.8.6/Cache/Memcached.pm line 371.
Use of uninitialized value in string eq at /usr/local/lib/perl5/site_perl/5.8.6/Cache/Memcached.pm line 492.
Use of uninitialized value in vec at /usr/local/lib/perl5/site_perl/5.8.6/Cache/Memcached.pm line 360.
Use of uninitialized value in vec at /usr/local/lib/perl5/site_perl/5.8.6/Cache/Memcached.pm line 367.
send() on closed socket $sock at /usr/local/lib/perl5/site_perl/5.8.6/Cache/Memcached.pm line 368.
Use of uninitialized value in numeric gt (>) at /usr/local/lib/perl5/site_perl/5.8.6/Cache/Memcached.pm line 371.
Use of uninitialized value in string eq at /usr/local/lib/perl5/site_perl/5.8.6/Cache/Memcached.pm line 492.

エラーを吐くタイミングで httpd プロセスが異常なほどメモリを食いまくる。メモリリークしたときの動きに似てる。で、肥大した httpd プロセスが数個立ち上がって swap して OS フリーズ。こんな症状でした。良く判らないけど mysql のプロセスまで肥大しやがった。全く意味不明。

- スポンサーリンク -

いろいろ切り分けして、mysql 止めてみたり memcached を再起動しても症状変わらずで何度もサーバが固まるので、取りあえず今までの経験則から Cache::Memcached を update してみると症状は治まった。

むむむぅぅぅ・・・謎だけど、使っていた Cache::Memcached は 1.21 で 1.24 に update された。ChangeLog みてみる。


2007-07-17: version 1.24

　* update the stats method, including tests for it
　　(Ronald J Kimball <[email protected]>)

　* arguments to 'new' constructor can be %hash or $hashref now
　　(previously was only $hashref)

　* work around a Perl segfault (Matthieu PATOU <[email protected]>)
　　see http://lists.danga.com/pipermail/memcached/2007-June/004511.html

2007-06-19: version 1.23

　* add 'remove' as an alias for 'delete' (Dave Cardwell <[email protected]>)

2007-06-18: version 1.22

　* lost connection handling broken due to wrong %sock_map indexing
　　http://rt.cpan.org/Public/Bug/Display.html?id=27181
　　fix from RHESA

　* let parser_class be configured as a constructor option,
　　defaulting to XS if available, else regular. (unless
　　$ENV{NO_XS} is set, in which case the default is regular)

うーん・・・1.22 になんかソレっぽい bug-fix がある。これ。

* lost connection handling broken due to wrong %sock_map indexing

ちょっと調べてみると、ここらへんが情報。

* Cache::Memcached fix for problems with sockets used as string
* Nabble - memcached - Some issues with how last Cache::Memcached version (1.21) handle closing sockets/disconnets

ページの情報が消えてしまうとアレなので備忘録として書き残しておきます。
sock_map って変数に socket のキャッシュが格納されるんですが、そのお掃除処理にバグありです。


And never attempt reconnect to memcached even if memcached full
available...


I looked into code and found some issues with how to %sock_map work:

First inside function sock_to_host element of %sock_map hash initialize
via:
$sock_map{$sock} = $host;

>From other hand we have 2 possible cleanup functions:

sub _dead_sock {
　　my ($sock, $ret, $dead_for) = @_;
　　if (my $ipport = $sock_map{\$sock}) {
　　　　my $now = time();
　　　　$host_dead{$ipport} = $now + $dead_for
　　　　　　if $dead_for;
　　　　delete $cache_sock{$ipport};
　　　　delete $sock_map{\$sock};
　　}
　　@buck2sock = ();
　　return $ret;　# 0 or undef, probably, depending on what caller wants
}

sub _close_sock {
　　my ($sock) = @_;
　　if (my $ipport = $sock_map{\$sock}) {
　　　　close $sock;
　　　　delete $cache_sock{$ipport};
　　　　delete $sock_map{\$sock};
　　}
　　@buck2sock = ();
}

Both of these function trying clean $sock_map{\$sock} !

So... Connect code set $sock_map{$sock} and cleanup code trying clean
$sock_map{\$sock}　 !?

And of course dead sock never cleaning at all and API try use dead sock
again and again.... (because bad socket permanently cached in %sock_map)

This is really painful issue leading instability of projects.

PS: Cache::Memcached installed from fresh FreeBSD ports (and i compared
with fresh cpan version... They are same)


本当に、これがサーバがフリーズした原因か？？と mysql の使用メモリの肥大化とか気になる点はいっぱいあるのですがひとまず解決？？

ってか、このマシン不具合多すぎ。ある日突然おかしくなる。同じ version でも何も変更していないのに動かなくなって再インストールすると動くようになるとか、意味不明。同じ構成の別のマシンは快調なのになぁ・・・

まぁいいや。もうすぐリース切れで更改だから。

- スポンサーリンク -

関連する記事＆スポンサーリンク