Debugger support

ComputerMage · December 4, 2019, 3:41am

I am happy with the results of my custom formatter (still need to implement few generic type formatters):

(lldb) p *context->request.headers.hash
(Hash(HTTP::Headers::Key, Array(String) | String)) $7 = {
first = 0
entries = 0x0000000101108d20
indices = 0x0000000000000000
size = 3
deleted_count = 0
indices_bytesize = ‘\x01’
indices_size_pow2 = ‘\x03’
compare_by_identity = false
}
Fix-it applied, fixed expression was:
*context->request->headers.hash
(lldb) p *context->request.headers.hash.entries
(Hash::Entry(HTTP::Headers::Key, Array(String) | String)) $8 = {
hash = 177174889
key = (name = “Host”)
}
Fix-it applied, fixed expression was:
*context->request->headers.hash->entries
(lldb) p *context->request.headers.hash.entries[0]
error: member reference type ‘HTTP::Request *’ is a pointer; did you mean to use ‘->’?
error: member reference type ‘Hash(HTTP::Headers::Key, Array(String) | String) *’ is a pointer; did you mean to use ‘->’?
error: indirection requires pointer operand (‘Hash::Entry(HTTP::Headers::Key, Array(String) | String)’ invalid)
(lldb) p context->request.headers.hash.entries[0]
(Hash::Entry(HTTP::Headers::Key, Array(String) | String)) $9 = {
hash = 177174889
key = (name = “Host”)
}
Fix-it applied, fixed expression was:
context->request->headers.hash->entries[0]
(lldb) p context->request.headers.hash.entries[1]
(Hash::Entry(HTTP::Headers::Key, Array(String) | String)) $10 = {
hash = 2057728823
key = (name = “User-Agent”)
}
Fix-it applied, fixed expression was:
context->request->headers.hash->entries[1]
(lldb) p context->request.headers.hash.entries[2]
(Hash::Entry(HTTP::Headers::Key, Array(String) | String)) $11 = {
hash = 890394483
key = (name = “”)
}

At the same time NativeDebug plugin is not doing any good in displaying structures:

So I am thinking to build my own VS Code DebugAdapter that will be implemented directly inside of LLDB on Python. It will give me maximum flexibility on what to show and what information to extract from debugger.

ComputerMage · December 4, 2019, 4:14am

I just found that CodeLLDB VSCode plugin works just fine. I just pointed it to my custom built lldb library with my path and here we go!

asterite · December 4, 2019, 11:30am

Wow, that’s so cool. and useful!! I had no idea the debug info we generate allowed doing that.

ComputerMage · December 4, 2019, 11:51am

@asterite Hey Ary!
Yes, it does allow to show quite plenty of info. You will have to use my branch (or accept my PR) and compile LLVM one liner fix I posted here above (to properly show scalars) to see it though.

I still see some improvements that needs to be done such as DWARF array range DIEs and inheritance stuff, also some local block variables as well as some self variables are not showing in some cases.

I will debug it though as I have some very good tool now ;)

ComputerMage · December 4, 2019, 12:12pm

CodeLLDB plugin still not picking up result from summary and synthetic providers by default (so no proper arrays and Strings shown for a moment) but I am investigating how I can tell it to plugin to extract this information.

Update: This is an issue no more. Looks like it is not picking up my ~/.lldbinit file so it needs to be specifically added to the CodeLLDB settings:

"lldb.launch.initCommands": [
    "command script import ~/Projects/crystal/crystal/lldb_formatters/crystal_formatters.py"
]

After that it starts to show it (at least strings) properly:

wontruefree · December 4, 2019, 6:02pm

wow this is amazing work. I have been waiting for this for a while. Thanks for all your work so far.

vlazar · December 4, 2019, 6:15pm

This is the thing. All you need is a single person persistent enough. Then everything is possible!

ComputerMage · December 5, 2019, 1:56am

This is just beginning.

I found quite plenty of debugging issues I want to tackle.
some of the local variables are not exposing to the debug information. extended classes are not showing all fields as well, array subscripts needs to be encoded properly to use that info in LLDB expression evaluator so I have to tackle it to have a good debugging support.

ComputerMage · December 5, 2019, 1:58am

IT persistence is trainable.
It just takes 35 years of practicing it every day as in my case. ;)

ComputerMage · December 12, 2019, 3:48pm

Ok. After fixing my branch I am debugging Crystal itself to make debugger robust.
I found that debug line numbering is not really correct:

Quite often it uses line numbers that are outside of the actual file lines range.
Quite often it jumps into the comments with no code whatsoever.
Macros are not positioned properly. I suppose it should use internal position of the node and not the macro node.
Function scope (and internal scopes) variables are not always exposed to the code. I modified declare_var method like this:

def declare_var(var, location)
  llvm_var = context.vars[var.name]?
  if llvm_var.nil?
    ptr = alloca(llvm_type(var.type), var.name)
    declare_variable(var.name, var.type, ptr, location)
    llvm_var = LLVMVar.new(var.no_returns? ? llvm_nil : ptr, var.type)
    context.vars[var.name] = llvm_var
  end
  llvm_var
end

but it didn’t help much.

@asterite Can you give me some background on how are the scopes organized and at what moment variables debug info are ready to be injected to the LLVM? Is it during codegen or before?
What + means at the end of the type name? How to treat it?

Complex types are not properly shown in debugger. It shows most of the instance fields but not all of them. I am trying to figure it out why this is the case.
I see that sometimes debug line info jumps out of order to some code where it is not supposed to be and then goes back. Still trying to understand why is that by validating .ll and .s files

Can we ignore optimization of AST nodes if code is compiled with --debug flag?

rogerdpack · December 13, 2019, 4:54am

https://github.com/crystal-lang/crystal/pull/8499 helps a little with line numers (mostly the zeroes). Yeah there’s something else amiss though see https://github.com/crystal-lang/crystal/issues/7471 not sure if it’s in the parsing or generation…

ComputerMage · December 20, 2019, 3:47am

I am not lost. I am little busy with the main work and also trying to identify why quite often block variables and some of the arguments are lost from DWARF variables so I am in a deep debugging mode again (mostly in puts mode though and dumping and reading IR function dumps to identify the issue).

ComputerMage · December 21, 2019, 1:08am

@asterite:
Hey Ary,

I am debugging through the debug info generator and I found something that I want to discuss with you and get your help if possible.

Here is the snippet from my log where I dump some information for analysis:

create_local_copy_of_fun_args(def raise(exception : ArgumentError) : NoReturn
if __temp_49 = exception.callstack
__temp_49
else
exception.callstack = CallStack.new
end
unwind_ex = Pointer(LibUnwind::Exception).malloc
unwind_ex.value.exception_class = LibC::SizeT.zero
unwind_ex.value.exception_cleanup = LibC::SizeT.zero
unwind_ex.value.exception_object = exception.object_id
unwind_ex.value.exception_type_id = exception.crystal_type_id
__crystal_raise(unwind_ex)
end, , [exception : ArgumentError], false, false)
parent context vars:
{“capacity” => #<Crystal::CodeGenVisitor::LLVMVar:0x11476a9c0 @pointer=i64 %capacity, @type=UInt64, @already_loaded=true>}
Args:
[exception : ArgumentError]
Defined vars for 'raise:NoReturn’:
{“__temp_49” => #<Crystal::CodeGenVisitor::LLVMVar:0x11476a4e0 @pointer= %__temp_49 = alloca %“(CallStack | Nil)”, !dbg !8, @type=(CallStack | Nil), @already_loaded=false>, “unwind_ex” => #<Crystal::CodeGenVisitor::LLVMVar:0x11476a4b0 @pointer= %unwind_ex = alloca %“struct.LibUnwind::Exception”, !dbg !8, @type=Pointer(LibUnwind::Exception), @already_loaded=false>, “exception” => #<Crystal::CodeGenVisitor::LLVMVar:0x11476a420 @pointer=%ArgumentError* %exception, @type=ArgumentError, @already_loaded=true>}
declare_variable(__temp_49, (CallStack | Nil), %__temp_49 = alloca %“(CallStack | Nil)”, !dbg !8, expanded macro: macro_4516882848:20:3)
in declare_local. Location is ‘expanded macro: macro_4516882848:20:3’
Unsupported type for debugging: (CallStack | Nil) (Crystal::MixedUnionType)
in declare_local. Debug type is null. Type is: (CallStack | Nil)
declare_variable(unwind_ex, Pointer(LibUnwind::Exception), %unwind_ex = alloca %“struct.LibUnwind::Exception”, !dbg !8, expanded macro: macro_4516882848:20:3)
in declare_local. Location is ‘expanded macro: macro_4516882848:20:3’
di_builder.create_auto_variable Pointer(Void)@0x7ffe3f503380, unwind_ex, Pointer(Void)@0x7ffe3f5032e0, 191, Pointer(Void)@0x7ffe3f503848, 0
declare_parameter(exception, ArgumentError, 0, %ArgumentError %exception, expanded macro: macro_4516882848:20:3)
in declare_local. Location is ‘expanded macro: macro_4516882848:20:3’
di_builder.create_parameter_variable Pointer(Void)@0x7ffe3f503380, exception, 0, Pointer(Void)@0x7ffe3f5032e0, 191, Pointer(Void)@0x7ffe43001e78
============== Dumping func: *raise:NoReturn =============

; Function Attrs: noreturn uwtable
define internal void @“raise:NoReturn"(%ArgumentError %exception) #4 !dbg !113 {
alloca:
%__temp_49 = alloca %”(CallStack | Nil)", !dbg !116
%unwind_ex = alloca %“struct.LibUnwind::Exception”, !dbg !116
call void @llvm.dbg.declare(metadata %“struct.LibUnwind::Exception”** %unwind_ex, metadata !117, metadata !DIExpression()), !dbg !116
call void @llvm.dbg.declare(metadata %ArgumentError %exception, metadata !127, metadata !DIExpression()), !dbg !116

entry: ; No predecessors!
}
============== End Dumping =============

So my question is:

Unsupported type for debugging: (CallStack | Nil) (Crystal::MixedUnionType)
in declare_local. Debug type is null. Type is: (CallStack | Nil)

Why (CallStack | Nil) is recognized as MixedUnionType and not NullableType?

Is this a bug or there is some rules behind it?

ComputerMage · December 22, 2019, 12:59am

Nevermind, I found it in compiler/crystal/program.cr

ComputerMage · December 26, 2019, 2:20pm

@asterite: Ary, can you share your rationale why you decided not to use C-like unions to implement type unions in Crystal?
I am scratching my head how to implement unions type debugging in Crystal. It can be dome easily with C unions but underlining structure is different so I cannot do that that easily. I am still thinking if I can fake DWARF union types to emulate it as it has the same physical structure.

asterite · December 26, 2019, 2:33pm

What do you mean? The value component of a union type in Crystal is exactly like that in C. The difference is that a union type in Crystal knows which of the union types is the valid value.

That said, the representation of union types might change in the future (or it already changed? I can’t remember).

ComputerMage · December 26, 2019, 3:59pm

@asterite: I agree. It is similar to C unions. Looks like I am lost in the Crystal code and impulsively posted before doing full due diligence in LLVM code.
I was expecting that it will call LLVM functions but there is no LLVM functions for creation of Union types, except for debugging: .
I am planning to use LLVMDIBuilderCreateUnionType that I have to expose to the LibLLVM

PS: Found good docs re Unions in LLVM: https://mapping-high-level-constructs-to-llvm-ir.readthedocs.io/en/latest/basic-constructs/unions.html

ComputerMage · December 26, 2019, 5:12pm

@asterite So if I understood correctly every objects first integer is a type id that helps identify the object and which is encoded with type_id() call in the code?

asterite · December 26, 2019, 5:30pm

Yes, more or less. Structs don’t have this type ID in them.

ComputerMage · January 13, 2020, 8:07pm

I was able to implement unions. It shows them properly now (at least for pointers to nillable types.
I still have some issues with union structs in the classes but I am getting close to solve it.