Fix Nginx::Stream::Async race condition #437

pyama86 · 2019-11-08T11:14:53Z

Hi Mats!!!
Have you eaten dinner??

Nginx::Stream module is using mrb->ud.
it is a possibility of becoming a race condition when call Nginx::Stream::Async.sleep.

In this patch, added mrb-> ud consistency before and after run fiber.
Thanks!

Pull-Request Check List

Add patches into src/.
Add test into test/. Please see about test docs.
Add docs into docs/ if you change the features such as build system, Ruby methods, class and nginx directives.

matsumotory · 2019-11-09T00:29:57Z

Thank you for your PR. The test seems failed. Please check it.

matsumotory

I commented. Could you add simple tests?

matsumotory · 2019-11-09T00:43:24Z

build_config.rb

@@ -78,6 +78,7 @@
  conf.gem :github => 'matsumotory/mruby-simpletest'
  conf.gem :github => 'mattn/mruby-http'
  conf.gem :github => 'mattn/mruby-json'
+  conf.gem :github => 'mattn/mruby-thread'


Why did you include mruby-thread?

matsumotory · 2019-11-09T00:44:10Z

src/stream/ngx_stream_mruby_connection.c


-  mrb_get_args(mrb, "o", &upstream);
+  mrb_get_args(mrb, "|o", &upstream);


Why did you use optimal arguments?

I think it is not necessary to specify an upstream server.
What do you think?

You mean that even if we don't specify an upstream configuration, we want to use instance methods like local_ip, right? OK, fair enough.

exactly right!

matsumotory · 2019-11-09T00:45:23Z

src/stream/ngx_stream_mruby_connection.c

+
+  *ctx->ictx->s = *((ngx_stream_mruby_internal_ctx_t *)mrb->ud)->s;
+  ctx->ictx->stream_status = ((ngx_stream_mruby_internal_ctx_t *)mrb->ud)->stream_status;
+  ngx_stream_session_t *s = ctx->ictx->s;


You should declare the type at the beginning of the function.

matsumotory · 2019-11-09T00:46:53Z

src/stream/ngx_stream_mruby_connection.c

+  ctx->ictx = (ngx_stream_mruby_internal_ctx_t *)mrb_malloc(mrb, sizeof(ngx_stream_mruby_internal_ctx_t));
+  ctx->ictx->s = (ngx_stream_session_t *)mrb_malloc(mrb, sizeof(ngx_stream_session_t));
+
+  *ctx->ictx->s = *((ngx_stream_mruby_internal_ctx_t *)mrb->ud)->s;


Why did you copy the dereference data to ictx->s? I think we use only the pointer.

sorry.i fix it.

matsumotory · 2019-11-09T01:05:22Z

And could you please modify the documents in docs? If you finish to write the code, test, and docs, please check the check list of PR template.

matsumotory · 2019-11-09T04:43:20Z

ぴゃまさん、なんかよく見たら 1843183 のcommitでその前のテストの変更とか上書きしてしまって、全体として謎PRになっていたけど、だいたい理解した

pyama86 · 2019-11-09T04:51:45Z

当初のパッチで謎にsegvしてて、最後にクラスメソッドに気づいたから、メモリコピーしてたり謎なままコミットしてしまっていました。
ちょいこのあとコミット整理して投げます。

matsumotory · 2019-11-09T04:52:43Z

ほい！

pyama86 · 2019-11-09T07:23:12Z

CI、差し支えなければgithub actionsに移行しちゃいたいんですけどどうですか？

matsumotory · 2019-11-09T07:25:15Z

全然OK! なんですけど、別prで久米さんが色々ci弄ってるのでそれからが良いかも

pyama86 · 2019-11-09T07:27:25Z

ok牧場！

pyama86 · 2019-11-09T07:29:17Z

mrbgems/ngx_mruby_mrblib/mrblib/mrb_nginx.rb

+        )
+      end
+
+      def self.stream_status=(v)


これ意味ないなｗ

mrb->udから受け取ったポインタ上の値は書き換わるから意図した結果になるか。

他のクラスメソッドも同じように引数無しで渡すインスタンスメソッドのラッパーにして互換性持たすのも良いかもね

https://github.com/matsumotory/ngx_mruby/pull/437/files/1680fc49d363f1182ae23f1e79c31175fe9b2590#diff-334aed72520838c124d910450cd12989R107

これで同じ動きになると思っているのですがそういう意味ではない？

あ、そういう意味！ちゃんと実装してた

pyama86 · 2019-11-09T07:40:00Z

travisだけテスト落ちる病久しぶりだな。

matsumotory · 2019-11-09T08:54:03Z

ぴゃまさん明日はマラソンだし今日はもう寝なよ

matsumotory · 2019-11-09T09:49:32Z

src/stream/ngx_stream_mruby_connection.c

@@ -35,14 +36,13 @@ static const struct mrb_data_type ngx_stream_mrb_upstream_context_type = {
 static mrb_value ngx_stream_mrb_connection_init(mrb_state *mrb, mrb_value self)
 {
  ngx_uint_t i;
+  int argc;


pyama86 · 2019-11-09T16:06:18Z

ちょっとここまで書き進めて気付いたのですが、ログ周りもクラスメソッドになってるから、ictxをグローバル変数に待避できるようにして、run_fiberのときにpush、それぞれのメソッドでpopするような実装にしないとだめそうですね....

pyama86 · 2019-11-09T21:42:45Z

ちょい考えたのですが全部ud使わない実装に一気にやるとPRも膨れるのとリリースインパクトが大きくなってしまうので下記のステップで分けようかと思いますがどうですかね？

step1. mrd->udを利用したまま、async sleepの前後でudの整合性を取ることでレースを避ける実装を入れる
step2. 今回作業する中で気付いた部分をリファクタリング
step3. インスタンスメソッドはインスタンス変数を利用して、udを利用しない実装にし、クラスメソッドはグローバル変数にsession構造体をpush&getして、マルチスレッドでは競合する可能性があるが、動く状態にする

matsumotory · 2019-11-10T00:14:05Z

なんか全体的にこの辺は仕組みを考え直そうかな。少し考えます。

matsumotory · 2019-11-10T00:17:21Z

udのレースというも、udに入ったポインタを渡しているだけから、どういうケースで上書きが起きてるのかがちょっとわからないな。

matsumotory · 2019-11-10T00:32:03Z

再現コードだけ欲しいですね、セグフォルやつ

matsumotory · 2019-11-10T01:02:07Z

あー性能重視して起動時に一度だけictx作るようにしてるからか

matsumotory · 2019-11-10T01:04:43Z

んー？でも、fiber呼び直されるたびにsは同じものをそのまま渡しているから問題起きなさそうだけどな

matsumotory · 2019-11-10T01:08:53Z

https://github.com/matsumotory/ngx_mruby/blob/master/src/stream/ngx_stream_mruby_module.c#L709

このあたり。nginxはプロセス単位では直列で、ここみたいに毎回先に使うべきsを再格納しているから、レースが起きなさそうにも思える。再現コードをもらって僕もどこか問題がデバックしたいなと思えたので、再現コードあればまた教えてください！

pyama86 · 2019-11-10T05:55:51Z

Async sleepを多重に利用すると起きます。
Async sleepから、復帰後にmrb-udを使うと、スリープ中に処理された他のトランスポートセッションが入ってる感じすね。

pyama86 · 2019-11-10T05:58:18Z

それこそ、ログやクラスメソッドとかがmrb->udそのまま読むから、そこで他のセッションが格納されてる感じすね。いずれにせよセッションmrb->udっていうアクセス詞をやめないとダメそうに思うけどどうです？

pyama86 · 2019-11-10T06:01:10Z

家帰ってから再現テスト書いてコミットします

matsumotory · 2019-11-10T07:06:47Z

最初そう思ったんですけど、fiber単位でresume時であっても毎回このhandler #437 (comment) が呼ばれるから、sessionは常に対象の構造体になるはずなんですよね。再現コードやログデバッグなどでまさにここでおかしくなってるというのを確認できれば良いんですけど

matsumotory · 2019-11-10T09:45:50Z

それだと、Cで書かれた別のmgemがリンクされている場合は、使い方によってはそもそもmrubyの世界にmruby->ud->sを持っていくこと自体が競合になるので、その最初の一歩が使い方によっては干渉し合うんじゃないかなぁと。

pyama86 · 2019-11-10T09:49:45Z

ああ、そうですね。handlerの一番最初にインスタンス化されるとは限らないから。そうなるとnginxの構造体を受け取らないmrubyのメソッド全般しんどい感じですね。。コード眺めて考えてみる。

matsumotory · 2019-11-10T09:54:21Z

ひとまずやっていただけるということですので、run_fiberのバイトコード実行直前にちゃんとictxがそのバイトコード(proc)と紐づくnginxのコンテキスト(ictx->sなど）にアップデートできるようにする、これをこのPRでやる。

それで今のsegvは解決で、その後に、mrb->udが他のmgemで使った場合でもうまくいくような実装を考える、これをまた別PRでやる、みたいな感じはいかがでしょう？

matsumotory · 2019-11-10T09:54:54Z

マラソンは結構です！

pyama86 · 2019-11-10T09:56:28Z

はい、このPRはコミット整理しつつ、そうします。udの件は考えて別途提案します。

matsumotory · 2019-11-10T09:58:42Z

udの件は面白いので僕も考えてみます.....!いつもありがとうございます！

pyama86 · 2019-11-11T03:41:45Z

なんかセッション書き換わってしまうのなんでだと思っていたら、mrb->ud(ictx)のallocateがconfig読み込みのときだったからだった。
https://github.com/matsumotory/ngx_mruby/blob/segv-stream/src/stream/ngx_stream_mruby_module.c#L183

handlerごとにictxをコネクションからアロケートする方式へ変える。

matsumotory · 2019-11-11T03:45:32Z

あ、いえ、それは想定した実装で、性能を考慮してセッション単位での不要な都度メモリ確保はやめたいのでconfig時にやっています。できればその領域をmrubyの世界への橋渡しに使ってください。出来るだけゼロコピーの実装を目指したい

pyama86 · 2019-11-11T03:58:38Z

なるほどぉ、そうなるとictxまるっとreentrantに持っていくのではなくて、sessionとstream statusを別個に持っていくのが良さそうですねぇ。しばしお待ちを。

This reverts commit 551af63.

matsumotory · 2019-11-11T04:07:26Z

お！そのとおり！１００点の回答じゃないですか。ご飯食べなたら雑に返したので今から説明しようと思っていたところでした。

ictxは単一でもって、nginxの世界のデータをmrubyの世界に持っていくたったひとつのトンネルとして考えて、nginxのデータはすでに確保されているはずなので、ictxはhandlerごとにもたないことによってictxの不要な確保開放とメモリ使用をへらすのが狙いです。

pyama86 · 2019-11-11T04:24:33Z

その場合run_fiberでmrb->udの状態を戻すとなるとstream_statusを引数で渡してやらにゃならんのですが、実用上はpost_fiberでもどしてやれば問題ないのでその方向で実装しました。

matsumotory · 2019-11-11T04:52:58Z

うっす

matsumotory · 2019-11-11T06:42:00Z

src/stream/ngx_stream_mruby_async.c


-  ngx_stream_session_t *s = ngx_mrb_get_session();
-  ctx = ngx_stream_mrb_get_module_ctx(mrb, s);
+  ictx = mrb->ud;


この段階でictx->sがfiberで実行すべきsと別のfiberのsになっている可能性はありませんかねぇ？

post_handlerはfiberがresumeありのときに呼ばれますが、通常のsyncなhandlerのときは呼ばれませんが、それでも整合性はとれていそうでしょうか？

はい。その場合、ngx_stream_mruby_handlerでictxが初期化され、ngx_stream_mrb_run_fiberがコールされるので問題ないです。
初期化経路としては ngx_stream_mruby_handler 、ngx_stream_mrb_post_fiberのいずれかになります。

ふむふむ、そうですね。asyncが実行されてコールバック待ちのときにhandlerが呼ばれてudの情報が変わっても、asyncからpost_fiberがコールバックされたときに、そこでudの情報をasyncのものに置き換えるので、その後のrun_fiberでは正しいsession情報が渡される、ということですね。

また、handlerについても、syncなhandlerはそもそも必ずhandler内でsession情報を初期化するので問題ない、と。

OKです！なんかこのあたりをコードでわかりやすく表現できると良いなと思いましたが、それはまた別のリファクタということで、ここではスコープ外のほうがよいですね。

確かに。prepare〜みたいなメソッド掘るだけでもだいぶリーダブルになりそうですね。

matsumotory · 2019-11-11T06:50:24Z

Thank you for your effort and good job マラソン!

pyama86 · 2019-11-11T06:53:20Z

はい〜。実機であれこれ確認します。

matsumotory requested changes Nov 9, 2019

View reviewed changes

pyama86 force-pushed the segv-stream branch from 44a2685 to 1680fc4 Compare November 9, 2019 07:09

pyama86 commented Nov 9, 2019

View reviewed changes

matsumotory reviewed Nov 9, 2019

View reviewed changes

pyama86 force-pushed the segv-stream branch 3 times, most recently from 57ca5a2 to 1a4b6d4 Compare November 9, 2019 12:49

pyama86 changed the title ~~Fix Nginx::Stream::Async race condition~~ [WIP]Fix Nginx::Stream::Async race condition Nov 9, 2019

pyama86 added 2 commits November 10, 2019 23:40

add test

8ee3850

keep mrb->ud consistent before and after run fiber

551af63

pyama86 force-pushed the segv-stream branch from 1a4b6d4 to 551af63 Compare November 10, 2019 15:06

pyama86 changed the title ~~[WIP]Fix Nginx::Stream::Async race condition~~ Fix Nginx::Stream::Async race condition Nov 10, 2019

miss

fd118c1

pyama86 changed the title ~~Fix Nginx::Stream::Async race condition~~ [wip]Fix Nginx::Stream::Async race condition Nov 11, 2019

unnessary push sesion

fea2821

pyama86 changed the title ~~[wip]Fix Nginx::Stream::Async race condition~~ Fix Nginx::Stream::Async race condition Nov 11, 2019

Revert "keep mrb->ud consistent before and after run fiber"

8d8585c

This reverts commit 551af63.

keep ictx consistent before and after run fiber

0fb0860

pyama86 force-pushed the segv-stream branch from 7ab46aa to 0fb0860 Compare November 11, 2019 04:38

more simply

8933b1d

matsumotory reviewed Nov 11, 2019

View reviewed changes

matsumotory approved these changes Nov 11, 2019

View reviewed changes

matsumotory merged commit ac1cca0 into master Nov 11, 2019

matsumotory deleted the segv-stream branch November 11, 2019 06:50


		mrb_get_args(mrb, "o", &upstream);
		mrb_get_args(mrb, "\|o", &upstream);

Fix Nginx::Stream::Async race condition #437

Fix Nginx::Stream::Async race condition #437

Conversation

pyama86 commented Nov 8, 2019 • edited Loading

Pull-Request Check List

matsumotory commented Nov 9, 2019

matsumotory left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

matsumotory commented Nov 9, 2019

matsumotory commented Nov 9, 2019

pyama86 commented Nov 9, 2019

matsumotory commented Nov 9, 2019

pyama86 commented Nov 9, 2019

matsumotory commented Nov 9, 2019

pyama86 commented Nov 9, 2019

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

pyama86 commented Nov 9, 2019

matsumotory commented Nov 9, 2019

Choose a reason for hiding this comment

pyama86 commented Nov 9, 2019

pyama86 commented Nov 9, 2019

matsumotory commented Nov 10, 2019

matsumotory commented Nov 10, 2019

matsumotory commented Nov 10, 2019

matsumotory commented Nov 10, 2019

matsumotory commented Nov 10, 2019

matsumotory commented Nov 10, 2019

pyama86 commented Nov 10, 2019 • edited Loading

pyama86 commented Nov 10, 2019

pyama86 commented Nov 10, 2019

matsumotory commented Nov 10, 2019

matsumotory commented Nov 10, 2019

pyama86 commented Nov 10, 2019

matsumotory commented Nov 10, 2019

matsumotory commented Nov 10, 2019

pyama86 commented Nov 10, 2019

matsumotory commented Nov 10, 2019

pyama86 commented Nov 11, 2019

matsumotory commented Nov 11, 2019

pyama86 commented Nov 11, 2019

matsumotory commented Nov 11, 2019

pyama86 commented Nov 11, 2019

matsumotory commented Nov 11, 2019

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

matsumotory commented Nov 11, 2019

pyama86 commented Nov 11, 2019

pyama86 commented Nov 8, 2019 •

edited

Loading

pyama86 commented Nov 10, 2019 •

edited

Loading