Debugger support

Ok. I was able to compile crystal in debug mode with Language Unknown and also dumped LLVM IR.

What I found. I found a bug that when it is in debug mode it show isOptimized: true

!0 = distinct !DICompileUnit(file: !1, producer: “Crystal”, isOptimized: true, runtimeVersion: 0, emissionKind: FullDebug, enums: !2)

To fix this bug we have to change the same line (where we change the language id) the debug value from 0 to false so it starts to treat it properly.
Otherwise LLVM is doing some optimizations on the data and debug variables.

So my current line is:

    di_builder.create_compile_unit(UNKNOWN_LANG_DEBUG_IDENTIFIER, file, dir, "Crystal", false, "", 0_u32)

And I am able to get this:

(lldb) s
Process 1035 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = step in
    frame #0: 0x0000000100d8cf40 crystal`run(options=0x0000000200000003) at command.cr:46:5
   43  	    USAGE
   44
   45  	  def self.run(options = ARGV)
-> 46  	    new(options).run
   47  	  end
   48
   49  	  private getter options
(lldb) var
(Array(String) *) options = 0x0000000200000003
(lldb) p *options
error: Couldn't apply expression side effects : Couldn't dematerialize a result variable: couldn't read its memory
(lldb) p options
(Array(String) *) $1 = 0x0000000200000003
(lldb)

Options are showing wrong value though.
I used llvm-dumpdwarf on crystal.dwarf file and traced it down to:

0x0020cc98: DW_TAG_variable
DW_AT_location (DW_OP_fbreg -8)
DW_AT_name (“options”)
DW_AT_decl_file (“/Users/sergey/Projects/crystal/crystal/src/compiler/crystal/command.cr”)
DW_AT_decl_line (45)
DW_AT_type (cu + 0x258de9 “Array(String)”)

So it is Stack Pointer - 8 but something is not correct. I will need to look at disassembled code file around that function.

But at least you are able to get variables with lldb.

3 Likes

@asterite @bcardiff Can you guys tell me what is calling convention is used? At least on macOS.
I see that parameters are passed on registers rdi, rsi, rcx, rax.

I think we are using the c calling convention, or the default one LLVM uses.

1 Like

I just found that macOS and all other unix based systems are using System V ABI and for 64 bits is uses registers for parameters (al test for first 6 parameters).
It is described here (page 21):

I was mostly Windows guy when I did low-level programming 20-25 years ago so I still remember Windows calling conventions and it fooled me somehow.

Ok. After some deep low level debugging on asm level I think I know why it is showing incorrect values for variables.
Please note that stack values are correct though (with some exceptions).

Issue number one. When we store Int32 into stack lldb is trying to get it as Int64 when shows the value.

Here is the example:

def self.startHTTPServer (serverPort)
server = HTTP::Server.new do |context|
context.response.content_type = “text/plain”
context.response.print “!”
end
server.listen(serverPort)
end

If we put break point on self.startHTTPServer and ask for the values then we will see:
value of the stack before storing serverPort value to that location:

(lldb) x/x $rbp-0x1c
0x7ffeefbff264: 0x01183eb000000022

right after we store the serverPort value to the stack it becomes:

(lldb) x/x $rbp-0x1c
0x7ffeefbff264: 0x01183eb000000bb8

and if we will call vars:

(lldb) v
(int) serverPort = <read memory from 0x1183eb000000bb8 failed (0 of 4 bytes read)>

(HTTP::Server *) server = 0x0000000101183eb0

because it reads it as an 64-bit address and trying to dereference it even though it is a value as is.
and this is the same issue with other values on the stack. It always trying to dereference it twice.

If you will look at DIE for this parameter variable you will no see any pointer types for base value:

0x0002c9e2: DW_TAG_formal_parameter
DW_AT_location (0x0003a830
0x00000000000dc7e0 - 0x00000000000dc7eb: DW_OP_breg5 RDI+0
0x00000000000dc7eb - 0x00000000000dc821: DW_OP_breg6 RBP-28, DW_OP_deref)
DW_AT_name (“serverPort”)
DW_AT_decl_file (“/Users/sergey/Projects/crystal/crweb/src/crweb.cr”)
DW_AT_decl_line (8)
DW_AT_type (0x0000000000000159 “Int32”)

Here is the DIE for base type:

0x00000159: DW_TAG_base_type
DW_AT_name (“Int32”)
DW_AT_encoding (DW_ATE_signed)
DW_AT_byte_size (0x04)

so I suspect that for some reason LLDB trying to dereference it twice.

I think I can solve this issue with custom command built with lldb python script.
I am experimenting with it at this moment.
lldb Python is very cool stuff to be honest. It wraps all lldb classes and methods via SWIG and it allows you to do almost anything. I am checking how far I can go with it.

LLDB Python API (for those who is interested to play with it) can be found here:
https://lldb.llvm.org/python_reference
Also some LLDB Python scripting examples can be found here:

2 Likes

I am really excited to have more support for this in Crystal.

1 Like

I am working on it.
At this moment to have access to DWARF info in lldb python (as it is unavailable or I cannot find it in documentation) I have to implement Mach-O part to be able to use pyelftools with Linux and macOS and access DWARF information with it.

I implemented Python DWARF reader but it is quite slow on big dwarf files like Crystal’s dwarf file.
I decided to try to build native LLDB language and language runtime plugins based on C++ plugins for now. I will see how it goes and if it worked out okay I will create a PR with LLVM team.

By some reason my Crystal DWARF parser is even little slower than my Python DWARF reader.
I am somewhat puzzled. It takes in average 1 minute and 13 seconds to parse the DWARF flle for Crystal. It is only 23MB file. My Java .class/.jar parser is able to process way much more files in that time. I will investigate later on the performance of it, but initially I want to make debugger workable for Crystal debugging.

3 Likes

After extensive debugging I figured out why Crystal scalars (less than 64-bit) are shown improperly.
When LLDB is evaluating DWARF expression it is reading value from the stack of the size of current architecture( 64-bit on my MacBook’s i7 CPU). In case of Int32 we store only 32 bits to stack without expanding it to 64-bits, because of that LLDB is reading the value + extra value on the stack.
I think that for debug mode it is valuable to store the scalars as words of the architecture’s native size.
I understand that we are waisting some stack space in this case but at least it will simplify debugging as we can do it only in debug mode.
In this case I will look if I can expand stack values to alway occupy 64 bits in debug mode.

It will buy me some time to properly implement a LLDB type system for Crystal.

@asterite can you give me some pointers where should I do it?

Sorry, I don’t know how to do that.

1 Like

No worries, I will figure it out. I asked just in case if you know.

Heh, looks like I found LLDB bug in DWARF Expression evaluator.
If it uses Deref op code it is not resetting value type. It still keeping value type eValueLoadAddress instead of scalar type. Because of that LLDB is trying to dereference it later on.

2 Likes

You going to be surprised but I fixed llvm and now it shows this:

(lldb) v
(int) serverPort = 3000
(HTTP::Server *) server = 0x0000000101280a60
(lldb) p server
(HTTP::Server *) $4 = 0x0000000101280a60
(lldb) p *server
(HTTP::Server) $5 = {
  closed = false
  listening = false
  sockets = 0x0000000101280a40
  processor = 0x00000001012854c0
}
(lldb) p *server->sockets
(Array(Socket::Server)) $7 = (size = 0, capacity = 0)
(lldb)

so technically lldb debugger is working for Crystal when selected DWARF language is C++.

The fix is one liner:

In lldb/source/Expression/DWARFExpression.cpp ( branch llvm-9) after line 1327:

        if (pointer_value != LLDB_INVALID_ADDRESS) {
          stack.back().GetScalar() = pointer_value;
          /// This line below is what I added:
          stack.back().SetValueType(Value::eValueTypeScalar);
          stack.back().ClearContext();
        } else {

few small fixes was done in crystal compiler as well, but it works and I am able to test it now.

Will experiment more with the code to be sure that it is working as expected and there is no edge cases.

3 Likes

@asterite: Ary, I created Pull Request with my changes. Feel free to play with it.
To allow proper showing of the value you will have to apply my patch (in previous message) to LLDB source and compile it.

It feels like some of these fixes maybe could also be submitted upstream (to lldb)? Just thinking out loud… :)

I am working on it. Just checking that it will not introduce any side effects.

I am playing with Crystal debugging capability (by debugging crystal itself) and I frigging LOVE it!
VS Code NativeDebug plugin is showing this info too but it hangs in some cases so I am doing it via lldb CLI itself so I am planning to build a python script value formatters to show them properly.

3 Likes

After playing with NativeDebug and LLDB TUI (invoked with gui command) I found that NativeDebug plugin is not useful at all as it is not properly formatting values.
On the other side LLDB TUI is much more useful and shows value much nicer.
So I still hope that python plugins that implement SynthProviders will help to show it proper.

1 Like

Ok here is the type providers python code to show properly Strings and Arrays (works okay but looking if I can further improve it) in LLDB:

import lldb
import struct

class CrystalArraySyntheticProvider:
    def __init__(self, valobj, internal_dict):
        self.valobj = valobj.Dereference() if valobj.type.is_pointer else valobj
        self.buffer = None
        self.size = None

    def num_children(self):
        size = 0 if self.size is None else self.size
        return size
   
    def get_child_at_index(self,index):
        if index >= self.size:
            return None
        
        try:
            elementType = self.buffer.type.GetPointeeType()
            offset = self.type.size * index
            return self.buffer.CreateChildAtOffset('[' + str(index) + ']', offset, elementType)
        except Exception as e:
            return None

    def update(self):
        self.size = int(self.valobj.GetChildMemberWithName('size').value)
        self.type = self.valobj.type
        self.buffer = self.valobj.GetChildMemberWithName('buffer')

def findType(name, module):
    cachedTypes = module.GetTypes()
    for idx in range(cachedTypes.GetSize()):
        type = cachedTypes.GetTypeAtIndex(idx)
        if type.name == name:
            return type
    return None


def CrystalString_SummaryProvider(value, dict):
    error = lldb.SBError()
    if value.TypeIsPointerType():
        value = value.Dereference()
    process = value.GetTarget().GetProcess()
    lenAddr = value.child[1].load_addr
    strAddr = value.child[2].load_addr
    mem = bytearray(process.ReadMemory(lenAddr, 4, error))
    (len,) = struct.unpack('I', mem)
    val = process.ReadCStringFromMemory(strAddr, len + 1, error)
    return '"%s"' % val


def __lldb_init_module(debugger, dict):
    debugger.HandleCommand('type synthetic add -l crystal_formatters.CrystalArraySyntheticProvider -x "^Array\(.+\)$" -w Crystal')
    # By some reason summary and synthetic providers are not working well together for now. Will fix it later
    # debugger.HandleCommand('type summary add --summary-string "Count: ${var.size}" -x "^Array\(.+\)$" -w Crystal')
    debugger.HandleCommand('type summary add -F crystal_formatters.CrystalString_SummaryProvider -x "^String(\s*\**)?$" -w Crystal')
    debugger.HandleCommand('type category enable Crystal')

save it to some path as crystal_formatters.py

It can be loaded into LLDB with command:
command script import <path to the script>/crystal_formatters.py

and it will register itself in a proper way.

I still need to implement set types to make it more useful like Hash and Set and so on but with this two types it makes life much easier.

@asterite @ysbaddaden : I removed NoInline code from the PR, can you look at it again?

2 Likes