Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

runtime: sweep increased allocation count crash on arm64 #36101

Closed
jing-rui opened this issue Dec 12, 2019 · 20 comments
Closed

runtime: sweep increased allocation count crash on arm64 #36101

jing-rui opened this issue Dec 12, 2019 · 20 comments
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. release-blocker
Milestone

Comments

@jing-rui
Copy link

jing-rui commented Dec 12, 2019

What version of Go are you using (go version)?

$ go version
go version go1.13.3 linux/arm64

we applied some patch to go1.13.3:

2019-08-06 02:42 b25ec50b69  syscall: implement rawVforkSyscall for linux/arm64
2019-09-11 02:26 904f046e2b  runtime: fix crash during VDSO calls on arm
2019-10-23 11:42 758eb020f7  runtime: save/fetch g register during VDSO on ARM and ARM64
2019-10-31 10:32 f07cbc7f88  runtime: don't fetch G from signal stack when using cgo
2019-11-10 13:18 75c839af22  runtime: don't save G during VDSO if we're handling signal
2019-10-28 09:29 0ae9389609  runtime: fix textOff for multiple text sections

tested using go1.11.2 and go1.13.3, crash occurs on both golang version.

Does this issue reproduce with the latest release?

not tested, the go1.13.5 shall reproducible. I'll try master branch soon.

What operating system and processor architecture are you using (go env)?

go env Output
$ go env
GO111MODULE=""
GOARCH="arm64"
GOBIN=""
GOCACHE="/root/.cache/go-build"
GOENV="/root/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="arm64"
GOHOSTOS="linux"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/root/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/lib/golang"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/lib/golang/pkg/tool/linux_arm64"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD=""
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build956154425=/tmp/go-build -gno-record-gcc-switches"

What did you do?

  1. build and install docker-engine(we use docker-ce 18.09) using go1.13.3 on arm64 environment. linux kernel 4.19.36. We can reproduce using physical machine, but not easy on virtual machines.
  2. run container using follow command, then wait a long time.
#!/bin/bash

for ((i=0;i<100;i++)); do
docker run -tid --name=jj-$i --health-interval 1s --health-cmd date ubuntu-arm64 bash
done
  1. some containers will exit, and core files generated.
    image

we get 2 core files core_containerd-shim_31862_1576112309 core_containerd-shim_53653_1576133943

gdb ./containerd-shim core_containerd-shim_31862_1576112309
(gdb) bt
#0  runtime.raise () at /usr/lib/golang/src/runtime/sys_linux_arm64.s:156
#1  0x00000000000517b8 in runtime.dieFromSignal (sig=6) at /usr/lib/golang/src/runtime/signal_unix.go:454
#2  0x0000000000051d70 in runtime.sigfwdgo (sig=6, info=0x4000106da0, ctx=0x4000106e20, ~r3=<optimized out>) at /usr/lib/golang/src/runtime/signal_unix.go:657
#3  0x0000000000050f78 in runtime.sigtrampgo (sig=<optimized out>, info=0x4000106da0, ctx=0x4000106e20) at /usr/lib/golang/src/runtime/signal_unix.go:316
#4  0x0000000000069438 in runtime.sigtramp () at /usr/lib/golang/src/runtime/sys_linux_arm64.s:404
#5  <signal handler called>
#6  runtime.raise () at /usr/lib/golang/src/runtime/sys_linux_arm64.s:156
#7  0x00000000000517b8 in runtime.dieFromSignal (sig=6) at /usr/lib/golang/src/runtime/signal_unix.go:454
#8  0x0000000000051978 in runtime.crash () at /usr/lib/golang/src/runtime/signal_unix.go:546
#9  0x0000000000064988 in runtime.fatalthrow.func1 () at /usr/lib/golang/src/runtime/panic.go:833
#10 0x000000000003c520 in runtime.fatalthrow () at /usr/lib/golang/src/runtime/panic.go:826
#11 0x000000000003c384 in runtime.throw (s=...) at /usr/lib/golang/src/runtime/panic.go:774
#12 0x0000000000031838 in runtime.(*mspan).sweep (s=0xffff86a10b88, preserve=false, ~r1=<optimized out>) at /usr/lib/golang/src/runtime/mgcsweep.go:328
#13 0x0000000000025ab0 in runtime.(*mcentral).uncacheSpan (c=0x5a64f8 <runtime.mheap_+8760>, s=0xffff86a10b88) at /usr/lib/golang/src/runtime/mcentral.go:197
#14 0x0000000000025390 in runtime.(*mcache).releaseAll (c=0xffff86a046d0) at /usr/lib/golang/src/runtime/mcache.go:158
#15 0x000000000002541c in runtime.(*mcache).prepareForSweep (c=0xffff86a046d0) at /usr/lib/golang/src/runtime/mcache.go:185
#16 0x0000000000047c98 in runtime.acquirep (_p_=0x4000022500) at /usr/lib/golang/src/runtime/proc.go:4117
#17 0x0000000000042188 in runtime.stopm () at /usr/lib/golang/src/runtime/proc.go:1930
#18 0x0000000000042bfc in runtime.gcstopm () at /usr/lib/golang/src/runtime/proc.go:2125
#19 0x000000000004428c in runtime.schedule () at /usr/lib/golang/src/runtime/proc.go:2481
#20 0x0000000000044608 in runtime.goschedImpl (gp=0x40001b9c80) at /usr/lib/golang/src/runtime/proc.go:2625
#21 0x0000000000044838 in runtime.gopreempt_m (gp=0x40001b9c80) at /usr/lib/golang/src/runtime/proc.go:2653
#22 0x0000000000054924 in runtime.newstack () at /usr/lib/golang/src/runtime/stack.go:1038
#23 0x0000000000066130 in runtime.morestack () at /usr/lib/golang/src/runtime/asm_arm64.s:310
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

325         nfreed := s.allocCount - nalloc
326         if nalloc > s.allocCount {
327                 print("runtime: nelems=", s.nelems, " nalloc=", nalloc, " previous allocCount=", s.allocCount, " nfreed=", nfreed, "\n")
**328                 throw("sweep increased allocation count")**
329         }


(gdb) x /100 0xffff86a10b88
0xffff86a10b88: 0x00000000      0x00000000      0x00000000      0x00000000
next=0 prev=0
0xffff86a10b98: 0x005a6508      0x00000000      0x00238000      0x00000040
list=0x005a6508 startAddr=0x00000040/0x00238000
0xffff86a10ba8: 0x00000005      0x00000000      0x00000000      0x00000000
npages=5 manualFreeList=0
0xffff86a10bb8: 0x00000001      0x00000000      0x00000002      0x00000000
freeindex=1 nelems=2
0xffff86a10bc8: 0xffffffff      0x7fffffff      0x845d3c18      0x0000ffff
allocCache=0x7fffffff/0xffffffff allocBits=0x0000ffff/0x845d3c18
0xffff86a10bd8: 0x845d3c10      0x0000ffff      0x00069c41      0x00000007
gcmarkBits=0x0000ffff/0x845d3c10 sweepgen=7 divMul=6 baseMask=0x9c41
0xffff86a10be8: 0x017a0001      0x00050c00      0x00005000      0x00000000
allocCount=5 spanClass=0xc state=0 needzero=1 divShift=0x7a divShift2=0 scavenged=true
elemsize=0x5000
0xffff86a10bf8: 0x00242000      0x00000040      0x00000000      0x00000000
limit=0x00000040/0x00242000 speciallock=0
0xffff86a10c08: 0x00000000      0x00000000      0x00000000      0x00000000
specials=0


gdb ./containerd-shim core_containerd-shim_53653_1576133943
(gdb) bt
#0  runtime.raise () at /usr/lib/golang/src/runtime/sys_linux_arm64.s:156
#1  0x00000000000517b8 in runtime.dieFromSignal (sig=6) at /usr/lib/golang/src/runtime/signal_unix.go:454
#2  0x0000000000051d70 in runtime.sigfwdgo (sig=6, info=0x400015eda0, ctx=0x400015ee20, ~r3=<optimized out>) at /usr/lib/golang/src/runtime/signal_unix.go:657
#3  0x0000000000050f78 in runtime.sigtrampgo (sig=<optimized out>, info=0x400015eda0, ctx=0x400015ee20) at /usr/lib/golang/src/runtime/signal_unix.go:316
#4  0x0000000000069438 in runtime.sigtramp () at /usr/lib/golang/src/runtime/sys_linux_arm64.s:404
#5  <signal handler called>
#6  runtime.raise () at /usr/lib/golang/src/runtime/sys_linux_arm64.s:156
#7  0x00000000000517b8 in runtime.dieFromSignal (sig=6) at /usr/lib/golang/src/runtime/signal_unix.go:454
#8  0x0000000000051978 in runtime.crash () at /usr/lib/golang/src/runtime/signal_unix.go:546
#9  0x0000000000064988 in runtime.fatalthrow.func1 () at /usr/lib/golang/src/runtime/panic.go:833
#10 0x0000000000066080 in runtime.systemstack () at /usr/lib/golang/src/runtime/asm_arm64.s:237
#11 0x0000000000040970 in runtime.startTheWorldWithSema (emitTraceEvent=false, ~r1=<optimized out>) at /usr/lib/golang/src/runtime/proc.go:1080
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

1078 }
1079
**1080 func startTheWorldWithSema(emitTraceEvent bool) int64 {**
1081         mp := acquirem() // disable preemption because it can be holding p in a local var
1082         if netpollinited() {
1083                 list := netpoll(false) // non-blocking
1084                 injectglist(&list)
1085         }

 223         // switch to g0
 224         MOVD    R5, g
 225         BL      runtime·save_g(SB)
 226         MOVD    (g_sched+gobuf_sp)(g), R3
 227         // make it look like mstart called systemstack on g0, to stop traceback
 228         SUB     $16, R3
 229         AND     $~15, R3
 230         MOVD    $runtime·mstart(SB), R4
 231         MOVD    R4, 0(R3)
 232         MOVD    R3, RSP
 233         MOVD    (g_sched+gobuf_bp)(g), R29
 234
 235         // call target function
 236         MOVD    0(R26), R3      // code pointer
 **237         BL      (R3)**

What did you expect to see?

containerd-shim not crash and no core files generated.

What did you see instead?

containerd-shim crash on arm64.

@ALTree ALTree changed the title runtime/gc: sweep increased allocation count crash on arm64 runtime: sweep increased allocation count crash on arm64 Dec 12, 2019
@ALTree ALTree added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Dec 12, 2019
@ALTree
Copy link
Member

ALTree commented Dec 12, 2019

cc @aclements @mknyszek

@jing-rui
Copy link
Author

jing-rui commented Dec 13, 2019

We can reproduce crash using golang master branch:

2019-12-10 17:27 22d28a24c8  runtime: force segv for nil defer function to be in deferre.. Dan Scales  danscales@googl..  (gh/master)
gdb ./containerd-shim core_containerd-shim_53653_1576133943
Core was generated by `containerd-shim -namespace moby -workdir /var/lib/docker/containerd/daemon/io.c'.
Program terminated with signal SIGABRT, Aborted.
#0  0x00000000000690f8 in runtime.gcStart.func2 () at /usr/lib/golang/src/runtime/mgc.go:1367
1367                    now = startTheWorldWithSema(trace.enabled)
[Current thread is 1 (LWP 53663)]
Loading Go Runtime support.
(gdb) bt
#0  0x00000000000690f8 in runtime.gcStart.func2 () at /usr/lib/golang/src/runtime/mgc.go:1367
#1  0x0000000000051d70 in runtime.(*hchan).sortkey (c=<optimized out>) at /usr/lib/golang/src/runtime/select.go:175
#2  runtime.selectgo (cas0=0x4000158000, order0=0x14, ncases=43, ~r3=<optimized out>, ~r4=<optimized out>) at /usr/lib/golang/src/runtime/select.go:188
#3  0x0000000000000000 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

stderr print like below:

2019-12-13T12:01:59.106556+08:00|info|dockerd[67698]|runtime: nelems=2 nalloc=2 previous allocCount=1 nfreed=65535
2019-12-13T12:01:59.106556+08:00|info|dockerd[67698]|fatal error: sweep increased allocation count

runtime stack:
runtime.throw(0x3116d4, 0x20)
        /usr/lib/golang/src/runtime/panic.go:1112 +0x54 fp=0x400009fcc0 sp=0x400009fc90 pc=0x402d4
runtime.(*mspan).sweep(0xffff6e0b9ef8, 0xffff6e0b9e00, 0x0)
        /usr/lib/golang/src/runtime/mgcsweep.go:328 +0x858 fp=0x400009fdf0 sp=0x400009fcc0 pc=0x31558
runtime.(*mcentral).uncacheSpan(0x5a96d8, 0xffff6e0b9ef8)
        /usr/lib/golang/src/runtime/mcentral.go:197 +0x120 fp=0x400009fe30 sp=0x400009fdf0 pc=0x25900
runtime.(*mcache).releaseAll(0xffff94d837d0)
        /usr/lib/golang/src/runtime/mcache.go:158 +0x70 fp=0x400009fe60 sp=0x400009fe30 pc=0x25220
runtime.(*mcache).prepareForSweep(0xffff94d837d0)
        /usr/lib/golang/src/runtime/mcache.go:185 +0x4c fp=0x400009fe90 sp=0x400009fe60 pc=0x252ac
runtime.procresize(0x2, 0x0)
        /usr/lib/golang/src/runtime/proc.go:4203 +0x468 fp=0x400009ff40 sp=0x400009fe90 pc=0x4c968
runtime.startTheWorldWithSema(0x6fd01, 0xb9ba1)
        /usr/lib/golang/src/runtime/proc.go:1024 +0x88 fp=0x400009ffa0 sp=0x400009ff40 pc=0x44ec8
runtime.gcMarkTermination.func3()
        /usr/lib/golang/src/runtime/mgc.go:1741 +0x28 fp=0x400009ffc0 sp=0x400009ffa0 pc=0x69588
runtime.systemstack(0x0)
        /usr/lib/golang/src/runtime/asm_arm64.s:237 +0xa0 fp=0x400009ffd0 sp=0x400009ffc0 pc=0x6c820
runtime.mstart()
        /usr/lib/golang/src/runtime/proc.go:1077 fp=0x400009ffd0 sp=0x400009ffd0 pc=0x450c0
goroutine 44 [running]:
runtime.systemstack_switch()
        /usr/lib/golang/src/runtime/asm_arm64.s:182 +0x8 fp=0x4000156520 sp=0x4000156510 pc=0x6c768
runtime.gcMarkTermination(0x3fe90b5c8c493dd4)
        /usr/lib/golang/src/runtime/mgc.go:1741 +0x474 fp=0x40001566f0 sp=0x4000156520 pc=0x296b4
runtime.gcMarkDone()
        /usr/lib/golang/src/runtime/mgc.go:1616 +0x260 fp=0x4000156750 sp=0x40001566f0 pc=0x29190
runtime.gcBgMarkWorker(0x4000022800)
        /usr/lib/golang/src/runtime/mgc.go:2007 +0x2e4 fp=0x40001567d0 sp=0x4000156750 pc=0x2a114
runtime.goexit()
        /usr/lib/golang/src/runtime/asm_arm64.s:1148 +0x4 fp=0x40001567d0 sp=0x40001567d0 pc=0x6ef54
created by runtime.gcBgMarkStartWorkers
        /usr/lib/golang/src/runtime/mgc.go:1828 +0x80

326 if nalloc > s.allocCount {
327 print("runtime: nelems=", s.nelems, " nalloc=", nalloc, " previous allocCount=", s.allocCount, " nfreed=", nfreed, "\n")
328 throw("sweep increased allocation count")
329 }

full stderr logs Output
2019-12-13T12:01:59.108770+08:00|info|dockerd[67698]|runtime stack:
2019-12-13T12:01:59.108770+08:00|info|dockerd[67698]|runtime.throw(0x3116d4, 0x20)
2019-12-13T12:01:59.108770+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/panic.go:1112 +0x54 fp=0x400009fcc0 sp=0x400009fc90 pc=0x402d4
2019-12-13T12:01:59.108770+08:00|info|dockerd[67698]|runtime.(*mspan).sweep(0xffff6e0b9ef8, 0xffff6e0b9e00, 0x0)
2019-12-13T12:01:59.108770+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/mgcsweep.go:328 +0x858 fp=0x400009fdf0 sp=0x400009fcc0 pc=0x31558
2019-12-13T12:01:59.108770+08:00|info|dockerd[67698]|runtime.(*mcentral).uncacheSpan(0x5a96d8, 0xffff6e0b9ef8)
2019-12-13T12:01:59.108770+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/mcentral.go:197 +0x120 fp=0x400009fe30 sp=0x400009fdf0 pc=0x25900
2019-12-13T12:01:59.108770+08:00|info|dockerd[67698]|runtime.(*mcache).releaseAll(0xffff94d837d0)
2019-12-13T12:01:59.108770+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/mcache.go:158 +0x70 fp=0x400009fe60 sp=0x400009fe30 pc=0x25220
2019-12-13T12:01:59.108770+08:00|info|dockerd[67698]|runtime.(*mcache).prepareForSweep(0xffff94d837d0)
2019-12-13T12:01:59.108770+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/mcache.go:185 +0x4c fp=0x400009fe90 sp=0x400009fe60 pc=0x252ac
2019-12-13T12:01:59.108770+08:00|info|dockerd[67698]|runtime.procresize(0x2, 0x0)
2019-12-13T12:01:59.108770+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:4203 +0x468 fp=0x400009ff40 sp=0x400009fe90 pc=0x4c968
2019-12-13T12:01:59.108770+08:00|info|dockerd[67698]|runtime.startTheWorldWithSema(0x6fd01, 0xb9ba1)
2019-12-13T12:01:59.108770+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:1024 +0x88 fp=0x400009ffa0 sp=0x400009ff40 pc=0x44ec8
2019-12-13T12:01:59.108770+08:00|info|dockerd[67698]|runtime.gcMarkTermination.func3()
2019-12-13T12:01:59.109019+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/mgc.go:1741 +0x28 fp=0x400009ffc0 sp=0x400009ffa0 pc=0x69588
2019-12-13T12:01:59.109019+08:00|info|dockerd[67698]|runtime.systemstack(0x0)
2019-12-13T12:01:59.109019+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/asm_arm64.s:237 +0xa0 fp=0x400009ffd0 sp=0x400009ffc0 pc=0x6c820
2019-12-13T12:01:59.109019+08:00|info|dockerd[67698]|runtime.mstart()
2019-12-13T12:01:59.109019+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:1077 fp=0x400009ffd0 sp=0x400009ffd0 pc=0x450c0
2019-12-13T12:01:59.109019+08:00|info|dockerd[67698]|goroutine 44 [running]:
2019-12-13T12:01:59.109019+08:00|info|dockerd[67698]|runtime.systemstack_switch()
2019-12-13T12:01:59.109019+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/asm_arm64.s:182 +0x8 fp=0x4000156520 sp=0x4000156510 pc=0x6c768
2019-12-13T12:01:59.109019+08:00|info|dockerd[67698]|runtime.gcMarkTermination(0x3fe90b5c8c493dd4)
2019-12-13T12:01:59.109019+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/mgc.go:1741 +0x474 fp=0x40001566f0 sp=0x4000156520 pc=0x296b4
2019-12-13T12:01:59.109019+08:00|info|dockerd[67698]|runtime.gcMarkDone()
2019-12-13T12:01:59.109019+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/mgc.go:1616 +0x260 fp=0x4000156750 sp=0x40001566f0 pc=0x29190
2019-12-13T12:01:59.109019+08:00|info|dockerd[67698]|runtime.gcBgMarkWorker(0x4000022800)
2019-12-13T12:01:59.109019+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/mgc.go:2007 +0x2e4 fp=0x40001567d0 sp=0x4000156750 pc=0x2a114
2019-12-13T12:01:59.109019+08:00|info|dockerd[67698]|runtime.goexit()
2019-12-13T12:01:59.109019+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/asm_arm64.s:1148time="2019-12-13T12:01:59+08:00" level=info msg="try publish event(1) /tasks/exit &TaskExit{ContainerID:8560643a251e128464cad380cf644dde81d0607d24247d1b1a3078be0658a2b7,ID:9a49113ec471c31394b1f057c571767b92bd06ca663ed66e6a372a696f424fe6,Pid:97782,ExitStatus:0,ExitedAt:2019-12-13 12:01:58.88912011 +0800 CST m=+3589.699822311,} "
2019-12-13T12:01:59.109019+08:00|info|dockerd[67698]| +0x4 fp=0x40001567d0 sp=0x40001567d0 pc=0x6ef54
2019-12-13T12:01:59.109019+08:00|info|dockerd[67698]|created by runtime.gcBgMarkStartWorkers
2019-12-13T12:01:59.109019+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/mgc.go:1828 +0x80
2019-12-13T12:01:59.109019+08:00|info|dockerd[67698]|goroutine 1 [select]:
2019-12-13T12:01:59.109019+08:00|info|dockerd[67698]|runtime.gopark(0x31b880, 0x0, 0x1809, 0x1)
2019-12-13T12:01:59.109019+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:304 +0xd0 fp=0x40001898e0 sp=0x40001898c0 pc=0x42b00
2019-12-13T12:01:59.109019+08:00|info|dockerd[67698]|runtime.selectgo(0x4000189ab8, 0x4000189a38, 0x2, 0x1, 0x4000104201)
2019-12-13T12:01:59.109019+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/select.go:316 +0xa74 fp=0x4000189a00 sp=0x40001898e0 pc=0x525c4
2019-12-13T12:01:59.109019+08:00|info|dockerd[67698]|main.handleSignals(0x4000104230, 0x400004e720, 0x4000114090, 0x400010c0c0, 0x400013fe40, 0x0)
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/cmd/containerd-shim/main_unix.go:224 +0xbc fp=0x4000189c20 sp=0x4000189a00 pc=0x26911c
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|main.executeShim(0xffffc24dfbe2, 0x86)
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/cmd/containerd-shim/main_unix.go:180 +0x4f8 fp=0x4000189eb0 sp=0x4000189c20 pc=0x268c58
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|main.main()
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/cmd/containerd-shim/main_unix.go:109 +0x184 fp=0x4000189f70 sp=0x4000189eb0 pc=0x2684f4
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|runtime.main()
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:203 +0x234 fp=0x4000189fd0 sp=0x4000189f70 pc=0x42704
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|runtime.goexit()
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/asm_arm64.s:1148 +0x4 fp=0x4000189fd0 sp=0x4000189fd0 pc=0x6ef54
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|goroutine 2 [force gc (idle), 58 minutes]:
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|runtime.gopark(0x31b828, 0x57fee0, 0x1411, 0x1)
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:304 +0xd0 fp=0x400002efa0 sp=0x400002ef80 pc=0x42b00
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|runtime.goparkunlock(...)
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:310
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|runtime.forcegchelper()
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:253 +0xc0 fp=0x400002efd0 sp=0x400002efa0 pc=0x429b0
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|runtime.goexit()
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/asm_arm64.s:1148 +0x4 fp=0x400002efd0 sp=0x400002efd0 pc=0x6ef54
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|created by runtime.init.5
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:242 +0x30
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|goroutine 3 [runnable]:
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|runtime.gopark(0x31b828, 0x5800e0, 0x140c, 0x1)
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:304 +0xd0 fp=0x400002f7a0 sp=0x400002f780 pc=0x42b00
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|runtime.goparkunlock(...)
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:310
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|runtime.bgsweep(0x400004c000)
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/mgcsweep.go:89 +0x180 fp=0x400002f7d0 sp=0x400002f7a0 pc=0x306d0
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|runtime.goexit()
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/asm_arm64.s:1148 +0x4 fp=0x400002f7d0 sp=0x400002f7d0 pc=0x6ef54
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|created by runtime.gcenable
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/mgc.go:214 +0x54
2019-12-13T12:01:59.109360+08:00|info|dockerd[67698]|goroutine 4 [runnable]:
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|runtime.gopark(0x31b828, 0x5800a0, 0x4000021313, 0x2)
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:304time="2019-12-13T12:01:59+08:00" level=info msg="try publish event(1) /tasks/exit &TaskExit{ContainerID:cdb41101d2e2573147afd6aa0b70168475d7eaee737a7084d073e85188a8bc98,ID:df8c25c8bfbbcb31b499220444ca491c918a96577a50f166db7066f80e607870,Pid:97443,ExitStatus:0,ExitedAt:2019-12-13 12:01:58.82195383 +0800 CST m=+3490.412291761,} "
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]| +0xd0 fp=0x400002ff00 sp=0x400002fee0 pc=0x42b00
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|runtime.goparkunlock(...)
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:310
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|runtime.scavengeSleep(0x1324fc, 0xc7858)
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/mgcscavenge.go:203 +0xa4 fp=0x400002ff40 sp=0x400002ff00 pc=0x2ee54
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|runtime.bgscavenge(0x400004c000)
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/mgcscavenge.go:302 +0x2d4 fp=0x400002ffd0 sp=0x400002ff40 pc=0x2f154
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|runtime.goexit()
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/asm_arm64.s:1148 +0x4 fp=0x400002ffd0 sp=0x400002ffd0 pc=0x6ef54
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|created by runtime.gcenable
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/mgc.go:215 +0x74
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|goroutine 5 [finalizer wait]:
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|runtime.gopark(0x31b828, 0x5a9ca8, 0x4000111410, 0x1)
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:304 +0xd0 fp=0x400002e730 sp=0x400002e710 pc=0x42b00
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|runtime.goparkunlock(...)
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:310
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|runtime.runfinq()
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/mfinal.go:175 +0xbc fp=0x400002e7d0 sp=0x400002e730 pc=0x2663c
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|runtime.goexit()
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/asm_arm64.s:1148 +0x4 fp=0x400002e7d0 sp=0x400002e7d0 pc=0x6ef54
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|created by runtime.createfing
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/mfinal.go:156 +0x78
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|goroutine 6 [chan receive]:
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|runtime.gopark(0x31b648, 0x4000100058, 0x31170e, 0x2)
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:304 +0xd0 fp=0x4000050ec0 sp=0x4000050ea0 pc=0x42b00
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|runtime.chanrecv(0x4000100000, 0x4000050fb0, 0x31b801, 0x4000100101)
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/chan.go:563 +0x2c4 fp=0x4000050f50 sp=0x4000050ec0 pc=0x15904
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|runtime.chanrecv2(0x4000100000, 0x4000050fb0, 0x1)
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/chan.go:438 +0x28 fp=0x4000050f80 sp=0x4000050f50 pc=0x15628
2019-12-13T12:01:59.109786+08:00|info|dockerd[67698]|main.main.func1()
2019-12-13T12:01:59.110227+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/cmd/containerd-shim/main_unix.go:84 +0x6c fp=0x4000050fd0 sp=0x4000050f80 pc=0x269efc
2019-12-13T12:01:59.110227+08:00|info|dockerd[67698]|runtime.goexit()
2019-12-13T12:01:59.110227+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/asm_arm64.s:1148 +0x4 fp=0x4000050fd0 sp=0x4000050fd0 pc=0x6ef54
2019-12-13T12:01:59.110227+08:00|info|dockerd[67698]|created by main.main
2019-12-13T12:01:59.110227+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/cmd/containerd-shim/main_unix.go:83 +0x64
2019-12-13T12:01:59.110227+08:00|info|dockerd[67698]|goroutine 18 [syscall, 58 minutes]:
2019-12-13T12:01:59.110227+08:00|info|dockerd[67698]|syscall.Syscall6(0x16, 0xb, 0x40000547b0, 0x80, 0xffffffffffffffff, 0x0, 0x0, 0x40001640d8, 0x4000054748, 0x21d660)
2019-12-13T12:01:59.110227+08:00|info|dockerd[67698]|	/usr/lib/golang/src/syscall/asm_linux_arm64.s:35 +0x10 fp=0x40000546e0 sp=0x40000546d0 pc=0x90770
2019-12-13T12:01:59.110227+08:00|info|dockerd[67698]|github.com/containerd/containerd/vendor/golang.org/x/sys/unix.EpollWait(0xb, 0x40000547b0, 0x80, 0x80, 0xffffffffffffffff, 0x1, 0x0, 0x0)
2019-12-13T12:01:59.110227+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/vendor/golang.org/x/sys/unix/zsyscall_linux_arm64.go:1499 +0x58 fp=0x4000054750 sp=0x40000546e0 pc=0x21ca08
2019-12-13T12:01:59.110227+08:00|info|dockerd[67698]|github.com/containerd/containerd/vendor/github.com/containerd/console.(*Epoller).Wait(0x4000102060, 0x40000a3a50, 0x40000a3a58)
2019-12-13T12:01:59.110227+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/vendor/github.com/containerd/console/console_linux.go:110 +0x64 fp=0x4000054fc0 sp=0x4000054750 pc=0x21d594
2019-12-13T12:01:59.110227+08:00|info|dockerd[67698]|runtime.goexit()
2019-12-13T12:01:59.110227+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/asm_arm64.s:1148 +0x4 fp=0x4000054fc0 sp=0x4000054fc0 pc=0x6ef54
2019-12-13T12:01:59.110227+08:00|info|dockerd[67698]|created by github.com/containerd/containerd/runtime/v1/shim.(*Service).initPlatform
2019-12-13T12:01:59.110227+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/runtime/v1/shim/service_linux.go:111 +0xac
2019-12-13T12:01:59.110227+08:00|info|dockerd[67698]|goroutine 17 [runnable]:
2019-12-13T12:01:59.110227+08:00|info|dockerd[67698]|reflect.Copy(0x293cc0, 0x40001dd5c0, 0x97, 0x293cc0, 0x400015ac28, 0x197, 0x97)
2019-12-13T12:01:59.110227+08:00|info|dockerd[67698]|	/usr/lib/golang/src/reflect/value.go:2051 +0x354 fp=0x4000240cd0 sp=0x4000240cd0 pc=0xbf964
2019-12-13T12:01:59.110227+08:00|info|dockerd[67698]|encoding/json.(*decodeState).array(0x400008a420, 0x293cc0, 0x400015ac28, 0x197, 0x400008a448, 0x5b)
2019-12-13T12:01:59.110227+08:00|info|dockerd[67698]|	/usr/lib/golang/src/encoding/json/decode.go:565 +0x534 fp=0x4000240dc0 sp=0x4000240cd0 pc=0x140fb4
2019-12-13T12:01:59.110522+08:00|info|dockerd[67698]|encoding/json.(*decodeState).value(0x400008a420, 0x293cc0, 0x400015ac28, 0x197, 0x293cc0, 0x400015ac28)
2019-12-13T12:01:59.110522+08:00|info|dockerd[67698]|	/usr/lib/golang/src/encoding/json/decode.go:377 +0xcc fp=0x4000240e30 sp=0x4000240dc0 pc=0x1401cc
2019-12-13T12:01:59.110522+08:00|info|dockerd[67698]|encoding/json.(*decodeState).object(0x400008a420, 0x28c1a0, 0x400015c080, 0x196, 0x400008a448, 0x7b)
2019-12-13T12:01:59.110522+08:00|info|dockerd[67698]|	/usr/lib/golang/src/encoding/json/decode.go:782 +0xf54 fp=0x40002410d0 sp=0x4000240e30 pc=0x142354
2019-12-13T12:01:59.110522+08:00|info|dockerd[67698]|encoding/json.(*decodeState).value(0x400008a420, 0x28c1a0, 0x400015c080, 0x196, 0x28c1a0, 0x400015c080)
2019-12-13T12:01:59.110522+08:00|info|dockerd[67698]|	/usr/lib/golang/src/encoding/json/decode.go:387 +0x58 fp=0x4000241140 sp=0x40002410d0 pc=0x140158
2019-12-13T12:01:59.110522+08:00|info|dockerd[67698]|encoding/json.(*decodeState).object(0x400008a420, 0x28bd60, 0x400009a1d8, 0x196, 0x400008a448, 0x7b)
2019-12-13T12:01:59.110522+08:00|info|dockerd[67698]|	/usr/lib/golang/src/encoding/json/decode.go:782 +0xf54 fp=0x40002413e0 sp=0x4000241140 pc=0x142354
2019-12-13T12:01:59.110522+08:00|info|dockerd[67698]|encoding/json.(*decodeState).value(0x400008a420, 0x28bd60, 0x400009a1d8, 0x196, 0x28bd60, 0x400009a1d8)
2019-12-13T12:01:59.110522+08:00|info|dockerd[67698]|	/usr/lib/golang/src/encoding/json/decode.go:387 +0x58 fp=0x4000241450 sp=0x40002413e0 pc=0x140158
2019-12-13T12:01:59.110522+08:00|info|dockerd[67698]|encoding/json.(*decodeState).object(0x400008a420, 0x28c560, 0x400009a180, 0x16, 0x400008a448, 0x7b)
2019-12-13T12:01:59.110522+08:00|info|dockerd[67698]|	/usr/lib/golang/src/encoding/json/decode.go:782 +0xf54 fp=0x40002416f0 sp=0x4000241450 pc=0x142354
2019-12-13T12:01:59.110522+08:00|info|dockerd[67698]|encoding/json.(*decodeState).value(0x400008a420, 0x28c560, 0x400009a180, 0x16, 0x40002417b8, 0x14e674)
2019-12-13T12:01:59.110522+08:00|info|dockerd[67698]|	/usr/lib/golang/src/encoding/json/decode.go:387 +0x58 fp=0x4000241760 sp=0x40002416f0 pc=0x140158
2019-12-13T12:01:59.110522+08:00|info|dockerd[67698]|encoding/json.(*decodeState).unmarshal(0x400008a420, 0x28c560, 0x400009a180, 0x400008a448, 0x0)
2019-12-13T12:01:59.110522+08:00|info|dockerd[67698]|	/usr/lib/golang/src/encoding/json/decode.go:180 +0x1c8 fp=0x40002417f0 sp=0x4000241760 pc=0x13f8d8
2019-12-13T12:01:59.110522+08:00|info|dockerd[67698]|encoding/json.Unmarshal(0x40001e0000, 0x508c, 0x528c, 0x28c560, 0x400009a180, 0x0, 0x0)
2019-12-13T12:01:59.110522+08:00|info|dockerd[67698]|	/usr/lib/golang/src/encoding/json/decode.go:107 +0xe4 fp=0x4000241840 sp=0x40002417f0 pc=0x13f364
2019-12-13T12:01:59.110522+08:00|info|dockerd[67698]|github.com/containerd/containerd/runtime/v1/shim.shouldKillAllOnExit(0x40000d4090, 0x86, 0x4000241b10, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/runtime/v1/shim/service.go:599 +0xe4 fp=0x40002418b0 sp=0x4000241840 pc=0x265754
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|github.com/containerd/containerd/runtime/v1/shim.(*Service).checkProcesses(0x400010c0c0, 0xbf74e12dc63ea098, 0x32ff0bf3b8d, 0x5804c0, 0x669, 0x0)
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/runtime/v1/shim/service.go:540 +0x84 fp=0x4000241f30 sp=0x40002418b0 pc=0x264e34
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|github.com/containerd/containerd/runtime/v1/shim.(*Service).processExits(0x400010c0c0)
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/runtime/v1/shim/service.go:532 +0x98 fp=0x4000241fd0 sp=0x4000241f30 pc=0x264d78
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|runtime.goexit()
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/asm_arm64.s:1148 +0x4 fp=0x4000241fd0 sp=0x4000241fd0 pc=0x6ef54
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|created by github.com/containerd/containerd/runtime/v1/shim.NewService
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/runtime/v1/shim/service.go:94 +0x358
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|goroutine 11 [syscall]:
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|runtime.notetsleepg(0x5aa060, 0xffffffffffffffff, 0x580d20)
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/lock_futex.go:227 +0x30 fp=0x4000031f80 sp=0x4000031f50 pc=0x1a000
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|os/signal.signal_recv(0x36be60)
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/sigqueue.go:147 +0xc4 fp=0x4000031fb0 sp=0x4000031f80 pc=0x576c4
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|os/signal.loop()
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|	/usr/lib/golang/src/os/signal/signal_unix.go:23 +0x20 fp=0x4000031fd0 sp=0x4000031fb0 pc=0x13d060
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|runtime.goexit()
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/asm_arm64.s:1148 +0x4 fp=0x4000031fd0 sp=0x4000031fd0 pc=0x6ef54
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|created by os/signal.Notify.func1
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|	/usr/lib/golang/src/os/signal/signal.go:127 +0x44
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|goroutine 12 [select, 58 minutes, locked to thread]:
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|runtime.gopark(0x31b880, 0x0, 0x1809, 0x1)
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:304 +0xd0 fp=0x400002a5f0 sp=0x400002a5d0 pc=0x42b00
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|runtime.selectgo(0x400002a770, 0x400002a768, 0x2, 0x8, 0x1)
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/select.go:316 +0xa74 fp=0x400002a710 sp=0x400002a5f0 pc=0x525c4
2019-12-13T12:01:59.110814+08:00|info|dockerd[67698]|runtime.ensureSigM.func1()
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/signal_unix.go:832 +0x1d0 fp=0x400002a7d0 sp=0x400002a710 pc=0x6bea0
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|runtime.goexit()
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/asm_arm64.s:1148 +0x4 fp=0x400002a7d0 sp=0x400002a7d0 pc=0x6ef54
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|created by runtime.ensureSigM
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/signal_unix.go:815 +0xdc
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|goroutine 19 [chan receive]:
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|runtime.gopark(0x31b648, 0x4000100238, 0x170e, 0x2)
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:304 +0xd0 fp=0x40001c3d00 sp=0x40001c3ce0 pc=0x42b00
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|runtime.chanrecv(0x40001001e0, 0x4000251e58, 0x1, 0x0)
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/chan.go:563 +0x2c4 fp=0x40001c3d90 sp=0x40001c3d00 pc=0x15904
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|runtime.chanrecv2(0x40001001e0, 0x4000251e58, 0x40001141b0)
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/chan.go:438 +0x28 fp=0x40001c3dc0 sp=0x40001c3d90 pc=0x15628
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|github.com/containerd/containerd/runtime/v1/shim.(*Service).forward(0x400010c0c0, 0x368260, 0x4000112010)
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/runtime/v1/shim/service.go:630 +0x4c fp=0x40001c3fc0 sp=0x40001c3dc0 pc=0x265a9c
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|runtime.goexit()
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/asm_arm64.s:1148 +0x4 fp=0x40001c3fc0 sp=0x40001c3fc0 pc=0x6ef54
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|created by github.com/containerd/containerd/runtime/v1/shim.NewService
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/runtime/v1/shim/service.go:98 +0x3e4
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|goroutine 20 [IO wait, 58 minutes]:
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|runtime.gopark(0x31b7f8, 0xffff6e0f6de0, 0x4000131b02, 0x5)
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:304 +0xd0 fp=0x4000056bb0 sp=0x4000056b90 pc=0x42b00
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|runtime.netpollblock(0xffff6e0f6db8, 0x72, 0x0)
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/netpoll.go:419 +0xa4 fp=0x4000056bf0 sp=0x4000056bb0 pc=0x3c3a4
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|internal/poll.runtime_pollWait(0xffff6e0f6db8, 0x72, 0x0)
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/netpoll.go:203 +0x44 fp=0x4000056c20 sp=0x4000056bf0 pc=0x3b8e4
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|internal/poll.(*pollDesc).wait(0x400014c098, 0x72, 0x0, 0x0, 0x308403)
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|	/usr/lib/golang/src/internal/poll/fd_poll_runtime.go:87 +0x38 fp=0x4000056c50 sp=0x4000056c20 pc=0xce098
2019-12-13T12:01:59.111177+08:00|info|dockerd[67698]|internal/poll.(*pollDesc).waitRead(...)
2019-12-13T12:01:59.111620+08:00|info|dockerd[67698]|	/usr/lib/golang/src/internal/poll/fd_poll_runtime.go:92
2019-12-13T12:01:59.111620+08:00|info|dockerd[67698]|internal/poll.(*FD).Accept(0x400014c080, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
2019-12-13T12:01:59.111620+08:00|info|dockerd[67698]|	/usr/lib/golang/src/internal/poll/fd_unix.go:384 +0x184 fp=0x4000056cd0 sp=0x4000056c50 pc=0xd03c4
2019-12-13T12:01:59.111620+08:00|info|dockerd[67698]|net.(*netFD).accept(0x400014c080, 0x4000060368, 0x4000056de8, 0x4aad4)
2019-12-13T12:01:59.111620+08:00|info|dockerd[67698]|	/usr/lib/golang/src/net/fd_unix.go:238 +0x2c fp=0x4000056dc0 sp=0x4000056cd0 pc=0x111e8c
2019-12-13T12:01:59.111620+08:00|info|dockerd[67698]|net.(*UnixListener).accept(0x40001142a0, 0x4000056e50, 0x4000056e58, 0x18)
2019-12-13T12:01:59.111620+08:00|info|dockerd[67698]|	/usr/lib/golang/src/net/unixsock_posix.go:162 +0x2c fp=0x4000056e00 sp=0x4000056dc0 pc=0x13031c
2019-12-13T12:01:59.111620+08:00|info|dockerd[67698]|net.(*UnixListener).Accept(0x40001142a0, 0x31a720, 0x40000602d0, 0x36f820, 0x4000014030)
2019-12-13T12:01:59.111620+08:00|info|dockerd[67698]|	/usr/lib/golang/src/net/unixsock.go:260 +0x5c fp=0x4000056e40 sp=0x4000056e00 pc=0x12e96c
2019-12-13T12:01:59.111620+08:00|info|dockerd[67698]|github.com/containerd/containerd/vendor/github.com/containerd/ttrpc.(*Server).Serve(0x4000114090, 0x36f820, 0x4000014030, 0x36e660, 0x40001142a0, 0x0, 0x0)
2019-12-13T12:01:59.111620+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/vendor/github.com/containerd/ttrpc/server.go:84 +0xc4 fp=0x4000056f30 sp=0x4000056e40 pc=0x23f9b4
2019-12-13T12:01:59.111620+08:00|info|dockerd[67698]|main.serve.func1(0x36e660, 0x40001142a0, 0x4000114090, 0x36f820, 0x4000014030)
2019-12-13T12:01:59.111620+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/cmd/containerd-shim/main_unix.go:209 +0x6c fp=0x4000056fb0 sp=0x4000056f30 pc=0x26a05c
2019-12-13T12:01:59.111620+08:00|info|dockerd[67698]|runtime.goexit()
2019-12-13T12:01:59.111620+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/asm_arm64.s:1148 +0x4 fp=0x4000056fb0 sp=0x4000056fb0 pc=0x6ef54
2019-12-13T12:01:59.111620+08:00|info|dockerd[67698]|created by main.serve
2019-12-13T12:01:59.111620+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/cmd/containerd-shim/main_unix.go:207 +0x178
2019-12-13T12:01:59.111620+08:00|info|dockerd[67698]|goroutine 21 [chan receive, 58 minutes]:
2019-12-13T12:01:59.111620+08:00|info|dockerd[67698]|runtime.gopark(0x31b648, 0x40001001d8, 0x170e, 0x2)
2019-12-13T12:01:59.111620+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:304 +0xd0 fp=0x4000154ec0 sp=0x4000154ea0 pc=0x42b00
2019-12-13T12:01:59.111620+08:00|info|dockerd[67698]|runtime.chanrecv(0x4000100180, 0x4000154fa8, 0x1, 0x0)
2019-12-13T12:01:59.111620+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/chan.go:563 +0x2c4 fp=0x4000154f50 sp=0x4000154ec0 pc=0x15904
2019-12-13T12:01:59.111620+08:00|info|dockerd[67698]|runtime.chanrecv2(0x4000100180, 0x4000154fa8, 0x0)
2019-12-13T12:01:59.111620+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/chan.go:438 +0x28 fp=0x4000154f80 sp=0x4000154f50 pc=0x15628
2019-12-13T12:01:59.111971+08:00|info|dockerd[67698]|main.executeShim.func1(0x4000100180, 0x4000104230)
2019-12-13T12:01:59.111971+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/cmd/containerd-shim/main_unix.go:176 +0x48 fp=0x4000154fc0 sp=0x4000154f80 pc=0x269fc8
2019-12-13T12:01:59.111971+08:00|info|dockerd[67698]|runtime.goexit()
2019-12-13T12:01:59.111971+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/asm_arm64.s:1148 +0x4 fp=0x4000154fc0 sp=0x4000154fc0 pc=0x6ef54
2019-12-13T12:01:59.111971+08:00|info|dockerd[67698]|created by main.executeShim
2019-12-13T12:01:59.111971+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/cmd/containerd-shim/main_unix.go:175 +0x4d4
2019-12-13T12:01:59.111971+08:00|info|dockerd[67698]|goroutine 13 [select]:
2019-12-13T12:01:59.111971+08:00|info|dockerd[67698]|runtime.gopark(0x31b880, 0x0, 0x1809, 0x1)
2019-12-13T12:01:59.111971+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:304 +0xd0 fp=0x40001c1ca0 sp=0x40001c1c80 pc=0x42b00
2019-12-13T12:01:59.111971+08:00|info|dockerd[67698]|runtime.selectgo(0x40001c1ef0, 0x40001c1e58, 0x4, 0x36f7e0, 0x400015a080)
2019-12-13T12:01:59.111971+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/select.go:316 +0xa74 fp=0x40001c1dc0 sp=0x40001c1ca0 pc=0x525c4
2019-12-13T12:01:59.111971+08:00|info|dockerd[67698]|github.com/containerd/containerd/vendor/github.com/containerd/ttrpc.(*serverConn).run(0x40000602d0, 0x36f820, 0x4000014030)
2019-12-13T12:01:59.111971+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/vendor/github.com/containerd/ttrpc/server.go:413 +0x28c fp=0x40001c1fc0 sp=0x40001c1dc0 pc=0x240cfc
2019-12-13T12:01:59.111971+08:00|info|dockerd[67698]|runtime.goexit()
2019-12-13T12:01:59.111971+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/asm_arm64.s:1148 +0x4 fp=0x40001c1fc0 sp=0x40001c1fc0 pc=0x6ef54
2019-12-13T12:01:59.111971+08:00|info|dockerd[67698]|created by github.com/containerd/containerd/vendor/github.com/containerd/ttrpc.(*Server).Serve
2019-12-13T12:01:59.111971+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/vendor/github.com/containerd/ttrpc/server.go:124 +0x204
2019-12-13T12:01:59.111971+08:00|info|dockerd[67698]|goroutine 22 [IO wait]:
2019-12-13T12:01:59.111971+08:00|info|dockerd[67698]|runtime.gopark(0x31b7f8, 0xffff6e0f6d00, 0x4000131b02, 0x5)
2019-12-13T12:01:59.111971+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:304 +0xd0 fp=0x40000529e0 sp=0x40000529c0 pc=0x42b00
2019-12-13T12:01:59.111971+08:00|info|dockerd[67698]|runtime.netpollblock(0xffff6e0f6cd8, 0x72, 0x4000159000)
2019-12-13T12:01:59.111971+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/netpoll.go:419 +0xa4 fp=0x4000052a20 sp=0x40000529e0 pc=0x3c3a4
2019-12-13T12:01:59.111971+08:00|info|dockerd[67698]|internal/poll.runtime_pollWait(0xffff6e0f6cd8, 0x72, 0xffffffffffffffff)
2019-12-13T12:01:59.111971+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/netpoll.go:203 +0x44 fp=0x4000052a50 sp=0x4000052a20 pc=0x3b8e4
2019-12-13T12:01:59.111971+08:00|info|dockerd[67698]|internal/poll.(*pollDesc).wait(0x400009a398, 0x72, 0x1000, 0x1000, 0xffffffffffffffff)
2019-12-13T12:01:59.112319+08:00|info|dockerd[67698]|	/usr/lib/golang/src/internal/poll/fd_poll_runtime.go:87 +0x38 fp=0x4000052a80 sp=0x4000052a50 pc=0xce098
2019-12-13T12:01:59.112319+08:00|info|dockerd[67698]|internal/poll.(*pollDesc).waitRead(...)
2019-12-13T12:01:59.112319+08:00|info|dockerd[67698]|	/usr/lib/golang/src/internal/poll/fd_poll_runtime.go:92
2019-12-13T12:01:59.112319+08:00|info|dockerd[67698]|internal/poll.(*FD).Read(0x400009a380, 0x4000159000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
2019-12-13T12:01:59.112319+08:00|info|dockerd[67698]|	/usr/lib/golang/src/internal/poll/fd_unix.go:169 +0x158 fp=0x4000052af0 sp=0x4000052a80 pc=0xceee8
2019-12-13T12:01:59.112319+08:00|info|dockerd[67698]|net.(*netFD).Read(0x400009a380, 0x4000159000, 0x1000, 0x1000, 0x4000052bd8, 0x15298, 0x4000052ba8)
2019-12-13T12:01:59.112319+08:00|info|dockerd[67698]|	/usr/lib/golang/src/net/fd_unix.go:202 +time="2019-12-13T12:01:59.112005680+08:00" level=debug msg="event published" ns=moby topic="/tasks/exit" type=containerd.events.TaskExit
2019-12-13T12:01:59.112319+08:00|info|dockerd[67698]|0x44 fp=0x4000052b50 sp=0x4000052af0 pc=0x111734
2019-12-13T12:01:59.112319+08:00|info|dockerd[67698]|net.(*conn).Read(0x400000e080, 0x4000159000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
2019-12-13T12:01:59.112319+08:00|info|dockerd[67698]|	/usr/lib/golang/src/net/net.go:184 +0x74 fp=0x4000052bb0 sp=0x4000052b50 pc=0x121fc4
2019-12-13T12:01:59.112319+08:00|info|dockerd[67698]|bufio.(*Reader).Read(0x40001003c0, 0x400015a060, 0xa, 0xa, time="2019-12-13T12:01:59.112118080+08:00" level=info msg="exit-del moby/221f3232721532fb516836d321f4c7b8dc2f423ef162695734db4912a41c691a.874.0 error="
2019-12-13T12:01:59.112319+08:00|info|dockerd[67698]|0x400006a478, 0x3, 0x4000052c48)
2019-12-13T12:01:59.112319+08:00|info|dockerd[67698]|	/usr/lib/golang/src/bufio/bufio.go:226 +0x238 fp=0x4000052c00 sp=0x4000052bb0 pc=0x1588d8
2019-12-13T12:01:59.112319+08:00|info|dockerd[67698]|io.ReadAtLeast(0x367ee0, 0x40001003c0, 0x400015a060, 0xa, 0xa, 0xa, 0x0, 0x2958c0, 0x2)
2019-12-13T12:01:59.112319+08:00|info|dockerd[67698]|	/usr/lib/golang/src/io/io.go:310 +0x78 fp=0x4000052c60 sp=0x4000052c00 pc=0x7b6f8
2019-12-13T12:01:59.112319+08:00|info|dockerd[67698]|io.ReadFull(...)
2019-12-13T12:01:59.112319+08:00|info|dockerd[67698]|	/usr/lib/golang/src/io/io.go:329
2019-12-13T12:01:59.112319+08:00|info|dockerd[67698]|github.com/containerd/containerd/vendor/github.com/containerd/ttrpc.readMessageHeader(0x400015a060, 0xa, 0xa, 0x367ee0, 0x40001003c0, 0x4000052f50, 0x4000116180, 0xffff94d83108, 0x4000052d38)
2019-12-13T12:01:59.112319+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/vendor/github.com/containerd/ttrpc/channel.go:54 +0x54 fp=0x4000052cc0 sp=0x4000052c60 pc=0x23ea14
2019-12-13T12:01:59.112596+08:00|info|dockerd[67698]|time="2019-12-13T12:01:59.112241140+08:00" level=info msg=event ExitStatus=0 ExitedAt="2019-12-13 04:01:59.05069064 +0000 UTC" Pid=874 ProcessID=e9de334155fece2bc946118b7831c741890b78dd74dc8c338f99278e8fb7b299 containerID=221f3232721532fb516836d321f4c7b8dc2f423ef162695734db4912a41c691a module=libcontainerd namespace=moby topic=/tasks/exit
2019-12-13T12:01:59.112623+08:00|info|dockerd[67698]|github.com/containerd/containerd/vendor/github.com/containerd/ttrpc.(*channel).recv(0x400015a040, 0x36f7e0, 0x400015a080, 0x2, 0x400008ed00, 0x0, 0x0, 0x72, 0x0, 0x0)
2019-12-13T12:01:59.112623+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/vendor/github.com/containerd/ttrpc/channel.go:102 +0x4c fp=0x4000052d70 sp=0x4000052cc0 pc=0x23eeec
2019-12-13T12:01:59.112623+08:00|info|dockerd[67698]|github.com/containerd/containerd/vendor/github.com/containerd/ttrpc.(*serverConn).run.func1(0x40001160c0, 0x40000602d0, 0x4000116180, 0x400015a040, 0x36f7e0, 0x400015a080, 0x4000116120, 0x4000100420)
2019-12-13T12:01:59.112623+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/vendor/github.com/containerd/ttrpc/server.go:344 +0x11c fp=0x4000052f90 sp=0x4000052d70 pc=0x24293c
2019-12-13T12:01:59.112623+08:00|info|dockerd[67698]|runtime.goexit()
2019-12-13T12:01:59.112623+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/asm_arm64.s:1148 +0x4 fp=0x4000052f90 sp=0x4000052f90 pc=0x6ef54
2019-12-13T12:01:59.112730+08:00|info|dockerd[67698]|created by time="2019-12-13T12:01:59.112411600+08:00" level=debug msg="attach: stdout: end"
2019-12-13T12:01:59.112753+08:00|info|dockerd[67698]|github.com/containerd/containerd/vendor/github.com/containerd/ttrpc.(*serverConn).run
2019-12-13T12:01:59.112753+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/vendor/github.com/containerd/ttrpc/server.go:314 +0x1b0
2019-12-13T12:01:59.112789+08:00|info|dockerd[67698]|goroutine 27 [IO waittime="2019-12-13T12:01:59.112444930+08:00" level=debug msg="attach: stderr: end"
2019-12-13T12:01:59.112810+08:00|info|dockerd[67698]|, 58 minutes]:
2019-12-13T12:01:59.112810+08:00|info|dockerd[67698]|runtime.gopark(0x31b7f8, 0xffff6e0f6b40, 0x4000131b02, 0x5)
2019-12-13T12:01:59.112843+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:304 +0xd0 fp=0x4000155c00 sp=0x4000155be0 pc=time="2019-12-13T12:01:59.112466010+08:00" level=debug msg="attach done"
2019-12-13T12:01:59.112863+08:00|info|dockerd[67698]|0x42b00
2019-12-13T12:01:59.112863+08:00|info|dockerd[67698]|runtime.netpollblock(0xffff6e0f6b18, 0x72, 0x40001c4000)
2019-12-13T12:01:59.112895+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/netpoll.go:419 +0xa4 fp=0x4000155c40 sp=0x4000155c00 pc=0x3c3a4time="2019-12-13T12:01:59.112497970+08:00" level=debug msg="Health check for container 221f3232721532fb516836d321f4c7b8dc2f423ef162695734db4912a41c691a done (exitCode=0)"
2019-12-13T12:01:59.112915+08:00|info|dockerd[67698]|internal/poll.runtime_pollWait(0xffff6e0f6b18, 0x72, 0xffffffffffffffff)
2019-12-13T12:01:59.112915+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/netpoll.go:203 +0x44 fp=0x4000155c70 sp=0x4000155c40 pc=0x3b8e4
2019-12-13T12:01:59.112915+08:00|info|dockerd[67698]|internal/poll.(*pollDesc).wait(0x4000100858, 0x72, 0x8001, 0x8000, 0xffffffffffffffff)
2019-12-13T12:01:59.112915+08:00|info|dockerd[67698]|	/usr/lib/golang/src/internal/poll/fd_poll_runtime.go:87 +0x38 fp=0x4000155ca0 sp=0x4000155c70 pc=0xce098
2019-12-13T12:01:59.112915+08:00|info|dockerd[67698]|internal/poll.(*pollDesc).waitRead(...)
2019-12-13T12:01:59.112915+08:00|info|dockerd[67698]|	/usr/lib/golang/src/internal/poll/fd_poll_runtime.go:92
2019-12-13T12:01:59.112915+08:00|info|dockerd[67698]|internal/poll.(*FD).Read(0x4000100840, 0x40001c4000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
2019-12-13T12:01:59.112915+08:00|info|dockerd[67698]|	/usr/lib/golang/src/internal/poll/fd_unix.go:169 +0x158 fp=0x4000155d10 sp=0x4000155ca0 pc=0xceee8
2019-12-13T12:01:59.112915+08:00|info|dockerd[67698]|os.(*File).read(...)
2019-12-13T12:01:59.112915+08:00|info|dockerd[67698]|	/usr/lib/golang/src/os/file_unix.go:263
2019-12-13T12:01:59.112915+08:00|info|dockerd[67698]|os.(*File).Read(0x4000106040, 0x40001c4000, 0x8000, 0x8000, 0x4000155df8, 0x1939c, 0x5a9cc0)
2019-12-13T12:01:59.112915+08:00|info|dockerd[67698]|	/usr/lib/golang/src/os/file.go:116 +0x60 fp=0x4000155d80 sp=0x4000155d10 pc=0xd5650
2019-12-13T12:01:59.112915+08:00|info|dockerd[67698]|github.com/containerd/containerd/vendor/github.com/containerd/fifo.(*fifo).Read(0x40001007e0, 0x40001c4000, 0x8000, 0x8000, 0x0, 0x270800, 0x4000155e88)
2019-12-13T12:01:59.112915+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/vendor/github.com/containerd/fifo/fifo.go:154 +0x218 fp=0x4000155e30 sp=0x4000155d80 pc=0x219b48
2019-12-13T12:01:59.112915+08:00|info|dockerd[67698]|io.copyBuffer(0x3680c0, 0x40001143f0, 0xffff6e0f70c0, 0x40001007e0, 0x40001c4000, 0x8000, 0x8000, 0x2bb4c0, 0x0, 0xffff6e0f70c0)
2019-12-13T12:01:59.112915+08:00|info|dockerd[67698]|	/usr/lib/golang/src/io/io.go:405 +0xd4 fp=0x4000155eb0 sp=0x4000155e30 pc=0x7b9f4
2019-12-13T12:01:59.112915+08:00|info|dockerd[67698]|io.CopyBuffer(0x3680c0, 0x40001143f0, 0xffff6e0f70c0, 0x40001007e0, 0x40001c4000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
2019-12-13T12:01:59.112915+08:00|info|dockerd[67698]|	/usr/lib/golang/src/io/io.go:378 +0x60 fp=0x4000155f10 sp=0x4000155eb0 pc=0x7b8c0
2019-12-13T12:01:59.113167+08:00|info|dockerd[67698]|github.com/containerd/containerd/runtime/v1/shim.(*linuxPlatform).CopyConsole.func1(0x400010a0f0, 0x40001143f0, 0x36dea0, 0x40001007e0, 0x4000106010)
2019-12-13T12:01:59.113167+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/runtime/v1/shim/service_linux.go:54 +0x10c fp=0x4000155fb0 sp=0x4000155f10 pc=0x26786c
2019-12-13T12:01:59.113167+08:00|info|dockerd[67698]|runtime.goexit()
2019-12-13T12:01:59.113167+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/asm_arm64.s:1148 +0x4 fp=0x4000155fb0 sp=0x4000155fb0 pc=0x6ef54
2019-12-13T12:01:59.113167+08:00|info|dockerd[67698]|created by github.com/containerd/containerd/runtime/v1/shim.(*linuxPlatform).CopyConsole
2019-12-13T12:01:59.113167+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/runtime/v1/shim/service_linux.go:50 +0x254
2019-12-13T12:01:59.113167+08:00|info|dockerd[67698]|goroutine 32 [sync.Cond.Wait, 58 minutes]:
2019-12-13T12:01:59.113167+08:00|info|dockerd[67698]|runtime.gopark(0x31b828, 0x400015a158, 0x1a14, 0x3)
2019-12-13T12:01:59.113167+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:304 +0xd0 fp=0x4000157540 sp=0x4000157520 pc=0x42b00
2019-12-13T12:01:59.113167+08:00|info|dockerd[67698]|runtime.goparkunlock(...)
2019-12-13T12:01:59.113167+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:310
2019-12-13T12:01:59.113167+08:00|info|dockerd[67698]|sync.runtime_notifyListWait(0x400015a150, 0x1)
2019-12-13T12:01:59.113167+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/sema.go:513 +0xfc fp=0x4000157590 sp=0x4000157540 pc=0x540dc
2019-12-13T12:01:59.113167+08:00|info|dockerd[67698]|sync.(*Cond).Wait(0x400015a140)
2019-12-13T12:01:59.113377+08:00|info|dockerd[67698]|	/usr/lib/golang/src/sync/cond.go:56 +0xb0 fp=0x40001575d0 sp=0x4000157590 pc=0x77880
2019-12-13T12:01:59.113377+08:00|info|dockerd[67698]|github.com/containerd/containerd/vendor/github.com/containerd/console.(*EpollConsole).Read(0x40001143f0, 0x4000166000, 0x8000, 0x8000, 0x0, 0x3683e0, 0x4000230d80)
2019-12-13T12:01:59.113377+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/vendor/github.com/containerd/console/console_linux.go:191 +0x84 fp=0x4000157630 sp=0x40001575d0 pc=0x21da04
2019-12-13T12:01:59.113377+08:00|info|dockerd[67698]|io.copyBuffer(0xffff6e0b60f8, 0x4000100900, 0x3680a0, 0x40001143f0, 0x4000166000, 0x8000, 0x8000, 0x2bb4c0, 0x0, 0xffff6e0b60f8)
2019-12-13T12:01:59.113377+08:00|info|dockerd[67698]|	/usr/lib/golang/src/io/io.go:405 +0xd4 fp=0x40001576b0 sp=0x4000157630 pc=0x7b9f4
2019-12-13T12:01:59.113377+08:00|info|dockerd[67698]|io.CopyBuffer(0xffff6e0b60f8, 0x4000100900, 0x3680a0, 0x40001143f0, 0x4000166000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
2019-12-13T12:01:59.113471+08:00|info|dockerd[67698]|	/usr/lib/golang/src/io/io.go:378 +0x60 fp=0x4000157710 sp=0x40001576b0 pc=0x7b8c0
2019-12-13T12:01:59.113471+08:00|info|dockerd[67698]|github.com/containerd/containerd/runtime/v1/shim.(*linuxPlatform).CopyConsole.func2(0x400010a0f0, 0x36dea0, 0x4000100900, 0x40001143f0, 0x36dea0, 0x4000100a20, 0x400008c2c0)
2019-12-13T12:01:59.113510+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/runtime/v1/shim/service_linux.go:74 +0x10c fp=0x40001577a0 sp=0x4000157710 pc=0x267a0c
2019-12-13T12:01:59.113510+08:00|info|dockerd[67698]|runtime.goexit()
2019-12-13T12:01:59.113541+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/asm_arm64.s:1148 +0x4 fp=0x40001577a0 sp=0x40001577a0 pc=0x6ef54
2019-12-13T12:01:59.113541+08:00|info|dockerd[67698]|created by github.com/containerd/containerd/runtime/v1/shim.(*linuxPlatform).CopyConsole
2019-12-13T12:01:59.113541+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/runtime/v1/shim/service_linux.go:70 +0x180
2019-12-13T12:01:59.113583+08:00|info|dockerd[67698]|goroutine 54 [GC worker (idle)]:
2019-12-13T12:01:59.113583+08:00|info|dockerd[67698]|runtime.gopark(0x31b6b8, 0x4000332840, 0x1418, 0x0)
2019-12-13T12:01:59.113616+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:304 +0xd0 fp=0x4000150f50 sp=0x4000150f30 pc=0x42b00
2019-12-13T12:01:59.113616+08:00|info|dockerd[67698]|runtime.gcBgMarkWorker(0x4000020000)
2019-12-13T12:01:59.113646+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/mgc.go:1880 +0xe8 fp=0x4000150fd0 sp=0x4000150f50 pc=0x29f18
2019-12-13T12:01:59.113646+08:00|info|dockerd[67698]|runtime.goexit()
2019-12-13T12:01:59.113691+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/asm_arm64.s:1148 +0x4 fp=0x4000150fd0 sp=0x4000150fd0 pc=0x6ef54
2019-12-13T12:01:59.113691+08:00|info|dockerd[67698]|created by runtime.gcBgMarkStartWorkers
2019-12-13T12:01:59.113740+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/mgc.go:1828 +0x80
2019-12-13T12:01:59.113740+08:00|info|dockerd[67698]|goroutine 96550 [semacquire]:
2019-12-13T12:01:59.113740+08:00|info|dockerd[67698]|runtime.gopark(0x31b828, 0x585fe0, 0x4000101912, 0x5)
2019-12-13T12:01:59.113792+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:304 +0xd0 fp=0x4000055a70 sp=0x4000055a50 pc=0x42b00
2019-12-13T12:01:59.113792+08:00|info|dockerd[67698]|runtime.goparkunlock(...)
2019-12-13T12:01:59.113792+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/proc.go:310
2019-12-13T12:01:59.113842+08:00|info|dockerd[67698]|runtime.semacquire1(0x400010c0c4, 0x79500, 0x3, 0x1)
2019-12-13T12:01:59.113842+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/sema.go:144 +0x190 fp=0x4000055ad0 sp=0x4000055a70 pc=0x53090
2019-12-13T12:01:59.113842+08:00|info|dockerd[67698]|sync.runtime_SemacquireMutex(0x400010c0c4, 0x4000016100, 0x1)
2019-12-13T12:01:59.113897+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/sema.go:71 +0x40 fp=0x4000055b00 sp=0x4000055ad0 pc=0x52e20
2019-12-13T12:01:59.113897+08:00|info|dockerd[67698]|sync.(*Mutex).lockSlow(0x400010c0c0)
2019-12-13T12:01:59.113935+08:00|info|dockerd[67698]|	/usr/lib/golang/src/sync/mutex.go:138 +0xec fp=0x4000055b80 sp=0x4000055b00 pc=0x794dc
2019-12-13T12:01:59.113935+08:00|info|dockerd[67698]|sync.(*Mutex).Lock(...)
2019-12-13T12:01:59.113969+08:00|info|dockerd[67698]|	/usr/lib/golang/src/sync/mutex.go:81
2019-12-13T12:01:59.113969+08:00|info|dockerd[67698]|github.com/containerd/containerd/runtime/v1/shim.(*Service).getExecProcess(0x400010c0c0, 0x400017e100, 0x40, 0x0, 0x0, 0x0, 0x0)
2019-12-13T12:01:59.114005+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/runtime/v1/shim/service.go:651 +0x180 fp=0x4000055c00 sp=0x4000055b80 pc=0x265f90
2019-12-13T12:01:59.114029+08:00|info|dockerd[67698]|github.com/containerd/containerd/runtime/v1/shim.(*Service).State(0x400010c0c0, 0x36f7e0, 0x400015a080, 0x400001eb00, 0x4000197d38, 0x2414ec, 0x40001dd380)
2019-12-13T12:01:59.114050+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/runtime/v1/shim/service.go:319 +0x3c fp=0x4000055ce0 sp=0x4000055c00 pc=0x2639cc
2019-12-13T12:01:59.114088+08:00|info|dockerd[67698]|github.com/containerd/containerd/runtime/v1/shim/v1.RegisterShimService.func1(0x36f7e0, 0x400015a080, 0x40001dd380, 0x40002fabd8, 0x5, 0x40001020c0, 0x0)
2019-12-13T12:01:59.114120+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/runtime/v1/shim/v1/shim.pb.go:1607 +0xac fp=0x4000055d40 sp=0x4000055ce0 pc=0x258b2c
2019-12-13T12:01:59.114173+08:00|info|dockerd[67698]|github.com/containerd/containerd/vendor/github.com/containerd/ttrpc.(*serviceSet).dispatch(0x4000106008, 0x36f7e0, 0x400015a080, 0x40001600c0, 0x25, 0x40002fabd8, 0x5, 0x40000161e0, 0x42, 0x42, ...)
2019-12-13T12:01:59.114194+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/vendor/github.com/containerd/ttrpc/services.go:87 +0xc4 fp=0x4000055dc0 sp=0x4000055d40 pc=0x241544
2019-12-13T12:01:59.114242+08:00|info|dockerd[67698]|github.com/containerd/containerd/vendor/github.com/containerd/ttrpc.(*serviceSet).call(0x4000106008, 0x36f7e0, 0x400015a080, 0x40001600c0, 0x25, 0x40002fabd8, 0x5, 0x40000161e0, 0x42, 0x42, ...)
2019-12-13T12:01:59.114273+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/vendor/github.com/containerd/ttrpc/services.go:60 +0x70 fp=0x4000055e80 sp=0x4000055dc0 pc=0x241340
2019-12-13T12:01:59.114304+08:00|info|dockerd[67698]|github.com/containerd/containerd/vendor/github.com/containerd/ttrpc.(*serverConn).run.func2(0x40000602d0, 0x36f7e0, 0x400015a080, 0xb175, 0x400008edc0, 0x40001160c0, 0x4000116180, 0x400000b175)
2019-12-13T12:01:59.114338+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/vendor/github.com/containerd/ttrpc/server.go:417 +0x84 fp=0x4000055f90 sp=0x4000055e80 pc=0x242ee4
2019-12-13T12:01:59.114338+08:00|info|dockerd[67698]|runtime.goexit()
2019-12-13T12:01:59.114370+08:00|info|dockerd[67698]|	/usr/lib/golang/src/runtime/asm_arm64.s:1148 +0x4 fp=0x4000055f90 sp=0x4000055f90 pc=0x6ef54
2019-12-13T12:01:59.114370+08:00|info|dockerd[67698]|created by github.com/containerd/containerd/vendor/github.com/containerd/ttrpc.(*serverConn).run
2019-12-13T12:01:59.114401+08:00|info|dockerd[67698]|	/data/containerd-1.2.0/.gopath/src/github.com/containerd/containerd/vendor/github.com/containerd/ttrpc/server.go:416 +0x688

@ianlancetaylor
Copy link
Contributor

Do you have any patches on the master branch you are using?

Tell us about your program. The most common cause of this kind of error is a pointer being incorrectly converted to uintptr, or C code storing a Go pointer into Go memory. Those are both forbidden. So: do you use unsafe? Do you use cgo?

Is there a way that we can reproduce the problem ourselves?

@jing-rui
Copy link
Author

jing-rui commented Dec 13, 2019

Do you have any patches on the master branch you are using?

no.

Tell us about your program. The most common cause of this kind of error is a pointer being incorrectly converted to uintptr, or C code storing a Go pointer into Go memory. Those are both forbidden. So: do you use unsafe? Do you use cgo?

the program use unsafe.
not use cgo.

if we set GODEBUG=gcstoptheworld=2, we can not reproduce the crash.

Is there a way that we can reproduce the problem ourselves?

reproduce steps:

  1. prepare an arm64 machine, with golang installed.
  2. install docke-ce 18.09, rpm files can be download from https://download.docker.com/linux/centos/7/aarch64/stable/Packages/
    rpm -ivh docker-ce-cli-18.09.9-3.el7.aarch64.rpm docker-ce-18.09.9-3.el7.aarch64.rpm containerd.io-1.2.10-3.2.el7.aarch64.rpm  --nodeps
    
  3. download and build containerd from https://github.com/containerd/containerd/releases/tag/v1.2.0
  4. install the new build bin/containerd-shim to /usr/bin/containerd-shim.
  5. run script to create 100 containers. then wait some containers exit.
    #!/bin/bash
    
    for ((i=0;i<100;i++)); do
    docker run -tid --name=jj-$i --health-interval 1s --health-cmd date ubuntu bash
    done
    

I'm trying to find a simple way to reproduce it.

@ianlancetaylor
Copy link
Contributor

You could try GODEBUG=gccheckmark=1. That might point to the erroneous object.

@jing-rui
Copy link
Author

using GODEBUG=gccheckmark=1

(gdb) bt
#0  runtime.raise () at /usr/lib/golang/src/runtime/sys_linux_arm64.s:167
#1  0x0000000000056838 in runtime.dieFromSignal (sig=6) at /usr/lib/golang/src/runtime/signal_unix.go:711
#2  0x0000000000056e3c in runtime.sigfwdgo (sig=6, info=0x4000132da0, ctx=0x4000132e20, ~r3=<optimized out>) at /usr/lib/golang/src/runtime/signal_unix.go:925
#3  0x0000000000055838 in runtime.sigtrampgo (sig=6, info=0x4000132da0, ctx=0x4000132e20) at /usr/lib/golang/src/runtime/signal_unix.go:404
#4  0x000000000006feb8 in runtime.sigtramp () at /usr/lib/golang/src/runtime/sys_linux_arm64.s:429
#5  <signal handler called>
#6  runtime.raise () at /usr/lib/golang/src/runtime/sys_linux_arm64.s:167
#7  0x0000000000056838 in runtime.dieFromSignal (sig=6) at /usr/lib/golang/src/runtime/signal_unix.go:711
#8  0x00000000000569e8 in runtime.crash () at /usr/lib/golang/src/runtime/signal_unix.go:803
#9  0x000000000006b0b8 in runtime.fatalthrow.func1 () at /usr/lib/golang/src/runtime/panic.go:1171
#10 0x0000000000040470 in runtime.fatalthrow () at /usr/lib/golang/src/runtime/panic.go:1164
#11 0x00000000000402d4 in runtime.throw (s=...) at /usr/lib/golang/src/runtime/panic.go:1112
#12 0x000000000002e244 in runtime.greyobject (obj=274878567872, base=274877989088, off=176, span=0xffff81c59338, gcw=0x4000023e90, objIndex=174)
    at /usr/lib/golang/src/runtime/mgcmark.go:1432
#13 0x000000000002da94 in runtime.scanobject (b=274877989088, gcw=0x4000023e90) at /usr/lib/golang/src/runtime/mgcmark.go:1275
#14 0x000000000002d23c in runtime.gcDrain (gcw=0x4000023e90, flags=7) at /usr/lib/golang/src/runtime/mgcmark.go:1032
#15 0x0000000000069850 in runtime.gcBgMarkWorker.func2 () at /usr/lib/golang/src/runtime/mgc.go:1970
#16 0x000000000006c820 in runtime.systemstack () at /usr/lib/golang/src/runtime/asm_arm64.s:237
#17 0x00000000000450c0 in runtime.startTheWorldWithSema (emitTraceEvent=false, ~r1=<optimized out>) at <autogenerated>:1
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

# at /usr/lib/golang/src/runtime/mgcmark.go:1432
1427                 if debug.gccheckmark > 0 && span.isFree(objIndex) {
1428                         print("runtime: marking free object ", hex(obj), " found at *(", hex(base), "+", hex(off), ")\n")
1429                         gcDumpObject("base", base, off)
1430                         gcDumpObject("obj", obj, ^uintptr(0))
1431                         getg().m.traceback = 2
1432                         throw("marking free object")
1433                 }

obj=274878567872 / 0x40000a15c0
base=274877989088 / 0x40000140e0
off=176 / 0xb0

(gdb) bt
#0  runtime.raise () at /usr/lib/golang/src/runtime/sys_linux_arm64.s:167
#1  0x0000000000056838 in runtime.dieFromSignal (sig=6) at /usr/lib/golang/src/runtime/signal_unix.go:711
#2  0x0000000000056e3c in runtime.sigfwdgo (sig=6, info=0x40001e6da0, ctx=0x40001e6e20, ~r3=<optimized out>) at /usr/lib/golang/src/runtime/signal_unix.go:925
#3  0x0000000000055838 in runtime.sigtrampgo (sig=6, info=0x40001e6da0, ctx=0x40001e6e20) at /usr/lib/golang/src/runtime/signal_unix.go:404
#4  0x000000000006feb8 in runtime.sigtramp () at /usr/lib/golang/src/runtime/sys_linux_arm64.s:429
#5  <signal handler called>
#6  runtime.raise () at /usr/lib/golang/src/runtime/sys_linux_arm64.s:167
#7  0x0000000000056838 in runtime.dieFromSignal (sig=6) at /usr/lib/golang/src/runtime/signal_unix.go:711
#8  0x00000000000569e8 in runtime.crash () at /usr/lib/golang/src/runtime/signal_unix.go:803
#9  0x000000000006b0b8 in runtime.fatalthrow.func1 () at /usr/lib/golang/src/runtime/panic.go:1171
#10 0x0000000000040470 in runtime.fatalthrow () at /usr/lib/golang/src/runtime/panic.go:1164
#11 0x00000000000402d4 in runtime.throw (s=...) at /usr/lib/golang/src/runtime/panic.go:1112
#12 0x000000000002e244 in runtime.greyobject (obj=274878994560, base=274880063232, off=152, span=0xffff794e0910, gcw=0x4000021690, objIndex=7) at /usr/lib/golang/src/runtime/mgcmark.go:1432
#13 0x000000000002da94 in runtime.scanobject (b=274880063232, gcw=0x4000021690) at /usr/lib/golang/src/runtime/mgcmark.go:1275
#14 0x000000000002d23c in runtime.gcDrain (gcw=0x4000021690, flags=11) at /usr/lib/golang/src/runtime/mgcmark.go:1032
#15 0x000000000006986c in runtime.gcBgMarkWorker.func2 () at /usr/lib/golang/src/runtime/mgc.go:1968
#16 0x000000000006c820 in runtime.systemstack () at /usr/lib/golang/src/runtime/asm_arm64.s:237
#17 0x00000000000450c0 in runtime.startTheWorldWithSema (emitTraceEvent=false, ~r1=<optimized out>) at <autogenerated>:1

obj=274878994560 / 0x4000109880
base=274880063232 / 0x400020e700
off=152

Unfortunately, we did not get the stderr/stdout info. we'll update later when get it.

@jing-rui
Copy link
Author

update with stderr info

runtime: marking free object 0x400020f000 found at *(0x400025a000+0x2000)
base=0x400025a000 s.base()=0x400025a000 s.limit=0x4000267e00 s.spanclass=102 s.elemsize=9472 s.state=mSpanInUse
 *(base+0) = 0x4000074ac0
 *(base+8) = 0x1
 *(base+16) = 0x4
 *(base+24) = 0x400016b4b0
 *(base+32) = 0xe
 *(base+40) = 0x0
 *(base+48) = 0x0
 *(base+56) = 0x0
 *(base+64) = 0x4000074b00
 *(base+72) = 0x1
 *(base+80) = 0x4
 *(base+88) = 0x400016b4c0
 *(base+96) = 0xe
 *(base+104) = 0x0
 *(base+112) = 0x0
 *(base+120) = 0x0
 *(base+128) = 0x4000074b40
 *(base+136) = 0x1
 *(base+144) = 0x4
...
 *(base+8152) = 0x40000c41b0
 *(base+8160) = 0xe
 *(base+8168) = 0x0
 *(base+8176) = 0x0
 *(base+8184) = 0x0
 *(base+8192) = 0x4000218ac0 <==
 *(base+8200) = 0x1
 *(base+8208) = 0x4
 *(base+8216) = 0x40000c41d0
 *(base+8224) = 0xe
 *(base+8232) = 0x0
 *(base+8240) = 0x0
 *(base+8248) = 0x0
 *(base+8256) = 0x4000218b00
 *(base+8264) = 0x1
 *(base+8272) = 0x4
 *(base+8280) = 0x40000c41e0
 *(base+8288) = 0xe
 *(base+8296) = 0x0
 *(base+8304) = 0x0
 *(base+8312) = 0x0
 ...
obj=0x400020f000 s.base()=0x400020a000 s.limit=0x4000214000 s.spanclass=122 s.elemsize=20480 s.state=mSpanInUse
 *(obj+0) = 0x0
 *(obj+8) = 0x0
... // all 0x0
 *(obj+1000) = 0x0
 *(obj+1008) = 0x0
 *(obj+1016) = 0x0
 ...
fatal error: marking free object

dump 0x4000218ac0

(gdb) x /100x 0x4000218ac0
0x4000218ac0:   0x000c41c0      0x00000040      0x00000005      0x00000000
0x4000218ad0:   0x00000000      0x00000000      0x00000000      0x00000000
0x4000218ae0:   0x00000000      0x00000000      0x00000000      0x00000000
0x4000218af0:   0x00000000      0x00000000      0x00000000      0x00000000
0x4000218b00:   0x000c41c5      0x00000040      0x00000007      0x00000000
0x4000218b10:   0x00000000      0x00000000      0x00000000      0x00000000
0x4000218b20:   0x00000000      0x00000000      0x00000000      0x00000000
0x4000218b30:   0x00000000      0x00000000      0x00000000      0x00000000
0x4000218b40:   0x000c41f0      0x00000040      0x00000007      0x00000000
0x4000218b50:   0x00000000      0x00000000      0x00000000      0x00000000
0x4000218b60:   0x00000000      0x00000000      0x00000000      0x00000000
0x4000218b70:   0x00000000      0x00000000      0x00000000      0x00000000
0x4000218b80:   0x000c4210      0x00000040      0x0000000c      0x00000000
0x4000218b90:   0x00000000      0x00000000      0x00000000      0x00000000
0x4000218ba0:   0x00000000      0x00000000      0x00000000      0x00000000
0x4000218bb0:   0x00000000      0x00000000      0x00000000      0x00000000
0x4000218bc0:   0x000c41f7      0x00000040      0x00000007      0x00000000
0x4000218bd0:   0x00000000      0x00000000      0x00000000      0x00000000
0x4000218be0:   0x00000000      0x00000000      0x00000000      0x00000000
0x4000218bf0:   0x00000000      0x00000000      0x00000000      0x00000000
0x4000218c00:   0x000c4240      0x00000040      0x00000005      0x00000000
0x4000218c10:   0x00000000      0x00000000      0x00000000      0x00000000
0x4000218c20:   0x00000000      0x00000000      0x00000000      0x00000000
0x4000218c30:   0x00000000      0x00000000      0x00000000      0x00000000
0x4000218c40:   0x000c4245      0x00000040      0x00000007      0x00000000

unsafe pointer mainly used by golang.org/x/sys, I'm trying to update sys package and try again.

@jing-rui
Copy link
Author

We create a program which can reproduce on go1.13.3.(we'll test later on master)

git clone https://github.com/jing-rui/go-issue-36101
cd go-issue-36101
go build
nohup ./go-issue-36101 config.json &
nohup ./go-issue-36101 config.json &

we try to create many(more than 10) go-issue-36101 processs, then wait hours get message in nohup.out.

cat nohup.out
runtime: nelems=19 nalloc=2 previous allocCount=1 nfreed=65535
fatal error: sweep increased allocation count

goroutine 3 [running]:
runtime.throw(0x118e0a, 0x20)
        /usr/lib/golang/src/runtime/panic.go:774 +0x54 fp=0x4000105610 sp=0x40001055e0 pc=0x399a4
runtime.(*mspan).sweep(0xffff8f8645e0, 0x0, 0x4000105700)
        /usr/lib/golang/src/runtime/mgcsweep.go:328 +0x848 fp=0x4000105730 sp=0x4000105610 pc=0x30038
runtime.sweepone(0x11c280)
        /usr/lib/golang/src/runtime/mgcsweep.go:136 +0x304 fp=0x40001057a0 sp=0x4000105730 pc=0x2f504
runtime.bgsweep(0x400012c000)
        /usr/lib/golang/src/runtime/mgcsweep.go:73 +0xe0 fp=0x40001057d0 sp=0x40001057a0 pc=0x2f120
runtime.goexit()
        /usr/lib/golang/src/runtime/asm_arm64.s:1128 +0x4 fp=0x40001057d0 sp=0x40001057d0 pc=0x62d14
created by runtime.gcenable
        /usr/lib/golang/src/runtime/mgc.go:210 +0x54

full nohup.out Output
runtime: nelems=19 nalloc=2 previous allocCount=1 nfreed=65535 fatal error: sweep increased allocation count

goroutine 3 [running]:
runtime.throw(0x118e0a, 0x20)
/usr/lib/golang/src/runtime/panic.go:774 +0x54 fp=0x4000105610 sp=0x40001055e0 pc=0x399a4
runtime.(*mspan).sweep(0xffff8f8645e0, 0x0, 0x4000105700)
/usr/lib/golang/src/runtime/mgcsweep.go:328 +0x848 fp=0x4000105730 sp=0x4000105610 pc=0x30038
runtime.sweepone(0x11c280)
/usr/lib/golang/src/runtime/mgcsweep.go:136 +0x304 fp=0x40001057a0 sp=0x4000105730 pc=0x2f504
runtime.bgsweep(0x400012c000)
/usr/lib/golang/src/runtime/mgcsweep.go:73 +0xe0 fp=0x40001057d0 sp=0x40001057a0 pc=0x2f120
runtime.goexit()
/usr/lib/golang/src/runtime/asm_arm64.s:1128 +0x4 fp=0x40001057d0 sp=0x40001057d0 pc=0x62d14
created by runtime.gcenable
/usr/lib/golang/src/runtime/mgc.go:210 +0x54

goroutine 1 [runnable]:
encoding/json.stateInString(0x4000640028, 0x106c6e, 0x0)
/usr/lib/golang/src/encoding/json/scanner.go:300 +0x218
encoding/json.checkValid(0x40003c9500, 0x508c, 0x528c, 0x4000640028, 0x40003f0028, 0x109ce0)
/usr/lib/golang/src/encoding/json/scanner.go:29 +0xb0
encoding/json.Unmarshal(0x40003c9500, 0x508c, 0x528c, 0xe0100, 0x40005c8100, 0x0, 0x0)
/usr/lib/golang/src/encoding/json/decode.go:100 +0x58
main.loadspec(0xffffca696579, 0xb)
/root/jingrui/helper/test/src/loadspec.go:654 +0x80
main.loopload(0xffffca696579, 0xb)
/root/jingrui/helper/test/src/loadspec.go:661 +0x38
main.main()
/root/jingrui/helper/test/src/loadspec.go:672 +0xd0

goroutine 18 [runnable]:
reflect.Value.SetString(0xe6bc0, 0x4000243040, 0x198, 0x400041b600, 0xa)
/usr/lib/golang/src/reflect/value.go:1714 +0x10c
encoding/json.(*decodeState).literalStore(0x40001b20b0, 0x40007a0400, 0xc, 0x188c, 0xe6bc0, 0x4000243040, 0x198, 0xb8400, 0x0, 0xe4d60)
/usr/lib/golang/src/encoding/json/decode.go:1010 +0x192c
encoding/json.(*decodeState).value(0x40001b20b0, 0xe6bc0, 0x4000243040, 0x198, 0xe6bc0, 0x4000243040)
/usr/lib/golang/src/encoding/json/decode.go:443 +0x190
encoding/json.(*decodeState).array(0x40001b20b0, 0xe4d60, 0x4000539740, 0x197, 0x40001b20d8, 0xb8f5b)
/usr/lib/golang/src/encoding/json/decode.go:616 +0x130
encoding/json.(*decodeState).value(0x40001b20b0, 0xe4d60, 0x4000539740, 0x197, 0xe4d60, 0x4000539740)
/usr/lib/golang/src/encoding/json/decode.go:419 +0xcc
encoding/json.(*decodeState).object(0x40001b20b0, 0xfc7c0, 0x4000539740, 0x199, 0x400033d388, 0xb8818)
/usr/lib/golang/src/encoding/json/decode.go:823 +0x1020
encoding/json.(*decodeState).value(0x40001b20b0, 0xfc7c0, 0x4000539740, 0x199, 0xfc7c0, 0x4000539740)
/usr/lib/golang/src/encoding/json/decode.go:429 +0x58
encoding/json.(*decodeState).array(0x40001b20b0, 0xe41e0, 0x40003353a8, 0x197, 0x40001b20d8, 0x5b)
/usr/lib/golang/src/encoding/json/decode.go:616 +0x130
encoding/json.(*decodeState).value(0x40001b20b0, 0xe41e0, 0x40003353a8, 0x197, 0xe41e0, 0x40003353a8)
/usr/lib/golang/src/encoding/json/decode.go:419 +0xcc
encoding/json.(*decodeState).object(0x40001b20b0, 0xdfd40, 0x4000555040, 0x196, 0x40001b20d8, 0x7b)
/usr/lib/golang/src/encoding/json/decode.go:823 +0x1020
encoding/json.(*decodeState).value(0x40001b20b0, 0xdfd40, 0x4000555040, 0x196, 0xdfd40, 0x4000555040)
/usr/lib/golang/src/encoding/json/decode.go:429 +0x58
encoding/json.(*decodeState).object(0x40001b20b0, 0xdf900, 0x400029e158, 0x196, 0x40001b20d8, 0x7b)
/usr/lib/golang/src/encoding/json/decode.go:823 +0x1020
encoding/json.(*decodeState).value(0x40001b20b0, 0xdf900, 0x400029e158, 0x196, 0xdf900, 0x400029e158)
/usr/lib/golang/src/encoding/json/decode.go:429 +0x58
encoding/json.(*decodeState).object(0x40001b20b0, 0xe0100, 0x400029e100, 0x16, 0x40001b20d8, 0x7b)
/usr/lib/golang/src/encoding/json/decode.go:823 +0x1020
encoding/json.(*decodeState).value(0x40001b20b0, 0xe0100, 0x400029e100, 0x16, 0x400033de78, 0xc58c4)
/usr/lib/golang/src/encoding/json/decode.go:429 +0x58
encoding/json.(*decodeState).unmarshal(0x40001b20b0, 0xe0100, 0x400029e100, 0x40001b20d8, 0x0)
/usr/lib/golang/src/encoding/json/decode.go:179 +0x1d0
encoding/json.Unmarshal(0x400079ca00, 0x508c, 0x528c, 0xe0100, 0x400029e100, 0x0, 0x0)
/usr/lib/golang/src/encoding/json/decode.go:106 +0xe4
main.loadspec(0xffffca696579, 0xb)
/root/jingrui/helper/test/src/loadspec.go:654 +0x80
main.loopload(0xffffca696579, 0xb)
/root/jingrui/helper/test/src/loadspec.go:661 +0x38
created by main.main
/root/jingrui/helper/test/src/loadspec.go:669 +0x6c

goroutine 19 [runnable]:
reflect.Value.Len(0xe4d60, 0x40003580b0, 0x197, 0x198)
/usr/lib/golang/src/reflect/value.go:1133 +0x1dc
encoding/json.(*decodeState).array(0x40001b2000, 0xe4d60, 0x40003580b0, 0x197, 0x40001b2028, 0x5b)
/usr/lib/golang/src/encoding/json/decode.go:639 +0x18c
encoding/json.(*decodeState).value(0x40001b2000, 0xe4d60, 0x40003580b0, 0x197, 0xe4d60, 0x40003580b0)
/usr/lib/golang/src/encoding/json/decode.go:419 +0xcc
encoding/json.(*decodeState).object(0x40001b2000, 0xdf900, 0x400029e0d8, 0x196, 0x40001b2028, 0x7b)
/usr/lib/golang/src/encoding/json/decode.go:823 +0x1020
encoding/json.(*decodeState).value(0x40001b2000, 0xdf900, 0x400029e0d8, 0x196, 0xdf900, 0x400029e0d8)
/usr/lib/golang/src/encoding/json/decode.go:429 +0x58
encoding/json.(*decodeState).object(0x40001b2000, 0xe0100, 0x400029e080, 0x16, 0x40001b2028, 0x7b)
/usr/lib/golang/src/encoding/json/decode.go:823 +0x1020
encoding/json.(*decodeState).value(0x40001b2000, 0xe0100, 0x400029e080, 0x16, 0x40001a1e78, 0xc58c4)
/usr/lib/golang/src/encoding/json/decode.go:429 +0x58
encoding/json.(*decodeState).unmarshal(0x40001b2000, 0xe0100, 0x400029e080, 0x40001b2028, 0x0)
/usr/lib/golang/src/encoding/json/decode.go:179 +0x1d0
encoding/json.Unmarshal(0x4000797500, 0x508c, 0x528c, 0xe0100, 0x400029e080, 0x0, 0x0)
/usr/lib/golang/src/encoding/json/decode.go:106 +0xe4
main.loadspec(0xffffca696579, 0xb)
/root/jingrui/helper/test/src/loadspec.go:654 +0x80
main.loopload(0xffffca696579, 0xb)
/root/jingrui/helper/test/src/loadspec.go:661 +0x38
created by main.main
/root/jingrui/helper/test/src/loadspec.go:670 +0x94

goroutine 20 [runnable]:
sync.(*Map).Load(0x1e7000, 0x10d720, 0xfc7c0, 0x199, 0x10, 0xc77)
/usr/lib/golang/src/sync/map.go:104 +0x98
encoding/json.cachedTypeFields(0x136ce0, 0xfc7c0, 0x199, 0x136ce0, 0xfc7c0, 0x0)
/usr/lib/golang/src/encoding/json/encode.go:1275 +0x44
encoding/json.(*decodeState).object(0x4000640420, 0xfc7c0, 0x40002c1700, 0x199, 0x40005ad388, 0xb8818)
/usr/lib/golang/src/encoding/json/decode.go:709 +0x200
encoding/json.(*decodeState).value(0x4000640420, 0xfc7c0, 0x40002c1700, 0x199, 0xfc7c0, 0x40002c1700)
/usr/lib/golang/src/encoding/json/decode.go:429 +0x58
encoding/json.(*decodeState).array(0x4000640420, 0xe41e0, 0x4000335028, 0x197, 0x4000640448, 0x5b)
/usr/lib/golang/src/encoding/json/decode.go:616 +0x130
encoding/json.(*decodeState).value(0x4000640420, 0xe41e0, 0x4000335028, 0x197, 0xe41e0, 0x4000335028)
/usr/lib/golang/src/encoding/json/decode.go:419 +0xcc
encoding/json.(*decodeState).object(0x4000640420, 0xdfd40, 0x40007ee080, 0x196, 0x4000640448, 0x7b)
/usr/lib/golang/src/encoding/json/decode.go:823 +0x1020
encoding/json.(*decodeState).value(0x4000640420, 0xdfd40, 0x40007ee080, 0x196, 0xdfd40, 0x40007ee080)
/usr/lib/golang/src/encoding/json/decode.go:429 +0x58
encoding/json.(*decodeState).object(0x4000640420, 0xdf900, 0x40005c8ed8, 0x196, 0x4000640448, 0x7b)
/usr/lib/golang/src/encoding/json/decode.go:823 +0x1020
encoding/json.(*decodeState).value(0x4000640420, 0xdf900, 0x40005c8ed8, 0x196, 0xdf900, 0x40005c8ed8)
/usr/lib/golang/src/encoding/json/decode.go:429 +0x58
encoding/json.(*decodeState).object(0x4000640420, 0xe0100, 0x40005c8e80, 0x16, 0x4000640448, 0x7b)
/usr/lib/golang/src/encoding/json/decode.go:823 +0x1020
encoding/json.(*decodeState).value(0x4000640420, 0xe0100, 0x40005c8e80, 0x16, 0x40005ade78, 0xc58c4)
/usr/lib/golang/src/encoding/json/decode.go:429 +0x58
encoding/json.(*decodeState).unmarshal(0x4000640420, 0xe0100, 0x40005c8e80, 0x4000640448, 0x0)
/usr/lib/golang/src/encoding/json/decode.go:179 +0x1d0
encoding/json.Unmarshal(0x40003c4000, 0x508c, 0x528c, 0xe0100, 0x40005c8e80, 0x0, 0x0)
/usr/lib/golang/src/encoding/json/decode.go:106 +0xe4
main.loadspec(0xffffca696579, 0xb)
/root/jingrui/helper/test/src/loadspec.go:654 +0x80
main.loopload(0xffffca696579, 0xb)
/root/jingrui/helper/test/src/loadspec.go:661 +0x38
created by main.main
/root/jingrui/helper/test/src/loadspec.go:671 +0xbc

@jing-rui
Copy link
Author

jing-rui commented Dec 19, 2019

yes, we can reproduce on go master branch.

fatal error: found bad pointer in Go heap Output
runtime: pointer 0x4000560000 to unallocated span span.base()=0x400055a000 span.limit=0x4000563f00 span.state=0
runtime: found in object at *(0x4000725500+0x3380)
object=0x4000725500 s.base()=0x4000722000 s.limit=0x400072bf00 s.spanclass=112 s.elemsize=13568 s.state=mSpanInUse
 *(object+0) = 0x40002367c0
 *(object+8) = 0x1
 *(object+16) = 0x4
... ... ... ...
fatal error: found bad pointer in Go heap (incorrect use of unsafe or cgo?)

runtime stack:
runtime.throw(0x114169, 0x3e)
/usr/lib/golang/src/runtime/panic.go:1112 +0x54 fp=0x4000267df0 sp=0x4000267dc0 pc=0x3dc64
runtime.badPointer(0xffff925ff048, 0x4000560000, 0x4000725500, 0x3380)
/usr/lib/golang/src/runtime/mbitmap.go:380 +0x1fc fp=0x4000267e40 sp=0x4000267df0 pc=0x2145c
runtime.findObject(0x4000560000, 0x4000725500, 0x3380, 0xffff925fe9e8, 0x4000024690, 0x12)
/usr/lib/golang/src/runtime/mbitmap.go:416 +0x8c fp=0x4000267e80 sp=0x4000267e40 pc=0x214fc
runtime.scanobject(0x4000725500, 0x4000024690)
/usr/lib/golang/src/runtime/mgcmark.go:1274 +0x1e8 fp=0x4000267f20 sp=0x4000267e80 pc=0x2c358
runtime.gcDrain(0x4000024690, 0x3)
/usr/lib/golang/src/runtime/mgcmark.go:1032 +0x21c fp=0x4000267f80 sp=0x4000267f20 pc=0x2bb5c
runtime.gcBgMarkWorker.func2()
/usr/lib/golang/src/runtime/mgc.go:1947 +0x70 fp=0x4000267fc0 sp=0x4000267f80 pc=0x647b0
runtime.systemstack(0x0)
/usr/lib/golang/src/runtime/asm_arm64.s:237 +0xa0 fp=0x4000267fd0 sp=0x4000267fc0 pc=0x67300
runtime.mstart()
/usr/lib/golang/src/runtime/proc.go:1077 fp=0x4000267fd0 sp=0x4000267fd0 pc=0x42a40
goroutine 67 [GC worker (idle)]:
runtime.systemstack_switch()
/usr/lib/golang/src/runtime/asm_arm64.s:182 +0x8 fp=0x40004c2750 sp=0x40004c2740 pc=0x67248
runtime.gcBgMarkWorker(0x4000023000)
/usr/lib/golang/src/runtime/mgc.go:1934 +0x1b8 fp=0x40004c27d0 sp=0x40004c2750 pc=0x28908
runtime.goexit()
/usr/lib/golang/src/runtime/asm_arm64.s:1148 +0x4 fp=0x40004c27d0 sp=0x40004c27d0 pc=0x69a34
created by runtime.gcBgMarkStartWorkers
/usr/lib/golang/src/runtime/mgc.go:1828 +0x80

goroutine 1 [GC assist wait]:
runtime.gopark(0x114ae8, 0x1e8828, 0x4000002a0b, 0x2)
/usr/lib/golang/src/runtime/proc.go:304 +0xd0 fp=0x400059d110 sp=0x400059d0f0 pc=0x40480
runtime.goparkunlock(...)
/usr/lib/golang/src/runtime/proc.go:310
runtime.gcParkAssist(0x400059d190)
/usr/lib/golang/src/runtime/mgcmark.go:611 +0x11c fp=0x400059d150 sp=0x400059d110 pc=0x2ae6c
runtime.gcAssistAlloc(0x4000000180)
/usr/lib/golang/src/runtime/mgcmark.go:475 +0x1b0 fp=0x400059d1b0 sp=0x400059d150 pc=0x2a7e0
runtime.mallocgc(0x4f00, 0xf70e0, 0x400059d201, 0xb9fe8)
/usr/lib/golang/src/runtime/malloc.go:938 +0x7a8 fp=0x400059d270 sp=0x400059d1b0 pc=0x1af38
runtime.newarray(0xf70e0, 0x13c, 0x400059d201)
/usr/lib/golang/src/runtime/malloc.go:1185 +0x70 fp=0x400059d2a0 sp=0x400059d270 pc=0x1b300
reflect.unsafe_NewArray(0xf70e0, 0x13c, 0xf70e0)
/usr/lib/golang/src/runtime/malloc.go:1190 +0x30 fp=0x400059d2d0 sp=0x400059d2a0 pc=0x1b3c0
reflect.MakeSlice(0x1316a0, 0xe0560, 0xd3, 0x13c, 0xe0560, 0x0, 0x199)
/usr/lib/golang/src/reflect/value.go:2268 +0xa8 fp=0x400059d300 sp=0x400059d2d0 pc=0x90058
encoding/json.(*decodeState).array(0x4000300160, 0xe0560, 0x40005b8a68, 0x197, 0x4000300188, 0x5b)
/usr/lib/golang/src/encoding/json/decode.go:564 +0x4f4 fp=0x400059d3f0 sp=0x400059d300 pc=0xba3b4
encoding/json.(*decodeState).value(0x4000300160, 0xe0560, 0x40005b8a68, 0x197, 0xe0560, 0x40005b8a68)
/usr/lib/golang/src/encoding/json/decode.go:377 +0xcc fp=0x400059d460 sp=0x400059d3f0 pc=0xb960c
encoding/json.(*decodeState).object(0x4000300160, 0xdc8e0, 0x40004fa160, 0x196, 0x4000300188, 0x7b)
/usr/lib/golang/src/encoding/json/decode.go:782 +0xf54 fp=0x400059d700 sp=0x400059d460 pc=0xbb794
encoding/json.(*decodeState).value(0x4000300160, 0xdc8e0, 0x40004fa160, 0x196, 0xdc8e0, 0x40004fa160)
/usr/lib/golang/src/encoding/json/decode.go:387 +0x58 fp=0x400059d770 sp=0x400059d700 pc=0xb9598
encoding/json.(*decodeState).object(0x4000300160, 0xdc4a0, 0x400044e5d8, 0x196, 0x4000300188, 0x7b)
/usr/lib/golang/src/encoding/json/decode.go:782 +0xf54 fp=0x400059da10 sp=0x400059d770 pc=0xbb794
encoding/json.(*decodeState).value(0x4000300160, 0xdc4a0, 0x400044e5d8, 0x196, 0xdc4a0, 0x400044e5d8)
/usr/lib/golang/src/encoding/json/decode.go:387 +0x58 fp=0x400059da80 sp=0x400059da10 pc=0xb9598
encoding/json.(*decodeState).object(0x4000300160, 0xdcca0, 0x400044e580, 0x16, 0x4000300188, 0x7b)
/usr/lib/golang/src/encoding/json/decode.go:782 +0xf54 fp=0x400059dd20 sp=0x400059da80 pc=0xbb794
encoding/json.(*decodeState).value(0x4000300160, 0xdcca0, 0x400044e580, 0x16, 0x400059dde8, 0xc71f4)
/usr/lib/golang/src/encoding/json/decode.go:387 +0x58 fp=0x400059dd90 sp=0x400059dd20 pc=0xb9598
encoding/json.(*decodeState).unmarshal(0x4000300160, 0xdcca0, 0x400044e580, 0x4000300188, 0x0)
/usr/lib/golang/src/encoding/json/decode.go:180 +0x1c8 fp=0x400059de20 sp=0x400059dd90 pc=0xb8df8
encoding/json.Unmarshal(0x4000807500, 0x508c, 0x528c, 0xdcca0, 0x400044e580, 0x0, 0x0)
/usr/lib/golang/src/encoding/json/decode.go:107 +0xe4 fp=0x400059de70 sp=0x400059de20 pc=0xb8884
main.loadspec(0xffffd7d0b573, 0xb)
/root/jingrui/rpm-go-master/go-issue-36101/main.go:654 +0x80 fp=0x400059dec0 sp=0x400059de70 pc=0xccb20
main.loopload(0xffffd7d0b573, 0xb)
/root/jingrui/rpm-go-master/go-issue-36101/main.go:661 +0x38 fp=0x400059df30 sp=0x400059dec0 pc=0xccb98
main.main()
/root/jingrui/rpm-go-master/go-issue-36101/main.go:672 +0xd0 fp=0x400059df70 sp=0x400059df30 pc=0xccd20
runtime.main()
/usr/lib/golang/src/runtime/proc.go:203 +0x234 fp=0x400059dfd0 sp=0x400059df70 pc=0x40094
runtime.goexit()
/usr/lib/golang/src/runtime/asm_arm64.s:1148 +0x4 fp=0x400059dfd0 sp=0x400059dfd0 pc=0x69a34

... ... ... ...

@jing-rui
Copy link
Author

jing-rui commented Dec 23, 2019

@ianlancetaylor would you please try https://github.com/jing-rui/go-issue-36101 to reproduce. We can reproduce at 2 different type of physical arm machine, set GODEBUG=stoptheworld=1 or GODEBUG=stoptheworld=2 still panic.

@jing-rui
Copy link
Author

We compared using jsoniter to replace json lib, the program using jsoniter can run days without crash. So I think there must be something wrong in encoding/json. The reproduce program is updated at https://github.com/jing-rui/go-issue-36101.

@cherrymui
Copy link
Member

Thanks @jing-rui . I'm able to reproduce this with https://github.com/jing-rui/go-issue-36101 on the Linux/ARM64 builder. Running with GOGC=1 GODEBUG=gccheckmark=1, it fails in an hour or two. I looked into a few failures, but I haven't been able to completely understand it. However, I have a guess. It may be that we didn't always write pointers atomically, so the GC observed a partially updated pointer, which may point to bad memory. I made CL http://golang.org/cl/212626 , which ensures atomic pointer writes in memmove. With the CL I haven't gotten a crash running 10+ hours. As the failure is pretty rare, I cannot be sure, though.

@jing-rui , could you test CL http://golang.org/cl/212626 ? Thanks.

@gopherbot
Copy link
Contributor

Change https://golang.org/cl/212626 mentions this issue: runtime: ensure memmove write pointer atomically on ARM64

@jing-rui
Copy link
Author

The test run 2 days, it works. Thanks @cherrymui .

@aclements aclements added this to the Go1.14 milestone Jan 2, 2020
@aclements
Copy link
Member

@gopherbot, please open a backport to Go 1.13

@gopherbot
Copy link
Contributor

Backport issue(s) opened: #36361 (for 1.13).

Remember to create the cherry-pick CL(s) as soon as the patch is submitted to master, according to https://golang.org/wiki/MinorReleases.

@aclements
Copy link
Member

@gopherbot, please open a backport to Go 1.12

@gopherbot
Copy link
Contributor

Change https://golang.org/cl/213418 mentions this issue: runtime: document special memmove requirements

@gopherbot
Copy link
Contributor

Change https://golang.org/cl/213683 mentions this issue: [release-branch.go1.13] runtime: ensure memmove write pointer atomically on ARM64

@gopherbot
Copy link
Contributor

Change https://golang.org/cl/213684 mentions this issue: [release-branch.go1.12] runtime: ensure memmove write pointer atomically on ARM64

gopherbot pushed a commit that referenced this issue Jan 8, 2020
…lly on ARM64

If a pointer write is not atomic, if the GC is running
concurrently, it may observe a partially updated pointer, which
may point to unallocated or already dead memory. Most pointer
writes, like the store instructions generated by the compiler,
are already atomic. But we still need to be careful in places
like memmove. In memmove, we don't know which bits are pointers
(or too expensive to query), so we ensure that all aligned
pointer-sized units are written atomically.

Fixes #36367.
Updates #36101.

Change-Id: I1b3ca24c6b1ac8a8aaf9ee470115e9a89ec1b00b
Reviewed-on: https://go-review.googlesource.com/c/go/+/212626
Reviewed-by: Austin Clements <austin@google.com>
(cherry picked from commit ffbc027)
Reviewed-on: https://go-review.googlesource.com/c/go/+/213684
Run-TryBot: Cherry Zhang <cherryyz@google.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
gopherbot pushed a commit that referenced this issue Jan 8, 2020
…lly on ARM64

If a pointer write is not atomic, if the GC is running
concurrently, it may observe a partially updated pointer, which
may point to unallocated or already dead memory. Most pointer
writes, like the store instructions generated by the compiler,
are already atomic. But we still need to be careful in places
like memmove. In memmove, we don't know which bits are pointers
(or too expensive to query), so we ensure that all aligned
pointer-sized units are written atomically.

Fixes #36361.
Updates #36101.

Change-Id: I1b3ca24c6b1ac8a8aaf9ee470115e9a89ec1b00b
Reviewed-on: https://go-review.googlesource.com/c/go/+/212626
Reviewed-by: Austin Clements <austin@google.com>
(cherry picked from commit ffbc027)
Reviewed-on: https://go-review.googlesource.com/c/go/+/213683
Run-TryBot: Cherry Zhang <cherryyz@google.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
gopherbot pushed a commit that referenced this issue Jan 22, 2020
Unlike C's memmove, Go's memmove must be careful to do indivisible
writes of pointer values because it may be racing with the garbage
collector reading the heap.

We've had various bugs related to this over the years (#36101, #13160,
 #12552). Indeed, memmove is a great target for optimization and it's
easy to forget the special requirements of Go's memmove.

The CL documents these (currently unwritten!) requirements. We're also
adding a test that should hopefully keep everyone honest going
forward, though it's hard to be sure we're hitting all cases of
memmove.

Change-Id: I2f59f8d8d6fb42d2f10006b55d605b5efd8ddc24
Reviewed-on: https://go-review.googlesource.com/c/go/+/213418
Reviewed-by: Cherry Zhang <cherryyz@google.com>
@golang golang locked and limited conversation to collaborators Jan 6, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. release-blocker
Projects
None yet
Development

No branches or pull requests

6 participants