nasty vim crash

[talek]

Hi,

Can anybody lead me to the right path for debugging the following
crash? I have the last vim 7.3 (with all patches applied), compiled
with ruby 1.8 support. From time to time my vim crashes with:

Vim: Caught deadly signal VTALRM
Vim: Finished.
Virtual timer expired

With the following script I think I found a way to reproduce this:

talek@talek-desktop:~/crash$ cat crash.vim
ruby <<EOF
require 'pty'
$reader, $writer, $pid = PTY.spawn('ls -al')
EOF

while 1
silent !ls -al
endwhile

talek@talek-desktop:~/crash$ vim -u NONE -c 'source crash.vim'

I can't figure out if this is a ruby issue, a vim problem or both.
I've tried with various ruby 1.8.7 patched versions and I've ended up
trying with ruby enterprise 1.8.7-2010.02 for Ubuntu, which has the
same issue. A similar test executed just on ruby environment is
working as expected:

require 'pty'

$VERBOSE=nil

$reader, $writer, $pid = PTY.spawn('gdb')
while true
system('ls -al')
end

No crash! Does anybody have any ideas about how to go on with
debugging this?

Thanks!

[Marc Weber]

usually you compile debug versions and then run valgrind or such.
Or you try to find a old version of vim which does not suffer of this
issue.

If I run your script I see the contents of ls -l scrolling by without
crash.

Can you run

ls -al | wc -l

and report how many files are in that directory?
Maybe that makes a difference.

Can you also try sourcing the script manually after Vim has loaded?

> talek@talek-desktop:~/crash$ vim -u NONE -c 'source crash.vim'

Can you decribe shortly what happens? is ls output printed at least
once before the crash?

Marc Weber

[Alec Tica]

Hi Marc,

> usually you compile debug versions and then run valgrind or such.

I will try valgrind. I don't have any experience using this tool but
maybe something will come up.

> Or you try to find a old version of vim which does not suffer of this
> issue.

I've also tried with vim 7.2 but the results are the same.

>
> If I run your script I see the contents of ls -l scrolling by without
> crash.
>
> Can you run
>
> ls -al | wc -l
>
> and report how many files are in that directory?
> Maybe that makes a difference.

talek@talek-desktop:~/crash$ ls -al | wc -l
5

What version of vim/ruby do you have?

>
> Can you also try sourcing the script manually after Vim has loaded?
>

Yes. I've attached a strace out file for a vim process where I
manually sourced crash.vim file.

> Can you decribe shortly what happens? is ls output printed at least
> once before the crash?

Please have a look into the output.txt file.

[Sergey Khorev]

> I have the last vim 7.3 (with all patches applied), compiled
> with ruby 1.8 support. From time to time my vim crashes with:
>
> Vim: Caught deadly signal VTALRM
> Vim: Finished.
> Virtual timer expired

First step is to try without Ruby. Most probably it is Ruby that
causes the problem.
If so, VTALRM should be ignored if Vim is compiled with Ruby (like it
is done for SIGPROF and MzScheme, see os_unix.c)

[Alec Tica]

> First step is to try without Ruby. Most probably it is Ruby that
> causes the problem.

Yes, I also suspect ruby is the problem. If I'd be able to reproduce
the bug using just ruby then I can report it directly to the ruby
community. Is it something special in the way vim makes calls and
inter-connects with the ruby interpreter? Using valgrind I get:

==8072== Invalid write of size 4
==8072== at 0x823E333: ??? (in /usr/local/bin/vim)
==8072== by 0x823E967: rb_thread_create (in /usr/local/bin/vim)
==8072== by 0x733A668: pty_getpty (pty.c:442)
==8072== by 0x822F884: ??? (in /usr/local/bin/vim)
==8072== by 0x823794C: ??? (in /usr/local/bin/vim)
==8072== by 0x8237AE8: ??? (in /usr/local/bin/vim)
==8072== by 0x8241CF8: ??? (in /usr/local/bin/vim)
==8072== by 0x82357B9: ??? (in /usr/local/bin/vim)
==8072== by 0x82356D9: ??? (in /usr/local/bin/vim)
==8072== by 0x8244DC9: ??? (in /usr/local/bin/vim)
==8072== by 0x8245692: rb_eval_string (in /usr/local/bin/vim)
==8072== by 0x82312E8: rb_protect (in /usr/local/bin/vim)
==8072== Address 0xbe9f67b8 is just below the stack ptr. To
suppress, use: --workaround-gcc296-bugs=yes
==8072==

Vim: Caught deadly signal VTALRM
Vim: Finished.

==8072==
==8072== HEAP SUMMARY:
==8072== in use at exit: 2,173,158 bytes in 30,633 blocks
==8072== total heap usage: 166,041 allocs, 135,408 frees, 11,591,377
bytes allocated
==8072==
==8072== LEAK SUMMARY:
==8072== definitely lost: 10,510 bytes in 131 blocks
==8072== indirectly lost: 15,195 bytes in 760 blocks
==8072== possibly lost: 1,113,102 bytes in 14,355 blocks
==8072== still reachable: 1,034,351 bytes in 15,387 blocks
==8072== suppressed: 0 bytes in 0 blocks
==8072== Rerun with --leak-check=full to see details of leaked memory
==8072==
==8072== For counts of detected and suppressed errors, rerun with: -v
==8072== ERROR SUMMARY: 265 errors from 2 contexts (suppressed: 226 from 12)

But, I have very little experience with valgrind, gdb and other such
tools therefore I don't know if the above reveals anything useful.

--
talek

[Dominique Pellé]

Alec Tica wrote:

For valgrind info to be useful, Vim should be built without
optimizations and with symbols (to avoid the ????? in the stack).

You can build Vim with symbols with minor changes to
vim/src/Makefile:

--- a/src/Makefile Sat Jan 08 16:06:37 2011 +0100
+++ b/src/Makefile Sun Jan 16 12:00:10 2011 +0100
@@ -554,7 +554,7 @@
# Often used for GCC: mixed optimizing, lot of optimizing, debugging
#CFLAGS = -g -O2 -fno-strength-reduce -Wall -Wshadow -Wmissing-prototypes
#CFLAGS = -g -O2 -fno-strength-reduce -Wall -Wmissing-prototypes
-#CFLAGS = -g -Wall -Wmissing-prototypes
+CFLAGS = -g -O0 -Wall -Wmissing-prototypes
#CFLAGS = -O6 -fno-strength-reduce -Wall -Wshadow -Wmissing-prototypes
#CFLAGS = -g -DDEBUG -Wall -Wshadow -Wmissing-prototypes
#CFLAGS = -g -O2 '-DSTARTUPTIME="vimstartup"' -fno-strength-reduce
-Wall -Wmissing-prototypes
@@ -1855,7 +1855,7 @@
rm -f $(DEST_BIN)/$(VIMNAME).rm; \
fi
$(INSTALL_PROG) $(VIMTARGET) $(DEST_BIN)
- $(STRIP) $(DEST_BIN)/$(VIMTARGET)
+ #$(STRIP) $(DEST_BIN)/$(VIMTARGET)
chmod $(BINMOD) $(DEST_BIN)/$(VIMTARGET)
# may create a link to the new executable from /usr/bin/vi
-$(LINKIT)

I was able to reproduce the crash on Linux x86
with Vim-7.3.99 built with "libruby1.8.so" by running
a different script:

$ cat crash.vim
for i in range(1, 200)
silent !ls -al

ruby <<EOF
require 'pty'
$reader, $writer, $pid = PTY.spawn('ls -al')
EOF

endfor

$ vim -u NONE -c 'crash.vim'
...

Vim: Caught deadly signal VTALRM
Vim: Finished.

Virtual timer expired

Valgrind does not indicate any invalid memory access.
Vim just exits when receiving signal SIGVTALARM.

I'm not sure why Ruby uses SIGVTALARM but Vim
no longer exits with the attached patch.

Regards
-- Dominique

[talek]

Hi Dominique,

Thanks a lot for this patch. Indeed, it solves the unexpectedly exit
of vim when ruby is used and VTALRM signal is received. I've just made
a few tests and it's working great. I believe VTALRM signal has to do
with the way ruby implements its green threads. The crash looks like
"[Bug #2103] rev23993 causes Virtual Timer Expired when
forking" (http://www.ruby-forum.com/topic/195414) but according to
ruby-enterprise guys the bug fix is included in their last ruby
enterprise package (http://blog.phusion.nl/2009/10/26/ruby-enterprise-
edition-1-8-7-2009-10-released/). Now, the big question is: are there
any chances this patch to be included into the official vim trunk? How
a patch becomes an official one?

-- talek

[Marc Weber]

Excerpts from talek's message of Sun Jan 16 14:49:01 +0100 2011:

Hi talek, Dominique,

The patch contained:

-#ifdef SIGVTALRM
+#if defined(SIGVTALRM) && !defined(FEAT_RUBY)
+ /* Ruby uses SIGVTALARM which makes Vim exit. */
{SIGVTALRM, "VTALRM", TRUE},
#endif

My sources contain this: (note the FALSE!)

#ifdef SIGALRM
{SIGALRM, "ALRM", FALSE}, /* Perl's alarm() can trigger it */
#endif

My source version: ftp://ftp.vim.org/pub/vim/unix/vim-7.3.tar.bz2

So maybe this FALSE is the upstream fix? Which version have you both
been using?

I checked both: amd64 and i686 versions and can't reproduce the issue.

Marc Weber

[Alec Tica]

> So maybe this FALSE is the upstream fix? Which version have you both
> been using?

I've got the sources from the mercurial repository:

hg clone https://vim.googlecode.com/hg/ vim

--
talek

[Dominique Pellé]

Marc Weber wrote:

Marc

You're looking at SIGALRM, whereas the patch I sent
changed SIGVTALRM (just a few lines below).

To answer your question, I'm using latest version of Vim-7.3.99
from Mercurial (2681:85c5a72551e2).

-- Dominique

[Marc Weber]

> You're looking at SIGALRM, whereas the patch I sent
> changed SIGVTALRM (just a few lines below).
>
> To answer your question, I'm using latest version of Vim-7.3.99
> from Mercurial (2681:85c5a72551e2).

You've been right. Still using the exact same vim mercurial version I
can't reproduce the failures ?

My ruby version is: 1.8.7-p302 (unpatched)

Again I tried both x86_64 and i686 versions.

However I can confirm that Vim dies when the segnal is sent using kill.
So it looks like the signal is not sent on my system for whatever
reasons

Marc Weber

[Alec Tica]

> My ruby version is: 1.8.7-p302 (unpatched)

I've just made a test with ruby 1.8.7-p302. Unfortunately, the same
problem. Vim exits with VTALRM signal.

>
> Again I tried both  x86_64 and i686 versions.
>

hmmm... just for reference:

talek@talek-desktop:~/crash$ uname -a
Linux talek-desktop 2.6.32-21-generic #32-Ubuntu SMP Fri Apr 16
08:10:02 UTC 2010 i686 GNU/Linux
talek@talek-desktop:~/crash$ ruby -v
ruby 1.8.7 (2010-08-16 patchlevel 302) [i686-linux]

> However I can confirm that Vim dies when the segnal is sent using kill.

Is there a good reason to force vim quit when a SIGVTALRM signal is received?

> So it looks like the signal is not sent on my system for whatever
> reasons

Could be an OS issue (pthread lib or something)?

--
talek