anyone seen this before? (long)

M

Martin Chase

--T7mxYSe680VjQnyC
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
Content-Transfer-Encoding: quoted-printable

i haven't been able to get a very minimal reproduction for this,
so i don't expect much in-depth input,
it's just this looks like something happening deep inside eval.c or
maybe a problem with how Test::Unit evaluates things,
and i could only get so far in my investigations.

so i'm playing around with some acceptance test scripts for good ole
FaerieMUD,
running ruby 1.8.2 (2004-08-24) [i686-linux] on a linux box
(Linux galendril.FaerieMUD.org 2.4.22 #4 SMP Thu Sep 25 13:34:22 MDT
2003 i686 unknown).
the script has a MUES server in one thread,
set up outside of the Test::Unit::TestCase subclass definition,
and then a telnet connection to that is made in the main thread during
one of the tests (relevant source included below).
at any point after the telnet connection is made,
if the server attempts to write a log message
(which it is doing constantly),
i get a seg fault.
it looks like:

valgrind's output:

=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
=2E..server started
Loaded suite acceptance/01_the_game_world.tests
Started
attempting to connect...
=3D=3D6585=3D=3D
=3D=3D6585=3D=3D Invalid read of size 4
=3D=3D6585=3D=3D at 0x4028AD1A: scope_dup (eval.c:7723)
=3D=3D6585=3D=3D by 0x402877BE: eval (eval.c:6140)
=3D=3D6585=3D=3D by 0x40287A3E: rb_f_eval (eval.c:6227)
=3D=3D6585=3D=3D by 0x402933C6: call_cfunc (eval.c:5401)
=3D=3D6585=3D=3D Address 0x14 is not stack'd, malloc'd or free'd
=2E./MUES/lib/mues/logger/outputter.rb:97: [BUG] Segmentation fault
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D

or gdb's:

=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
=2E..server started
Loaded suite acceptance/01_the_game_world.tests
Started
attempting to connect...

Program received signal SIGSEGV, Segmentation fault.
0x4005fd1d in scope_dup (scope=3D0x4) at eval.c:7723
7723 scope->flags |=3D SCOPE_DONT_RECYCLE;
(gdb) bt
#0 0x4005fd1d in scope_dup (scope=3D0x4) at eval.c:7723
#1 0x4005c7be in eval (self=3D1078829524, src=3D1079669984, scope=3D107967=
0584,=20
file=3D0x808b381 "../MUES/lib/mues/logger/outputter.rb", line=3D97) at =
eval.c:6141
#2 0x4005ca3e in rb_f_eval (argc=3D2, argv=3D0x4, self=3D1076749188) at ev=
al.c:6235
#3 0x400683c6 in call_cfunc (func=3D0x4005c950 <rb_f_eval>, recv=3D1076749=
188, len=3D4, argc=3D0, argv=3D0xbffe7a48) at eval.c:5401
=2E..(200 more frames)
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D


i can get rid of the seg fault a number of ways:
* run the tests under MacOSX
* run the server as a separate process
* make an initial connection out from inside of the TestCase subclass
(described later)
* or do the following:


here's where the seg fault is happening,
in mues/logger/outputter.rb:

=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
def write( time, level, name, frame, msg )
msg =3D @format.interpolate( binding )
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D


@format being something like '#{level}: #{name} happened at #{time}'
interpolate is defined in mues/utils.rb:

=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
class String
def interpolate( scope )
copy =3D self.gsub( /"/, %q:\": )
eval( '"' + copy + '"', scope )
rescue Exception =3D> err
nicetrace =3D err.backtrace.find_all {|frame|
/in `(interpolate|eval)'/i !~ frame
}
Kernel::raise( err, err.message, nicetrace )
end
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D


now if i change outputter.rb to:

=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
def write( time, level, name, frame, msg )
msg =3D eval( '"' + @format.gsub( /"/, %q:\": ) + '"', binding)
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D


the seg fault persists.
however, a change to:

=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
def write( time, level, name, frame, msg )
msg =3D eval( '"' + @format.gsub( /"/, %q:\": ) + '"')
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D


prevents it!
not passing the binding explicitly is fine for having this evaled in
the right scope,
so this doesn't really alter any behavior.
fixing it this way is what leaves me feeling the most bizarre,
and of the mind that the rest of the world might want to look at it.


oh,
at the other end of things,
the test script says:

=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
#...
$server.start(LOGINS)
STDERR.puts "...server started"


class TheGameWorld < Test::Unit::TestCase

def test_01_running_server
STDERR.puts "attempting to connect..."
connection =3D nil
assert_nothing_raised { connection =3D $server.connect }
assert connection
STDERR.puts "...connection made"
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D


"...connection made" is never printed, of course.

changing it to:

=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
#...
$server.start(LOGINS)
STDERR.puts "...server started"
STDERR.puts "attempting to connect..."
connection =3D $server.connect
STDERR.puts "...connection made"
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D


is also a way to prevent the seg fault,
so Test::Unit probly has something to do with how things break,
but just moving the connection =3D $server.connect outside of the
assert_nothing_raised block (but still in the method) will not fix
things.


also,
for reference sake,
eval.c has:

=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
6140 for (tag=3Dprot_tag; tag; tag=3Dtag->prev) {
*6141* scope_dup(tag->scope);
6142 }

=2E..

7716 static void
7717 scope_dup(scope)
7718 struct SCOPE *scope;
7719 {
7720 ID *tbl;
7721 VALUE *vars;
7722 =20
*7723* scope->flags |=3D SCOPE_DONT_RECYCLE;
7724 if (scope->flags & SCOPE_MALLOC) return;
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D


at time of seg fault,
the scope being passed to scope_dup is a value of 4.
prot_tag is a global variable all over the place in eval.c,
but not one i really understood.

murr,
- martin chase, the FaerieMUD consortium

--T7mxYSe680VjQnyC
Content-Type: application/pgp-signature
Content-Disposition: inline

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.2.4 (GNU/Linux)

iD8DBQFBNgmkNkwFbWPhZdERAuqpAJ9KgqTzURKk9N6Hb4kVgpSw0v8QnACeOM84
gVqkGK0XcPmtCCeqhLilfck=
=hwFA
-----END PGP SIGNATURE-----

--T7mxYSe680VjQnyC--
 
T

ts

M> i haven't been able to get a very minimal reproduction for this,
M> so i don't expect much in-depth input,

If you use a C extension, verify it and don't search the bug in ruby.


Guy Decoux
 

Ask a Question

Want to reply to this thread or ask your own question?

You'll need to choose a username for the site, which only take a couple of moments. After that, you can post your question and our members will help you out.

Ask a Question

Members online

No members online now.

Forum statistics

Threads
473,744
Messages
2,569,484
Members
44,903
Latest member
orderPeak8CBDGummies

Latest Threads

Top