再現させる

bulkneetsツールを使ったが、Ubuntu Intrepid (2.6.27-11-server)では再現せず。RHEL5(2.6.18-128.el5)では再現した。もうちょい色々な環境で試してみる必要が有りそう。

エラーメッセージからの追跡

stanakaさんの以下の発言より。

* http://twitter.com/stanaka/status/21037070317

以下のメッセージが出るらしい。

[err] event_queue_remove: 0x15ea9d88(fd 30) not on queue 8

event.c event_queue_remove()の先頭部分でのメッセージ。

void
event_queue_remove(struct event_base *base, struct event *ev, int queue)
{
        if (!(ev->ev_flags & queue))
                event_errx(1, "%s: %p(fd %d) not on queue %x", __func__,
                           ev, ev->ev_fd, queue);

queue “8″ は、event.hによるとEVLIST_ACTIVE.

#define EVLIST_ACTIVE   0x08

event_queue_removeをEVLIST_ACTIVEで呼び出している箇所は複数有る。が、ev_flags & EVLIST_ACTIVE をチェックせずに呼び出しているのは2箇所、event_reinit()とevent_process_active()になる。

event_reinit()はmemcachedからは呼び出されている所が無いので、自ずとevent_process_activeの以下の箇所になる。

        for (ev = TAILQ_FIRST(activeq); ev; ev = TAILQ_FIRST(activeq)) {
                if (ev->ev_events & EV_PERSIST)
                        event_queue_remove(base, ev, EVLIST_ACTIVE);
                else
                        event_del(ev);

activeqには入っているが、ev_flagsにEVLIST_ACTIVEが立っていない条件が成立しうるらしい。

activeqにいれているのは、一箇所、event_queue_insert()になる。ただし、入れる前にかならずev_flagsにEVLIST_ACTIVEは立てている。

ということで、他の場所でev_flagsを弄ってしまっているかメモリ破壊を疑いたい。

ひとまず前者を疑うと、ev_flagsを変更しているのは event_queue_insert(), event_queue_remove(), event_queue_set() になる。insert, removeに関しては問題ないので、疑うとすればset()。この関数が既存eventに対してevent_del()せずにいきなり呼ばれたりするのが怪しそう。

が、memcachedにはそんな箇所は無いので有った。メッセージが出る時の、ev->ev_flagsの値が欲しい…座礁ed.

現象からの追跡

event_base_loop()中のevent_haveevents(base)がfalse、つまりbase->event_countが0になっているらしい。

これは通常は有り得ない、というのもlisten用(新規コネクション受付用)のeventが常に有るはずなので。event_countが減算されるのは、event_queue_remove()。通常は、event_del()から呼ばれる。

となるとlisten用のeventまで消えてしまうのは、event_del()するかメモリ破壊ぐらいしか無い。listen用のeventをevent_del()しているのは、コネクションが溢れたときに呼ばれる以下の関数。

void do_accept_new_conns(const bool do_accept) {
    conn *next;

    for (next = listen_conn; next; next = next->next) {
        if (do_accept) {
            update_event(next, EV_READ | EV_PERSIST);
            if (listen(next->sfd, settings.backlog) != 0) {
                perror("listen");
            }
        }
        else {
            update_event(next, 0);
            if (listen(next->sfd, 0) != 0) {
                perror("listen");
            }
        }
    }
    ... snip ...
}

コネクションが溢れたときには、do_acceptがfalseになっている。update_event()では、event_del() => event_add()しているが、このevent_add() が失敗しているんじゃないかと予想(メモリ破壊じゃなければ)。そうすると、event_countが0になるシナリオは作れる。

このupdate_event()の失敗を捕まえられればなあ…やっぱ次はなんとか手元で再現させる事を考えよう。

mixiの件について、nealさんから情報を貰ったので数時間調査してみた。というのも、うちの製品でもlibevent(evhttp)をリクエスト処理に使っているので、これにバグが有ると非常に困る。

• Nealさんのつぶやき

ひとまず、libevent-1.3b, libmemcached-1.4.4をビルドする。memcachedは、-cで同時接続数を制限できる。で、この同時接続数というのは、実はファイルディスクリプタの数を制限する事で達成されている。memcached.cの以下の部分。

    /*
     * If needed, increase rlimits to allow as many connections
     * as needed.
     */
    if (getrlimit(RLIMIT_NOFILE, &rlim) != 0) {
        fprintf(stderr, "failed to getrlimit number of files\n");
        exit(EX_OSERR);
    } else {
        int maxfiles = settings.maxconns;
        if (rlim.rlim_cur < maxfiles)
            rlim.rlim_cur = maxfiles;
        if (rlim.rlim_max < rlim.rlim_cur)
            rlim.rlim_max = rlim.rlim_cur;
        if (setrlimit(RLIMIT_NOFILE, &amp;rlim) != 0) {
            fprintf(stderr, "failed to set rlimit for open files. Try running as root or requesting smaller maxconns value.\n");
            exit(EX_OSERR);
        }
    }

mixiでは30kコネクションだが、それをエミュレーションするのは辛い。ということで環境を擬似的に再現するために、以下のように変更してディスクリプタ数を非常に小さい値に設定して、クライアント側でそれ以上の並列数を指定してみる事にした。

        int maxfiles = settings.maxconns;
        rlim.rlim_cur = maxfiles;
        rlim.rlim_max = maxfiles;
        if (setrlimit(RLIMIT_NOFILE, &rlim) != 0) {
            fprintf(stderr, "failed to set rlimit for open files. Try running as root or requesting smaller maxconns value.\n");
            exit(EX_OSERR);
        }

これで、並列数を32などに制限できる。

$ ./memcached -c 32 -t 4 -v -v -v

次に、libmemcached付属のツールmemslapで負荷をかける

$ memslap -s localhost:11211 --threads=1 --concurrency=32 -S 1s

サーバーが固まります。以下のようなメッセージと共に。

event_add: No such file or directory
event_add: No such file or directory
event_add: No such file or directory
event_add: No such file or directory
event_add: No such file or directory
event_add: No such file or directory
event_add: No such file or directory
event_add: No such file or directory
event_add: No such file or directory

conn_new()のここ。

    if (event_add(&c->event, 0) == -1) {
        if (conn_add_to_freelist(c)) {
            conn_free(c);
        }
        perror("event_add");
        return NULL;
    }

まずはボトムアップだ！という事でstrace -f で調査してみた所、以下のような結果。

[pid 10655] write(2, "<31 new auto-negotiating client "..., 43<31 new auto-negotiating client connection
) = 43
[pid 10655] epoll_ctl(13, EPOLL_CTL_MOD, 31, {EPOLLIN|EPOLLOUT, {u32=31608592, u64=31608592}}) = -1 ENOENT (No such file or directory)
[pid 10655] write(2, "event_add: No such file or direc"..., 37event_add: No such file or directory
) = 37
[pid 10655] write(2, "Can\'t listen for events on fd 31"..., 33Can't listen for events on fd 31
) = 33   

EPOLL_CTL_ADDされていないディスクリプタにEPOLL_CTL_MODしようとしているらしい。これはmemcachedか、libeventが不正な状態を持っちゃってこうなってるんだろう。

memcachedはlibeventと変な形で密結合していて、上に登っていくのが厳しい。イベントベースなのも有るし。

という事で今度はトップダウンでソースから。サーバーでディスクリプタが足りなくなるのは、一箇所、accept(2)の所。

            if ((sfd = accept(c->sfd, (struct sockaddr *)&addr, &addrlen)) == -1) {
                if (errno == EAGAIN || errno == EWOULDBLOCK) {
                    /* these are transient, so don't log anything */
                    stop = true;
                } else if (errno == EMFILE) {
                    if (settings.verbose > 0)
                        fprintf(stderr, "Too many open connections\n");
                    accept_new_conns(false);
                    stop = true;
                } else {
                    perror("accept()");
                    stop = true;
                }
                break;
            }

この、accept_new_conns(false)が怪しい。ひとまずこれをコメントアウトした所、クライアント側は固まらなくなった。この先は、listen用のコネクションをepoll contextから外して新しいコネクションを受け付けないようにしている。

この辺りのクリーンアップ処理がおかしいのかも？と調査中….

    conn *next;
    for (next = listen_conn; next; next = next->next) {
        if (do_accept) {
            update_event(next, EV_READ | EV_PERSIST);
            if (listen(next->sfd, settings.backlog) != 0) {
                perror("listen");
            }
        }
        else {
            update_event(next, 0);
            if (listen(next->sfd, 0) != 0) {
                perror("listen");
            }
        }
    }

あとは、ニールさんが”base_event_loopからなぜか抜けてしまいます”とおっしゃっているのだが、これが再現出来ていない。ループを抜けるとサーバーが終了してしまうはずなのだが、手元ではサーバーが固まるのみ。

ふーむー。

木曜日ぐらいから発熱・悪寒がすごくて、病院に行ってきたら新型インフルエンザと診察されました。来週1週間は出禁とのことです。今はタミフルを飲んで少し熱が下がってきた感じです。

検査などは特にされなかったのですが、症状的に見て、ほとんど間違いないとのことです。検査の精度が約６０％程度であることと、あと同じような症状の人が前に並んでいたので、安全側に倒す＋手間を省いてるのだと思います。

病院に行ってみて分かったのですが、予想以上に流行ってるという印象です・・・。皆様もお気をつけてくださいませ・・・。

# 各方面の方々には、色々迷惑をかけてまして、本当にすいません。。。

十年ぶりぐらいに父親の実家(奈良県宇陀郡曽爾村)に帰省しました。自然しかない！サマーウォーズみた直後だったので、ちょっとテンションあがりました。草刈りのお手伝いとかしてきました。

太田家

縁側

彼岸花

とんぼ

牛

すすき(曽爾高原)

全写真リスト

Twinadoという携帯向けのTwitterクライアントを書いてみました。日常的に使えるレベルにはなっていると思います。

• Twinado: 携帯端末向けTwitterクライアント

特徴としては最近Facebookが公開したTornadoというフレームワークを使って、Twitter API呼び出しが全て非同期に行われている点です。なので、コネクション数が増えても高速に動くはずです。現状DoCoMo P905iでしか動作確認していません。

きっかけとしては、最近Perl界隈で非同期処理が流行っているのを見て、楽しそうだと思っていたところに、Tornadoが公開されたので、少し使ってみるかと思い立った事です。Tornadoについては以下を参考にして下さい(日本語訳、お疲れ様です！)。

• Tornado
• Tornado Document 日本語訳

Tornadoの特徴は、リクエストハンドラ内でHTTPリクエストを非同期に発行出来る事です。これによって、サーバー側でのネットワークの待ち時間を減らし、その間に別のリクエストを処理する事が出来ます。以下のサンプルコードは、FriendFeedのAPIを非同期で取得している例になります。取得終了時にon_response関数が呼ばれます。

class MainHandler(tornado.web.RequestHandler):
    @tornado.web.asynchronous
    def get(self):
        http = tornado.httpclient.AsyncHTTPClient()
        http.fetch("http://friendfeed-api.com/v2/feed/bret",
                   callback=self.async_callback(self.on_response))

    def on_response(self, response):
        if response.error: raise tornado.web.HTTPError(500)
        json = tornado.escape.json_decode(response.body)
        self.write("Fetched " + str(len(json["entries"])) + " entries "
                   "from the FriendFeed API")
        self.finish()

で、何か作ろうと思って、激しく外部APIアクセスするものって何かなと思ったところ、Twitterクライアントしか思いつかなかったので、作る事にしました。PythonのTwitterクライアントライブラリ「python-twitter」とTornadoに付属しているAsyncHTTPClientを密結合させました。

• python-twitter

変更後のソースはgithubにおいてあります。今のところ、一部の関数のみ非同期呼び出しに対応しています。差分を見て頂くと分かりますが、_FetchUrlAsync関数が肝です。

• python-async-twitter
• python-twitterとの差分

APIの非同期呼び出しは以下のように書けます。GetUserコマンドに渡しているasync_callbackというのがポイントです。読み込みが終わった瞬間に引数で渡した関数を呼び出してくれます。on_response関数ではAPIで取得したUserクラスのインスタンスが渡って来ます。

class UserMainHandler(tornado.web.RequestHandler):
    @tornado.web.asynchronous
    def get(self, username, password):
        try:
            api = async_twitter.Api(username, password)
            api.GetUser(user = username,
                        async_callback = self.async_callback(self.on_response))
        except:
            self.write("twitter api failed")
            print sys.exc_info()
            self.finish()

    def on_response(self, user):
        if user == None:
            self.write("twitter api failed")
            self.finish()
            return
        self.do_render(user)

    def do_render(self, user):
        self.render("tpl/user_main.html",
                    user = user)

この辺でかなり満足し切ったのですが、適当に機能を足して、冒頭で紹介したTwinadoという携帯向けのTwitterクライアントを書いてみました。

• Twinado

Tornadoで書いてみた雑感ですが、コールバックベースの非同期処理は記述が面倒臭すぎます。特にAPIを複数回呼びだしたりする必要の有る処理なんかは、コールバック関数をその都度作らないといけない。

また結果を引き回すために関数のcurry化をしたいのだけど、pythonだとfunctoolsというモジュールで明示的に関数を作ってやる必要が有ったり、楽とは言えない感じです。関数型言語だと大分マシにはなるけど、根本的解決じゃ無い気がします。

エラー処理も、結構問題です。メソッド内で起こったエラーをコールバック内に伝える必要があるため、必然的にオブジェクトを引き回す必要が有ります。

かと言って条件引数引き回すのもなんだかなぁ…。