visit_children SIGABRT

[ghazel]

Reproducible with code which is kind of long, but nests visit_children calls.

(lldb) bt
* thread #1: tid = 0x2c0a0f, 0x00007fff90e1437a libsystem_kernel.dylib`__pthread_kill + 10, queue = 'com.apple.main-thread', stop reason = signal SIGABRT
  * frame #0: 0x00007fff90e1437a libsystem_kernel.dylib`__pthread_kill + 10
    frame #1: 0x00007fff8d9be8f7 libsystem_pthread.dylib`pthread_kill + 90
    frame #2: 0x00007fff9653762b libsystem_c.dylib`abort + 129
    frame #3: 0x00000001000300f9 libruby.2.0.0.dylib`rb_bug + 185
    frame #4: 0x000000010013bb18 libruby.2.0.0.dylib`rb_thread_call_with_gvl + 99
    frame #5: 0x0000000102b559ca ffi_c.bundle`callback_invoke(cif=<unavailable>, retval=<unavailable>, parameters=<unavailable>, user_data=<unavailable>) + 372 at Function.c:479
    frame #6: 0x0000000102b5e517 ffi_c.bundle`ffi_closure_unix64_inner(closure=0x00000001002fc000, rvalue=0x00007fff5fbfe440, reg_args=0x00007fff5fbfe390, argp=0x00007fff5fbfe4a0) + 1223 at ffi64.c:629
    frame #7: 0x0000000102b5ed1e ffi_c.bundle`ffi_closure_unix64 + 70
    frame #8: 0x0000000102e0652a libclang.dylib`clang::cxcursor::CursorVisitor::Visit(CXCursor, bool) + 666
    frame #9: 0x0000000102e36066 libclang.dylib`bool clang::cxcursor::CursorVisitor::visitPreprocessedEntities<clang::PreprocessingRecord::iterator>(clang::PreprocessingRecord::iterator, clang::PreprocessingRecord::iterator, clang::PreprocessingRecord&, clang::FileID) + 438
    frame #10: 0x0000000102e0879b libclang.dylib`clang::cxcursor::CursorVisitor::visitPreprocessedEntitiesInRegion() + 923
    frame #11: 0x0000000102e07c8c libclang.dylib`clang::cxcursor::CursorVisitor::VisitChildren(CXCursor) + 1724
    frame #12: 0x0000000102e178e4 libclang.dylib`clang_visitChildren + 404
    frame #13: 0x0000000102b5eb9c ffi_c.bundle`ffi_call_unix64 + 76
    frame #14: 0x0000000102b5df19 ffi_c.bundle`ffi_call(cif=0x0000000102d49068, fn=0x0000000102e17750, rvalue=0x00007fff5fbfeed0, avalue=0x00007fff5fbfeeb0) + 1033 at ffi64.c:486
    frame #15: 0x0000000102b53650 ffi_c.bundle`rbffi_CallFunction(argc=<unavailable>, argv=<unavailable>, function=<unavailable>, fnInfo=<unavailable>) + 238 at Call.c:378
    frame #16: 0x0000000102b56f35 ffi_c.bundle`custom_trampoline(argc=<unavailable>, argv=<unavailable>, handle=<unavailable>) + 25 at MethodHandle.c:232
    frame #17: 0x0000000100135386 libruby.2.0.0.dylib`___lldb_unnamed_function2663$$libruby.2.0.0.dylib + 814
    frame #18: 0x0000000100134d67 libruby.2.0.0.dylib`___lldb_unnamed_function2662$$libruby.2.0.0.dylib + 614
    frame #19: 0x0000000100122553 libruby.2.0.0.dylib`___lldb_unnamed_function2526$$libruby.2.0.0.dylib + 11242
    frame #20: 0x000000010012d046 libruby.2.0.0.dylib`___lldb_unnamed_function2578$$libruby.2.0.0.dylib + 139
    frame #21: 0x000000010012dbc6 libruby.2.0.0.dylib`rb_iseq_eval_main + 138
    frame #22: 0x00000001000354c4 libruby.2.0.0.dylib`___lldb_unnamed_function568$$libruby.2.0.0.dylib + 128
    frame #23: 0x0000000100035415 libruby.2.0.0.dylib`ruby_run_node + 78
    frame #24: 0x0000000100000f26 ruby`main + 79
    frame #25: 0x00007fff9bf265c9 libdyld.dylib`start + 1

[ghazel]

One time it said:

lib/ffi/clang/cursor.rb:242: [BUG] rb_thread_call_with_gvl: called by a thread which has GVL.

[ioquatix]

Seems like some issue with threads and the global VM lock (GVL). Are you using threads?

[ghazel]

Nope, no threads.

[ioquatix]

If possible are you able to produce a failing spec?

[ghazel]

Currently the repro is 100 lines. Maybe “return”ing in the middle of a visit_children block is bad?

[ioquatix]

It shouldn't be but because it is a FFI callback perhaps there is some limitation on how FFI works. Can you try turning the return into some kind of state capture, e.g.

visit_children do
    return blah
end

becomes

result = nil

visit_children do
    result ||= blah
end

return result

[ioquatix]

See the second to last comment here: ffi/ffi#241

I wonder if that might help?

[ghazel]

State capture works to avoid the bug.

[ioquatix]

Okay, looks like perhaps some issue with how we are using FFI. If possible can you try editing the ffi-clang function in your installed gem, and add :blocking => true to the attach function for visit_children and see if that fixes the issue? I'm currently at work and can't do much until later tonight so if you could check this that would be great.

[ghazel]

Adding :blocking => true to attach_function :visit_children, ... makes the same crash occur much more quickly:

/Library/Ruby/Gems/2.0.0/gems/ffi-clang-0.2.0/lib/ffi/clang/cursor.rb:242: [BUG] rb_thread_call_with_gvl: called by a thread which has GVL.
ruby 2.0.0p451 (2014-02-24 revision 45167) [universal.x86_64-darwin14]

-- Crash Report log information --------------------------------------------
   See Crash Report log file under the one of following:
     * ~/Library/Logs/CrashReporter
     * /Library/Logs/CrashReporter
     * ~/Library/Logs/DiagnosticReports
     * /Library/Logs/DiagnosticReports
   the more detail of.

-- Control frame information -----------------------------------------------
c:0004 p:---- s:0021 e:000020 CFUNC  :visit_children
c:0003 p:0032 s:0015 E:0020d8 METHOD /Library/Ruby/Gems/2.0.0/gems/ffi-clang-0.2.0/lib/ffi/clang/cursor.rb:242
c:0002 p:0184 s:0010 E:000e48 EVAL   foo.rb:42 [FINISH]
c:0001 p:0000 s:0002 E:0012c8 TOP    [FINISH]

foo.rb:42:in `<main>'
/Library/Ruby/Gems/2.0.0/gems/ffi-clang-0.2.0/lib/ffi/clang/cursor.rb:242:in `visit_children'
/Library/Ruby/Gems/2.0.0/gems/ffi-clang-0.2.0/lib/ffi/clang/cursor.rb:242:in `visit_children'

-- C level backtrace information -------------------------------------------
0   libruby.2.0.0.dylib                 0x00000001001364c2 rb_vm_bugreport + 135
1   libruby.2.0.0.dylib                 0x000000010003021a rb_bug + 474
2   libruby.2.0.0.dylib                 0x00000001000300f4 rb_bug + 180
3   libruby.2.0.0.dylib                 0x000000010013bb18 rb_thread_call_with_gvl + 99
4   ffi_c.bundle                        0x000000010026c9ca callback_invoke + 372
5   ffi_c.bundle                        0x0000000100275517 ffi_closure_unix64_inner + 1223
6   ffi_c.bundle                        0x0000000100275d1e ffi_closure_unix64 + 70
7   libclang.dylib                      0x0000000102836066 _ZN5clang8cxcursor13CursorVisitor25visitPreprocessedEntitiesINS_19PreprocessingRecord8iteratorEEEbT_S5_RS3_NS_6FileIDE + 438
8   libclang.dylib                      0x000000010280879b _ZN5clang8cxcursor13CursorVisitor33visitPreprocessedEntitiesInRegionEv + 923
9   libclang.dylib                      0x0000000102807c8c _ZN5clang8cxcursor13CursorVisitor13VisitChildrenE8CXCursor + 1724
10  libclang.dylib                      0x00000001028178e4 clang_visitChildren + 404
11  ffi_c.bundle                        0x0000000100275b9c ffi_call_unix64 + 76
12  ???                                 0x00007fff5fbfeed0 0x0 + 140734799802064

[ghazel]

Maybe related? Found while trying to debug this; #34

[ioquatix]

Is this similar to what is causing the crash? Because it seems to work fine.

#!/usr/bin/env ruby

ENV['LLVM_CONFIG'] = 'llvm-config-mp-3.4'

# gem install ffi-clang
require 'ffi/clang'

def get_symbol
    File.write('foo.c', "int main(){}")

    index = FFI::Clang::Index.new
    translation_unit = index.parse_translation_unit('foo.c', nil, [], opts={:detailed_preprocessing_record => true})
    p "start"
    translation_unit.cursor.visit_children do |cursor, parent|
        return [cursor.kind, cursor.spelling]
    end
ensure
    p "done"
end

puts get_symbol.inspect

[ghazel]

Here's a small(ish) example which reproduces it (yes, it's a nonsense example, but I was just cutting bits out to make it short):

ENV['LIBCLANG'] = `xcode-select --print-path`.chomp + '/Toolchains/XcodeDefault.xctoolchain/usr/lib/libclang.dylib'
require 'ffi/clang'

# get the default include paths
o = `clang -E -x c - -v 2>&1 < /dev/null`
m = o.match(/\> search starts here\:\n(.*)\nEnd of search list/m)
l = m[1].split("\n")
l.reject!{|s| s =~ /framework directory/ }
$CLANG_ARGS = l.map{|s| "-I#{s.strip}" }

def inner
  File.write('foo2.c', "int x = 0;")
  index = FFI::Clang::Index.new
  translation_unit = index.parse_translation_unit('foo2.c', [])
  translation_unit.cursor.visit_children do |cursor, parent|
    return cursor.type.spelling
  end
end

index = FFI::Clang::Index.new(false, true)

File.write('foo.h', "#include <sys/socket.h>")
translation_unit = index.parse_translation_unit('foo.h', $CLANG_ARGS, [], opts={:detailed_preprocessing_record => true})
translation_unit.cursor.visit_children do |cursor, parent|
  p [cursor.spelling, inner]
  next :recurse
end

[ioquatix]

Are you able to test this again with the latest 0.5 release?