[Date Prev][Date Next] [Thread Prev][Thread Next] [Date Index] [Thread Index]

Re: Bug#673594: ruby1.8: FTBFS[kfreebsd-*]: test-all hangs/segfaults



Whereas the buildds experience hangs during some tests, I see segfaults
instead.  This sometimes happens even before the first test has been run.

This small Ruby testcase results in segfault 50% of the time under
ruby1.8 1.8.7.358-2, but always succeeds with ruby1.9.1 1.9.3.0-2:

> require 'thread'
> Thread.new do
>     foo = "bar"
> end

(Measured out of 100 runs, on kfreebsd-i386 with 4-way SMP)

Attached are outputs from ktrace for a success and from a failure;  then
I've tried to diff them.  There seems to be a race whereby thread0 tries
to call thr_kill on thread2, but if that happens too late thread2 will
trigger a segfault instead.

Regards,
-- 
Steven Chamberlain
steven@pyro.eu.org
--- ok.txt	2012-05-20 20:56:17.734917958 +0100
+++ fail.txt	2012-05-20 20:58:12.337235026 +0100
@@ -356,7 +356,7 @@
 <thread0> ruby1.8  RET   open 3
 <thread0> ruby1.8  CALL  read(0x3,0xbfbfe61c,0x4)
 <thread0> ruby1.8  GIO   fd 3 read 4 bytes
-     0x0000 f0be 5f81                                                                                                      |.._.|
+     0x0000 d52b 6642                                                                                                      |.+fB|
 
 <thread0> ruby1.8  RET   read 4
 <thread0> ruby1.8  CALL  close(0x3)
@@ -411,7 +411,7 @@
 <thread0> ruby1.8  CALL  gettimeofday(0xbfbfe5b8,0)
 <thread0> ruby1.8  RET   gettimeofday 0
 <thread0> ruby1.8  CALL  getpid
-<thread0> ruby1.8  RET   getpid 50320/0xc490
+<thread0> ruby1.8  RET   getpid 50346/0xc4aa
 <thread0> ruby1.8  CALL  break(0x808d000)
 <thread0> ruby1.8  RET   break 0
 <thread0> ruby1.8  CALL  sigaction(SIGINT,0xbfbfe564,0xbfbfe5b8)
@@ -750,65 +750,49 @@
 <thread2> ruby1.8  RET   sigprocmask 0
 <thread2> ruby1.8  CALL  clock_gettime(0,0x28b68eb8)
 <thread2> ruby1.8  RET   clock_gettime 0
+<thread2> ruby1.8  CALL  sigprocmask(SIG_SETMASK,0x28b68e90,0)
+<thread2> ruby1.8  RET   sigprocmask 0
+<thread2> ruby1.8  CALL  clock_gettime(0,0x28b68f30)
+<thread2> ruby1.8  RET   clock_gettime 0
+<thread2> ruby1.8  CALL  sigprocmask(SIG_BLOCK,0,0x28b68e80)
+<thread2> ruby1.8  RET   sigprocmask 0
+<thread0> ruby1.8  PSIG  SIGSEGV caught handler=0x2818ba50 mask=0x80000000 code=0x1
+<thread2> ruby1.8  CALL  sigprocmask(SIG_UNBLOCK,0x28b68ea0,0x28b68e90)
+<thread2> ruby1.8  RET   sigprocmask 0
+<thread0> ruby1.8  CALL  write(0x2,0xbfbfbf9c,0xb)
+<thread2> ruby1.8  CALL  clock_gettime(0,0x28b68eb8)
+<thread2> ruby1.8  RET   clock_gettime 0
+<thread0> ruby1.8  GIO   fd 2 wrote 11 bytes
+     "test.rb:4: "
 <thread2> ruby1.8  CALL  nanosleep(0x28b68eb0,0)
-<thread0> ruby1.8  CALL  thr_kill(<thread2>,SIG(null))
-<thread0> ruby1.8  RET   thr_kill 0
-<thread2> ruby1.8  RET   nanosleep -1 errno 4 Interrupted system call
-<thread0> ruby1.8  CALL  sigprocmask(SIG_SETMASK,0,0xbfbfdc4c)
-<thread2> ruby1.8  PSIG  SIG(null) caught handler=0x28188860 mask=0x7ffefeff code=0x10001
+<thread0> ruby1.8  RET   write 11/0xb
+<thread2> ruby1.8  RET   nanosleep -1 errno 22 Invalid argument
+<thread0> ruby1.8  CALL  write(0x2,0x2813751f,0x6)
+<thread2> ruby1.8  CALL  clock_gettime(0,0x28b68eb8)
+<thread0> ruby1.8  GIO   fd 2 wrote 6 bytes
+     "[BUG] "
+<thread2> ruby1.8  RET   clock_gettime 0
+<thread0> ruby1.8  RET   write 6
+<thread2> ruby1.8  CALL  nanosleep(0x28b68eb0,0)
+<thread2> ruby1.8  RET   nanosleep -1 errno 22 Invalid argument
+<thread0> ruby1.8  CALL  write(0x2,0xbfbf98a0,0x12)
+<thread2> ruby1.8  CALL  clock_gettime(0,0x28b68eb8)
+<thread0> ruby1.8  GIO   fd 2 wrote 18 bytes
+     "Segmentation fault"
+<thread2> ruby1.8  RET   clock_gettime 0
+<thread0> ruby1.8  RET   write 18/0x12
+<thread2> ruby1.8  CALL  nanosleep(0x28b68eb0,0)
+<thread0> ruby1.8  CALL  write(0x2,0xbfbf98a0,0x3d)
+<thread0> ruby1.8  GIO   fd 2 wrote 61 bytes
+     "
+(2012-02-08 patchlevel 358) [i486-kfreebsd-gnu]
+	
+     "
+<thread0> ruby1.8  RET   write 61/0x3d
+<thread0> ruby1.8  CALL  sigprocmask(SIG_UNBLOCK,0xbfbfbf50,0)
 <thread0> ruby1.8  RET   sigprocmask 0
-<thread2> ruby1.8  CALL  sigprocmask(SIG_SETMASK,0x28b68e80,0)
-<thread0> ruby1.8  CALL  sigsuspend(0xbfbfdc4c)
-<thread2> ruby1.8  RET   sigprocmask 0
-<thread2> ruby1.8  CALL  thr_kill(<thread0>,SIG(null))
-<thread2> ruby1.8  RET   thr_kill 0
-<thread0> ruby1.8  PSIG  SIG(null) caught handler=0x28188860 mask=0x80000000 code=0x10001
-<thread2> ruby1.8  CALL  thr_kill(<thread1>,SIG(null))
-<thread0> ruby1.8  RET   sigsuspend JUSTRETURN
-<thread2> ruby1.8  RET   thr_kill 0
-<thread0> ruby1.8  CALL  sigreturn(0xbfbfd930)
+<thread0> ruby1.8  CALL  thr_kill(<thread0>,SIGIOT)
+<thread0> ruby1.8  RET   thr_kill 0
+<thread0> ruby1.8  PSIG  SIGIOT SIG_DFL code=0x10001
 <thread1> ruby1.8  RET   poll -1 errno 4 Interrupted system call
-<thread0> ruby1.8  RET   sigreturn JUSTRETURN
-<thread1> ruby1.8  PSIG  SIG(null) caught handler=0x28188710 mask=0xfffefeef code=0x10001
-<thread2> ruby1.8  CALL  thr_exit(0x807c1c0)
-<thread0> ruby1.8  CALL  write(0x4,0xbfbfdc8c,0x24)
-<thread1> ruby1.8  CALL  sigreturn(0x807a850)
-<thread0> ruby1.8  GIO   fd 4 wrote 36 bytes
-     0x0000 a01a 3328 0100 0000 0204 0000 44a1 0e00 0060 0828 bc2a 1828 70fd 1628 d0d5 1728 e0dc bfbf                      |..3(........D....`.(.*.(p..(...(....|
-
-<thread1> ruby1.8  RET   sigreturn JUSTRETURN
-<thread0> ruby1.8  RET   write 36/0x24
-<thread1> ruby1.8  CALL  poll(0x807ac34,0x1,0x7d0)
-<thread1> ruby1.8  RET   poll 1
-<thread0> ruby1.8  CALL  sigaction(SIGINT,0xbfbfe548,0xbfbfe59c)
-<thread1> ruby1.8  CALL  read(0x3,0x807ac00,0x24)
-<thread0> ruby1.8  RET   sigaction 0
-<thread1> ruby1.8  GIO   fd 3 read 36 bytes
-     0x0000 a01a 3328 0100 0000 0204 0000 44a1 0e00 0060 0828 bc2a 1828 70fd 1628 d0d5 1728 e0dc bfbf                      |..3(........D....`.(.*.(p..(...(....|
-
-<thread0> ruby1.8  CALL  write(0x4,0xbfbfe5ec,0x24)
-<thread1> ruby1.8  RET   read 36/0x24
-<thread0> ruby1.8  GIO   fd 4 wrote 36 bytes
-     0x0000 a01a 3328 0200 0000 0000 0000 d85f 0628 0100 0000 0080 1a28 0500 0000 a0e5 bfbf 2800 0000                      |..3(........._.(.......(........(...|
-
-<thread1> ruby1.8  CALL  munmap(0x28369000,0x800000)
-<thread0> ruby1.8  RET   write 36/0x24
-<thread0> ruby1.8  CALL  sigprocmask(SIG_SETMASK,0,0xbfbfe580)
-<thread1> ruby1.8  RET   munmap 0
-<thread0> ruby1.8  RET   sigprocmask 0
-<thread1> ruby1.8  CALL  poll(0x807ac34,0x1,0x7d0)
-<thread0> ruby1.8  CALL  sigsuspend(0xbfbfe580)
-<thread1> ruby1.8  RET   poll 1
-<thread1> ruby1.8  CALL  read(0x3,0x807ac00,0x24)
-<thread1> ruby1.8  GIO   fd 3 read 36 bytes
-     0x0000 a01a 3328 0200 0000 0000 0000 d85f 0628 0100 0000 0080 1a28 0500 0000 a0e5 bfbf 2800 0000                      |..3(........._.(.......(........(...|
-
-<thread1> ruby1.8  RET   read 36/0x24
-<thread1> ruby1.8  CALL  thr_kill(<thread0>,SIG(null))
-<thread1> ruby1.8  RET   thr_kill 0
-<thread0> ruby1.8  PSIG  SIG(null) caught handler=0x28188860 mask=0x80000000 code=0x10001
-<thread1> ruby1.8  CALL  thr_exit(0x807b6c0)
-<thread0> ruby1.8  RET   sigsuspend JUSTRETURN
-<thread0> ruby1.8  CALL  sigreturn(0xbfbfe260)
-<thread0> ruby1.8  RET   sigreturn JUSTRETURN
-<thread0> ruby1.8  CALL  exit(0)
+<thread2> ruby1.8  RET   nanosleep -1 errno 4 Interrupted system call

Attachment: ok.txt.gz
Description: application/gzip

Attachment: fail.txt.gz
Description: application/gzip


Reply to: