https://ttboj.wordpress.com/2016/02/15/debugging-golang-programs/
I’ve been writing a lot of golang lately. I’ve hit painful problems in the past. Here are some debugging tips. Hopefully they help you out. I bet you don’t know #2.
#0 Use log.Printf:
This should go without saying, but I’m ashamed to say it’s what I use the most. We’ve only been C programming for 44+ years, and it’s still what is most useful!
#1 Use go run -race:
Since many problems are caused by random races, ensuring you use the built-in tools will help you catch some problems. One of these is a race detector. You can use it by adding the -race flag to the go run, go build or go test commands. In practice, it only ever caught beginner issues, and it hasn’t set off any alarms since. Maybe I need to write more test cases! Maybe you need to write more test cases!
#2 Use Control+Backslash:
Say what? If you press control+backslash, you will cause a core dump. Example:
james@computer:/tmp$ sleep 42h ^Quit (core dumped)
Obviously there are nicer ways to kill a process (I for one, welcome our robotic overlords) but in times of emergency, use what you’ve got. The interesting thing, is that when you do this to a golang program, you’ll get much more interesting output:
james@computer:~/code/mgmt$ ./mgmt run --file examples/graph0.yaml 16:19:26 main.go:65: This is: mgmt, version: 0.0.2-6-g6e68d6d 16:19:26 main.go:66: Main: Start: 1455571166809588335 16:19:26 main.go:196: Main: Running... 16:19:26 main.go:106: Etcd: Starting... 16:19:26 etcd.go:132: Etcd: Watching... 16:19:26 configwatch.go:54: Watching: examples/graph0.yaml 16:19:26 etcd.go:159: Etcd: Waiting 1000 ms for connection... 16:19:26 main.go:149: Graph: Vertices(2), Edges(1) 16:19:26 main.go:152: Graphviz: No filename given! 16:19:26 main.go:163: State: graphNil -> graphStarting 16:19:26 main.go:165: State: graphStarting -> graphStarted 16:19:26 file.go:340: File[file1]: Apply ^SIGQUIT: quit PC=0x482a53 m=2 goroutine 0 [idle]: runtime.futex(0xecae00, 0x0, 0x7f6f5dd8fde8, 0x0, 0x0, 0x4828ac, 0x3c, 0x0, 0x43392b, 0xecae00, ...) /usr/lib/golang/src/runtime/sys_linux_amd64.s:289 +0x23 runtime.futexsleep(0xecae00, 0x0, 0xdf8475800) /usr/lib/golang/src/runtime/os1_linux.go:56 +0xf0 runtime.notetsleep_internal(0xecae00, 0xdf8475800, 0xc820000900) /usr/lib/golang/src/runtime/lock_futex.go:171 +0x12b runtime.notetsleep(0xecae00, 0xdf8475800, 0x0) /usr/lib/golang/src/runtime/lock_futex.go:191 +0x6b runtime.sysmon() /usr/lib/golang/src/runtime/proc1.go:3022 +0x4aa runtime.mstart1() /usr/lib/golang/src/runtime/proc1.go:715 +0xe8 runtime.mstart() /usr/lib/golang/src/runtime/proc1.go:685 +0x72 goroutine 1 [select]: main.waitForSignal(0xc820076300) /home/james/code/mgmt/main.go:48 +0x5da main.run(0xc82011c0f0) /home/james/code/mgmt/main.go:198 +0x779 github.com/codegangsta/cli.Command.Run(0xb4e9d8, 0x3, 0x0, 0x0, 0xc8200799d0, 0x1, 0x1, 0xb4e9d8, 0x3, 0x0, ...) /home/james/code/src/gopath/src/github.com/codegangsta/cli/command.go:127 +0x1052 github.com/codegangsta/cli.(*App).Run(0xc8200a8500, 0xc820074100, 0x4, 0x4, 0x0, 0x0) /home/james/code/src/gopath/src/github.com/codegangsta/cli/app.go:159 +0xc2f main.main() /home/james/code/mgmt/main.go:283 +0xced goroutine 17 [syscall, locked to thread]: runtime.goexit() /usr/lib/golang/src/runtime/asm_amd64.s:1721 +0x1 goroutine 21 [syscall]: os/signal.loop() /usr/lib/golang/src/os/signal/signal_unix.go:22 +0x18 created by os/signal.init.1 /usr/lib/golang/src/os/signal/signal_unix.go:28 +0x37 goroutine 22 [select]: main.run.func2(0xc82011c0f0, 0xc820122040, 0xc82011a5d0, 0xc82011e130, 0x5, 0xc820076360, 0xc82011e010) /home/james/code/mgmt/main.go:110 +0x1061 created by main.run /home/james/code/mgmt/main.go:168 +0x60c goroutine 23 [select, locked to thread]: runtime.gopark(0xc8a258, 0xc82002e728, 0xb4ec08, 0x6, 0x18, 0x2) /usr/lib/golang/src/runtime/proc.go:185 +0x163 runtime.selectgoImpl(0xc82002e728, 0x0, 0x18) /usr/lib/golang/src/runtime/select.go:392 +0xa64 runtime.selectgo(0xc82002e728) /usr/lib/golang/src/runtime/select.go:212 +0x12 runtime.ensureSigM.func1() /usr/lib/golang/src/runtime/signal1_unix.go:227 +0x353 runtime.goexit() /usr/lib/golang/src/runtime/asm_amd64.s:1721 +0x1 goroutine 7 [select]: main.(*FileType).Watch(0xc820174180) /home/james/code/mgmt/file.go:156 +0x15f4 main.(*Graph).Start.func1(0xc82011e010, 0xc820010b80) /home/james/code/mgmt/pgraph.go:558 +0x7e created by main.(*Graph).Start /home/james/code/mgmt/pgraph.go:560 +0x171 goroutine 25 [select]: main.ConfigWatch.func1(0xc82009db40, 0x14, 0xc820076660) /home/james/code/mgmt/configwatch.go:74 +0x13c8 created by main.ConfigWatch /home/james/code/mgmt/configwatch.go:153 +0x67 goroutine 26 [sleep]: time.Sleep(0x3b9aca00) /usr/lib/golang/src/runtime/time.go:59 +0xf9 main.(*EtcdWObject).EtcdWatch.func1(0x7f6f5c512c20, 0xc82009db80, 0xc820122040, 0xffffffffffffffff, 0xc820076360, 0xc820072af0) /home/james/code/mgmt/etcd.go:160 +0x7db created by main.(*EtcdWObject).EtcdWatch /home/james/code/mgmt/etcd.go:205 +0xc2 goroutine 27 [chan send]: main.(*EtcdWObject).EtcdChannelWatch.func1(0x7f6f5c512c78, 0xc820122140, 0x7f6f5c512ca0, 0xc8200786d0, 0xc8200766c0) /home/james/code/mgmt/etcd.go:109 +0xd9 created by main.(*EtcdWObject).EtcdChannelWatch /home/james/code/mgmt/etcd.go:111 +0x7b goroutine 34 [syscall]: syscall.Syscall6(0xe8, 0x4, 0xc82018dc24, 0x7, 0xffffffffffffffff, 0x0, 0x0, 0x0, 0x0, 0x0) /usr/lib/golang/src/syscall/asm_linux_amd64.s:44 +0x5 syscall.EpollWait(0x4, 0xc82018dc24, 0x7, 0x7, 0xffffffffffffffff, 0x0, 0x0, 0x0) /usr/lib/golang/src/syscall/zsyscall_linux_amd64.go:365 +0x89 gopkg.in/fsnotify%2ev1.(*fdPoller).wait(0xc820146000, 0xc89a00, 0x0, 0x0) /home/james/code/src/gopath/src/gopkg.in/fsnotify.v1/inotify_poller.go:85 +0xbc gopkg.in/fsnotify%2ev1.(*Watcher).readEvents(0xc820158000) /home/james/code/src/gopath/src/gopkg.in/fsnotify.v1/inotify.go:179 +0x1af created by gopkg.in/fsnotify%2ev1.NewWatcher /home/james/code/src/gopath/src/gopkg.in/fsnotify.v1/inotify.go:58 +0x315 goroutine 8 [select]: main.(*NoopType).Watch(0xc82001c230) /home/james/code/mgmt/types.go:362 +0x31a main.(*Graph).Start.func1(0xc82011e010, 0xc820010b60) /home/james/code/mgmt/pgraph.go:558 +0x7e created by main.(*Graph).Start /home/james/code/mgmt/pgraph.go:560 +0x171 goroutine 31 [syscall]: syscall.Syscall6(0xe8, 0x9, 0xc8201f7c24, 0x7, 0xffffffffffffffff, 0x0, 0x0, 0xc82017c440, 0xc82017c420, 0x15) /usr/lib/golang/src/syscall/asm_linux_amd64.s:44 +0x5 syscall.EpollWait(0x9, 0xc8201f7c24, 0x7, 0x7, 0xffffffffffffffff, 0x1, 0x0, 0x0) /usr/lib/golang/src/syscall/zsyscall_linux_amd64.go:365 +0x89 gopkg.in/fsnotify%2ev1.(*fdPoller).wait(0xc82009dcc0, 0x8000, 0x0, 0x0) /home/james/code/src/gopath/src/gopkg.in/fsnotify.v1/inotify_poller.go:85 +0xbc gopkg.in/fsnotify%2ev1.(*Watcher).readEvents(0xc820090cd0) /home/james/code/src/gopath/src/gopkg.in/fsnotify.v1/inotify.go:179 +0x1af created by gopkg.in/fsnotify%2ev1.NewWatcher /home/james/code/src/gopath/src/gopkg.in/fsnotify.v1/inotify.go:58 +0x315 rax 0xfffffffffffffffc rbx 0x7f6f5dd8fde8 rcx 0x482a53 rdx 0x0 rdi 0xecae00 rsi 0x0 rbp 0x0 rsp 0x7f6f5dd8fdb0 r8 0x0 r9 0x0 r10 0x7f6f5dd8fde8 r11 0x246 r12 0x7ffec7010a4f r13 0x7f6f5dd90700 r14 0x800000 r15 0x0 rip 0x482a53 rflags 0x246 cs 0x33 fs 0x0 gs 0x0
I find this particularly useful when you have a “stuck” goroutine. Killing the program usually makes it easy to find where everyone was waiting. AFAIK, everything is ordered by most recently used at the top. You’re welcome!
#3 Use a real debugger:
There is a GDB like golang debugger called “delve“. It’s probably something I would use more often, except I haven’t needed that much power, and it still has a number of rough edges. I’m sure if you could help improve that, it would help out the project. There was a talk at FOSDEM about it. If we’re lucky, we’ll eventually get video. I’m “looking forward” to using it more in the future.
Hope this helped,
Happy Hacking!
James
PS: The “other” slash, isn’t called “forward slash”, it’s just called “slash”
PPS: Yes, I say “golang”, no “go”. I think it’s shitty that google basically ripped off the go! name. I guess David lost this one.
Go has a debugger—and it's awesome!
https://blog.cloudflare.com/go-has-a-debugger-and-its-awesome/
Something that often, uh... bugs[1] Go developers is the lack of a proper debugger. Sure, builds are ridiculously fast and easy, and println(hex.Dump(b)) is your friend, but sometimes it would be nice to just set a breakpoint and step through that endless if chain or print a bunch of values without recompiling ten times.
CC BY 2.0 image by Carl Milner
You could try to use some dirty gdb hacks that will work if you built your binary with a certain linker and ran it on some architectures when the moon was in a waxing crescent phase, but let's be honest, it isn't an enjoyable experience.
Well, worry no more! godebug is here!
godebug is an awesome cross-platform debugger created by the Mailgun team. You can read their introduction
for some under-the-hood details, but here's the cool bit: instead of
wrestling with half a dozen different ptrace interfaces that would not
be portable, godebug rewrites your source code and injects function calls like godebug.Line on every line, godebug.Declare at every variable declaration, and godebug.SetTrace for breakpoints (i.e. wherever you type _ = "breakpoint").
godebug is a different kind of debugger. Traditional debuggers for compiled languages use low-level system calls and read binary files for debugging symbols. They’re hard to get right and they’re hard to port.
godebug takes a different approach: take the source code of a target program, insert debugging code between every line, then compile and run that instead. The result is a fully-functional debugger that is extremely portable. (In fact, thanks to gopherjs, you can run it right here in your browser!)
I find this solution brilliant. What you get out of it is a (possibly cross-compiled) debug-enabled binary that you can drop on a staging server just like you would with a regular binary. When a breakpoint is reached, the program will stop inline and wait for you on stdin. It's the single-binary, zero-dependencies philosophy of Go that we love applied to debugging. Builds everywhere, runs everywhere, with no need for tools or permissions on the server. It even compiles to JavaScript with gopherjs (check out the Mailgun post above—show-offs ;) ).
You might ask, "But does it get a decent runtime speed or work with big applications?" Well, the other day I was seeing RRDNS—our in-house Go DNS server—hit a weird branch, so I placed a breakpoint a couple lines above the if in question, recompiled the whole of RRDNS with godebug instrumentation, dropped the binary on a staging server, and replayed some DNS traffic.
filippo@staging:~$ ./rrdns -config config.json
-> _ = "breakpoint"
(godebug) l
q := r.Query.Question[0]
--> _ = "breakpoint"
if !isQtypeSupported(q.Qtype) {
return
(godebug) n
-> if !isQtypeSupported(q.Qtype) {
(godebug) q
dns.Question{Name:"filippo.io.", Qtype:0x1, Qclass:0x1}
(godebug) c
Boom. The request and the debug log paused (make sure to kill any timeout you have in your tools), waiting for me to step through the code.
Sold yet? Here's how you use it: simply run godebug {build|run|test} instead of go {build|run|test}. We adapted godebug to resemble the go tool as much as possible. Remember to use -instrument if you want to be able to step into packages that are not main.
For example, here is part of the RRDNS Makefile:
bin/rrdns:
ifdef GODEBUG
GOPATH="${PWD}" go install github.com/mailgun/godebug
GOPATH="${PWD}" ./bin/godebug build -instrument "${GODEBUG}" -o bin/rrdns rrdns
else
GOPATH="${PWD}" go install rrdns
endif
test:
ifdef GODEBUG
GOPATH="${PWD}" go install github.com/mailgun/godebug
GOPATH="${PWD}" ./bin/godebug test -instrument "${GODEBUG}" rrdns/...
else
GOPATH="${PWD}" go test rrdns/...
endif
Debugging is just a make bin/rrdns GODEBUG=rrdns/... away.
This tool is still young, but in my experience, perfectly functional. The UX could use some love if you can spare some time (as you can see above it's pretty spartan), but it should be easy to build on what's there already.
About source rewriting
Before closing, I'd like to say a few words about the technique of source rewriting in general. It powers many different Go tools, like test coverage, fuzzing and, indeed, debugging. It's made possible primarily by Go’s blazing-fast compiles, and it enables amazing cross-platform tools to be built easily.
However, since it's such a handy and powerful pattern, I feel like there should be a standard way to apply it in the context of the build process. After all, all the source rewriting tools need to implement a subset of the following features:
- Wrap the main function
- Conditionally rewrite source files
- Keep global state
Why should every tool have to reinvent all the boilerplate to copy the source files, rewrite the source, make sure stale objects are not used, build the right packages, run the right tests, and interpret the CLI..? Basically, all of godebug/cmd.go. And what about gb, for example?
I think we need a framework for Go source code rewriting tools. (Spoiler, spoiler, ...)
If you’re interested in working on Go servers at scale and developing tools to do it better, remember we’re hiring in London, San Francisco, and Singapore!
Making debugger for Golang (part I)
https://medium.com/golangspec/making-debugger-for-golang-part-i-53124284b7c8
The goal of this series is not to write full-featured debugger for Go programming language. If you’re looking for some then please take a look at Delve. We’ll try to understand here how debuggers work in general and how to implement basic one on Linux which takes into account Golang’s features like goroutines.
Creating debugger isn’t easy though. We won’t even strive to cover this topic within a single story. Instead, this post starts a series with ultimate goal to have working solution handling most common scenarios. Along the way we’ll discuss topics like ELF, DWARF and will touch some architecture-specific issues.
Environment
Throughout this series we’ll use Docker to get repeatable playground environment based on Debian Jessie. I’m using x86–64 and this come into play at some point when we’ll move to low-level discussions. Project’s layout is like this:
> tree
.
├── Dockerfile
└── src
└── github.com
└── mlowicki
├── debugger
│ └── debugger.go
└── hello
└── hello.go
The main file of upcoming debugger is debugger.go and file hello.go holds source code of sample program being debugged while our journey. For now you can put there absolute minimum:
package main
func main() {
}
Let’s start with very simple Dockerfile:
FROM golang:1.8.1
RUN apt-get update && apt-get install -y tree
To build Docker image, go to the top-level directory (where Dockerfile sits) and run:
> docker build -t godebugger .
To spin the container up execute:
> docker run --rm -it -v "$PWD"/src:/go/src --security-opt seccomp=unconfined godebugger
Secure computing mode (seccomp) is described here. Now what is left is to compile both programs inside the container. First one can be done using:
> go install --gcflags="-N -l" github.com/mlowicki/hello
Flag —-gcflag has been used to disable function inlining (-l) and compiler optimizations (-N) to make debugging easier. Debugger can be built using:
> go install github.com/mlowicki/debugger
Inside the container PATH environment variable contains /go/bin so to run any of just prepared programs type either hello or debugger without full path.
First step
Our first task will be simple. Let’s stop the program before executing any instruction and then start it again, until it terminates (either voluntarily or caused by error). This is how you start working with most debuggers. You set some traps (breakpoints) and then run something like continue to actually launch till it’ll stopped at one of desired places. Let’s see how it works with Delve:
> cat hello.go
package main
import "fmt"
func f() int {
var n int
n = 1
n = 2
return n
}
func main() {
fmt.Println(f())
}
> dlv debug
break Type ‘help’ for list of commands.
(dlv) break main.f
Breakpoint 1 set at 0x1087050 for main.f() ./hello.go:5
(dlv) continue
> main.f() ./hello.go:5 (hits goroutine(1):1 total:1) (PC: 0x1087050)
1: package main
2:
3: import "fmt"
4:
=> 5: func f() int {
6: var n int
7: n = 1
8: n = 2
9: return n
10: }
(dlv) next
> main.f() ./hello.go:6 (PC: 0x1087067)
1: package main
2:
3: import "fmt"
4:
5: func f() int {
=> 6: var n int
7: n = 1
8: n = 2
9: return n
10: }
11:
(dlv) print n
842350461344
(dlv) next
> main.f() ./hello.go:7 (PC: 0x108706f)
2:
3: import "fmt"
4:
5: func f() int {
6: var n int
=> 7: n = 1
8: n = 2
9: return n
10: }
11:
12: func main() {
(dlv) print n
0
(dlv) next
> main.f() ./hello.go:8 (PC: 0x1087077)
3: import "fmt"
4:
5: func f() int {
6: var n int
7: n = 1
=> 8: n = 2
9: return n
10: }
11:
12: func main() {
13: fmt.Println(f())
(dlv) print n
1
Let’s see how to implement it on our own.
The first step is to have a mechanism for a process (our debugger) to control other process (program being debugged). Luckily on Linux we’ve something in place — ptrace. It’s not the last good news. Golang’s syscall package provides an interface to it like PtraceCont to restart traced process. So it covers the 2nd part but to have a chance to f.ex. set breakpoints before program starts its execution we need something more. While creating new process we can specify its behaviour through set of attributes— SysProcAttr. One of them is Ptrace which enables tracking and process will stop and send SIGSTOP signal to its parent before start. Let’s put everything we’ve just learned into a working machinery…
> cat src/github.com/mlowicki/hello/hello.go
package main
import "fmt"
func main() {
fmt.Println("hello world")
}
> cat src/github.com/mlowicki/debugger/debugger.go
package main
import (
"flag"
"log"
"os"
"os/exec"
"syscall"
)
func main() {
flag.Parse()
input := flag.Arg(0)
cmd := exec.Command(input)
cmd.Args = []string{input}
cmd.Stdout = os.Stdout
cmd.Stderr = os.Stderr
cmd.SysProcAttr = &syscall.SysProcAttr{Ptrace: true}
err := cmd.Start()
if err != nil {
log.Fatal(err)
}
err = cmd.Wait()
log.Printf("State: %v
", err)
log.Println("Restarting...")
err = syscall.PtraceCont(cmd.Process.Pid, 0)
if err != nil {
log.Panic(err)
}
var ws syscall.WaitStatus
_, err = syscall.Wait4(cmd.Process.Pid, &ws, syscall.WALL, nil)
if err != nil {
log.Fatal(err)
}
log.Printf("Exited: %v
", ws.Exited())
log.Printf("Exit status: %v
", ws.ExitStatus())
}
> go install -gcflags="-N -l" github.com/mlowicki/hello
> go install github.com/mlowicki/debugger
> debugger /go/bin/hello
2017/05/05 20:09:38 State: stop signal: trace/breakpoint trap
2017/05/05 20:09:38 Restarting...
hello world
2017/05/05 20:09:38 Exited: true
2017/05/05 20:09:38 Exit status: 0
One first version of debugger works in a very simple way. It start new process which is traced so it stops before executing first instruction and sends signal to the parent process. Parent process waits for such signal and issues logs like log.Printf("State: %v
", err). Afterwards process is restarted and parent waits for its termination. Such behaviour will give as an opportunity to f.ex. set breakpoints, start process and while reaching certain trap, inspect program’s state like current values of variables placed on stack or inside registers.
Even knowing so little we can do some pretty powerful things. It’ll lay the foundations for future enhancements and experiments (more soon).
Click ❤ below to help others discover this story. Please follow me if you want to get updates about new posts or boost work on future stories.
Making debugger in Golang (part II)
During the first part we’ve bootstrapped development environment and made a simple program (tracer) which stops child process (tracee) at the very beginning and then continues it execution together with showing its standard output. Now it’s time to extend its basic capabilities.
Usually debuggers allow to single-step through debugged program. It can be done using ptrace PTRACE_SINGLESTEP request which tells tracee to stop after execution of single instruction:
package main
import (
"flag"
"log"
"os"
"os/exec"
"syscall"
)
func main() {
flag.Parse()
input := flag.Arg(0)
cmd := exec.Command(input)
cmd.Args = []string{input}
cmd.Stdout = os.Stdout
cmd.Stderr = os.Stderr
cmd.SysProcAttr = &syscall.SysProcAttr{Ptrace: true}
err := cmd.Start()
if err != nil {
log.Fatal(err)
}
err = cmd.Wait()
log.Printf("State: %v
", err)
wpid := cmd.Process.Pid
pgid, err := syscall.Getpgid(cmd.Process.Pid)
if err != nil {
log.Panic(err)
}
err = syscall.PtraceSetOptions(cmd.Process.Pid, syscall.PTRACE_O_TRACECLONE)
if err != nil {
log.Fatal(err)
}
err = syscall.PtraceSingleStep(wpid)
if err != nil {
log.Fatal(err)
}
steps := 1
for {
var ws syscall.WaitStatus
wpid, err = syscall.Wait4(-1*pgid, &ws, syscall.WALL, nil)
if wpid == -1 {
log.Fatal(err)
}
if wpid == cmd.Process.Pid && ws.Exited() {
break
}
if !ws.Exited() {
err := syscall.PtraceSingleStep(wpid)
if err != nil {
log.Fatal(err)
}
steps += 1
}
}
log.Printf("Steps: %d
", steps)
}
Building and output looks like this (number of steps can vary between each calls):
> go install -gcflags="-N -l" github.com/mlowicki/hello
> go install github.com/mlowicki/debugger
> debugger /go/bin/hello
2017/06/09 19:54:42 State: stop signal: trace/breakpoint trap
hello world
2017/06/09 19:54:49 Steps: 297583
First part is the same as in our initial program from previous post. What is new is the use of syscall.PtraceSingleStep. It stops tracee (hello in our case) after execution of single instruction.
Option PTRACE_O_TRACECLONE has been also set:
PTRACE_O_TRACECLONE (since Linux 2.5.46)
Stop the tracee at the next clone(2) and automatically start tracing the newly cloned process...
(http://man7.org/linux/man-pages/man2/ptrace.2.html)
Thanks to that our debugger knows when new thread has been started and can step through it as well so the number of steps at the very end is a sum of executed instructions across all processes.
Number of instructions may seem pretty huge but it contains among others initialization of the whole Golang runtime (libc initialization should be known to those with C experience). We can prepare very simple program to check that our counting works fine. Let’s create src/github.com/mlowicki/hello/hello.asm:
section .data
msg db "hello, world!", 0xA
len equ $ — msg
section .text
global _start
_start:
mov rax, 1 ; write syscall (https://linux.die.net/man/2/write)
mov rdi, 1 ; stdout
mov rsi, msg
mov rdx, len
; Passing parameters to `syscall` instruction described in
; https://en.wikibooks.org/wiki/X86_Assembly/Interfacing_with_Linux#syscall
syscall
mov rax, 60 ; exit syscall (https://linux.die.net/man/2/exit)
mov rdi, 0 ; exit code
syscall
Inside the container let’s build our “hello world” program and see how many instructions we’ll count there:
> pwd
/go
> apt-get install nasm
> nasm -f elf64 -o hello.o src/github.com/mlowicki/hello/hello.asm && ld -o hello hello.o
> ./hello
hello, world!
> debugger ./hello
2017/06/17 17:58:43 State: stop signal: trace/breakpoint trap
hello, world!
2017/06/17 17:58:43 Steps: 8
It looks good since we get the exact number of instructions inside hello.asm.
So far we’ve learned how to stop the program at the very beginning, step through it instruction by instruction and track its processes / threads. Now it’s time to set trap at desired place and inspect state of the process like variable values.
Let’s start with some basics. We have a function main from our hello.go:
package main
import "fmt"
func main() {
fmt.Println("hello world")
}
How to set a trap at the beginning of this function? Ultimately our program after compilation and linking is a set of machine instructions. How to express that we want to set a breakpoint at particular place in the source code having only cooked binary (stuffed with instructions only CPUs understand)?
LineTable
Golang has built-in support to access debug information contained in Go binaries. The struct which maps program counter (PC) to line number and vice versa is called LineTable. Let’s see it in action:
package main
import (
"debug/elf"
"debug/gosym"
"flag"
"log"
)
func main() {
flag.Parse()
path := flag.Arg(0)
exe, err := elf.Open(path)
if err != nil {
log.Fatal(err)
}
var pclndat []byte
if sec := exe.Section(".gopclntab"); sec != nil {
pclndat, err = sec.Data()
if err != nil {
log.Fatalf("Cannot read .gopclntab section: %v", err)
}
}
sec := exe.Section(".gosymtab")
symTabRaw, err := sec.Data()
pcln := gosym.NewLineTable(pclndat, exe.Section(".text").Addr)
symTab, err := gosym.NewTable(symTabRaw, pcln)
if err != nil {
log.Fatal("Cannot create symbol table: %v", err)
}
sym := symTab.LookupFunc("main.main")
filename, lineno, _ := symTab.PCToLine(sym.Entry)
log.Printf("filename: %v ", filename)
log.Printf("lineno: %v ", lineno)
}
If we pass as an argument to above program something like:
1 package main
2
3 import "fmt"
4
5 func main() {
6 fmt.Println("hello world")
7 }
then it gives expected result:
> go install github.com/mlowicki/linetable
> go install — gcflags=”-N -l” github.com/mlowicki/hello
> linetable /go/bin/hello
2017/06/30 18:47:38 filename: /go/src/github.com/mlowicki/hello/hello.go
2017/06/30 18:47:38 lineno: 5
ELF stands for Executable and Linkable Format. It’s among others a format of executables:
> apt-get install file
> file /go/bin/hello
/go/bin/hello: ELF 64-bit LSB executable, x86-64, version 1 (SYSV), statically linked, not stripped
ELF file consists of sections and we’re using three of them: .text, .gopclntab and .gosymtab. The first one contains machine instructions, 2nd one maps instruction counter to source code lines and the last one is a symbol table.
In following story we’ll learn how to set a trap at desired place to make more practical use of LineTable and will see how to inspect program’s state.
Click ❤ below to help others discover this story. Please follow me if you want to get updates about new posts or boost work on future stories.
Making debugger in Golang (part III)
So far we’ve learned how to single-step ptraced process (tracee) and get some debugging info out of binary (read it here if you haven’t done it yet). Now it’s time to set a breakpoint at desired place, wait until reached and then investigate process state.
Let’s start with assembly code used before:
section .data
msg db "hello, world!", 0xA
len equ $ - msg
section .text
global _start
_start:
mov rax, 1 ; write syscall (https://linux.die.net/man/2/write)
mov rdi, 1 ; stdout
mov rsi, msg
mov rdx, len
; Passing parameters to `syscall` instruction described in
; https://en.wikibooks.org/wiki/X86_Assembly/Interfacing_with_Linux#syscall
syscall
mov rax, 60 ; exit syscall (https://linux.die.net/man/2/exit)
mov rdi, 0 ; exit code
syscall
The goal set a breakpoint at:
mov rdi, 1
so the trap will be activated before running this instruction. Then we’ll check that RDI register stores 0, run single step and confirm that register stores 1.
Breakpoint
For x86 processors there’s a INT instruction which generates software interrupt. These interrupts are used f.ex. to do syscall on Linux. x86–64 introduced dedicated syscall instruction which is faster this is why I’ve used it above but we could achieve the same with regular int. To set a breakpoint we’ll use int 3 which has an opcode 0xCC:
The INT 3 instruction generates a special one byte opcode (CC) that is intended for calling the debug exception handler. (This one byte form is valuable because it can be used to replace the first byte of any instruction with a breakpoint, including other one byte instructions, without over-writing other code).
(Intel® 64 and IA-32 Architectures Software Developer’s Manual)
We’ll use 0xCC to replace with it instruction at desired spot. Once that place will be reached we will:
- investigate process state,
- replace
0xCCback with its original value, - decrease program counter by 1,
- run a single step.
The first question is where to put 0xCC. We don’t know where exactly in memory instruction mov rdi, 1 will be stored. It’ll be the size of mov rax, 1 bytes further than the first instruction of the program since it’s a second instruction. Instruction lengths on x86 vary which makes the whole task more difficult. Location of the first instruction can be checked by stopping the program before processing any instruction (we’ve done that before). The length of the first instruction can be retrieved with a help of objdump program:
> nasm -f elf64 -o hello.o src/github.com/mlowicki/hello/hello.asm && ld -o /go/bin/hello hello.o
> objdump -d -M intel /go/bin/hello
/go/bin/hello: file format elf64-x86-64
Disassembly of section .text:
00000000004000b0 <_start>:
4000b0: b8 01 00 00 00 mov eax,0x1
4000b5: bf 01 00 00 00 mov edi,0x1
4000ba: 48 be d8 00 60 00 00 movabs rsi,0x6000d8
4000c1: 00 00 00
4000c4: ba 0e 00 00 00 mov edx,0xe
4000c9: 0f 05 syscall
4000cb: b8 3c 00 00 00 mov eax,0x3c
4000d0: bf 00 00 00 00 mov edi,0x0
4000d5: 0f 05 syscall
From above we see that the size of first instruction is 5 bytes (4000b5 — 4000b0). So for the address of first instruction we need to add 5 bytes and put 0xCC there. Let’s see it in action:
package main
import (
"flag"
"log"
"os"
"os/exec"
"syscall"
)
func step(pid int) {
err := syscall.PtraceSingleStep(pid)
if err != nil {
log.Fatal(err)
}
}
func cont(pid int) {
err := syscall.PtraceCont(pid, 0)
if err != nil {
log.Fatal(err)
}
}
func setPC(pid int, pc uint64) {
var regs syscall.PtraceRegs
err := syscall.PtraceGetRegs(pid, ®s)
if err != nil {
log.Fatal(err)
}
regs.SetPC(pc)
err = syscall.PtraceSetRegs(pid, ®s)
if err != nil {
log.Fatal(err)
}
}
func getPC(pid int) uint64 {
var regs syscall.PtraceRegs
err := syscall.PtraceGetRegs(pid, ®s)
if err != nil {
log.Fatal(err)
}
return regs.PC()
}
func setBreakpoint(pid int, breakpoint uintptr) []byte {
original := make([]byte, 1)
_, err := syscall.PtracePeekData(pid, breakpoint, original)
if err != nil {
log.Fatal(err)
}
_, err = syscall.PtracePokeData(pid, breakpoint, []byte{0xCC})
if err != nil {
log.Fatal(err)
}
return original
}
func clearBreakpoint(pid int, breakpoint uintptr, original []byte) {
_, err := syscall.PtracePokeData(pid, breakpoint, original)
if err != nil {
log.Fatal(err)
}
}
func printState(pid int) {
var regs syscall.PtraceRegs
err := syscall.PtraceGetRegs(pid, ®s)
if err != nil {
log.Fatal(err)
}
log.Printf("RAX=%d, RDI=%d
", regs.Rax, regs.Rdi)
}
func main() {
flag.Parse()
input := flag.Arg(0)
cmd := exec.Command(input)
cmd.Args = []string{input}
cmd.Stdout = os.Stdout
cmd.Stderr = os.Stderr
cmd.SysProcAttr = &syscall.SysProcAttr{Ptrace: true}
err := cmd.Start()
if err != nil {
log.Fatal(err)
}
err = cmd.Wait()
log.Printf("State: %v
", err)
pid := cmd.Process.Pid
breakpoint := uintptr(getPC(pid) + 5)
original := setBreakpoint(pid, breakpoint)
cont(pid)
var ws syscall.WaitStatus
_, err = syscall.Wait4(pid, &ws, syscall.WALL, nil)
clearBreakpoint(pid, breakpoint, original)
printState(pid)
setPC(pid, uint64(breakpoint))
step(pid)
_, err = syscall.Wait4(pid, &ws, syscall.WALL, nil)
printState(pid)
}
Set of helpers are placed at the top. Functions setPC and getPC are there to manipulate program counter. It’s worth to note that PC register holds the next instruction to be executed. If we’re stopping the process before running anything then PC hods an address of memory where program’s first instruction is placed. Functions to manipulate breakpoints (setBreakpoint and clearBreakpoint) are juggling the memory by either inserting 0xCC or removing it respectively. Output is as follows:
> go install github.com/mlowicki/breakpoint
> breakpoint /go/bin/hello
2017/07/16 21:06:33 State: stop signal: trace/breakpoint trap
2017/07/16 21:06:33 RAX=1, RDI=0
2017/07/16 21:06:33 RAX=1, RDI=1
It looks fine. When process reaches trap, RDI register isn’t set (holds 0). After single step (running the 2nd instruction) register RDI has desired value set by instruction:
mov rdi, 1
We’ve accomplished the task defined at the very top of this story. It requires extra work like calculating instructions lengths but we’ll fix that at some point so no worries.
REPL
Now it’s time to create the basic structure of our debugger. It’s a simple program which handles in a loop commands like “set a breakpoint at”, “go single step”.
package main
import (
"bufio"
"flag"
"fmt"
"io"
"log"
"os"
"os/exec"
"strings"
"syscall"
)
func initTracee(path string) int {
cmd := exec.Command(path)
cmd.Args = []string{path}
cmd.Stdout = os.Stdout
cmd.Stderr = os.Stderr
cmd.SysProcAttr = &syscall.SysProcAttr{Ptrace: true}
err := cmd.Start()
if err != nil {
log.Fatal(err)
}
err = cmd.Wait()
// Process should be stopped here because of trace/breakpoint trap
if err == nil {
log.Fatal("Program exited")
}
return cmd.Process.Pid
}
func main() {
flag.Parse()
_ = initTracee(flag.Arg(0))
for {
reader := bufio.NewReader(os.Stdin)
fmt.Print("> ")
command, err := reader.ReadString('
')
if err != nil {
if err == io.EOF {
fmt.Println()
break
}
log.Fatal(err)
}
command = command[:len(command)-1] // get rid of ending newline character
if strings.HasPrefix(command, "register ") {
fmt.Println("register...")
} else if strings.HasPrefix(command, "breakpoint ") {
fmt.Println("breakpoint...")
} else if command == "help" {
fmt.Println("help...")
} else if command == "step" {
fmt.Println("step...")
} else if command == "continue" {
fmt.Println("continue")
} else {
fmt.Println("unknown command")
}
}
}
This is the backbone for our debugger. It doesn’t provide too much (yet) but already has the necessary logic to provide elementary REPL environment. We know more or less how to handle step, continue, help and register commands and we’ll implement these gaps soon. The one which isn’t that obvious for Golang is a breakpoint command. It’ll thoroughly explained in the upcoming post why it’s a bit harder than expected and how to overcome that extra complexity.
Click ❤ below to help others discover this story. Please follow me if you want to get updates about new posts or boost work on future stories.
Debugging Go Code with GDB (official)
https://golang.org/doc/gdb