昨日からmasuidriveさんと調査してた eventmachineのバグ ですが、straceで追いかけてみた結果、 以下の部分が原因である事が分かりました。

em.cpp EventMachine_t::_RunEpollOnce() の最後付近

   1    timeval tv = {0,0};
   2    EmSelect (0, NULL, NULL, NULL, &tv); // <- これ
   3  
   4    return true;

見るからにWorkaroundっぽいですね。

straceの結果では、正常に実行されてる場合には ADDからEPOLLINまでのシステムコール呼び出しが以下のような感じなのに対して、

   1  write(1, "************** epoll-add: 0.0377"..., 39************** epoll-add: 0.03
   2  7784 - 8
   3  ) = 39epoll_ctl(6, EPOLL_CTL_ADD, 8, {EPOLLIN, {u32=138272384, u64=1323936545317780646
   4  4}}) = 0
   5  epoll_wait(6, {{EPOLLIN, {u32=138272384, u64=13239365453177806464}}}, 65536, 50)
   6  = 1
   7  gettimeofday({1230425221, 603705}, NULL) = 0
   8  write(1, "************** epoll-read: 0.020"..., 40************** epoll-read: 0.0
   9  20716 - 8

異常時には以下のように謎のselectが発生していました。

   1  write(1, "************** epoll-add: 0.0295"..., 39************** epoll-add: 0.029586 - 8
   2  ) = 39
   3  epoll_ctl(6, EPOLL_CTL_ADD, 8, {EPOLLIN, {u32=138272384, u64=1323936545317780646
   4  4}}) = 0
   5  epoll_wait(6, {}, 65536, 50)            = 0
   6  select(0, NULL, NULL, NULL, {0, 0})     = 0 (Timeout)
   7  time(NULL)                              = 1230425221
   8  gettimeofday({1230425221, 787115}, NULL) = 0
   9  epoll_wait(6, {}, 65536, 50)            = 0
  10  select(0, NULL, NULL, NULL, {0, 0})     = 0 (Timeout)time(NULL)                              = 1230425221
  11  gettimeofday({1230425221, 839105}, NULL) = 0
  12  epoll_wait(6, {{EPOLLIN, {u32=138272384, u64=13239365453177806464}}}, 65536, 50) = 1
  13  gettimeofday({1230425221, 843713}, NULL) = 0
  14  write(1, "************** epoll-read: 0.110"..., 40************** epoll-read: 0.1
  15  10337 - 8

どうやらこの謎のEmSelect呼び出しはビジーループ対策のために 挿入されているらしいのですが、以下のような形に直すと問題が 発生しなくなるようです。

   1    //timeval tv = {0,0};
   2    //EmSelect (0, NULL, NULL, NULL, &tv);
   3    #ifdef BUILD_FOR_RUBY
   4    if (!rb_thread_alone()) {
   5      rb_thread_schedule();
   6    }
   7    #endif

eventmachineのticketにpatchが上がっている ので、近いうちに修正されるかもしれません。

ということで、ひとまずお疲れさまでしたー＞masuidriveさん

masuidrive さんからeventmachineの挙動が不振だという相談を受けたので、 昔取った杵柄で色々調べてみています。

結局の所、EPOLL_CTL_ADD したあとに、epoll_waitがEPOLLIN になるまでにかかる時間が、稀に1000ミリ秒程度かかる事があるというのが 問題のようでした。 なぜかKQUEUEでも同様の問題が発生するようなのですが、 とりあえずは比較的親しみ深いepollの方を調べてみる事に。

epollの実装は、linuxカーネルの中にあります。 なので、linuxカーネルのソースをインストールします。

   1  # aptitude install linux-source-2.6.18

/usr/srcの下に圧縮されたカーネルのソースがインストールされるので、 展開します。

epoll関連のソースコードは、fs/eventepoll.cにあります。