debuginfo-lldb tests crash in OS X 10.11 / Xcode 7.3

[sophiajt]

With a recent OS X/Xcode (here I'm using OS X 10.11.4 and Xcode 7.3), running the debuginfo-lldb tests results in a crash, even when using the system python install.

The crash pops up a window with an error: Python quit unexpectedly while using the _lldb.so plug-in.

---- [debuginfo-lldb] debuginfo-lldb/associated-types.rs stdout ----
    NOTE: compiletest thinks it is using LLDB version 350

error: Error while running LLDB
status: signal: 11
command: "/usr/bin/python2.7" "/Users/jturner/Source/borrowcksnip/rust/src/etc/lldb_batchmode.py" "x86_64-apple-darwin/test/debuginfo-lldb/associated-types.stage1-x86_64-apple-darwin" "x86_64-apple-darwin/test/debuginfo-lldb/associated-types.debugger.script"
stdout:
------------------------------------------
LLDB batch-mode script
----------------------
Debugger commands script is 'x86_64-apple-darwin/test/debuginfo-lldb/associated-types.debugger.script'.
Target executable is 'x86_64-apple-darwin/test/debuginfo-lldb/associated-types.stage1-x86_64-apple-darwin'.
Current working directory is '/Users/jturner/Source/borrowcksnip/rust'
Creating a target for 'x86_64-apple-darwin/test/debuginfo-lldb/associated-types.stage1-x86_64-apple-darwin'
settings set auto-confirm true

version
lldb-350.0.21.3 
command script import /Users/jturner/Source/borrowcksnip/rust/./src/etc/lldb_rust_formatters.py
type summary add --no-value --python-function lldb_rust_formatters.print_val -x ".*" --category Rust
type category enable Rust

breakpoint set --file 'associated-types.rs' --line 108
Breakpoint 1: where = associated-types.stage1-x86_64-apple-darwin`associated_types::assoc_struct::h4341f3f2e118615c + 27, address = 0x0000000100000a1b 
breakpoint set --file 'associated-types.rs' --line 115
Breakpoint 2: where = associated-types.stage1-x86_64-apple-darwin`associated_types::assoc_local::ha6fb01c9f512d9e5 + 52, address = 0x0000000100000ab4 
breakpoint set --file 'associated-types.rs' --line 119
Breakpoint 3: where = associated-types.stage1-x86_64-apple-darwin`associated_types::assoc_arg::h539559d4f7c8d367 + 16, address = 0x0000000100000ad0 
breakpoint set --file 'associated-types.rs' --line 127
Breakpoint 4: where = associated-types.stage1-x86_64-apple-darwin`associated_types::assoc_tuple::hf722967e21a7aab9 + 27, address = 0x0000000100000b2b 
breakpoint set --file 'associated-types.rs' --line 134
Breakpoint 5: where = associated-types.stage1-x86_64-apple-darwin`associated_types::assoc_enum::hcb7af09daa207720 + 98, address = 0x0000000100000ba2 
breakpoint set --file 'associated-types.rs' --line 137
Breakpoint 6: where = associated-types.stage1-x86_64-apple-darwin`associated_types::assoc_enum::hcb7af09daa207720 + 125, address = 0x0000000100000bbd 
run
Hit breakpoint 1.1: where = associated-types.stage1-x86_64-apple-darwin`associated_types::assoc_struct::h4341f3f2e118615c + 27, address = 0x0000000100000a1b, resolved, hit count = 1 
Process 24928 stopped * thread #1: tid = 0xea91e, 0x0000000100000a1b associated-types.stage1-x86_64-apple-darwin`associated_types::assoc_struct::h4341f3f2e118615c + 27 at associated-types.rs:108, queue = 'com.apple.main-thread', stop reason = breakpoint 1.1 frame #0: 0x0000000100000a1b associated-types.stage1-x86_64-apple-darwin`associated_types::assoc_struct::h4341f3f2e118615c + 27 at associated-types.rs:108 105 } 106 107 fn assoc_struct<T: TraitWithAssocType>(arg: Struct<T>) { -> 108 zzz(); // #break 109 } 110 111 fn assoc_local<T: TraitWithAssocType>(x: T) { Process 24928 launched: '/Users/jturner/Source/borrowcksnip/rust/x86_64-apple-darwin/test/debuginfo-lldb/associated-types.stage1-x86_64-apple-darwin' (x86_64) 
print arg
continue
Hit breakpoint 2.1: where = associated-types.stage1-x86_64-apple-darwin`associated_types::assoc_local::ha6fb01c9f512d9e5 + 52, address = 0x0000000100000ab4, resolved, hit count = 1 
print inferred
print explicitly
continue
Hit breakpoint 3.1: where = associated-types.stage1-x86_64-apple-darwin`associated_types::assoc_arg::h539559d4f7c8d367 + 16, address = 0x0000000100000ad0, resolved, hit count = 1 
print arg
continue
Hit breakpoint 4.1: where = associated-types.stage1-x86_64-apple-darwin`associated_types::assoc_tuple::hf722967e21a7aab9 + 27, address = 0x0000000100000b2b, resolved, hit count = 1 
print arg
continue
Hit breakpoint 5.1: where = associated-types.stage1-x86_64-apple-darwin`associated_types::assoc_enum::hcb7af09daa207720 + 98, address = 0x0000000100000ba2, resolved, hit count = 1 
print a
print b
continue
Hit breakpoint 6.1: where = associated-types.stage1-x86_64-apple-darwin`associated_types::assoc_enum::hcb7af09daa207720 + 125, address = 0x0000000100000bbd, resolved, hit count = 1 
print a
print b
continue
quit


------------------------------------------
stderr:
------------------------------------------

------------------------------------------

thread '[debuginfo-lldb] debuginfo-lldb/associated-types.rs' panicked at 'explicit panic', /Users/jturner/Source/borrowcksnip/rust/src/compiletest/runtest.rs:1613
note: Run with `RUST_BACKTRACE=1` for a backtrace.


failures:
    [debuginfo-lldb] debuginfo-lldb/associated-types.rs

[alexcrichton]

I was also getting this recently, and I have no idea what's going on here unfortunately. We haven't gotten lots of reports about this so presumably it's only because of recent versions of XCode/OSX/python/etc.

I managed to reduce this to:

import lldb                                                          
debugger = lldb.SBDebugger.Create()                                  
target_error = lldb.SBError()                                        
target = debugger.CreateTarget('foo', None, None, True, target_error)

That small script crashes for me, albeit I'm not sure why. @michaelwoerister perhaps the LLDB API changed recently and we're doing something to trigger a bug? Do you have some docs where the original bindings were written from that we could perhaps reference as well?

[michaelwoerister]

Do you have some docs where the original bindings were written from that we could perhaps reference as well?

I mostly pieced it together from the examples provided in LLDB's source code and from the API Docs (although those never get updated it seems: "Generated by Epydoc 3.0.1 on Fri Jul 19 13:22:33 2013").

[jasonmolenda]

Seems to work for a do-nothing C program. How is it crashing?

% cat >a.c
int main () { }
% clang a.c
% setenv PYTHONPATH /Applications/Xcode.app/Contents/SharedFrameworks/LLDB.framework/Resources/Python/
% python
Python 2.7.10 (default, Oct 23 2015, 19:19:21) 
[GCC 4.2.1 Compatible Apple LLVM 7.0.0 (clang-700.0.59.5)] on darwin
Type "help", "copyright", "credits" or "license" for more information.
>>> import lldb
>>> debugger = lldb.SBDebugger.Create()
>>> target_error = lldb.SBError()
>>> target = debugger.CreateTarget('a.out', None, None, True, target_error)
>>> print target.IsValid()
True
>>> print debugger.GetVersionString()
lldb-350.0.21.3
>>> 

[jasonmolenda]

One thing to note is that lldb-350.0.21.3 (from Xcode 7.3) was branched off of the llvm.org sources circa mid-May 2015. If the tests depend on anything added after that, the Apple-distributed lldb 7.x series isn't going to work.

[alexcrichton]

@jasonmolenda weird! So I've got the same lldb/xcode version as you, and also all the same versions as @jonathandturner mentions, and I can also reproduce. The snippet you pasted also works for me, but the segfault happens when I exit python (same as @jonathandturner mentioned).

Does the segfault not happen for you?

[jasonmolenda]

Ah, I know what's going on. You need to add a call to debugger.Terminate() before you end your session. There's some problem with the order all the destructors are run if you just exit lldb without calling SBDebugger:Terminate() - this is needed now.

[alexcrichton]

Aha perfect! That does indeed make the segfault go away, thanks @jasonmolenda! Now it just appears that print foo isn't actually printing anything. The rabbit hole goes further...

[jasonmolenda]

Good luck. For what it's worth, it's more stable to use lldb via the SB API instead of sending raw command line commands to it (SBTarget::EvaulateExpression or the better SBFrame::EvaluateExpression). It's a little daunting at first to figure out "how do I get lldb to do X" via the API but you don't have to deal with parsing output (& keeping the regexps up-to-date) once you do it that way.

[alexcrichton]

Hm I'll admit to not knowing much about this area (@michaelwoerister is our resident expert on these scripts), but out current script I think is using the SB API (it at least looks like it isn't doing much parsing).

So specifically what's happening is that the tests are still failing for me. The failure looks the same as what @jonathandturner pasted above, except the first line about "error running LLDB" is instead:

error: line not found in debugger output: [...]$0 = Struct<i32> { b: -1, b1: 0 }

It looks like all of the print foo variable requests aren't actually printing anything here. Poking around the lldb.SBCommandReturnObject looks like there's not much in there as well.

Not entirely sure what's going on...

[jasonmolenda]

% cat >a.c
int main ()
{  
  int foo = 5;
  foo++; // break here
}
% clang -g a.c
% setenv PYTHONPATH /Applications/Xcode.app/Contents/SharedFrameworks/LLDB.framework/Resources/Python/
% python
>>> import lldb
>>> debugger = lldb.SBDebugger.Create()
>>> target_error = lldb.SBError()
>>> target = debugger.CreateTarget('a.out', None, None, True, target_error)
>>> srcfile = lldb.SBFileSpec("a.c")
>>> bp = target.BreakpointCreateBySourceRegex("break here", srcfile)
>>> debugger.SetAsync(False)
>>> process = target.LaunchSimple ([], [], ".")
>>> print process.IsValid()
True

>>> frame = process.GetSelectedThread().GetFrameAtIndex(0)
>>> print frame
frame #0: 0x0000000100973fad a.out`main + 13 at a.c:4
>>> print bp
SBBreakpoint: id = 1, source regex = "break here", exact_match = 0, locations = 1
>>> print bp.GetHitCount()
1
>>> 

We can create an SBValue for the local variable in this frame:

>>> var = frame.GetValueForVariablePath("foo")
>>> print var
(int) foo = 5
>>> print var.GetTypeName()
int
>>> print var.GetValue()
5
>>> print var.GetName()
foo
>>> 

Or we can evaluate an arbitrary expression in the context of this frame (e.g. "foo+10" would work just as well) and get that back as an SBValue object.

>>> expr = frame.EvaluateExpression("foo")
>>> print expr
(int) $0 = 5
>>> print expr.GetTypeName()
int
>>> print expr.GetValue()
5
>>> 

Or we can use HandleCommand which is what the script is doing.

>>> commandinterp = debugger.GetCommandInterpreter()
>>> returnobj = lldb.SBCommandReturnObject()
>>> print commandinterp.HandleCommand ("p foo", returnobj)
2
>>> print returnobj
Status:  Success
Output Message:
(int) $0 = 5
>>> print returnobj.Succeeded()
True
>>> print returnobj.GetOutput()
(int) $0 = 5
>>>

for this trivial example, it seems like everything is working as expected.

(btw this is what I meant by "sending lldb command line commands" vrs "using the SB API" - using HandleCommand() gets you back a raw text string. Using native SB API like SBTarget::BreakpointCreateBySourceRegex or SBFrame::GetValueForVariablePath get you back an object that you can query/use via methods that the object supports. Xcode does all of its debugger support through the SB API. About the only thing it needs to use HandleCommand for is the "settings" series of commands - that hasn't been codified in SB API yet.)

[alexcrichton]

Aha! Thanks for the pointers @jasonmolenda! Sounds like we have a rewrite of our script on the horizon for us.

[jasonmolenda]

Sounds like that could be a lot of work. ;) mostly I wanted to point in the direction of Best Practices for scripting lldb.

For what it's worth, when I'm working with SB objects, the way I usually use the docs is to have a command line lldb session open in a window and I'm doing things like 'script help (lldb.SBFrame)' etc which dumps the python documentation string for the SBFrame class. The docs on the website were last updated a long time ago - they should still be accurate (we don't have a deprecation mechanism for removing API) but they're definitely not inclusive for newer commands/methods.

[michaelwoerister]

Thanks for all the helpful information, @jasonmolenda!

The thinking behind using the SB object API as little as possible, was that we wanted to stay as close as possible to the command line interface a user would be interacting with, so that our tests gave some measure of the actual user experience.
We'll need to take a look now whether debugging Rust programs manually doesn't work with these newer versions of LLDB either. If it doesn't, there's something wrong with the DWARF we are emitting. If it's just a quirk of the Python API though, we'll adapt our test framework to use the SB objects API, I guess.
As a side note, I think I remember having to actually remove the debugger.Terminate() because having it there might older versions of LLDB crash :)

[jasonmolenda]

Sounds like your current system of using the HandleCommand calls makes sense - that's cool. As for debugging this specific problem, fwiw the first thing I'd do in this situation is reproduce it with command line lldb and see what's going on. I doubt "p foo" is actually not returning any output - expr ("p" is just an alias for "expr --") likes to print SOMETHING regardless of what happens, there should at least be an error message. Maybe the result object is indicating failure and you need to retrieve the error message? Anyway, I'd remove the intermediate layer of the SB API and do it with cmd line lldb to see what's going on.

I misspoke earlier when I said that Xcode 7.3's lldb (lldb-350) was based on May 2015. Xcode 7.0-7.2's lldb's (lldb-340) were based on mid-May 2015 lldb sources. In Xcode 7.3, a fresh import of the llvm.org sources was taken I think around mid-January -- so there's seven months of the open source lldb changes in Xcode 7.3. It is a pretty different lldb from the one in Xcode 7.2. It's entirely possible that the problem you're seeing is an lldb regression that was introduced in the llvm.org sources between May and January..

[michaelwoerister]

Likely related: #33062

[alexcrichton]

Hm yeah, so I suspect that #33062 is the bug that I'm running into!

[michaelwoerister]

PR #33097 should fix the missing output problems.