record btrace experience [Re: x86_64-m32 internal error for multi-thread-step.exp [Re: [PATCH v10 06/28] btrace: change branch trace data structure]]

[Jan Kratochvil <jan dot kratochvil at redhat dot com>]

On Fri, 23 Jan 2015 08:45:31 +0100, Metzger, Markus T wrote:
> > As I only now have a hardware capable of btrace
> 
> That's good.  I hope this feature is useful for your own debugging work.
> Let me know how you like it.

The functionality itself is really great, for example in this case - where did
kickoff() got called from?

------------------------------------------------------------------------------
gdb -ex 'tb main' -ex r -ex 'record btrace' -ex 'b *kickoff' -ex c --args docker -d 
[...]
Breakpoint 2, kickoff () at ../../../gcchead/libgo/runtime/proc.c:204
204		if(pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED) != 0)
(gdb) bt
#0  kickoff () at ../../../gcchead/libgo/runtime/proc.c:204
#1  0x00007ffff6e0a510 in ?? () from /lib64/libc.so.6
#2  0x0000000000000000 in ?? ()
(gdb) reverse-stepi
setcontext () at ../sysdeps/unix/sysv/linux/x86_64/setcontext.S:99
99		ret
(gdb) bt
#0  setcontext () at ../sysdeps/unix/sysv/linux/x86_64/setcontext.S:99
#1  0x00007ffff7df00e7 in _dl_runtime_resolve () at ../sysdeps/x86_64/dl-trampoline.S:115
#2  0x0000000000738f8c in ?? ()
#3  0x0000000000739470 in setcontext@plt ()
#4  0x0000000000a62447 in runtime_gogo (newg=newg@entry=<unavailable>) at ../../../gcchead/libgo/runtime/proc.c:226
#5  0x0000000000a624ea in execute (gp=gp@entry=<unavailable>) at ../../../gcchead/libgo/runtime/proc.c:1545
#6  0x0000000000a63f84 in schedule () at ../../../gcchead/libgo/runtime/proc.c:1752
#7  0x0000000000a642ca in runtime_mstart (mp=<optimized out>) at ../../../gcchead/libgo/runtime/proc.c:1003
#8  0x000000000073a79a in main (argc=<optimized out>, argv=<optimized out>) at ../../../gcchead/libgo/runtime/go-main.c:43
Backtrace stopped: not enough registers or memory available to unwind further
(gdb) _
------------------------------------------------------------------------------

Plain 'record' I have stopped after 2 minutes of run with no result:
gdb -ex 'set record insn-number-max 10000000' -ex 'tb main' -ex r -ex 'record' -ex 'b *kickoff' -ex c --args docker -d 

Although one cannot leave the history too long, despite it is set to
'unlimited'.  I have no idea why now, for example:

------------------------------------------------------------------------------
gdb -ex 'set record instruction-history-size unlimited' -ex 'set record function-call-history-size unlimited' -ex 'tb main' -ex r -ex 'record btrace' -ex 'catch fork' -ex c --args docker -d 
GNU gdb (GDB) 7.9.50.20150124-cvs
[...]
Catchpoint 2 (forked process 13346), syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
38		cmpq $-4095, %rax	/* Check %rax for error.  */
(gdb) bt
#0  syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
#1  0x0000000000b117f3 in syscall.RawSyscall6 (trap=trap@entry=56, a1=<optimized out>, a2=a2@entry=0, a3=a3@entry=0, a4=a4@entry=0, a5=0, a6=0) at ../../../gcchead/libgo/go/syscall/syscall_unix.go:92
#2  0x0000000000b1e122 in syscall.forkAndExecInChild (pipe=7, sys=0x1410fa0 <syscall.zeroSysProcAttr>, attr=<optimized out>, dir=0x0, chroot=0x0, param=..., param=..., argv0=0xc20808e740 "/usr/sbin/iptables") at ../../../gcchead/libgo/go/syscall/exec_linux.go:72
#3  syscall.forkExec (argv0=..., argv=..., attr=<optimized out>) at ../../../gcchead/libgo/go/syscall/exec_unix.go:227
#4  0x0000000000b1eaa9 in syscall.StartProcess (argv0=..., argv=..., attr=attr@entry=0xc208013090) at ../../../gcchead/libgo/go/syscall/exec_unix.go:273
#5  0x0000000000ac6a80 in os.startProcess (attr=<optimized out>, argv=..., name=...) at ../../../gcchead/libgo/go/os/exec_posix.go:45
#6  os.StartProcess (name=..., argv=..., attr=<optimized out>) at ../../../gcchead/libgo/go/os/doc.go:24
#7  0x0000000000c2462b in os_exec.Start.pN11_os_exec.Cmd (param=param@entry=0xc208037180) at ../../../gcchead/libgo/go/os/exec/exec.go:304
#8  0x0000000000c247e4 in os_exec.Run.pN11_os_exec.Cmd (c=<optimized out>) at ../../../gcchead/libgo/go/os/exec/exec.go:236
#9  0x000000000080c021 in iptables.$init0 () at /home/jkratoch/redhat/fedora/docker-io/master/docker-1.4.1/_build/src/github.com/docker/docker/pkg/iptables/iptables.go:43
#10 0x0000000000810764 in github_com_docker_docker_pkg_iptables..import () at /home/jkratoch/redhat/fedora/docker-io/master/docker-1.4.1/_build/src/github.com/docker/docker/pkg/iptables/iptables.go:42
#11 0x000000000073f648 in main.init () at /home/jkratoch/redhat/fedora/docker-io/master/docker-1.4.1/docker/daemon.go:3
#12 0x0000000000a65034 in runtime_main (dummy=<optimized out>) at ../../../gcchead/libgo/runtime/proc.c:514
#13 0x0000000000a631bf in kickoff () at ../../../gcchead/libgo/runtime/proc.c:211
#14 0x00007ffff6e0a510 in ?? () from /lib64/libc.so.6
#15 0x0000000000000000 in ?? ()
(gdb) b *kickoff
Breakpoint 3 at 0xa63190: file ../../../gcchead/libgo/runtime/proc.c, line 204.
(gdb) reverse-continue 
Continuing.

No more reverse-execution history.
syscall.BytePtrFromString (s=...) at ../../../gcchead/libgo/go/syscall/syscall.go:57
57	// If s contains a NUL byte this function panics instead of
(gdb) show record instruction-history-size 
Number of instructions to print in "record instruction-history" is unlimited.
(gdb) show record function-call-history-size 
Number of functions to print in "record function-call-history" is unlimited.
(gdb) bt
#0  syscall.BytePtrFromString (s=...) at ../../../gcchead/libgo/go/syscall/syscall.go:57
#1  0x0000000000b0f536 in syscall.SlicePtrFromStrings (ss=...) at ../../../gcchead/libgo/go/syscall/exec_unix.go:121
#2  0x0000000000b1db8d in syscall.forkExec (argv0=..., argv=..., 
    attr=<error reading variable: Registers are not available in btrace record history>)
    at ../../../gcchead/libgo/go/syscall/exec_unix.go:192
Backtrace stopped: not enough registers or memory available to unwind further
(gdb) _
------------------------------------------------------------------------------

BTW these defaults sometimes did limit my use of btrace but right now I do not
have a reproducer where it works with setting them unlimited while it does not
while leaving them as they are:
	(gdb) show record instruction-history-size
	Number of instructions to print in "record instruction-history" is 10.
	(gdb) show record function-call-history-size
	Number of functions to print in "record function-call-history" is 10.


The problem I see is how to transparently enable btrace on some host.

Instead of
	-ex r
one has to type
	-ex start -ex 'set record instruction-history-size unlimited' -ex 'set record function-call-history-size unlimited' -ex 'record btrace' -ex c
which is really not convenient.  Also "start" will stop at the high-level
language main-like function while we may want to start recording earlier, so
one may have to do:
	-ex 'tb main' -ex r -ex 'set record instruction-history-size unlimited' -ex 'set record function-call-history-size unlimited' -ex 'record btrace' -ex c


I have tried to enable btrace transparently from ~/.gdbinit which is possible
for the 'start' command but I failed how to transparently wrap
the 'run' command:

	set record instruction-history-size   unlimited
	set record function-call-history-size unlimited
	define hookpost-start
		record btrace
	end

	# internal-error: go_symbol_package_name: Assertion `SYMBOL_LANGUAGE (sym) == language_go' failed.
	# https://sourceware.org/bugzilla/show_bug.cgi?id=17876
	#define hook-run
	#       tb *_start
	#end
	#define hookpost-run
	#       continue
	#end

	# This breaks cases like: -ex 'b constructor' -ex run
	## Really redefine built-in command "run"? (y or n) [answered Y; input not from terminal]
	#set confirm no
	#define run
	#       start $arg0 $arg1 $arg2 $arg3 $arg4 $arg5 $arg6 $arg7 $arg8 $arg9
	#       continue
	#end
	#set confirm yes

Obviously it would be nice to be able to do just:
	echo 'record btrace' >>~/.gdbinit


Thanks,
Jan