Backport #7468: GC_GUARD漏れもしくはmark漏れっぽいエラーが発生してます。

• Status: Closed
• Assignee: usa (Usaku NAKAMURA)

[tarui (Masaya Tarui)]

いつからかtest-allで時々エラーが発生するようになってます。

make test-all TESTS="-qv -n /test_string$$/"

でsegvや

1. Error:
   test_string(DL::TestFunc):
   ArgumentError: assertion message must be String or Proc, but Thread::Backtrace was given.
   などと言われるようになりました。
   GC.stress = true なのと、Thread::Backtraceが通常のpassでは入る事はないっぽいのでGC周りのバグだと思います。

[shugo (Shugo Maeda)]

• Status changed from Open to Assigned
• Assignee set to tarui (Masaya Tarui)

tarui (Masaya Tarui) wrote:

いつからかtest-allで時々エラーが発生するようになってます。

make test-all TESTS="-qv -n /test_string$$/"

でsegvや

1. Error:
   test_string(DL::TestFunc):
   ArgumentError: assertion message must be String or Proc, but Thread::Backtrace was given.
   などと言われるようになりました。
   GC.stress = true なのと、Thread::Backtraceが通常のpassでは入る事はないっぽいのでGC周りのバグだと思います。

原因と思われるcommitをrevertしましたので、確認の上問題なければcloseいただけますか?

[tarui (Masaya Tarui)]

• Status changed from Assigned to Open
• Assignee deleted (tarui (Masaya Tarui))

ruby 2.0.0dev (2012-11-30 trunk 38022) [x86_64-linux]
でも残念ながらというか幸いというかsegvが起こります。
ので、shugoさんのpatchが原因ではないようです。

あの後 r37990 で試してやはり発生してたのでその時に関係ないだろうという結論に達していました。お手数を取らせてすいません。

ささださんが軽く実験した結果としてはGCCのバージョンによって発生するので、
最適化が進んで、これまで隠れてた漏れが顕在化したのでは無いかと疑っています。
手元のバージョンは gcc (Ubuntu/Linaro 4.6.1-9ubuntu3) 4.6.1 です。

[tarui (Masaya Tarui)]

• Category set to core
• Assignee set to authorNari (Narihiro Nakamura)

rb_threadptr_execute_interrupts経由でthread切替が起こる時、
machine_stack_endが正確にとれておらず、mark抜けが発生しています。
以下、アセンブラコードの抜粋

(gdb) disassemble
Dump of assembler code for function rb_threadptr_execute_interrupts:
0x00002aab414e6c30 <+0>: push %r15
0x00002aab414e6c32 <+2>: mov %rsp,%rdx

0x00002aab414e6c40 <+16>: sub $0x98,%rsp

0x00002aab414e6c4b <+27>: mov %rdx,0x38(%rsp)

0x00002aab414e6f26 <+758>: callq 0x2aab414e69b0 <rb_gc_save_machine_context>
0x00002aab414e6f2b <+763>: mov 0x38(%rsp),%rdx
0x00002aab414e6f30 <+768>: mov 0x8(%r12),%rdi
0x00002aab414e6f35 <+773>: mov %rdx,0x1b0(%r12)
0x00002aab414e6f3d <+781>: callq 0x2aab414e4730 <gvl_yield>

のように実際のrspではなく、関数に入った当初のrspをmachine_stack_endとしてしまっています。
rb_thread_scheduleでは
0x00002aab414e8f40 <+48>: callq 0x2aab414e69b0 <rb_gc_save_machine_context>
0x00002aab414e8f45 <+53>: mov 0x8(%rbx),%rdi
0x00002aab414e8f49 <+57>: mov %rsp,%rax
0x00002aab414e8f4c <+60>: mov %rax,0x1b0(%rbx)
0x00002aab414e8f53 <+67>: callq 0x2aab414e4730 <gvl_yield>
のようにちゃんとrspを使ってるんですが、この辺の挙動はよくわからないですね。
gccのバグだったりするのかなとも。。

inline assemblerを使わずにrb_gc_set_stack_endを使うようにするか、
rb_thread_schedule_limitsが現在各関数へ展開されてるのを防げば、
発生しないようになるのですが、
具体的にどう手当するのかはnariさんにお任せしてよいでしょうか？

[kosaki (Motohiro KOSAKI)]

SET_MACHINE_STACK_ENDの実体が

#if defined(x86_64) && defined(GNUC) && !defined(native_client)
#define SET_MACHINE_STACK_END(p) asm ("movq\t%%rsp, %0" : "=r" (*(p)))

のように volatileなしasmで、かつオペランド制約にrspを使うということが一切記述されてないので
どういう最適化されても文句はいえないのではないでしょうか。

とりあえず r38134 で volatileつけときました。この結果アセンブリは

3f92:	e8 00 00 00 00       	callq  3f97 <rb_threadptr_execute_interrupts+0x317>
3f97:	48 89 e0             	mov    %rsp,%rax
3f9a:	49 8b 7c 24 08       	mov    0x8(%r12),%rdi
3f9f:	49 89 84 24 b0 01 00 	mov    %rax,0x1b0(%r12)
3fa6:	00 
3fa7:	4c 89 e6             	mov    %r12,%rsi
3faa:	e8 c1 fa ff ff       	callq  3a70 <gvl_yield>

という感じになって、意図した通り gvl_yield()の直前に%rspをメモリに書いているように見えます。問題が再現出来る人がいれば
誰か確認お願いできませんか。

＃ たとえ直ってなくても r38134 は1.9.3にバックポート必要でしょうね。現状危なすぎる

[tarui (Masaya Tarui)]

• Status changed from Open to Closed
• % Done changed from 0 to 100

This issue was solved with changeset r38136.
Masaya, thank you for reporting this issue.
Your contribution to Ruby is greatly appreciated.
May Ruby be with you.

---

add ticket ref: [ruby-dev:46665] [Bug #7468]

[tarui (Masaya Tarui)]

最適化？(手間が増えてるように見える)によって前に飛ばされてたんですね。
そこまで気が回ってませんでした。再現しない事を確認したのでticketを閉じました。

修正ありがとうございます。

2012年12月2日 6:23 kosaki (Motohiro KOSAKI) [e-mail]:

Issue #7468 has been updated by kosaki (Motohiro KOSAKI).

SET_MACHINE_STACK_ENDの実体が

#if defined(x86_64) && defined(GNUC) && !defined(native_client)
#define SET_MACHINE_STACK_END(p) asm ("movq\t%%rsp, %0" : "=r" (*(p)))

のように volatileなしasmで、かつオペランド制約にrspを使うということが一切記述されてないので
どういう最適化されても文句はいえないのではないでしょうか。

とりあえず r38134 で volatileつけときました。この結果アセンブリは

3f92:       e8 00 00 00 00          callq  3f97 <rb_threadptr_execute_interrupts+0x317>
3f97:       48 89 e0                mov    %rsp,%rax
3f9a:       49 8b 7c 24 08          mov    0x8(%r12),%rdi
3f9f:       49 89 84 24 b0 01 00    mov    %rax,0x1b0(%r12)
3fa6:       00
3fa7:       4c 89 e6                mov    %r12,%rsi
3faa:       e8 c1 fa ff ff          callq  3a70 <gvl_yield>

という感じになって、意図した通り gvl_yield()の直前に%rspをメモリに書いているように見えます。問題が再現出来る人がいれば
誰か確認お願いできませんか。

＃ たとえ直ってなくても r38134 は1.9.3にバックポート必要でしょうね。現状危なすぎる

---

Bug #7468: GC_GUARD漏れもしくはmark漏れっぽいエラーが発生してます。
https://bugs.ruby-lang.org/issues/7468#change-34296

Author: tarui (Masaya Tarui)
Status: Open
Priority: High
Assignee: authorNari (Narihiro Nakamura)
Category: core
Target version: 2.0.0
ruby -v: ruby -v: ruby 2.0.0dev (2012-11-30 trunk 37999) [x86_64-linux]

いつからかtest-allで時々エラーが発生するようになってます。

make test-all TESTS="-qv -n /test_string$$/"

でsegvや

1. Error:
   test_string(DL::TestFunc):
   ArgumentError: assertion message must be String or Proc, but Thread::Backtrace was given.
   などと言われるようになりました。
   GC.stress = true なのと、Thread::Backtraceが通常のpassでは入る事はないっぽいのでGC周りのバグだと思います。

--
http://bugs.ruby-lang.org/

--
樽家昌也(Masaya TARUI)
No Tool,No Life.

[kosaki (Motohiro KOSAKI)]

• Tracker changed from Bug to Backport
• Project changed from Ruby to 13
• Category deleted (core)
• Status changed from Closed to Assigned
• Assignee changed from authorNari (Narihiro Nakamura) to usa (Usaku NAKAMURA)
• Target version deleted (2.0.0)

1.9.3 へのバックポートを希望します。
r38134 と r38136.

[usa (Usaku NAKAMURA)]

• Status changed from Assigned to Closed

This issue was solved with changeset r38501.
Masaya, thank you for reporting this issue.
Your contribution to Ruby is greatly appreciated.
May Ruby be with you.

---

merge revision(s) 38134,38136: [Backport #7468]

* gc.h (SET_MACHINE_STACK_END): add volatile for preventing
  harmful optimization.
  harmful optimization.  [ruby-dev:46665] [Bug #7468]