Go运行时bug调试过程解析

fatal error: unexpected signal during runtime execution
[signal SIGSEGV: segmentation violation code=0x1 addr=0xc41ffc7fff pc=0x41439e]

goroutine 2395 [running]:
runtime.throw(0xae6fb8, 0x2a)
        /usr/lib64/go/src/runtime/panic.go:605 +0x95 fp=0xc4203e8be8 sp=0xc4203e8bc8 pc=0x42c815
runtime.sigpanic()
        /usr/lib64/go/src/runtime/signal_unix.go:351 +0x2b8 fp=0xc4203e8c38 sp=0xc4203e8be8 pc=0x443318
runtime.heapBitsSetType(0xc4204b6fc0, 0x30, 0x30, 0xc420304058)
        /usr/lib64/go/src/runtime/mbitmap.go:1224 +0x26e fp=0xc4203e8c90 sp=0xc4203e8c38 pc=0x41439e
runtime.mallocgc(0x30, 0xc420304058, 0x1, 0x1)
        /usr/lib64/go/src/runtime/malloc.go:741 +0x546 fp=0xc4203e8d38 sp=0xc4203e8c90 pc=0x411876
runtime.newobject(0xa717e0, 0xc42032f430)
        /usr/lib64/go/src/runtime/malloc.go:840 +0x38 fp=0xc4203e8d68 sp=0xc4203e8d38 pc=0x411d68
github.com/prometheus/node_exporter/vendor/github.com/prometheus/client_golang/prometheus.NewConstMetric(0xc42018e460, 0x2, 0x3ff0000000000000, 0xc42032f430, 0x1, 0x1, 0x10, 0x9f9dc0, 0x8a0601, 0xc42032f430)
        /var/tmp/portage/net-analyzer/prometheus-node_exporter-0.15.0/work/prometheus-node_exporter-0.15.0/src/github.com/prometheus/node_exporter/vendor/github.com/prometheus/client_golang/prometheus/value.go:165 +0xd0 fp=0xc4203e8dd0 sp=0xc4203e8d68 pc=0x77a980

2017/11/07 06:32:49 http: panic serving 172.20.0.1:38504: runtime error: growslice: cap out of range
goroutine 41 [running]:
net/http.(*conn).serve.func1(0xc4201cdd60)
        /usr/lib64/go/src/net/http/server.go:1697 +0xd0
panic(0xa24f20, 0xb41190)
        /usr/lib64/go/src/runtime/panic.go:491 +0x283
fmt.(*buffer).WriteString(...)
        /usr/lib64/go/src/fmt/print.go:82
fmt.(*fmt).padString(0xc42053a040, 0xc4204e6800, 0xc4204e6850)
        /usr/lib64/go/src/fmt/format.go:110 +0x110
fmt.(*fmt).fmt_s(0xc42053a040, 0xc4204e6800, 0xc4204e6850)
        /usr/lib64/go/src/fmt/format.go:328 +0x61
fmt.(*pp).fmtString(0xc42053a000, 0xc4204e6800, 0xc4204e6850, 0xc400000073)
        /usr/lib64/go/src/fmt/print.go:433 +0x197
fmt.(*pp).printArg(0xc42053a000, 0x9f4700, 0xc42041c290, 0x73)
        /usr/lib64/go/src/fmt/print.go:664 +0x7b5
fmt.(*pp).doPrintf(0xc42053a000, 0xae7c2d, 0x2c, 0xc420475670, 0x2, 0x2)
        /usr/lib64/go/src/fmt/print.go:996 +0x15a
fmt.Sprintf(0xae7c2d, 0x2c, 0xc420475670, 0x2, 0x2, 0x10, 0x9f4700)
        /usr/lib64/go/src/fmt/print.go:196 +0x66
fmt.Errorf(0xae7c2d, 0x2c, 0xc420475670, 0x2, 0x2, 0xc420410301, 0xc420410300)
        /usr/lib64/go/src/fmt/print.go:205 +0x5a

runtime: pointer 0xc4203e2fb0 to unallocated span idx=0x1f1 span.base()=0xc4203dc000 span.limit=0xc4203e6000 span.state=3
runtime: found in object at *(0xc420382a80+0x80)
object=0xc420382a80 k=0x62101c1 s.base()=0xc420382000 s.limit=0xc420383f80 s.spanclass=42 s.elemsize=384 s.state=_MSpanInUse
 <snip>
fatal error: found bad pointer in Go heap (incorrect use of unsafe or cgo?)

runtime stack:
runtime.throw(0xaee4fe, 0x3e)
        /usr/lib64/go/src/runtime/panic.go:605 +0x95 fp=0x7f0f19ffab90 sp=0x7f0f19ffab70 pc=0x42c815
runtime.heapBitsForObject(0xc4203e2fb0, 0xc420382a80, 0x80, 0xc41ffd8a33, 0xc400000000, 0x7f0f400ac560, 0xc420031260, 0x11)
        /usr/lib64/go/src/runtime/mbitmap.go:425 +0x489 fp=0x7f0f19ffabe8 sp=0x7f0f19ffab90 pc=0x4137c9
runtime.scanobject(0xc420382a80, 0xc420031260)
        /usr/lib64/go/src/runtime/mgcmark.go:1187 +0x25d fp=0x7f0f19ffac90 sp=0x7f0f19ffabe8 pc=0x41ebed
runtime.gcDrain(0xc420031260, 0x5)
        /usr/lib64/go/src/runtime/mgcmark.go:943 +0x1ea fp=0x7f0f19fface0 sp=0x7f0f19ffac90 pc=0x41e42a
runtime.gcBgMarkWorker.func2()
        /usr/lib64/go/src/runtime/mgc.go:1773 +0x80 fp=0x7f0f19ffad20 sp=0x7f0f19fface0 pc=0x4580b0
runtime.systemstack(0xc420436ab8)
        /usr/lib64/go/src/runtime/asm_amd64.s:344 +0x79 fp=0x7f0f19ffad28 sp=0x7f0f19ffad20 pc=0x45a469
runtime.mstart()
        /usr/lib64/go/src/runtime/proc.go:1125 fp=0x7f0f19ffad30 sp=0x7f0f19ffad28 pc=0x430fe0

unexpected fault address 0x0
unexpected fault address 0x0
fatal error: fault
[signal SIGSEGV: segmentation violation code=0x80 addr=0x0 pc=0x76b998]

goroutine 13 [running]:
runtime.throw(0xabfb11, 0x5)
        /usr/local/go/src/runtime/panic.go:605 +0x95 fp=0xc420060c40 sp=0xc420060c20 pc=0x42c725
runtime.sigpanic()
        /usr/local/go/src/runtime/signal_unix.go:374 +0x227 fp=0xc420060c90 sp=0xc420060c40 pc=0x443197
github.com/prometheus/node_exporter/vendor/github.com/prometheus/client_model/go.(*LabelPair).GetName(...)
        /go/src/github.com/prometheus/node_exporter/vendor/github.com/prometheus/client_model/go/metrics.pb.go:85
github.com/prometheus/node_exporter/vendor/github.com/prometheus/client_golang/prometheus.(*Desc).String(0xc4203ae010, 0xaea9d0, 0xc42045c000)
        /go/src/github.com/prometheus/node_exporter/vendor/github.com/prometheus/client_golang/prometheus/desc.go:179 +0xc8 fp=0xc420060dc8 sp=0xc420060c90 pc=0x76b998

GRUB_BADRAM="0x36a700000,0xfffffffffff00000,0x460e00000,0xfffffffffff00000,0x4ea000000,0xfffffffffff00000"

dir /dev 755 0 0
nod /dev/console 0600 0 0 c 5 1
nod /dev/null 0666 0 0 c 1 3
dir /bin 755 0 0
file /bin/busybox busybox 755 0 0
slink /bin/sh busybox 755 0 0
slink /bin/true busybox 755 0 0
file /init init.sh 755 0 0
file /reproducer reproducer 755 0 0

#!/bin/sh
export PATH=/bin

start=$(busybox date +%s)

echo "Starting test now..."
/reproducer
ret=$?
end=$(busybox date +%s)
echo "Test exited with status $ret after $((end-start)) seconds"

scripts/gen_initramfs_list.sh -o initramfs.gz list.txt

qemu-system-x86_64 -kernel /boot/vmlinuz-4.13.9-gentoo -initrd initramfs.gz -append 'console=ttyS0' -smp 8 -nographic -serial mon:stdio -cpu host -enable-kvm

/*
 * Force always-inline if the user requests it so via the .config,
 * or if gcc is too old.
 * GCC does not warn about unused static inline functions for
 * -Wunused-function.  This turns out to avoid the need for complex #ifdef
 * directives.  Suppress the warning in clang as well by using "unused"
 * function attribute, which is redundant but not harmful for gcc.
 */
#if !defined(CONFIG_ARCH_SUPPORTS_OPTIMIZED_INLINING) ||                \
    !defined(CONFIG_OPTIMIZE_INLINING) || (__GNUC__ < 4)
#define inline inline           __attribute__((always_inline,unused)) notrace
#define __inline__ __inline__   __attribute__((always_inline,unused)) notrace
#define __inline __inline       __attribute__((always_inline,unused)) notrace
#else
/* A lot of inline functions can cause havoc with function tracing */
#define inline inline           __attribute__((unused)) notrace
#define __inline__ __inline__   __attribute__((unused)) notrace
#define __inline __inline       __attribute__((unused)) notrace
#endif

#!/bin/bash
args=("$@")

doit=
while [ $# -gt 0 ]; do
        case "$1" in
                -c)
                        doit=1
                        ;;
                -o)
                        shift
                        objfile="$1"
                        ;;
        esac
        shift
done

extra=
if [ ! -z "$doit" ]; then
        sha="$(echo -n "$objfile" | sha1sum - | cut -d" " -f1)"
        echo "${sha:0:8} $objfile" >> objs.txt
        if [ $((0x${sha:0:8} & (0x80000000 >> $BIT))) = 0 ]; then
                echo "[n]" "$objfile" 1>&2
        else
                extra=-DCONFIG_OPTIMIZE_INLINING
                echo "[y]" "$objfile" 1>&2
        fi
fi

exec gcc $extra "${args[@]}"

$ grep '^[0246][012389ab][0189][014589cd][028a][012389ab][014589cd]' objs_0.txt
6b9cab4f arch/x86/entry/vdso/vclock_gettime.o

arch/x86/entry/vdso/vclock_gettime.o.no_inline_opt:     file format elf64-x86-64


Disassembly of section .text:

0000000000000000 <vread_tsc>:
   0:   55                      push   %rbp
   1:   48 89 e5                mov    %rsp,%rbp
   4:   90                      nop
   5:   90                      nop
   6:   90                      nop
   7:   0f 31                   rdtsc  
   9:   48 c1 e2 20             shl    $0x20,%rdx
   d:   48 09 d0                or     %rdx,%rax
  10:   48 8b 15 00 00 00 00    mov    0x0(%rip),%rdx        # 17 <vread_tsc+0x17>
  17:   48 39 c2                cmp    %rax,%rdx
  1a:   77 02                   ja     1e <vread_tsc+0x1e>
  1c:   5d                      pop    %rbp
  1d:   c3                      retq   
  1e:   48 89 d0                mov    %rdx,%rax
  21:   5d                      pop    %rbp
  22:   c3                      retq   
  23:   0f 1f 00                nopl   (%rax)
  26:   66 2e 0f 1f 84 00 00    nopw   %cs:0x0(%rax,%rax,1)
  2d:   00 00 00 

0000000000000030 <__vdso_clock_gettime>:
  30:   55                      push   %rbp
  31:   48 89 e5                mov    %rsp,%rbp
  34:   48 81 ec 20 10 00 00    sub    $0x1020,%rsp
  3b:   48 83 0c 24 00          orq    $0x0,(%rsp)
  40:   48 81 c4 20 10 00 00    add    $0x1020,%rsp
  47:   4c 8d 0d 00 00 00 00    lea    0x0(%rip),%r9        # 4e <__vdso_clock_gettime+0x1e>
  4e:   83 ff 01                cmp    $0x1,%edi
  51:   74 66                   je     b9 <__vdso_clock_gettime+0x89>
  53:   0f 8e dc 00 00 00       jle    135 <__vdso_clock_gettime+0x105>
  59:   83 ff 05                cmp    $0x5,%edi
  5c:   74 34                   je     92 <__vdso_clock_gettime+0x62>
  5e:   83 ff 06                cmp    $0x6,%edi
  61:   0f 85 c2 00 00 00       jne    129 <__vdso_clock_gettime+0xf9>
[...]

arch/x86/entry/vdso/vclock_gettime.o.inline_opt:     file format elf64-x86-64


Disassembly of section .text:

0000000000000000 <__vdso_clock_gettime>:
   0:   55                      push   %rbp
   1:   4c 8d 0d 00 00 00 00    lea    0x0(%rip),%r9        # 8 <__vdso_clock_gettime+0x8>
   8:   83 ff 01                cmp    $0x1,%edi
   b:   48 89 e5                mov    %rsp,%rbp
   e:   74 66                   je     76 <__vdso_clock_gettime+0x76>
  10:   0f 8e dc 00 00 00       jle    f2 <__vdso_clock_gettime+0xf2>
  16:   83 ff 05                cmp    $0x5,%edi
  19:   74 34                   je     4f <__vdso_clock_gettime+0x4f>
  1b:   83 ff 06                cmp    $0x6,%edi
  1e:   0f 85 c2 00 00 00       jne    e6 <__vdso_clock_gettime+0xe6>
[...]

 30:   55                      push   %rbp
  31:   48 89 e5                mov    %rsp,%rbp
  34:   48 81 ec 20 10 00 00    sub    $0x1020,%rsp
  3b:   48 83 0c 24 00          orq    $0x0,(%rsp)
  40:   48 81 c4 20 10 00 00    add    $0x1020,%rsp

TEXT runtime·walltime(SB),NOSPLIT,$16
    // Be careful. We're calling a function with gcc calling convention here.
    // We're guaranteed 128 bytes on entry, and we've taken 16, and the
    // call uses another 8.
    // That leaves 104 for the gettime code to use. Hope that's enough!