[#20227] dyna_vars problem? — Tanaka Akira <akr@...17n.org>

しばらく前から、稀に Ruby が core を吐くという問題を追いかけているので

15 messages 2003/05/19
[#20234] Re: dyna_vars problem? — matz@... (Yukihiro Matsumoto) 2003/05/19

まつもと ゆきひろです

[#20236] Re: dyna_vars problem? — Tanaka Akira <akr@...17n.org> 2003/05/19

In article <1053363181.529491.30320.nullmailer@picachu.netlab.jp>,

[ruby-dev:20248] Re: dyna_vars problem?

From: Tanaka Akira <akr@...17n.org>
Date: 2003-05-20 09:33:41 UTC
List: ruby-dev #20248
In article <1053422521.786672.22712.nullmailer@picachu.netlab.jp>,
  matz@ruby-lang.org (Yukihiro Matsumoto) writes:

> |たとえば、次のような問題が起きることがあります。
> |(起きないことも多々ありますし、他の問題が起きることもあります。)
>
> 再現しませんでした。rb_gc()を追加すると処理が全然進まないし。

あ、その進まないという奴も症状のひとつです。

たぶん、strace をかけると次のようにぜんぜん IO をしない状況になるんで
すよね?

sigreturn()                             = ? (mask now [])
--- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
sigreturn()                             = ? (mask now [])
--- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
sigreturn()                             = ? (mask now [])
--- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
sigreturn()                             = ? (mask now [])
--- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
sigreturn()                             = ? (mask now [])
--- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
sigreturn()                             = ? (mask now [])
--- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
sigreturn()                             = ? (mask now [])
--- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
sigreturn()                             = ? (mask now [])
--- SIGVTALRM (Virtual timer expired) @ 0 (0) ---

これを gdb で attach してみると、(loop になる場所は何箇所かあるんです
が、そのうちのひとつは) 次のような無限ループに陥っています。

dvar_asgn_internal (id=18985, value=4, curr=1) at eval.c:774
774             if (vars->id == id) {
(gdb) p vars
$1 = (struct RVarmap *) 0x403c9b58
(gdb) p *vars
$2 = {super = {flags = 61, klass = 0}, id = 7729, val = 1077561272, next = 0x403
c9b58}
(gdb) n
778             vars = vars->next;
(gdb) 
779         }
(gdb) 
769             if (curr && vars->id == 0) {
(gdb) 
774             if (vars->id == id) {
(gdb) n
778             vars = vars->next;
(gdb) p vars
$3 = (struct RVarmap *) 0x403c9b58
(gdb) p *vars 
$4 = {super = {flags = 61, klass = 0}, id = 7729, val = 1077561272, next = 0x403
c9b58}
(gdb) 

また、GC 自体が無限に呼び出されるループになることもあります。

サイクルができるのは、えーと、たしか dyna_vars 関係がいくつかと
final_list だった覚えがあります。final_list は最初はサイクルがないのに
最初に run_final した後にはサイクルができているということを確認してい
ます。

というようなわけで、かなりやりにくい状況なわけですが、私は次のように
assert をいれまくって追い詰めようとしていました。まぁ、最初の質問のよ
うに間違った assert をいれてるところもあるかも知れませんが。

あ、一回だけ、サイクルの大きさが 1 ではなくて 2 になったときもありまし
た。これはここで入れているような assert では検査できないので止まらない
はずです。

Index: eval.c
===================================================================
RCS file: /src/ruby/eval.c,v
retrieving revision 1.434
diff -u -r1.434 eval.c
--- eval.c	19 May 2003 15:44:42 -0000	1.434
+++ eval.c	20 May 2003 01:58:10 -0000
@@ -12,6 +12,7 @@
 
 **********************************************************************/
 
+#include <assert.h>
 #include "ruby.h"
 #include "node.h"
 #include "env.h"
@@ -691,14 +692,29 @@
 
 #define DVAR_DONT_RECYCLE FL_USER2
 
+#define live(v) (((struct RBasic *)(v))->flags != 0)
+#define live_null(v) (!(v) || ((struct RBasic *)(v))->flags != 0)
+
 static struct RVarmap*
 new_dvar(id, value, prev)
     ID id;
     VALUE value;
     struct RVarmap *prev;
 {
-    NEWOBJ(vars, struct RVarmap);
+    volatile struct RVarmap *v = prev;
+    struct RVarmap *vars;
+    assert(live_null(prev));
+    assert(v == prev);
+    {
+      NEWOBJ(vars2, struct RVarmap);
+      assert(vars2 != prev);
+      vars = vars2;
+    }
+    assert(vars != prev);
+    assert(v == prev);
     OBJSETUP(vars, 0, T_VARMAP);
+    assert(v == prev);
+    assert(vars != prev);
     vars->id = id;
     vars->val = value;
     vars->next = prev;
@@ -743,6 +759,7 @@
 	if (vars->id == id) {
 	    return vars->val;
 	}
+        assert(vars != vars->next);
 	vars = vars->next;
     }
     return Qnil;
@@ -754,6 +771,7 @@
     VALUE value;
 {
     ruby_dyna_vars = new_dvar(id, value, ruby_dyna_vars);
+    assert(ruby_dyna_vars != ruby_dyna_vars->next);
 }
 
 static void
@@ -764,6 +782,7 @@
 {
     int n = 0;
     struct RVarmap *vars = ruby_dyna_vars;
+    assert(live_null(ruby_dyna_vars));
 
     while (vars) {
 	if (curr && vars->id == 0) {
@@ -775,13 +794,17 @@
 	    vars->val = value;
 	    return;
 	}
+        assert(vars != vars->next);
 	vars = vars->next;
     }
     if (!ruby_dyna_vars) {
 	ruby_dyna_vars = new_dvar(id, value, 0);
     }
     else {
+        assert(live(ruby_dyna_vars));
+        assert(live_null(ruby_dyna_vars->next));
 	vars = new_dvar(id, value, ruby_dyna_vars->next);
+        assert(ruby_dyna_vars != vars);
 	ruby_dyna_vars->next = vars;
     }
 }
@@ -791,6 +814,7 @@
     ID id;
     VALUE value;
 {
+    assert(live_null(ruby_dyna_vars));
     dvar_asgn_internal(id, value, 0);
 }
 
@@ -799,6 +823,7 @@
     ID id;
     VALUE value;
 {
+    assert(live_null(ruby_dyna_vars));
     dvar_asgn_internal(id, value, 1);
 }
 
@@ -806,14 +831,28 @@
 rb_svar(cnt)
     int cnt;
 {
-    struct RVarmap *vars = ruby_dyna_vars;
+    struct RVarmap * volatile vars = ruby_dyna_vars;
     ID id;
 
+    {
+      struct RVarmap * volatile v = ruby_dyna_vars;
+      while (v) {
+        assert(TYPE(v) == T_VARMAP);
+	v = v->next;
+      }
+    }
+
+    assert(ruby_scope);
     if (!ruby_scope->local_tbl) return NULL;
+    assert(ruby_scope->local_tbl);
     if (cnt >= ruby_scope->local_tbl[0]) return NULL;
     id = ruby_scope->local_tbl[cnt+1];
     while (vars) {
-	if (vars->id == id) return &vars->val;
+        assert(vars);
+        assert(TYPE(vars) == T_VARMAP);
+        assert(vars != (struct RVarmap *)0x200);
+	if (vars->id == id)
+          return &vars->val;
 	vars = vars->next;
     }
     if (ruby_scope->local_vars == 0) return NULL;
@@ -4099,9 +4138,11 @@
 	if (ruby_dyna_vars->id == 0) {
 	    vars = ruby_dyna_vars->next;
 	    rb_gc_force_recycle((VALUE)ruby_dyna_vars);
+            /*fprintf(stderr, "rb_gc_force_recycle ruby_dyna_vars: %08x\n", ruby_dyna_vars);*/
 	    while (vars && vars->id != 0 && vars != block->dyna_vars) {
 		struct RVarmap *tmp = vars->next;
 		rb_gc_force_recycle((VALUE)vars);
+                /*fprintf(stderr, "rb_gc_force_recycle ruby_dyna_vars: %08x\n", vars);*/
 		vars = tmp;
 	    }
 	}
@@ -7929,6 +7970,8 @@
 
 extern VALUE *rb_gc_stack_start;
 
+volatile long thread_switch_count = 0;
+
 static void
 rb_thread_save_context(th)
     rb_thread_t th;
@@ -7942,6 +7985,7 @@
     th->stk_pos = (rb_gc_stack_start<pos)?rb_gc_stack_start
 				         :rb_gc_stack_start - len;
     if (len > th->stk_max) {
+        rb_gc();
 	REALLOC_N(th->stk_ptr, VALUE, len);
 	th->stk_max = len;
     }
@@ -8036,6 +8080,14 @@
     static int ex;
     static VALUE tval;
 
+    {
+      struct RVarmap * volatile v = th->dyna_vars;
+      while (v) {
+        assert(TYPE(v) == T_VARMAP);
+        v = v->next;
+      }
+    }
+
     if (!th->stk_ptr) rb_bug("unsaved context");
 
     if (&v < rb_gc_stack_start) {
@@ -8073,6 +8125,14 @@
     FLUSH_REGISTER_WINDOWS;
     MEMCPY(tmp->stk_pos, tmp->stk_ptr, VALUE, tmp->stk_len);
 
+    {
+      struct RVarmap * volatile v = ruby_dyna_vars;
+      while (v) {
+        assert(TYPE(v) == T_VARMAP);
+        v = v->next;
+      }
+    }
+
     tval = rb_lastline_get();
     rb_lastline_set(tmp->last_line);
     tmp->last_line = tval;
@@ -8080,6 +8140,7 @@
     rb_backref_set(tmp->last_match);
     tmp->last_match = tval;
 
+    thread_switch_count++;
     longjmp(tmp->context, ex);
 }
 
@@ -8412,6 +8473,15 @@
 	}
     }
     END_FOREACH_FROM(curr, th); 
+    if (next)
+    {
+      struct RVarmap * volatile v = next->dyna_vars;
+      while (v) {
+        assert(TYPE(v) == T_VARMAP);
+        v = v->next;
+      }
+    }
+    if (next && next->status == THREAD_RUNNABLE) assert(next->stk_ptr);
 
     if (!next) {
 	/* raise fatal error to main thread */
@@ -8444,10 +8514,24 @@
 	}
 	rb_thread_deadlock();
     }
+    {
+      struct RVarmap * volatile v = next->dyna_vars;
+      while (v) {
+        assert(TYPE(v) == T_VARMAP);
+        v = v->next;
+      }
+    }
     next->wait_for = 0;
     if (next->status == THREAD_RUNNABLE && next == curr_thread) {
 	return;
     }
+    {
+      struct RVarmap * volatile v = next->dyna_vars;
+      while (v) {
+        assert(TYPE(v) == T_VARMAP);
+        v = v->next;
+      }
+    }
 
     /* context switch */
     if (curr == curr_thread) {
@@ -8455,6 +8539,14 @@
 	    return;
 	}
     }
+    assert(next->stk_ptr);
+    {
+      struct RVarmap * volatile v = next->dyna_vars;
+      while (v) {
+        assert(TYPE(v) == T_VARMAP);
+        v = v->next;
+      }
+    }
 
     curr_thread = next;
     if (next->status == THREAD_TO_KILL) {
@@ -8463,6 +8555,15 @@
 	    /* terminate; execute ensure-clause if any */
 	    rb_thread_restore_context(next, RESTORE_FATAL);
 	}
+        assert(next->stk_ptr);
+    }
+    assert(next->stk_ptr);
+    {
+      struct RVarmap * volatile v = next->dyna_vars;
+      while (v) {
+        assert(TYPE(v) == T_VARMAP);
+        v = v->next;
+      }
     }
     rb_thread_restore_context(next, RESTORE_NORMAL);
 }
Index: gc.c
===================================================================
RCS file: /src/ruby/gc.c,v
retrieving revision 1.132
diff -u -r1.132 gc.c
--- gc.c	8 May 2003 09:45:52 -0000	1.132
+++ gc.c	20 May 2003 01:58:10 -0000
@@ -12,6 +12,12 @@
 
 **********************************************************************/
 
+volatile long finalizer_count = 0;
+volatile long gc_count = 0;
+volatile long gc_try_count = 0;
+extern volatile long thread_switch_count;
+
+#include <assert.h>
 #include "ruby.h"
 #include "rubysig.h"
 #include "st.h"
@@ -927,6 +933,7 @@
 		    obj_free((VALUE)p);
 		}
 		if (need_call_final && FL_TEST(p, FL_FINALIZE)) {
+                  assert(p != final_list);
 		    p->as.free.flags = FL_MARK; /* remain marked */
 		    p->as.free.next = final_list;
 		    final_list = p;
@@ -972,15 +979,52 @@
     /* clear finalization list */
     if (final_list) {
 	RVALUE *tmp;
+        volatile int count = 0;
 
 	if (rb_prohibit_interrupt || ruby_in_compile) {
 	    deferred_final_list = final_list;
 	    return;
 	}
 
+        count = 0;
 	for (p = final_list; p; p = tmp) {
+          tmp = p->as.free.next;
+          if (count == 0) assert(p != tmp);
+          if (count != 0) assert(p != tmp);
+          count++;
+        }
+
+        count = 0;
+	for (p = final_list; p; p = tmp) {
+            RVALUE *q;
+            volatile long prev_finalizer_count;
+            volatile long prev_gc_try_count;
+            volatile long prev_gc_count;
+            volatile long prev_thread_switch_count;
+            for (q = p; q; q = q->as.free.next) {
+              assert(q != q->as.free.next);
+            }
+
 	    tmp = p->as.free.next;
+            if (count == 0) assert(p != tmp);
+            if (count == 1) assert(p != tmp);
+            if (count >= 2) assert(p != tmp);
+            count++;
+            prev_finalizer_count = finalizer_count;
+            prev_gc_count = gc_count;
+            prev_gc_try_count = gc_try_count;
+            prev_thread_switch_count = thread_switch_count;
+
+            for (q = p; q; q = q->as.free.next) {
+              assert(q != q->as.free.next);
+            }
+
 	    run_final((VALUE)p);
+
+            for (q = p; q; q = q->as.free.next) {
+              assert(q != q->as.free.next);
+            }
+
 	    if (!FL_TEST(p, FL_SINGLETON)) { /* not freeing page */
 		p->as.free.flags = 0;
 		p->as.free.next = freelist;
@@ -1007,6 +1051,7 @@
 rb_gc_force_recycle(p)
     VALUE p;
 {
+    assert(RANY(p)->as.free.flags != 0);
     RANY(p)->as.free.flags = 0;
     RANY(p)->as.free.next = freelist;
     freelist = RANY(p);
@@ -1194,6 +1239,8 @@
     jmp_buf save_regs_gc_mark;
     SET_STACK_END;
 
+    gc_try_count++;
+
     if (dont_gc || during_gc) {
 	if (!freelist) {
 	    add_heap();
@@ -1203,6 +1250,8 @@
     if (during_gc) return;
     during_gc++;
 
+    gc_count++;
+
     init_mark_stack();
     
     /* mark frame stack */
@@ -1482,6 +1531,7 @@
 	finalizer_table = st_init_numtable();
     }
     if (st_lookup(finalizer_table, obj, &table)) {
+      assert(0);
 	rb_ary_push(table, proc);
     }
     else {
@@ -1510,6 +1560,7 @@
 run_single_final(args)
     VALUE *args;
 {
+    finalizer_count++;
     rb_eval_cmd(args[0], args[1], 0);
     return Qnil;
 }
@@ -1523,11 +1574,13 @@
     VALUE args[2], table;
 
     args[1] = rb_ary_new3(1, rb_obj_id(obj)); /* make obj into id */
+    assert(RARRAY(finalizers)->len == 0);
     for (i=0; i<RARRAY(finalizers)->len; i++) {
 	args[0] = RARRAY(finalizers)->ptr[i];
 	rb_protect((VALUE(*)_((VALUE)))run_single_final, (VALUE)args, &status);
     }
     if (finalizer_table && st_delete(finalizer_table, &obj, &table)) {
+      assert(RARRAY(table)->len == 1);
 	for (i=0; i<RARRAY(table)->len; i++) {
 	    args[0] = RARRAY(table)->ptr[i];
 	    rb_protect((VALUE(*)_((VALUE)))run_single_final, (VALUE)args, &status);
Index: io.c
===================================================================
RCS file: /src/ruby/io.c,v
retrieving revision 1.207
diff -u -r1.207 io.c
--- io.c	19 May 2003 06:27:06 -0000	1.207
+++ io.c	20 May 2003 01:58:10 -0000
@@ -11,6 +11,7 @@
   Copyright (C) 2000  Information-technology Promotion Agency, Japan
 
 **********************************************************************/
+#include <assert.h>
 
 #if defined(__VMS)
 #define _XOPEN_SOURCE
@@ -400,6 +401,8 @@
     return len - n;
 }
 
+#define live(v) (((struct RBasic *)(v))->flags != 0)
+
 static VALUE
 io_write(io, str)
     VALUE io, str;
@@ -414,6 +417,7 @@
     if (RSTRING(str)->len == 0) return INT2FIX(0);
 
     if (TYPE(io) != T_FILE) {
+        assert(live(io));
 	/* port is not IO, call write method for it. */
 	return rb_funcall(io, id_write, 1, str);
     }
Index: parse.y
===================================================================
RCS file: /src/ruby/parse.y,v
retrieving revision 1.273
diff -u -r1.273 parse.y
--- parse.y	26 Apr 2003 14:59:19 -0000	1.273
+++ parse.y	20 May 2003 01:58:13 -0000
@@ -14,6 +14,7 @@
 
 #define YYDEBUG 1
 
+#include <assert.h>
 #include "ruby.h"
 #include "env.h"
 #include "intern.h"
@@ -5968,10 +5969,22 @@
 VALUE
 rb_lastline_get()
 {
-    VALUE *var = rb_svar(0);
+    volatile int pos = 0;
+    VALUE *var;
+    {
+      struct RVarmap * volatile v = ruby_dyna_vars;
+      while (v) {
+        assert(TYPE(v) == T_VARMAP);
+        v = v->next;
+      }
+    }
+    var = rb_svar(0);
+    pos = 1;
     if (var) {
+    pos = 2;
 	return *var;
     }
+    pos = 3;
     return Qnil;
 }
 
Index: signal.c
===================================================================
RCS file: /src/ruby/signal.c,v
retrieving revision 1.44
diff -u -r1.44 signal.c
--- signal.c	19 May 2003 04:52:55 -0000	1.44
+++ signal.c	20 May 2003 01:58:13 -0000
@@ -730,7 +730,7 @@
     install_sighandler(SIGBUS, sigbus);
 #endif
 #ifdef SIGSEGV
-    install_sighandler(SIGSEGV, sigsegv);
+    /*install_sighandler(SIGSEGV, sigsegv);*/
 #endif
 #ifdef SIGPIPE
     install_sighandler(SIGPIPE, sigpipe);
-- 
[田中 哲][たなか あきら][Tanaka Akira]

In This Thread