Build stalls early #991

msg555 · 2019-05-08T20:45:36Z

This is running buildkitd from the moby/buildkit:v0.5.0 image. If I wait long enough the connection is eventually dropped. This issue is transient and I do not have a good way of reliably reproducing it. It has happened on several different images I've tried to build.

Below is the output after sending SIGABRT to the buildkitd daemon:

SIGABRT: abort
PC=0x45e951 m=0 sigcode=0

goroutine 0 [idle]:
runtime.futex(0x1c776e8, 0x80, 0x0, 0x0, 0xc000000000, 0x7ffef69fe110, 0x0, 0x0, 0x7ffef69fe130, 0x40ab01, ...)
	/usr/local/go/src/runtime/sys_linux_amd64.s:535 +0x21
runtime.futexsleep(0x1c776e8, 0x7ffe00000000, 0xffffffffffffffff)
	/usr/local/go/src/runtime/os_linux.go:46 +0x4b
runtime.notesleep(0x1c776e8)
	/usr/local/go/src/runtime/lock_futex.go:151 +0xa1
runtime.stoplockedm()
	/usr/local/go/src/runtime/proc.go:2076 +0x8c
runtime.schedule()
	/usr/local/go/src/runtime/proc.go:2477 +0x3ba
runtime.park_m(0xc000001c80)
	/usr/local/go/src/runtime/proc.go:2605 +0xa1
runtime.mcall(0x1c1e018)
	/usr/local/go/src/runtime/asm_amd64.s:299 +0x5b

goroutine 1 [select, 51 minutes]:
main.main.func3(0xc0000d71e0, 0x0, 0x0)
	/src/cmd/buildkitd/main.go:246 +0x826
github.com/urfave/cli.HandleAction(0xf5a4a0, 0x1135d08, 0xc0000d71e0, 0xc0000d71e0, 0xc0001e5858)
	/src/vendor/github.com/urfave/cli/app.go:502 +0xc8
github.com/urfave/cli.(*App).Run(0xc00013c540, 0xc000032090, 0x9, 0x9, 0x0, 0x0)
	/src/vendor/github.com/urfave/cli/app.go:268 +0x5aa
main.main()
	/src/cmd/buildkitd/main.go:269 +0xd6c

goroutine 18 [chan receive, 51 minutes]:
github.com/moby/buildkit/solver.(*scheduler).loop.func2(0xc00033f8f0)
	/src/solver/scheduler.go:76 +0x38
created by github.com/moby/buildkit/solver.(*scheduler).loop
	/src/solver/scheduler.go:75 +0x6d

goroutine 6 [syscall, 51 minutes]:
os/signal.signal_recv(0x0)
	/usr/local/go/src/runtime/sigqueue.go:139 +0x9c
os/signal.loop()
	/usr/local/go/src/os/signal/signal_unix.go:23 +0x22
created by os/signal.init.0
	/usr/local/go/src/os/signal/signal_unix.go:29 +0x41

goroutine 8 [chan receive, 51 minutes]:
github.com/moby/buildkit/util/appcontext.Context.func1.1(0xc00038a180, 0xc0002e9960, 0xc0003465f0)
	/src/util/appcontext/appcontext.go:30 +0x38
created by github.com/moby/buildkit/util/appcontext.Context.func1
	/src/util/appcontext/appcontext.go:28 +0xff

goroutine 10 [sync.Cond.Wait, 4 minutes]:
runtime.goparkunlock(...)
	/usr/local/go/src/runtime/proc.go:307
sync.runtime_notifyListWait(0xc0003fc450, 0x16c1)
	/usr/local/go/src/runtime/sema.go:510 +0xf9
sync.(*Cond).Wait(0xc0003fc440)
	/usr/local/go/src/sync/cond.go:56 +0x9e
github.com/moby/buildkit/util/cond.(*StatefulCond).Wait(0xc0003fe810)
	/src/util/cond/cond.go:28 +0x98
github.com/moby/buildkit/solver.(*scheduler).loop(0xc00033f8f0)
	/src/solver/scheduler.go:101 +0x168
created by github.com/moby/buildkit/solver.newScheduler
	/src/solver/scheduler.go:35 +0x1ad

goroutine 11 [IO wait, 4 minutes]:
internal/poll.runtime_pollWait(0x7fbd265a5f08, 0x72, 0x0)
	/usr/local/go/src/runtime/netpoll.go:182 +0x56
internal/poll.(*pollDesc).wait(0xc0002f6898, 0x72, 0x0, 0x0, 0x10eed19)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:87 +0x9b
internal/poll.(*pollDesc).waitRead(...)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Accept(0xc0002f6880, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
	/usr/local/go/src/internal/poll/fd_unix.go:384 +0x1ba
net.(*netFD).accept(0xc0002f6880, 0xc000952601, 0x0, 0x0)
	/usr/local/go/src/net/fd_unix.go:238 +0x42
net.(*TCPListener).accept(0xc0000106a8, 0xc0004b3e20, 0xc0004b3e28, 0x18)
	/usr/local/go/src/net/tcpsock_posix.go:139 +0x32
net.(*TCPListener).Accept(0xc0000106a8, 0x1135890, 0xc00013c700, 0x1281e00, 0xc000952670)
	/usr/local/go/src/net/tcpsock.go:260 +0x48
google.golang.org/grpc.(*Server).Serve(0xc00013c700, 0x126d0e0, 0xc0000106a8, 0x0, 0x0)
	/src/vendor/google.golang.org/grpc/server.go:544 +0x1f2
main.serveGRPC.func1.1(0x0, 0x0)
	/src/cmd/buildkitd/main.go:297 +0x10e
golang.org/x/sync/errgroup.(*Group).Go.func1(0xc0003fe960, 0xc0003b8e80)
	/src/vendor/golang.org/x/sync/errgroup/errgroup.go:58 +0x57
created by golang.org/x/sync/errgroup.(*Group).Go
	/src/vendor/golang.org/x/sync/errgroup/errgroup.go:55 +0x66

goroutine 12 [semacquire, 51 minutes]:
sync.runtime_Semacquire(0xc0003fe970)
	/usr/local/go/src/runtime/sema.go:56 +0x39
sync.(*WaitGroup).Wait(0xc0003fe968)
	/usr/local/go/src/sync/waitgroup.go:130 +0x65
golang.org/x/sync/errgroup.(*Group).Wait(0xc0003fe960, 0x0, 0x0)
	/src/vendor/golang.org/x/sync/errgroup/errgroup.go:41 +0x31
main.serveGRPC.func2(0xc00038b2c0, 0xc0003fe960)
	/src/cmd/buildkitd/main.go:302 +0x2b
created by main.serveGRPC
	/src/cmd/buildkitd/main.go:301 +0x27a

goroutine 169909 [select]:
github.com/moby/buildkit/session.monitorHealth(0x1272a60, 0xc00075c0c0, 0xc0005f2000, 0xc0012ab5f0)
	/src/session/grpc.go:69 +0x189
created by github.com/moby/buildkit/session.grpcClientConn
	/src/session/grpc.go:55 +0x23e

goroutine 169888 [sync.Cond.Wait, 4 minutes]:
runtime.goparkunlock(...)
	/usr/local/go/src/runtime/proc.go:307
sync.runtime_notifyListWait(0xc000555590, 0xc000000005)
	/usr/local/go/src/runtime/sema.go:510 +0xf9
sync.(*Cond).Wait(0xc000555580)
	/usr/local/go/src/sync/cond.go:56 +0x9e
github.com/moby/buildkit/util/progress.(*progressReader).Read(0xc000ff0b70, 0x1272a60, 0xc0006b3e00, 0x0, 0x0, 0x0, 0x0, 0x0)
	/src/util/progress/progress.go:125 +0x10b
github.com/moby/buildkit/solver.(*Job).Status(0xc00032d650, 0x1272a60, 0xc0006b3e00, 0xc0006a1d40, 0x0, 0x0)
	/src/solver/progress.go:25 +0xd14
github.com/moby/buildkit/solver/llbsolver.(*Solver).Status(0xc00033f880, 0x1272a60, 0xc0006b3e00, 0xc000559fe0, 0x19, 0xc0006a1d40, 0xc000c00f88, 0xc000c00f90)
	/src/solver/llbsolver/solver.go:280 +0xbe
github.com/moby/buildkit/control.(*Controller).Status.func1(0x8, 0x11366d8)
	/src/control/control.go:289 +0x5e
golang.org/x/sync/errgroup.(*Group).Go.func1(0xc001305b30, 0xc001305b60)
	/src/vendor/golang.org/x/sync/errgroup/errgroup.go:58 +0x57
created by golang.org/x/sync/errgroup.(*Group).Go
	/src/vendor/golang.org/x/sync/errgroup/errgroup.go:55 +0x66

goroutine 169907 [chan receive, 4 minutes]:
github.com/moby/buildkit/control.(*Controller).Session.func1(0xc00046f620, 0xc0012ab520)
	/src/control/control.go:346 +0x34
created by github.com/moby/buildkit/control.(*Controller).Session
	/src/control/control.go:345 +0x153

goroutine 169900 [select, 4 minutes]:
main.unaryInterceptor.func1.1(0x1272a60, 0xc0005550c0, 0x1272a60, 0xc000295bc0, 0xc000202dd0)
	/src/cmd/buildkitd/main.go:477 +0xd8
created by main.unaryInterceptor.func1
	/src/cmd/buildkitd/main.go:476 +0x108

goroutine 169925 [sync.Cond.Wait, 4 minutes]:
runtime.goparkunlock(...)
	/usr/local/go/src/runtime/proc.go:307
sync.runtime_notifyListWait(0xc0005551d0, 0xc000000005)
	/usr/local/go/src/runtime/sema.go:510 +0xf9
sync.(*Cond).Wait(0xc0005551c0)
	/usr/local/go/src/sync/cond.go:56 +0x9e
github.com/moby/buildkit/util/progress.(*progressReader).Read(0xc000ecbaa0, 0x1272aa0, 0xc0000380a8, 0x0, 0x0, 0x0, 0x0, 0x0)
	/src/util/progress/progress.go:125 +0x10b
github.com/moby/buildkit/util/progress.(*MultiReader).handle(0xc000ecbbc0, 0xc000ff0c30, 0xc000ecbbc0)
	/src/util/progress/multireader.go:56 +0x118
created by github.com/moby/buildkit/util/progress.(*MultiReader).Reader
	/src/util/progress/multireader.go:47 +0x1ea

goroutine 169908 [select, 4 minutes]:
google.golang.org/grpc.(*ccResolverWrapper).watcher(0xc001305d10)
	/src/vendor/google.golang.org/grpc/resolver_conn_wrapper.go:109 +0x13f
created by google.golang.org/grpc.(*ccResolverWrapper).start
	/src/vendor/google.golang.org/grpc/resolver_conn_wrapper.go:95 +0x3f

goroutine 169911 [select, 3 minutes]:
google.golang.org/grpc.(*addrConn).transportMonitor(0xc000145b80)
	/src/vendor/google.golang.org/grpc/clientconn.go:1373 +0x1c4
google.golang.org/grpc.(*addrConn).connect.func1(0xc000145b80)
	/src/vendor/google.golang.org/grpc/clientconn.go:949 +0x1d9
created by google.golang.org/grpc.(*addrConn).connect
	/src/vendor/google.golang.org/grpc/clientconn.go:940 +0xe1

goroutine 169979 [chan receive, 4 minutes]:
github.com/moby/buildkit/frontend/gateway.serve.func1(0x1272b20, 0xc000ecb8c0, 0x12818c0, 0xc000821dd0)
	/src/frontend/gateway/gateway.go:661 +0x48
created by github.com/moby/buildkit/frontend/gateway.serve
	/src/frontend/gateway/gateway.go:660 +0x64

goroutine 169913 [select]:
google.golang.org/grpc/transport.(*controlBuffer).get(0xc00075c240, 0x1, 0x0, 0x0, 0x0, 0x0)
	/src/vendor/google.golang.org/grpc/transport/controlbuf.go:289 +0x104
google.golang.org/grpc/transport.(*loopyWriter).run(0xc0001c4180)
	/src/vendor/google.golang.org/grpc/transport/controlbuf.go:374 +0x1ca
google.golang.org/grpc/transport.newHTTP2Client.func3(0xc00050e240)
	/src/vendor/google.golang.org/grpc/transport/http2_client.go:298 +0x77
created by google.golang.org/grpc/transport.newHTTP2Client
	/src/vendor/google.golang.org/grpc/transport/http2_client.go:296 +0xcf2

goroutine 169898 [chan receive, 4 minutes]:
github.com/moby/buildkit/session.(*Manager).handleConn(0xc0003b8620, 0x1272a60, 0xc00075c0c0, 0x1281b60, 0xc0002b9ea0, 0xc000ecb2f0, 0x0, 0x0)
	/src/session/manager.go:144 +0x491
github.com/moby/buildkit/session.(*Manager).HandleConn(0xc0003b8620, 0x1272a60, 0xc0006b3e40, 0x1281b60, 0xc0002b9ea0, 0xc000ecb2f0, 0x0, 0x0)
	/src/session/manager.go:97 +0x75
github.com/moby/buildkit/control.(*Controller).Session(0xc0002f6800, 0x1281800, 0xc0012ab510, 0x0, 0x0)
	/src/control/control.go:350 +0x199
github.com/moby/buildkit/api/services/control._Control_Session_Handler(0x104fda0, 0xc0002f6800, 0x127a7e0, 0xc000d976a0, 0x10a1080, 0x1c99b40)
	/src/api/services/control/control.pb.go:1391 +0xad
github.com/grpc-ecosystem/grpc-opentracing/go/otgrpc.OpenTracingStreamServerInterceptor.func1(0x104fda0, 0xc0002f6800, 0x127aba0, 0xc0003ba420, 0xc000d97640, 0x1135030, 0x0, 0x0)
	/src/vendor/github.com/grpc-ecosystem/grpc-opentracing/go/otgrpc/server.go:114 +0x365
google.golang.org/grpc.(*Server).processStreamingRPC(0xc00013c700, 0x12845c0, 0xc000110400, 0xc000212b40, 0xc0003fe8a0, 0x1c29b60, 0x0, 0x0, 0x0)
	/src/vendor/google.golang.org/grpc/server.go:1167 +0x423
google.golang.org/grpc.(*Server).handleStream(0xc00013c700, 0x12845c0, 0xc000110400, 0xc000212b40, 0x0)
	/src/vendor/google.golang.org/grpc/server.go:1253 +0x124e
google.golang.org/grpc.(*Server).serveStreams.func1.1(0xc000ea42f0, 0xc00013c700, 0x12845c0, 0xc000110400, 0xc000212b40)
	/src/vendor/google.golang.org/grpc/server.go:680 +0x9f
created by google.golang.org/grpc.(*Server).serveStreams.func1
	/src/vendor/google.golang.org/grpc/server.go:678 +0xa1

goroutine 169889 [chan receive, 4 minutes]:
github.com/moby/buildkit/control.(*Controller).Status.func2(0x8, 0x11366d8)
	/src/control/control.go:294 +0x782
golang.org/x/sync/errgroup.(*Group).Go.func1(0xc001305b30, 0xc000d97600)
	/src/vendor/golang.org/x/sync/errgroup/errgroup.go:58 +0x57
created by golang.org/x/sync/errgroup.(*Group).Go
	/src/vendor/golang.org/x/sync/errgroup/errgroup.go:55 +0x66

goroutine 169896 [select, 4 minutes]:
google.golang.org/grpc/transport.(*http2Server).keepalive(0xc000110400)
	/src/vendor/google.golang.org/grpc/transport/http2_server.go:867 +0x1ed
created by google.golang.org/grpc/transport.newHTTP2Server
	/src/vendor/google.golang.org/grpc/transport/http2_server.go:280 +0xe8b

goroutine 170075 [syscall, 3 minutes]:
syscall.Syscall6(0xf7, 0x1, 0x19dc, 0xc001e6dde8, 0x1000004, 0x0, 0x0, 0x0, 0x10, 0xc001e6de68)
	/usr/local/go/src/syscall/asm_linux_amd64.s:44 +0x5
os.(*Process).blockUntilWaitable(0xc000302750, 0x60, 0x19, 0xc00049b870)
	/usr/local/go/src/os/wait_waitid.go:31 +0x98
os.(*Process).wait(0xc000302750, 0xc000270900, 0x4, 0xc001e6df38)
	/usr/local/go/src/os/exec_unix.go:22 +0x39
os.(*Process).Wait(...)
	/usr/local/go/src/os/exec.go:125
os/exec.(*Cmd).Wait(0xc000a48580, 0xc000160bd0, 0x4359a6)
	/usr/local/go/src/os/exec/exec.go:474 +0x61
github.com/containerd/go-runc.(*defaultMonitor).Start.func1(0xc000a48580, 0xc0001c4840)
	/src/vendor/github.com/containerd/go-runc/monitor.go:55 +0x2f
created by github.com/containerd/go-runc.(*defaultMonitor).Start
	/src/vendor/github.com/containerd/go-runc/monitor.go:53 +0xa5

goroutine 170073 [select, 3 minutes]:
github.com/moby/buildkit/executor/runcexecutor.(*runcExecutor).Exec.func1(0x1272b20, 0xc0001fa180, 0xc00038aa80, 0xc0004d53c1, 0x19, 0xc001f94430, 0xc0013c2ae0)
	/src/executor/runcexecutor/executor.go:245 +0xcc
created by github.com/moby/buildkit/executor/runcexecutor.(*runcExecutor).Exec
	/src/executor/runcexecutor/executor.go:243 +0xbe2

goroutine 169901 [chan receive, 4 minutes]:
github.com/moby/buildkit/util/progress.pipe.func1(0x1272a60, 0xc000555180, 0xc000ecbaa0)
	/src/util/progress/progress.go:165 +0x48
created by github.com/moby/buildkit/util/progress.pipe
	/src/util/progress/progress.go:164 +0x131

goroutine 169897 [IO wait]:
internal/poll.runtime_pollWait(0x7fbd265a5618, 0x72, 0xffffffffffffffff)
	/usr/local/go/src/runtime/netpoll.go:182 +0x56
internal/poll.(*pollDesc).wait(0xc000bb2498, 0x72, 0xb00, 0xb65, 0xffffffffffffffff)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:87 +0x9b
internal/poll.(*pollDesc).waitRead(...)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc000bb2480, 0xc0004fc400, 0xb65, 0xb65, 0x0, 0x0, 0x0)
	/usr/local/go/src/internal/poll/fd_unix.go:169 +0x19b
net.(*netFD).Read(0xc000bb2480, 0xc0004fc400, 0xb65, 0xb65, 0x203000, 0x0, 0xb58)
	/usr/local/go/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc000952670, 0xc0004fc400, 0xb65, 0xb65, 0x0, 0x0, 0x0)
	/usr/local/go/src/net/net.go:177 +0x69
crypto/tls.(*atLeastReader).Read(0xc0012db740, 0xc0004fc400, 0xb65, 0xb65, 0x2e, 0x1250f20, 0xc000063a30)
	/usr/local/go/src/crypto/tls/conn.go:761 +0x60
bytes.(*Buffer).ReadFrom(0xc000f3d3d8, 0x1250e00, 0xc0012db740, 0x40a035, 0xfb5a80, 0x10be3a0)
	/usr/local/go/src/bytes/buffer.go:207 +0xbd
crypto/tls.(*Conn).readFromUntil(0xc000f3d180, 0x12523a0, 0xc000952670, 0x5, 0xc000952670, 0x11)
	/usr/local/go/src/crypto/tls/conn.go:783 +0xf8
crypto/tls.(*Conn).readRecordOrCCS(0xc000f3d180, 0x1136600, 0xc000f3d2b8, 0x0)
	/usr/local/go/src/crypto/tls/conn.go:590 +0x125
crypto/tls.(*Conn).readRecord(...)
	/usr/local/go/src/crypto/tls/conn.go:558
crypto/tls.(*Conn).Read(0xc000f3d180, 0xc0001a6000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
	/usr/local/go/src/crypto/tls/conn.go:1236 +0x137
bufio.(*Reader).Read(0xc00059a3c0, 0xc00037f458, 0x9, 0x9, 0xc000918a80, 0x7fbd2a8166d0, 0x0)
	/usr/local/go/src/bufio/bufio.go:223 +0x23e
io.ReadAtLeast(0x1250c60, 0xc00059a3c0, 0xc00037f458, 0x9, 0x9, 0x9, 0xbf2ceaa34d6e7d3a, 0x2d3e71ef16c, 0x1c767c0)
	/usr/local/go/src/io/io.go:310 +0x88
io.ReadFull(...)
	/usr/local/go/src/io/io.go:329
golang.org/x/net/http2.readFrameHeader(0xc00037f458, 0x9, 0x9, 0x1250c60, 0xc00059a3c0, 0x0, 0x0, 0xc0007706e0, 0x7070e0910100402)
	/src/vendor/golang.org/x/net/http2/frame.go:237 +0x88
golang.org/x/net/http2.(*Framer).ReadFrame(0xc00037f420, 0xc001039080, 0xc001039080, 0x0, 0x0)
	/src/vendor/golang.org/x/net/http2/frame.go:492 +0xa1
google.golang.org/grpc/transport.(*http2Server).HandleStreams(0xc000110400, 0xc000ecb080, 0x11358e8)
	/src/vendor/google.golang.org/grpc/transport/http2_server.go:426 +0x7c
google.golang.org/grpc.(*Server).serveStreams(0xc00013c700, 0x12845c0, 0xc000110400)
	/src/vendor/google.golang.org/grpc/server.go:676 +0xdd
google.golang.org/grpc.(*Server).handleRawConn.func2()
	/src/vendor/google.golang.org/grpc/server.go:631 +0x3c
google.golang.org/grpc.(*Server).handleRawConn.func3(0xc0005b6640, 0xc00013c700, 0x7fbd265ae5b8, 0xc000110400)
	/src/vendor/google.golang.org/grpc/server.go:639 +0x27
created by google.golang.org/grpc.(*Server).handleRawConn
	/src/vendor/google.golang.org/grpc/server.go:638 +0x5e5

goroutine 169923 [chan receive, 4 minutes]:
github.com/moby/buildkit/util/progress.pipe.func1(0x1272a60, 0xc000555540, 0xc000ff0b70)
	/src/util/progress/progress.go:165 +0x48
created by github.com/moby/buildkit/util/progress.pipe
	/src/util/progress/progress.go:164 +0x131

goroutine 169895 [select]:
google.golang.org/grpc/transport.(*controlBuffer).get(0xc000554e40, 0x1, 0x0, 0x0, 0x0, 0x0)
	/src/vendor/google.golang.org/grpc/transport/controlbuf.go:289 +0x104
google.golang.org/grpc/transport.(*loopyWriter).run(0xc00059a420)
	/src/vendor/google.golang.org/grpc/transport/controlbuf.go:374 +0x1ca
google.golang.org/grpc/transport.newHTTP2Server.func2(0xc000110400)
	/src/vendor/google.golang.org/grpc/transport/http2_server.go:276 +0xc3
created by google.golang.org/grpc/transport.newHTTP2Server
	/src/vendor/google.golang.org/grpc/transport/http2_server.go:273 +0xe66

goroutine 169977 [select, 4 minutes]:
github.com/moby/buildkit/util/progress.(*progressReader).Read.func1(0xc00101c000, 0x1272aa0, 0xc0000380a8, 0xc000ecbaa0)
	/src/util/progress/progress.go:101 +0xb7
created by github.com/moby/buildkit/util/progress.(*progressReader).Read
	/src/util/progress/progress.go:100 +0xdd

goroutine 169978 [select, 4 minutes]:
github.com/moby/buildkit/util/progress.(*progressReader).Read.func1(0xc00101c060, 0x1272a60, 0xc0006b3e00, 0xc000ff0b70)
	/src/util/progress/progress.go:101 +0xb7
created by github.com/moby/buildkit/util/progress.(*progressReader).Read
	/src/util/progress/progress.go:100 +0xdd

goroutine 169910 [select, 4 minutes]:
google.golang.org/grpc.(*ccBalancerWrapper).watcher(0xc00075c140)
	/src/vendor/google.golang.org/grpc/balancer_conn_wrappers.go:122 +0x110
created by google.golang.org/grpc.newCCBalancerWrapper
	/src/vendor/google.golang.org/grpc/balancer_conn_wrappers.go:113 +0x13e

goroutine 169924 [select, 4 minutes]:
github.com/moby/buildkit/util/progress.(*MultiReader).Reader.func1(0x1272b20, 0xc000ff0c30, 0xc000ecbbc0, 0xc0005b7040)
	/src/util/progress/multireader.go:37 +0xbb
created by github.com/moby/buildkit/util/progress.(*MultiReader).Reader
	/src/util/progress/multireader.go:36 +0x195

goroutine 170074 [select, 3 minutes]:
os/exec.(*Cmd).Start.func2(0xc000a48580)
	/usr/local/go/src/os/exec/exec.go:416 +0xc4
created by os/exec.(*Cmd).Start
	/usr/local/go/src/os/exec/exec.go:415 +0x62d

goroutine 169899 [chan receive, 3 minutes]:
github.com/containerd/go-runc.(*defaultMonitor).Wait(0x1c996e0, 0xc000a48580, 0xc0001c4840, 0x0, 0x0, 0x6)
	/src/vendor/github.com/containerd/go-runc/monitor.go:74 +0x4e
github.com/containerd/go-runc.(*Runc).Run(0xc0002f6600, 0x1272a60, 0xc000a211c0, 0xc0004d53c1, 0x19, 0xc000a1c190, 0x43, 0xc0006749b8, 0xc0013c2ae0, 0x0, ...)
	/src/vendor/github.com/containerd/go-runc/runc.go:278 +0x1af
github.com/moby/buildkit/executor/runcexecutor.(*runcExecutor).Exec(0xc00038aa80, 0x1272b20, 0xc0001fa180, 0xc000746a00, 0x1, 0x4, 0xc002496e80, 0x6, 0x8, 0x0, ...)
	/src/executor/runcexecutor/executor.go:271 +0xe1e
github.com/moby/buildkit/worker/base.(*Worker).Exec(0xc0003142d0, 0x1272b20, 0xc0001fa180, 0xc000746a00, 0x1, 0x4, 0xc002496e80, 0x6, 0x8, 0x0, ...)
	/src/worker/base/worker.go:235 +0x254
github.com/moby/buildkit/solver/llbsolver.(*llbBridge).Exec(0xc00059a660, 0x1272b20, 0xc000ecb8c0, 0xc000746a00, 0x1, 0x4, 0xc002496e80, 0x6, 0x8, 0x0, ...)
	/src/solver/llbsolver/bridge.go:141 +0x206
github.com/moby/buildkit/frontend/gateway.(*gatewayFrontend).Solve(0xc0003b4b80, 0x1272b20, 0xc000ecb8c0, 0x126be60, 0xc00059a660, 0xc000ecb800, 0x0, 0x0, 0x0)
	/src/frontend/gateway/gateway.go:210 +0xd60
github.com/moby/buildkit/solver/llbsolver.(*llbBridge).Solve(0xc00059a660, 0x1272b20, 0xc000ecb8c0, 0x0, 0xc000ea4340, 0xa, 0xc000ecb800, 0xc0005b69e0, 0x1, 0x1, ...)
	/src/solver/llbsolver/bridge.go:110 +0x371
github.com/moby/buildkit/solver/llbsolver.(*Solver).Solve(0xc00033f880, 0x1272b20, 0xc000ecb8c0, 0xc0009025e0, 0x19, 0x0, 0xc000ea4340, 0xa, 0xc000ecb800, 0xc0005b69e0, ...)
	/src/solver/llbsolver/solver.go:133 +0x399
github.com/moby/buildkit/control.(*Controller).Solve(0xc0002f6800, 0x1272b20, 0xc000ecb860, 0xc0002e46c0, 0x0, 0x0, 0x0)
	/src/control/control.go:266 +0x467
github.com/moby/buildkit/api/services/control._Control_Solve_Handler.func1(0x1272b20, 0xc000ecb860, 0x10bad80, 0xc0002e46c0, 0x10a1080, 0x1c99b40, 0x1272b20, 0xc000ecb860)
	/src/api/services/control/control.pb.go:1364 +0x86
github.com/grpc-ecosystem/grpc-opentracing/go/otgrpc.OpenTracingServerInterceptor.func1(0x1272a60, 0xc0005550c0, 0x10bad80, 0xc0002e46c0, 0xc0005b6960, 0xc0005b6980, 0x0, 0x0, 0x1250f20, 0xc00003d070)
	/src/vendor/github.com/grpc-ecosystem/grpc-opentracing/go/otgrpc/server.go:57 +0x2eb
main.unaryInterceptor.func1(0x1272a60, 0xc0005550c0, 0x10bad80, 0xc0002e46c0, 0xc0005b6960, 0xc0005b6980, 0x0, 0x0, 0x0, 0x0)
	/src/cmd/buildkitd/main.go:484 +0x15f
github.com/moby/buildkit/api/services/control._Control_Solve_Handler(0x104fda0, 0xc0002f6800, 0x1272b20, 0xc000ecb770, 0xc00032d5e0, 0xc0003214c0, 0x1272b20, 0xc000ecb770, 0xc000466dc0, 0x31)
	/src/api/services/control/control.pb.go:1366 +0x158
google.golang.org/grpc.(*Server).processUnaryRPC(0xc00013c700, 0x12845c0, 0xc000110400, 0xc000212c30, 0xc0003fe8a0, 0x1c27318, 0x0, 0x0, 0x0)
	/src/vendor/google.golang.org/grpc/server.go:1011 +0x4c3
google.golang.org/grpc.(*Server).handleStream(0xc00013c700, 0x12845c0, 0xc000110400, 0xc000212c30, 0x0)
	/src/vendor/google.golang.org/grpc/server.go:1249 +0x12b5
google.golang.org/grpc.(*Server).serveStreams.func1.1(0xc000ea42f0, 0xc00013c700, 0x12845c0, 0xc000110400, 0xc000212c30)
	/src/vendor/google.golang.org/grpc/server.go:680 +0x9f
created by google.golang.org/grpc.(*Server).serveStreams.func1
	/src/vendor/google.golang.org/grpc/server.go:678 +0xa1

goroutine 169912 [select]:
google.golang.org/grpc/transport.(*recvBufferReader).read(0xc000770aa0, 0xc000d97630, 0x5, 0x5, 0xc0013cdf20, 0xc0004afa50, 0xa3e306)
	/src/vendor/google.golang.org/grpc/transport/transport.go:142 +0x1bb
google.golang.org/grpc/transport.(*recvBufferReader).Read(0xc000770aa0, 0xc000d97630, 0x5, 0x5, 0x850e80, 0xc000902560, 0xc0004af9f8)
	/src/vendor/google.golang.org/grpc/transport/transport.go:131 +0x5a
google.golang.org/grpc/transport.(*transportReader).Read(0xc000ecb3b0, 0xc000d97630, 0x5, 0x5, 0x10926c0, 0xc0004afa20, 0x86e1dc)
	/src/vendor/google.golang.org/grpc/transport/transport.go:369 +0x55
io.ReadAtLeast(0x1252100, 0xc000ecb3b0, 0xc000d97630, 0x5, 0x5, 0x5, 0xc0006fe1c0, 0xc0013cdf00, 0x13)
	/usr/local/go/src/io/io.go:310 +0x88
io.ReadFull(...)
	/usr/local/go/src/io/io.go:329
google.golang.org/grpc/transport.(*Stream).Read(0xc000212b40, 0xc000d97630, 0x5, 0x5, 0x13, 0x0, 0x0)
	/src/vendor/google.golang.org/grpc/transport/transport.go:353 +0xc8
google.golang.org/grpc.(*parser).recvMsg(0xc000d97620, 0x400000, 0x13, 0x13, 0x10926c0, 0xc0006fe1c0, 0xc000939380, 0xc00028fcc0)
	/src/vendor/google.golang.org/grpc/rpc_util.go:452 +0x63
google.golang.org/grpc.recv(0xc000d97620, 0x7fbd265ae5d8, 0x1c99b40, 0xc000212b40, 0x0, 0x0, 0x10926c0, 0xc0006fe280, 0x400000, 0x0, ...)
	/src/vendor/google.golang.org/grpc/rpc_util.go:561 +0x4d
google.golang.org/grpc.(*serverStream).RecvMsg(0xc0003ba420, 0x10926c0, 0xc0006fe280, 0x0, 0x0)
	/src/vendor/google.golang.org/grpc/stream.go:746 +0x122
github.com/moby/buildkit/session/grpchijack.(*conn).Read(0xc0002b9ea0, 0xc002014000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
	/src/session/grpchijack/dial.go:68 +0x1d8
bufio.(*Reader).Read(0xc0001c40c0, 0xc000535df8, 0x9, 0x9, 0xc000918a80, 0x7fbd2a816008, 0x0)
	/usr/local/go/src/bufio/bufio.go:223 +0x23e
io.ReadAtLeast(0x1250c60, 0xc0001c40c0, 0xc000535df8, 0x9, 0x9, 0x9, 0x82c695, 0xc0013cdf4c, 0xc0004afe40)
	/usr/local/go/src/io/io.go:310 +0x88
io.ReadFull(...)
	/usr/local/go/src/io/io.go:329
golang.org/x/net/http2.readFrameHeader(0xc000535df8, 0x9, 0x9, 0x1250c60, 0xc0001c40c0, 0x0, 0xc000000000, 0x2d3e71bfdd9, 0x1c767c0)
	/src/vendor/golang.org/x/net/http2/frame.go:237 +0x88
golang.org/x/net/http2.(*Framer).ReadFrame(0xc000535dc0, 0xc0013cdf40, 0xc0013cdf40, 0x0, 0x0)
	/src/vendor/golang.org/x/net/http2/frame.go:492 +0xa1
google.golang.org/grpc/transport.(*http2Client).reader(0xc00050e240)
	/src/vendor/google.golang.org/grpc/transport/http2_client.go:1123 +0x116
created by google.golang.org/grpc/transport.newHTTP2Client
	/src/vendor/google.golang.org/grpc/transport/http2_client.go:265 +0xb92

goroutine 169887 [semacquire, 4 minutes]:
sync.runtime_Semacquire(0xc001305b40)
	/usr/local/go/src/runtime/sema.go:56 +0x39
sync.(*WaitGroup).Wait(0xc001305b38)
	/usr/local/go/src/sync/waitgroup.go:130 +0x65
golang.org/x/sync/errgroup.(*Group).Wait(0xc001305b30, 0xc000d97600, 0xc001305b30)
	/src/vendor/golang.org/x/sync/errgroup/errgroup.go:41 +0x31
github.com/moby/buildkit/control.(*Controller).Status(0xc0002f6800, 0xc001305ad0, 0x127f040, 0xc0012ab4b0, 0xc0002f6800, 0x20)
	/src/control/control.go:336 +0x174
github.com/moby/buildkit/api/services/control._Control_Status_Handler(0x104fda0, 0xc0002f6800, 0x127a7e0, 0xc000d975e0, 0x10a1080, 0x1c99b40)
	/src/api/services/control/control.pb.go:1374 +0x109
github.com/grpc-ecosystem/grpc-opentracing/go/otgrpc.OpenTracingStreamServerInterceptor.func1(0x104fda0, 0xc0002f6800, 0x127aba0, 0xc0003ba370, 0xc000d97580, 0x1135040, 0x0, 0x0)
	/src/vendor/github.com/grpc-ecosystem/grpc-opentracing/go/otgrpc/server.go:114 +0x365
google.golang.org/grpc.(*Server).processStreamingRPC(0xc00013c700, 0x12845c0, 0xc000110400, 0xc000314870, 0xc0003fe8a0, 0x1c29b40, 0x0, 0x0, 0x0)
	/src/vendor/google.golang.org/grpc/server.go:1167 +0x423
google.golang.org/grpc.(*Server).handleStream(0xc00013c700, 0x12845c0, 0xc000110400, 0xc000314870, 0x0)
	/src/vendor/google.golang.org/grpc/server.go:1253 +0x124e
google.golang.org/grpc.(*Server).serveStreams.func1.1(0xc000ea42f0, 0xc00013c700, 0x12845c0, 0xc000110400, 0xc000314870)
	/src/vendor/google.golang.org/grpc/server.go:680 +0x9f
created by google.golang.org/grpc.(*Server).serveStreams.func1
	/src/vendor/google.golang.org/grpc/server.go:678 +0xa1

rax    0xca
rbx    0x1c775a0
rcx    0x45e953
rdx    0x0
rdi    0x1c776e8
rsi    0x80
rbp    0x7ffef69fe0f8
rsp    0x7ffef69fe0b0
r8     0x0
r9     0x0
r10    0x0
r11    0x286
r12    0x1
r13    0xc000084b40
r14    0xc000084ba0
r15    0x0
rip    0x45e951
rflags 0x286
cs     0x33
fs     0x0
gs     0x0

The text was updated successfully, but these errors were encountered:

msg555 · 2019-05-08T20:53:31Z

The CLI invocation looked like

buildctl build --frontend=gateway.v0 --opt=source=docker/dockerfile:experimental --local=context=/my-context --local=dockerfile=/my-context --output=type=image,name=my-registry/myimage:mytag,push=true --import-cache=type=registry,ref=otherregistry/myimage:mytag-cache

msg555 · 2019-05-09T19:04:32Z

Upgraded to 5.1, still happens

SIGABRT: abort
PC=0x45ea11 m=0 sigcode=0

goroutine 0 [idle]:
runtime.futex(0x1c7c6e8, 0x80, 0x0, 0x0, 0x0, 0x7ffe46c22d60, 0x0, 0x0, 0x7ffe46c22d80, 0x40ac01, ...)
	/usr/local/go/src/runtime/sys_linux_amd64.s:535 +0x21
runtime.futexsleep(0x1c7c6e8, 0x7ffe00000000, 0xffffffffffffffff)
	/usr/local/go/src/runtime/os_linux.go:46 +0x4b
runtime.notesleep(0x1c7c6e8)
	/usr/local/go/src/runtime/lock_futex.go:151 +0xa1
runtime.stoplockedm()
	/usr/local/go/src/runtime/proc.go:2076 +0x8c
runtime.schedule()
	/usr/local/go/src/runtime/proc.go:2477 +0x3ba
runtime.park_m(0xc00011e600)
	/usr/local/go/src/runtime/proc.go:2605 +0xa1
runtime.mcall(0x1c23018)
	/usr/local/go/src/runtime/asm_amd64.s:299 +0x5b

goroutine 1 [select, 35 minutes]:
main.main.func3(0xc0000d7340, 0x0, 0x0)
	/src/cmd/buildkitd/main.go:262 +0x998
github.com/urfave/cli.HandleAction(0xf5cec0, 0x1138cf0, 0xc0000d7340, 0xc0000d7340, 0xc000207858)
	/src/vendor/github.com/urfave/cli/app.go:502 +0xc8
github.com/urfave/cli.(*App).Run(0xc000160540, 0xc000032090, 0x9, 0x9, 0x0, 0x0)
	/src/vendor/github.com/urfave/cli/app.go:268 +0x5aa
main.main()
	/src/cmd/buildkitd/main.go:289 +0xd6c

goroutine 6 [syscall, 35 minutes]:
os/signal.signal_recv(0x0)
	/usr/local/go/src/runtime/sigqueue.go:139 +0x9c
os/signal.loop()
	/usr/local/go/src/os/signal/signal_unix.go:23 +0x22
created by os/signal.init.0
	/usr/local/go/src/os/signal/signal_unix.go:29 +0x41

goroutine 8 [chan receive, 35 minutes]:
github.com/moby/buildkit/util/appcontext.Context.func1.1(0xc0003ac240, 0xc00030d9b0, 0xc00036a600)
	/src/util/appcontext/appcontext.go:30 +0x38
created by github.com/moby/buildkit/util/appcontext.Context.func1
	/src/util/appcontext/appcontext.go:28 +0xff

goroutine 10 [sync.Cond.Wait, 4 minutes]:
runtime.goparkunlock(...)
	/usr/local/go/src/runtime/proc.go:307
sync.runtime_notifyListWait(0xc000416490, 0x670)
	/usr/local/go/src/runtime/sema.go:510 +0xf9
sync.(*Cond).Wait(0xc000416480)
	/usr/local/go/src/sync/cond.go:56 +0x9e
github.com/moby/buildkit/util/cond.(*StatefulCond).Wait(0xc000418990)
	/src/util/cond/cond.go:28 +0x98
github.com/moby/buildkit/solver.(*scheduler).loop(0xc000363960)
	/src/solver/scheduler.go:101 +0x168
created by github.com/moby/buildkit/solver.newScheduler
	/src/solver/scheduler.go:35 +0x1ad

goroutine 11 [IO wait, 4 minutes]:
internal/poll.runtime_pollWait(0x7f8ed9bfdf08, 0x72, 0x0)
	/usr/local/go/src/runtime/netpoll.go:182 +0x56
internal/poll.(*pollDesc).wait(0xc00031e918, 0x72, 0x0, 0x0, 0x10f1be0)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:87 +0x9b
internal/poll.(*pollDesc).waitRead(...)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Accept(0xc00031e900, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
	/usr/local/go/src/internal/poll/fd_unix.go:384 +0x1ba
net.(*netFD).accept(0xc00031e900, 0xc000796101, 0x0, 0x0)
	/usr/local/go/src/net/fd_unix.go:238 +0x42
net.(*TCPListener).accept(0xc0000106c0, 0xc000064e20, 0xc000064e28, 0x18)
	/usr/local/go/src/net/tcpsock_posix.go:139 +0x32
net.(*TCPListener).Accept(0xc0000106c0, 0x1138870, 0xc000160700, 0x12853c0, 0xc000796150)
	/usr/local/go/src/net/tcpsock.go:260 +0x48
google.golang.org/grpc.(*Server).Serve(0xc000160700, 0x12706a0, 0xc0000106c0, 0x0, 0x0)
	/src/vendor/google.golang.org/grpc/server.go:544 +0x1f2
main.serveGRPC.func1.1(0x0, 0x0)
	/src/cmd/buildkitd/main.go:322 +0x10e
golang.org/x/sync/errgroup.(*Group).Go.func1(0xc000418ae0, 0xc0003d4ee0)
	/src/vendor/golang.org/x/sync/errgroup/errgroup.go:58 +0x57
created by golang.org/x/sync/errgroup.(*Group).Go
	/src/vendor/golang.org/x/sync/errgroup/errgroup.go:55 +0x66

goroutine 12 [semacquire, 35 minutes]:
sync.runtime_Semacquire(0xc000418af0)
	/usr/local/go/src/runtime/sema.go:56 +0x39
sync.(*WaitGroup).Wait(0xc000418ae8)
	/usr/local/go/src/sync/waitgroup.go:130 +0x65
golang.org/x/sync/errgroup.(*Group).Wait(0xc000418ae0, 0x0, 0x0)
	/src/vendor/golang.org/x/sync/errgroup/errgroup.go:41 +0x31
main.serveGRPC.func2(0xc0003ad380, 0xc000418ae0)
	/src/cmd/buildkitd/main.go:327 +0x2b
created by main.serveGRPC
	/src/cmd/buildkitd/main.go:326 +0x2ba

goroutine 13 [chan receive, 35 minutes]:
github.com/moby/buildkit/solver.(*scheduler).loop.func2(0xc000363960)
	/src/solver/scheduler.go:76 +0x38
created by github.com/moby/buildkit/solver.(*scheduler).loop
	/src/solver/scheduler.go:75 +0x6d

goroutine 59869 [chan receive, 4 minutes]:
github.com/moby/buildkit/util/progress.pipe.func1(0x1276020, 0xc00063ca80, 0xc000a25620)
	/src/util/progress/progress.go:165 +0x48
created by github.com/moby/buildkit/util/progress.pipe
	/src/util/progress/progress.go:164 +0x131

goroutine 59893 [select, 4 minutes]:
github.com/moby/buildkit/util/progress.(*MultiReader).Reader.func1(0x12760e0, 0xc0005c2120, 0xc000a25740, 0xc001fe9fe0)
	/src/util/progress/multireader.go:37 +0xbb
created by github.com/moby/buildkit/util/progress.(*MultiReader).Reader
	/src/util/progress/multireader.go:36 +0x195

goroutine 59855 [chan receive, 4 minutes]:
github.com/moby/buildkit/control.(*Controller).Session.func1(0xc000664480, 0xc0003fc2b0)
	/src/control/control.go:346 +0x34
created by github.com/moby/buildkit/control.(*Controller).Session
	/src/control/control.go:345 +0x153

goroutine 59877 [select]:
google.golang.org/grpc/transport.(*controlBuffer).get(0xc000b16e00, 0x1, 0x0, 0x0, 0x0, 0x0)
	/src/vendor/google.golang.org/grpc/transport/controlbuf.go:289 +0x104
google.golang.org/grpc/transport.(*loopyWriter).run(0xc00045faa0)
	/src/vendor/google.golang.org/grpc/transport/controlbuf.go:374 +0x1ca
google.golang.org/grpc/transport.newHTTP2Client.func3(0xc000298480)
	/src/vendor/google.golang.org/grpc/transport/http2_client.go:298 +0x77
created by google.golang.org/grpc/transport.newHTTP2Client
	/src/vendor/google.golang.org/grpc/transport/http2_client.go:296 +0xcf2

goroutine 59875 [select, 4 minutes]:
google.golang.org/grpc.(*addrConn).transportMonitor(0xc0000dab00)
	/src/vendor/google.golang.org/grpc/clientconn.go:1373 +0x1c4
google.golang.org/grpc.(*addrConn).connect.func1(0xc0000dab00)
	/src/vendor/google.golang.org/grpc/clientconn.go:949 +0x1d9
created by google.golang.org/grpc.(*addrConn).connect
	/src/vendor/google.golang.org/grpc/clientconn.go:940 +0xe1

goroutine 59853 [chan receive, 4 minutes]:
github.com/containerd/go-runc.(*defaultMonitor).Wait(0x1c9e6e0, 0xc000626420, 0xc0013abc20, 0x0, 0x0, 0x6)
	/src/vendor/github.com/containerd/go-runc/monitor.go:74 +0x4e
github.com/containerd/go-runc.(*Runc).Run(0xc00031e680, 0x1276020, 0xc001a1c2c0, 0xc00241ca01, 0x19, 0xc00025c320, 0x43, 0xc0000bc9b8, 0xc001f749c0, 0x0, ...)
	/src/vendor/github.com/containerd/go-runc/runc.go:278 +0x1af
github.com/moby/buildkit/executor/runcexecutor.(*runcExecutor).Exec(0xc0003acb40, 0x12760e0, 0xc0013ea930, 0xc00114f940, 0x1, 0x4, 0xc0013cd900, 0x6, 0x8, 0x0, ...)
	/src/executor/runcexecutor/executor.go:275 +0xe29
github.com/moby/buildkit/worker/base.(*Worker).Exec(0xc0003382d0, 0x12760e0, 0xc0013ea930, 0xc00114f940, 0x1, 0x4, 0xc0013cd900, 0x6, 0x8, 0x0, ...)
	/src/worker/base/worker.go:235 +0x254
github.com/moby/buildkit/solver/llbsolver.(*llbBridge).Exec(0xc000d86de0, 0x12760e0, 0xc000a25530, 0xc00114f940, 0x1, 0x4, 0xc0013cd900, 0x6, 0x8, 0x0, ...)
	/src/solver/llbsolver/bridge.go:141 +0x206
github.com/moby/buildkit/frontend/gateway.(*gatewayFrontend).Solve(0xc0003d0be0, 0x12760e0, 0xc000a25530, 0x126f420, 0xc000d86de0, 0xc000a25470, 0x0, 0x0, 0x0)
	/src/frontend/gateway/gateway.go:210 +0xd60
github.com/moby/buildkit/solver/llbsolver.(*llbBridge).Solve(0xc000d86de0, 0x12760e0, 0xc000a25530, 0x0, 0xc0010fcd10, 0xa, 0xc000a25470, 0xc001fe9c00, 0x1, 0x1, ...)
	/src/solver/llbsolver/bridge.go:110 +0x371
github.com/moby/buildkit/solver/llbsolver.(*Solver).Solve(0xc0003638f0, 0x12760e0, 0xc000a25530, 0xc0002e51a0, 0x19, 0x0, 0xc0010fcd10, 0xa, 0xc000a25470, 0xc001fe9c00, ...)
	/src/solver/llbsolver/solver.go:133 +0x399
github.com/moby/buildkit/control.(*Controller).Solve(0xc00031e880, 0x12760e0, 0xc000a254d0, 0xc00044b0e0, 0x0, 0x0, 0x0)
	/src/control/control.go:266 +0x467
github.com/moby/buildkit/api/services/control._Control_Solve_Handler.func1(0x12760e0, 0xc000a254d0, 0x10bdc40, 0xc00044b0e0, 0x10a3ca0, 0x1c9eb40, 0x12760e0, 0xc000a254d0)
	/src/api/services/control/control.pb.go:1364 +0x86
github.com/grpc-ecosystem/grpc-opentracing/go/otgrpc.OpenTracingServerInterceptor.func1(0x1276020, 0xc00063c9c0, 0x10bdc40, 0xc00044b0e0, 0xc001fe9b80, 0xc001fe9ba0, 0x0, 0x0, 0x12544e0, 0xc00003d0c0)
	/src/vendor/github.com/grpc-ecosystem/grpc-opentracing/go/otgrpc/server.go:57 +0x2eb
main.unaryInterceptor.func1(0x1276020, 0xc00063c9c0, 0x10bdc40, 0xc00044b0e0, 0xc001fe9b80, 0xc001fe9ba0, 0x0, 0x0, 0x0, 0x0)
	/src/cmd/buildkitd/main.go:509 +0x15f
github.com/moby/buildkit/api/services/control._Control_Solve_Handler(0x1052900, 0xc00031e880, 0x12760e0, 0xc000a253e0, 0xc0003627e0, 0xc000343520, 0x12760e0, 0xc000a253e0, 0x503b4f, 0xf42ee0)
	/src/api/services/control/control.pb.go:1366 +0x158
google.golang.org/grpc.(*Server).processUnaryRPC(0xc000160700, 0x1287b20, 0xc000132600, 0xc00065c0f0, 0xc000418a20, 0x1c2c318, 0x0, 0x0, 0x0)
	/src/vendor/google.golang.org/grpc/server.go:1011 +0x4c3
google.golang.org/grpc.(*Server).handleStream(0xc000160700, 0x1287b20, 0xc000132600, 0xc00065c0f0, 0x0)
	/src/vendor/google.golang.org/grpc/server.go:1249 +0x12b5
google.golang.org/grpc.(*Server).serveStreams.func1.1(0xc0010fcce0, 0xc000160700, 0x1287b20, 0xc000132600, 0xc00065c0f0)
	/src/vendor/google.golang.org/grpc/server.go:680 +0x9f
created by google.golang.org/grpc.(*Server).serveStreams.func1
	/src/vendor/google.golang.org/grpc/server.go:678 +0xa1

goroutine 59874 [select, 4 minutes]:
google.golang.org/grpc.(*ccBalancerWrapper).watcher(0xc000b16d00)
	/src/vendor/google.golang.org/grpc/balancer_conn_wrappers.go:122 +0x110
created by google.golang.org/grpc.newCCBalancerWrapper
	/src/vendor/google.golang.org/grpc/balancer_conn_wrappers.go:113 +0x13e

goroutine 59886 [select, 4 minutes]:
os/exec.(*Cmd).Start.func2(0xc000626420)
	/usr/local/go/src/os/exec/exec.go:416 +0xc4
created by os/exec.(*Cmd).Start
	/usr/local/go/src/os/exec/exec.go:415 +0x62d

goroutine 59885 [select, 4 minutes]:
github.com/moby/buildkit/executor/runcexecutor.(*runcExecutor).Exec.func1(0x12760e0, 0xc0013ea930, 0xc0003acb40, 0xc00241ca01, 0x19, 0xc001094290, 0xc001f749c0)
	/src/executor/runcexecutor/executor.go:249 +0xcc
created by github.com/moby/buildkit/executor/runcexecutor.(*runcExecutor).Exec
	/src/executor/runcexecutor/executor.go:247 +0xbe2

goroutine 59866 [chan receive, 4 minutes]:
github.com/moby/buildkit/control.(*Controller).Status.func2(0xc000000008, 0x11396c8)
	/src/control/control.go:294 +0x782
golang.org/x/sync/errgroup.(*Group).Go.func1(0xc000a25380, 0xc001fe9b20)
	/src/vendor/golang.org/x/sync/errgroup/errgroup.go:58 +0x57
created by golang.org/x/sync/errgroup.(*Group).Go
	/src/vendor/golang.org/x/sync/errgroup/errgroup.go:55 +0x66

goroutine 59857 [select]:
github.com/moby/buildkit/session.monitorHealth(0x1276020, 0xc000b16c80, 0xc000370000, 0xc0003fc3e0)
	/src/session/grpc.go:69 +0x189
created by github.com/moby/buildkit/session.grpcClientConn
	/src/session/grpc.go:55 +0x23e

goroutine 59887 [syscall, 4 minutes]:
syscall.Syscall6(0xf7, 0x1, 0x7d8, 0xc000201de8, 0x1000004, 0x0, 0x0, 0x405a9e, 0xc001124900, 0x3)
	/usr/local/go/src/syscall/asm_linux_amd64.s:44 +0x5
os.(*Process).blockUntilWaitable(0xc0003f7d40, 0xc00040c950, 0xc000201fb0, 0xc001a4d908)
	/usr/local/go/src/os/wait_waitid.go:31 +0x98
os.(*Process).wait(0xc0003f7d40, 0xc000d76900, 0xc000201fb0, 0x1052901)
	/usr/local/go/src/os/exec_unix.go:22 +0x39
os.(*Process).Wait(...)
	/usr/local/go/src/os/exec.go:125
os/exec.(*Cmd).Wait(0xc000626420, 0xc00003c050, 0x435a66)
	/usr/local/go/src/os/exec/exec.go:474 +0x61
github.com/containerd/go-runc.(*defaultMonitor).Start.func1(0xc000626420, 0xc0013abc20)
	/src/vendor/github.com/containerd/go-runc/monitor.go:55 +0x2f
created by github.com/containerd/go-runc.(*defaultMonitor).Start
	/src/vendor/github.com/containerd/go-runc/monitor.go:53 +0xa5

goroutine 59862 [select]:
google.golang.org/grpc/transport.(*controlBuffer).get(0xc00063c900, 0x1, 0x0, 0x0, 0x0, 0x0)
	/src/vendor/google.golang.org/grpc/transport/controlbuf.go:289 +0x104
google.golang.org/grpc/transport.(*loopyWriter).run(0xc00045f440)
	/src/vendor/google.golang.org/grpc/transport/controlbuf.go:374 +0x1ca
google.golang.org/grpc/transport.newHTTP2Server.func2(0xc000132600)
	/src/vendor/google.golang.org/grpc/transport/http2_server.go:276 +0xc3
created by google.golang.org/grpc/transport.newHTTP2Server
	/src/vendor/google.golang.org/grpc/transport/http2_server.go:273 +0xe66

goroutine 59856 [select, 4 minutes]:
google.golang.org/grpc.(*ccResolverWrapper).watcher(0xc0010b8090)
	/src/vendor/google.golang.org/grpc/resolver_conn_wrapper.go:109 +0x13f
created by google.golang.org/grpc.(*ccResolverWrapper).start
	/src/vendor/google.golang.org/grpc/resolver_conn_wrapper.go:95 +0x3f

goroutine 59852 [semacquire, 4 minutes]:
sync.runtime_Semacquire(0xc000a25390)
	/usr/local/go/src/runtime/sema.go:56 +0x39
sync.(*WaitGroup).Wait(0xc000a25388)
	/usr/local/go/src/sync/waitgroup.go:130 +0x65
golang.org/x/sync/errgroup.(*Group).Wait(0xc000a25380, 0xc001fe9b20, 0xc000a25380)
	/src/vendor/golang.org/x/sync/errgroup/errgroup.go:41 +0x31
github.com/moby/buildkit/control.(*Controller).Status(0xc00031e880, 0xc000a25320, 0x1282600, 0xc0005cdc00, 0xc00031e880, 0x20)
	/src/control/control.go:336 +0x174
github.com/moby/buildkit/api/services/control._Control_Status_Handler(0x1052900, 0xc00031e880, 0x127dda0, 0xc001fe9b00, 0x10a3ca0, 0x1c9eb40)
	/src/api/services/control/control.pb.go:1374 +0x109
github.com/grpc-ecosystem/grpc-opentracing/go/otgrpc.OpenTracingStreamServerInterceptor.func1(0x1052900, 0xc00031e880, 0x127e160, 0xc000cf4370, 0xc001fe9aa0, 0x1138020, 0x0, 0x0)
	/src/vendor/github.com/grpc-ecosystem/grpc-opentracing/go/otgrpc/server.go:114 +0x365
google.golang.org/grpc.(*Server).processStreamingRPC(0xc000160700, 0x1287b20, 0xc000132600, 0xc00065c000, 0xc000418a20, 0x1c2eb40, 0x0, 0x0, 0x0)
	/src/vendor/google.golang.org/grpc/server.go:1167 +0x423
google.golang.org/grpc.(*Server).handleStream(0xc000160700, 0x1287b20, 0xc000132600, 0xc00065c000, 0x0)
	/src/vendor/google.golang.org/grpc/server.go:1253 +0x124e
google.golang.org/grpc.(*Server).serveStreams.func1.1(0xc0010fcce0, 0xc000160700, 0x1287b20, 0xc000132600, 0xc00065c000)
	/src/vendor/google.golang.org/grpc/server.go:680 +0x9f
created by google.golang.org/grpc.(*Server).serveStreams.func1
	/src/vendor/google.golang.org/grpc/server.go:678 +0xa1

goroutine 59868 [select, 4 minutes]:
main.unaryInterceptor.func1.1(0x1276020, 0xc00063c9c0, 0x1276020, 0xc0002b9bc0, 0xc0005cddf0)
	/src/cmd/buildkitd/main.go:502 +0xd8
created by main.unaryInterceptor.func1
	/src/cmd/buildkitd/main.go:501 +0x108

goroutine 59925 [select, 4 minutes]:
github.com/moby/buildkit/util/progress.(*progressReader).Read.func1(0xc000adf7a0, 0x1276020, 0xc00063c980, 0xc0005c2030)
	/src/util/progress/progress.go:101 +0xb7
created by github.com/moby/buildkit/util/progress.(*progressReader).Read
	/src/util/progress/progress.go:100 +0xdd

goroutine 59863 [select, 4 minutes]:
google.golang.org/grpc/transport.(*http2Server).keepalive(0xc000132600)
	/src/vendor/google.golang.org/grpc/transport/http2_server.go:867 +0x1ed
created by google.golang.org/grpc/transport.newHTTP2Server
	/src/vendor/google.golang.org/grpc/transport/http2_server.go:280 +0xe8b

goroutine 59865 [sync.Cond.Wait, 4 minutes]:
runtime.goparkunlock(...)
	/usr/local/go/src/runtime/proc.go:307
sync.runtime_notifyListWait(0xc00063ce90, 0xc000000004)
	/usr/local/go/src/runtime/sema.go:510 +0xf9
sync.(*Cond).Wait(0xc00063ce80)
	/usr/local/go/src/sync/cond.go:56 +0x9e
github.com/moby/buildkit/util/progress.(*progressReader).Read(0xc0005c2030, 0x1276020, 0xc00063c980, 0x0, 0x0, 0x0, 0x0, 0x0)
	/src/util/progress/progress.go:125 +0x10b
github.com/moby/buildkit/solver.(*Job).Status(0xc000362850, 0x1276020, 0xc00063c980, 0xc000d86cc0, 0x0, 0x0)
	/src/solver/progress.go:25 +0xd14
github.com/moby/buildkit/solver/llbsolver.(*Solver).Status(0xc0003638f0, 0x1276020, 0xc00063c980, 0xc0002e5160, 0x19, 0xc000d86cc0, 0xc000a70788, 0xc000a70790)
	/src/solver/llbsolver/solver.go:280 +0xbe
github.com/moby/buildkit/control.(*Controller).Status.func1(0x8, 0x11396c8)
	/src/control/control.go:289 +0x5e
golang.org/x/sync/errgroup.(*Group).Go.func1(0xc000a25380, 0xc000a253b0)
	/src/vendor/golang.org/x/sync/errgroup/errgroup.go:58 +0x57
created by golang.org/x/sync/errgroup.(*Group).Go
	/src/vendor/golang.org/x/sync/errgroup/errgroup.go:55 +0x66

goroutine 59924 [select, 4 minutes]:
github.com/moby/buildkit/util/progress.(*progressReader).Read.func1(0xc000adf740, 0x1276060, 0xc0000380a8, 0xc000a25620)
	/src/util/progress/progress.go:101 +0xb7
created by github.com/moby/buildkit/util/progress.(*progressReader).Read
	/src/util/progress/progress.go:100 +0xdd

goroutine 59919 [chan receive, 4 minutes]:
github.com/moby/buildkit/frontend/gateway.serve.func1(0x12760e0, 0xc000a25530, 0x1284e80, 0xc0013ea5d0)
	/src/frontend/gateway/gateway.go:661 +0x48
created by github.com/moby/buildkit/frontend/gateway.serve
	/src/frontend/gateway/gateway.go:660 +0x64

goroutine 59876 [select]:
google.golang.org/grpc/transport.(*recvBufferReader).read(0xc0025364b0, 0xc001407530, 0x5, 0x5, 0xc000562e60, 0xc000061a50, 0xa40216)
	/src/vendor/google.golang.org/grpc/transport/transport.go:142 +0x1bb
google.golang.org/grpc/transport.(*recvBufferReader).Read(0xc0025364b0, 0xc001407530, 0x5, 0x5, 0x852d90, 0xc000c9e640, 0xc0000619f8)
	/src/vendor/google.golang.org/grpc/transport/transport.go:131 +0x5a
google.golang.org/grpc/transport.(*transportReader).Read(0xc000a2de60, 0xc001407530, 0x5, 0x5, 0x10952e0, 0xc000061a20, 0x8700ec)
	/src/vendor/google.golang.org/grpc/transport/transport.go:369 +0x55
io.ReadAtLeast(0x12556c0, 0xc000a2de60, 0xc001407530, 0x5, 0x5, 0x5, 0xc0010ff440, 0xc000562e40, 0x13)
	/usr/local/go/src/io/io.go:310 +0x88
io.ReadFull(...)
	/usr/local/go/src/io/io.go:329
google.golang.org/grpc/transport.(*Stream).Read(0xc00065c1e0, 0xc001407530, 0x5, 0x5, 0x13, 0x0, 0x0)
	/src/vendor/google.golang.org/grpc/transport/transport.go:353 +0xc8
google.golang.org/grpc.(*parser).recvMsg(0xc001407520, 0x400000, 0x13, 0x13, 0x10952e0, 0xc0010ff440, 0xc001f9a900, 0xc000598f50)
	/src/vendor/google.golang.org/grpc/rpc_util.go:452 +0x63
google.golang.org/grpc.recv(0xc001407520, 0x7f8ed9c08c40, 0x1c9eb40, 0xc00065c1e0, 0x0, 0x0, 0x10952e0, 0xc000514dc0, 0x400000, 0x0, ...)
	/src/vendor/google.golang.org/grpc/rpc_util.go:561 +0x4d
google.golang.org/grpc.(*serverStream).RecvMsg(0xc000a820b0, 0x10952e0, 0xc000514dc0, 0x0, 0x0)
	/src/vendor/google.golang.org/grpc/stream.go:746 +0x122
github.com/moby/buildkit/session/grpchijack.(*conn).Read(0xc00017f180, 0xc000b6c000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
	/src/session/grpchijack/dial.go:68 +0x1d8
bufio.(*Reader).Read(0xc00045f980, 0xc00039ce38, 0x9, 0x9, 0xc0006c0000, 0x7f8edde6e008, 0x0)
	/usr/local/go/src/bufio/bufio.go:223 +0x23e
io.ReadAtLeast(0x1254220, 0xc00045f980, 0xc00039ce38, 0x9, 0x9, 0x9, 0x82e5a5, 0xc000562eac, 0xc000061e40)
	/usr/local/go/src/io/io.go:310 +0x88
io.ReadFull(...)
	/usr/local/go/src/io/io.go:329
golang.org/x/net/http2.readFrameHeader(0xc00039ce38, 0x9, 0x9, 0x1254220, 0xc00045f980, 0x0, 0xc000000000, 0x1f38b7a8457, 0x1c7b7c0)
	/src/vendor/golang.org/x/net/http2/frame.go:237 +0x88
golang.org/x/net/http2.(*Framer).ReadFrame(0xc00039ce00, 0xc000562ea0, 0xc000562ea0, 0x0, 0x0)
	/src/vendor/golang.org/x/net/http2/frame.go:492 +0xa1
google.golang.org/grpc/transport.(*http2Client).reader(0xc000298480)
	/src/vendor/google.golang.org/grpc/transport/http2_client.go:1123 +0x116
created by google.golang.org/grpc/transport.newHTTP2Client
	/src/vendor/google.golang.org/grpc/transport/http2_client.go:265 +0xb92

goroutine 59864 [IO wait]:
internal/poll.runtime_pollWait(0x7f8ed9bfd888, 0x72, 0xffffffffffffffff)
	/usr/local/go/src/runtime/netpoll.go:182 +0x56
internal/poll.(*pollDesc).wait(0xc0000f4518, 0x72, 0xb00, 0xb65, 0xffffffffffffffff)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:87 +0x9b
internal/poll.(*pollDesc).waitRead(...)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc0000f4500, 0xc0001d4400, 0xb65, 0xb65, 0x0, 0x0, 0x0)
	/usr/local/go/src/internal/poll/fd_unix.go:169 +0x19b
net.(*netFD).Read(0xc0000f4500, 0xc0001d4400, 0xb65, 0xb65, 0x203000, 0x0, 0xb58)
	/usr/local/go/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc000796150, 0xc0001d4400, 0xb65, 0xb65, 0x0, 0x0, 0x0)
	/usr/local/go/src/net/net.go:177 +0x69
crypto/tls.(*atLeastReader).Read(0xc0014008a0, 0xc0001d4400, 0xb65, 0xb65, 0x2e, 0x12544e0, 0xc000256a30)
	/usr/local/go/src/crypto/tls/conn.go:761 +0x60
bytes.(*Buffer).ReadFrom(0xc000dea258, 0x12543c0, 0xc0014008a0, 0x40a135, 0xfb8560, 0x10c1260)
	/usr/local/go/src/bytes/buffer.go:207 +0xbd
crypto/tls.(*Conn).readFromUntil(0xc000dea000, 0x1255960, 0xc000796150, 0x5, 0xc000796150, 0x11)
	/usr/local/go/src/crypto/tls/conn.go:783 +0xf8
crypto/tls.(*Conn).readRecordOrCCS(0xc000dea000, 0x1139600, 0xc000dea138, 0x0)
	/usr/local/go/src/crypto/tls/conn.go:590 +0x125
crypto/tls.(*Conn).readRecord(...)
	/usr/local/go/src/crypto/tls/conn.go:558
crypto/tls.(*Conn).Read(0xc000dea000, 0xc000474000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
	/usr/local/go/src/crypto/tls/conn.go:1236 +0x137
bufio.(*Reader).Read(0xc000d86b40, 0xc0004883b8, 0x9, 0x9, 0xc0006c0000, 0x7f8edde6e6d0, 0x0)
	/usr/local/go/src/bufio/bufio.go:223 +0x23e
io.ReadAtLeast(0x1254220, 0xc000d86b40, 0xc0004883b8, 0x9, 0x9, 0x9, 0xbf2d3c3ed04c18b8, 0x1f38b7d8266, 0x1c7b7c0)
	/usr/local/go/src/io/io.go:310 +0x88
io.ReadFull(...)
	/usr/local/go/src/io/io.go:329
golang.org/x/net/http2.readFrameHeader(0xc0004883b8, 0x9, 0x9, 0x1254220, 0xc000d86b40, 0x0, 0x0, 0xc0004917c0, 0x7070e0910100402)
	/src/vendor/golang.org/x/net/http2/frame.go:237 +0x88
golang.org/x/net/http2.(*Framer).ReadFrame(0xc000488380, 0xc0002e4720, 0xc0002e4720, 0x0, 0x0)
	/src/vendor/golang.org/x/net/http2/frame.go:492 +0xa1
google.golang.org/grpc/transport.(*http2Server).HandleStreams(0xc000132600, 0xc000a25290, 0x11388c8)
	/src/vendor/google.golang.org/grpc/transport/http2_server.go:426 +0x7c
google.golang.org/grpc.(*Server).serveStreams(0xc000160700, 0x1287b20, 0xc000132600)
	/src/vendor/google.golang.org/grpc/server.go:676 +0xdd
google.golang.org/grpc.(*Server).handleRawConn.func2()
	/src/vendor/google.golang.org/grpc/server.go:631 +0x3c
google.golang.org/grpc.(*Server).handleRawConn.func3(0xc001fe99e0, 0xc000160700, 0x7f8ed7ba5290, 0xc000132600)
	/src/vendor/google.golang.org/grpc/server.go:639 +0x27
created by google.golang.org/grpc.(*Server).handleRawConn
	/src/vendor/google.golang.org/grpc/server.go:638 +0x5e5

goroutine 59894 [sync.Cond.Wait, 4 minutes]:
runtime.goparkunlock(...)
	/usr/local/go/src/runtime/proc.go:307
sync.runtime_notifyListWait(0xc00063cad0, 0xc000000004)
	/usr/local/go/src/runtime/sema.go:510 +0xf9
sync.(*Cond).Wait(0xc00063cac0)
	/usr/local/go/src/sync/cond.go:56 +0x9e
github.com/moby/buildkit/util/progress.(*progressReader).Read(0xc000a25620, 0x1276060, 0xc0000380a8, 0x0, 0x0, 0x0, 0x0, 0x0)
	/src/util/progress/progress.go:125 +0x10b
github.com/moby/buildkit/util/progress.(*MultiReader).handle(0xc000a25740, 0xc0005c2120, 0xc000a25740)
	/src/util/progress/multireader.go:56 +0x118
created by github.com/moby/buildkit/util/progress.(*MultiReader).Reader
	/src/util/progress/multireader.go:47 +0x1ea

goroutine 59892 [chan receive, 4 minutes]:
github.com/moby/buildkit/util/progress.pipe.func1(0x1276020, 0xc00063ce00, 0xc0005c2030)
	/src/util/progress/progress.go:165 +0x48
created by github.com/moby/buildkit/util/progress.pipe
	/src/util/progress/progress.go:164 +0x131

goroutine 59854 [chan receive, 4 minutes]:
github.com/moby/buildkit/session.(*Manager).handleConn(0xc0003d4680, 0x1276020, 0xc000b16c80, 0x1285120, 0xc00017f180, 0xc000a2dda0, 0x0, 0x0)
	/src/session/manager.go:144 +0x491
github.com/moby/buildkit/session.(*Manager).HandleConn(0xc0003d4680, 0x1276020, 0xc000b16b40, 0x1285120, 0xc00017f180, 0xc000a2dda0, 0x0, 0x0)
	/src/session/manager.go:97 +0x75
github.com/moby/buildkit/control.(*Controller).Session(0xc00031e880, 0x1284dc0, 0xc0003fc2a0, 0x0, 0x0)
	/src/control/control.go:350 +0x199
github.com/moby/buildkit/api/services/control._Control_Session_Handler(0x1052900, 0xc00031e880, 0x127dda0, 0xc0014075a0, 0x10a3ca0, 0x1c9eb40)
	/src/api/services/control/control.pb.go:1391 +0xad
github.com/grpc-ecosystem/grpc-opentracing/go/otgrpc.OpenTracingStreamServerInterceptor.func1(0x1052900, 0xc00031e880, 0x127e160, 0xc000a820b0, 0xc001407540, 0x1138010, 0x0, 0x0)
	/src/vendor/github.com/grpc-ecosystem/grpc-opentracing/go/otgrpc/server.go:114 +0x365
google.golang.org/grpc.(*Server).processStreamingRPC(0xc000160700, 0x1287b20, 0xc000132600, 0xc00065c1e0, 0xc000418a20, 0x1c2eb60, 0x0, 0x0, 0x0)
	/src/vendor/google.golang.org/grpc/server.go:1167 +0x423
google.golang.org/grpc.(*Server).handleStream(0xc000160700, 0x1287b20, 0xc000132600, 0xc00065c1e0, 0x0)
	/src/vendor/google.golang.org/grpc/server.go:1253 +0x124e
google.golang.org/grpc.(*Server).serveStreams.func1.1(0xc0010fcce0, 0xc000160700, 0x1287b20, 0xc000132600, 0xc00065c1e0)
	/src/vendor/google.golang.org/grpc/server.go:680 +0x9f
created by google.golang.org/grpc.(*Server).serveStreams.func1
	/src/vendor/google.golang.org/grpc/server.go:678 +0xa1

rax    0xca
rbx    0x1c7c5a0
rcx    0x45ea13
rdx    0x0
rdi    0x1c7c6e8
rsi    0x80
rbp    0x7ffe46c22d48
rsp    0x7ffe46c22d00
r8     0x0
r9     0x0
r10    0x0
r11    0x286
r12    0x1
r13    0xc000084b40
r14    0xc000084ba0
r15    0x0
rip    0x45ea11
rflags 0x286
cs     0x33
fs     0x0
gs     0x0

msg555 · 2019-05-09T20:03:55Z

#2 DONE 0.1s

#1 resolve image config for docker.io/docker/dockerfile:experimental
#1 DONE 0.1s

#3 docker-image://docker.io/docker/dockerfile:experimental@sha256:9022e9111...
#3 resolve docker.io/docker/dockerfile:experimental@sha256:9022e911101f01b2854c7a4b2c77f524b998891941da55208e71c0335e6e82c3 done
#3 CACHED

is the client output I get prior to this happening

msg555 · 2019-05-10T02:07:52Z

Looking at the go routines it appeared that the build was stalled on a runc execution. With @tonistiigi help we saw that it was the dockerfile-frontend that appeared to be hanging. Sent a SIGQUIT to it and got this output on the buildkitd server

SIGQUIT: quit
PC=0x45a371 m=0 sigcode=0

goroutine 0 [idle]:
runtime.futex(0x11d36c8, 0x80, 0x0, 0x0, 0xc000000000, 0x7ffdcf8b6200, 0x0, 0x0, 0x7ffdcf8b6220, 0x40a2e1, ...)
	/usr/local/go/src/runtime/sys_linux_amd64.s:535 +0x21
runtime.futexsleep(0x11d36c8, 0x7ffd00000000, 0xffffffffffffffff)
	/usr/local/go/src/runtime/os_linux.go:46 +0x4b
runtime.notesleep(0x11d36c8)
	/usr/local/go/src/runtime/lock_futex.go:151 +0xa1
runtime.stoplockedm()
	/usr/local/go/src/runtime/proc.go:2076 +0x8c
runtime.schedule()
	/usr/local/go/src/runtime/proc.go:2477 +0x3ba
runtime.park_m(0xc000001380)
	/usr/local/go/src/runtime/proc.go:2605 +0xa1
runtime.mcall(0x0)
	/usr/local/go/src/runtime/asm_amd64.s:299 +0x5b

goroutine 1 [select]:
google.golang.org/grpc/transport.(*Stream).waitOnHeader(0xc000356000, 0xbfa440, 0xc0001bfb48)
	/src/vendor/google.golang.org/grpc/transport/transport.go:222 +0xcf
google.golang.org/grpc/transport.(*Stream).RecvCompress(...)
	/src/vendor/google.golang.org/grpc/transport/transport.go:233
google.golang.org/grpc.(*csAttempt).recvMsg(0xc000324340, 0xb97ee0, 0xc000316150, 0x0, 0x0)
	/src/vendor/google.golang.org/grpc/stream.go:515 +0x61e
google.golang.org/grpc.(*clientStream).RecvMsg(...)
	/src/vendor/google.golang.org/grpc/stream.go:395
google.golang.org/grpc.invoke(0xcc1500, 0xc0002fe140, 0xbe2a8d, 0x29, 0xb86600, 0xc000308400, 0xb97ee0, 0xc000316150, 0xc00030c000, 0x0, ...)
	/src/vendor/google.golang.org/grpc/call.go:83 +0x195
google.golang.org/grpc.(*ClientConn).Invoke(0xc00030c000, 0xcc1500, 0xc0002fe140, 0xbe2a8d, 0x29, 0xb86600, 0xc000308400, 0xb97ee0, 0xc000316150, 0x0, ...)
	/src/vendor/google.golang.org/grpc/call.go:37 +0x1b4
github.com/moby/buildkit/frontend/gateway/pb.(*lLBBridgeClient).Ping(0xc00031a000, 0xcc1500, 0xc0002fe140, 0xc000308400, 0x0, 0x0, 0x0, 0xc0001bfd78, 0xa54a2d, 0xc00031c000)
	/src/frontend/gateway/pb/gateway.pb.go:1262 +0xd2
github.com/moby/buildkit/frontend/gateway/grpcclient.New(0xcc1500, 0xc0002fe140, 0xc000304090, 0xc00003a014, 0x19, 0xc00003a049, 0x8, 0xcc6b20, 0xc00031a000, 0xc0003100c0, ...)
	/src/frontend/gateway/grpcclient/client.go:31 +0x8e
github.com/moby/buildkit/frontend/gateway/grpcclient.current(0x46da92, 0x11ef500, 0x1, 0x11ef508)
	/src/frontend/gateway/grpcclient/client.go:66 +0x213
github.com/moby/buildkit/frontend/gateway/grpcclient.RunFromEnvironment(0xcc1500, 0xc0002fe000, 0xbfa0c8, 0x0, 0x0)
	/src/frontend/gateway/grpcclient/client.go:81 +0x26
main.main()
	/src/frontend/dockerfile/cmd/dockerfile-frontend/main.go:24 +0x288

goroutine 5 [syscall]:
os/signal.signal_recv(0x0)
	/usr/local/go/src/runtime/sigqueue.go:139 +0x9c
os/signal.loop()
	/usr/local/go/src/os/signal/signal_unix.go:23 +0x22
created by os/signal.init.0
	/usr/local/go/src/os/signal/signal_unix.go:29 +0x41

goroutine 17 [chan receive]:
github.com/moby/buildkit/util/appcontext.Context.func1.1(0xc0001fd140, 0xc000300000, 0xc0002fc000)
	/src/util/appcontext/appcontext.go:30 +0x38
created by github.com/moby/buildkit/util/appcontext.Context.func1
	/src/util/appcontext/appcontext.go:28 +0xff

goroutine 18 [select]:
google.golang.org/grpc.(*ccResolverWrapper).watcher(0xc000304060)
	/src/vendor/google.golang.org/grpc/resolver_conn_wrapper.go:109 +0x13f
created by google.golang.org/grpc.(*ccResolverWrapper).start
	/src/vendor/google.golang.org/grpc/resolver_conn_wrapper.go:95 +0x3f

goroutine 19 [select]:
google.golang.org/grpc.(*ccBalancerWrapper).watcher(0xc0002fe240)
	/src/vendor/google.golang.org/grpc/balancer_conn_wrappers.go:122 +0x110
created by google.golang.org/grpc.newCCBalancerWrapper
	/src/vendor/google.golang.org/grpc/balancer_conn_wrappers.go:113 +0x13e

goroutine 20 [select]:
google.golang.org/grpc.(*addrConn).transportMonitor(0xc00032e000)
	/src/vendor/google.golang.org/grpc/clientconn.go:1373 +0x1c4
google.golang.org/grpc.(*addrConn).connect.func1(0xc00032e000)
	/src/vendor/google.golang.org/grpc/clientconn.go:949 +0x1d9
created by google.golang.org/grpc.(*addrConn).connect
	/src/vendor/google.golang.org/grpc/clientconn.go:940 +0xe1

goroutine 22 [syscall]:
syscall.Syscall(0x0, 0x0, 0xc000334000, 0x8000, 0x42ac5f, 0x8, 0xc0002926c0)
	/usr/local/go/src/syscall/asm_linux_amd64.s:18 +0x5
syscall.read(0x0, 0xc000334000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
	/usr/local/go/src/syscall/zsyscall_linux_amd64.go:732 +0x5a
syscall.Read(...)
	/usr/local/go/src/syscall/syscall_unix.go:172
internal/poll.(*FD).Read(0xc000074060, 0xc000334000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
	/usr/local/go/src/internal/poll/fd_unix.go:165 +0x131
os.(*File).read(...)
	/usr/local/go/src/os/file_unix.go:263
os.(*File).Read(0xc00000e010, 0xc000334000, 0x8000, 0x8000, 0x0, 0x20, 0x203000)
	/usr/local/go/src/os/file.go:108 +0x70
bufio.(*Reader).Read(0xc00030a5a0, 0xc00034c038, 0x9, 0x9, 0x20, 0x18, 0xc0002d2e00)
	/usr/local/go/src/bufio/bufio.go:223 +0x23e
io.ReadAtLeast(0xcae360, 0xc00030a5a0, 0xc00034c038, 0x9, 0x9, 0x9, 0xc0001f1620, 0xc00004f670, 0x927cf6)
	/usr/local/go/src/io/io.go:310 +0x88
io.ReadFull(...)
	/usr/local/go/src/io/io.go:329
golang.org/x/net/http2.readFrameHeader(0xc00034c038, 0x9, 0x9, 0xcae360, 0xc00030a5a0, 0x0, 0x0, 0xc0001f1600, 0xc00004f601)
	/src/vendor/golang.org/x/net/http2/frame.go:237 +0x88
golang.org/x/net/http2.(*Framer).ReadFrame(0xc00034c000, 0xc0001f9410, 0xc0001f9401, 0x0, 0x0)
	/src/vendor/golang.org/x/net/http2/frame.go:492 +0xa1
google.golang.org/grpc/transport.(*http2Client).reader(0xc000322480)
	/src/vendor/google.golang.org/grpc/transport/http2_client.go:1123 +0x116
created by google.golang.org/grpc/transport.newHTTP2Client
	/src/vendor/google.golang.org/grpc/transport/http2_client.go:265 +0xb92

goroutine 23 [select]:
google.golang.org/grpc/transport.(*controlBuffer).get(0xc0002fe340, 0x1, 0x0, 0x0, 0x0, 0x0)
	/src/vendor/google.golang.org/grpc/transport/controlbuf.go:289 +0x104
google.golang.org/grpc/transport.(*loopyWriter).run(0xc00030a720)
	/src/vendor/google.golang.org/grpc/transport/controlbuf.go:374 +0x1ca
google.golang.org/grpc/transport.newHTTP2Client.func3(0xc000322480)
	/src/vendor/google.golang.org/grpc/transport/http2_client.go:298 +0x77
created by google.golang.org/grpc/transport.newHTTP2Client
	/src/vendor/google.golang.org/grpc/transport/http2_client.go:296 +0xcf2

rax    0xca
rbx    0x11d3580
rcx    0x45a373
rdx    0x0
rdi    0x11d36c8
rsi    0x80
rbp    0x7ffdcf8b61e8
rsp    0x7ffdcf8b61a0
r8     0x0
r9     0x0
r10    0x0
r11    0x286
r12    0xc
r13    0xff
r14    0xc9bbcc
r15    0x0
rip    0x45a371
rflags 0x286
cs     0x33
fs     0x0
gs     0x0
time="2019-05-10T02:03:17Z" level=error msg="/moby.buildkit.v1.Control/Solve returned error: exit code: 2\ngithub.com/moby/buildkit/executor/runcexecutor.(*runcExecutor).Exec\n\t/src/executor/runcexecutor/executor.go:285\ngithub.com/moby/buildkit/worker/base.(*Worker).Exec\n\t/src/worker/base/worker.go:235\ngithub.com/moby/buildkit/solver/llbsolver.(*llbBridge).Exec\n\t/src/solver/llbsolver/bridge.go:141\ngithub.com/moby/buildkit/frontend/gateway.(*gatewayFrontend).Solve\n\t/src/frontend/gateway/gateway.go:210\ngithub.com/moby/buildkit/solver/llbsolver.(*llbBridge).Solve\n\t/src/solver/llbsolver/bridge.go:110\ngithub.com/moby/buildkit/solver/llbsolver.(*Solver).Solve\n\t/src/solver/llbsolver/solver.go:133\ngithub.com/moby/buildkit/control.(*Controller).Solve\n\t/src/control/control.go:266\ngithub.com/moby/buildkit/api/services/control._Control_Solve_Handler.func1\n\t/src/api/services/control/control.pb.go:1364\ngithub.com/grpc-ecosystem/grpc-opentracing/go/otgrpc.OpenTracingServerInterceptor.func1\n\t/src/vendor/github.com/grpc-ecosystem/grpc-opentracing/go/otgrpc/server.go:57\nmain.unaryInterceptor.func1\n\t/src/cmd/buildkitd/main.go:509\ngithub.com/moby/buildkit/api/services/control._Control_Solve_Handler\n\t/src/api/services/control/control.pb.go:1366\ngoogle.golang.org/grpc.(*Server).processUnaryRPC\n\t/src/vendor/google.golang.org/grpc/server.go:1011\ngoogle.golang.org/grpc.(*Server).handleStream\n\t/src/vendor/google.golang.org/grpc/server.go:1249\ngoogle.golang.org/grpc.(*Server).serveStreams.func1.1\n\t/src/vendor/google.golang.org/grpc/server.go:680\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1337"

tonistiigi · 2019-05-12T05:47:53Z

created #1003 to mitigate the hang part

grpc does not return errors from ServeConn but it should write a message to buildkitd logs (at least most of them). Please check if there is a specific log message there when this issue appears for you.

msg555 · 2019-05-13T04:04:38Z

Building buildkitd from master now I get the message

time="2019-05-13T03:58:50Z" level=error msg="failed to kill runc cja1eam7owyapvj7esmg2mxod: buildkit-runc did not terminate sucessfully: container \"cja1eam7owyapvj7esmg2mxod\" does not exist\n"
time="2019-05-13T03:58:50Z" level=error msg="failed to kill runc cja1eam7owyapvj7esmg2mxod: buildkit-runc did not terminate sucessfully: container \"cja1eam7owyapvj7esmg2mxod\" does not exist\n"
time="2019-05-13T03:58:50Z" level=error msg="/moby.buildkit.v1.Control/Solve returned error: frontend grpc server closed unexpectedly\ngithub.com/moby/buildkit/frontend/gateway.(*gatewayFrontend).Solve\n\t/src/frontend/gateway/gateway.go:214\ngithub.com/moby/buildkit/solver/llbsolver.(*llbBridge).Solve\n\t/src/solver/llbsolver/bridge.go:110\ngithub.com/moby/buildkit/solver/llbsolver.(*Solver).Solve\n\t/src/solver/llbsolver/solver.go:133\ngithub.com/moby/buildkit/control.(*Controller).Solve\n\t/src/control/control.go:266\ngithub.com/moby/buildkit/api/services/control._Control_Solve_Handler.func1\n\t/src/api/services/control/control.pb.go:1364\ngithub.com/grpc-ecosystem/grpc-opentracing/go/otgrpc.OpenTracingServerInterceptor.func1\n\t/src/vendor/github.com/grpc-ecosystem/grpc-opentracing/go/otgrpc/server.go:57\nmain.unaryInterceptor.func1\n\t/src/cmd/buildkitd/main.go:509\ngithub.com/moby/buildkit/api/services/control._Control_Solve_Handler\n\t/src/api/services/control/control.pb.go:1366\ngoogle.golang.org/grpc.(*Server).processUnaryRPC\n\t/src/vendor/google.golang.org/grpc/server.go:1011\ngoogle.golang.org/grpc.(*Server).handleStream\n\t/src/vendor/google.golang.org/grpc/server.go:1249\ngoogle.golang.org/grpc.(*Server).serveStreams.func1.1\n\t/src/vendor/google.golang.org/grpc/server.go:680\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1337"

The embedded error message is expanded below for convenience.

/moby.buildkit.v1.Control/Solve returned error: frontend grpc server closed unexpectedly
github.com/moby/buildkit/frontend/gateway.(*gatewayFrontend).Solve
	/src/frontend/gateway/gateway.go:214
github.com/moby/buildkit/solver/llbsolver.(*llbBridge).Solve
	/src/solver/llbsolver/bridge.go:110
github.com/moby/buildkit/solver/llbsolver.(*Solver).Solve
	/src/solver/llbsolver/solver.go:133
github.com/moby/buildkit/control.(*Controller).Solve
	/src/control/control.go:266
github.com/moby/buildkit/api/services/control._Control_Solve_Handler.func1
	/src/api/services/control/control.pb.go:1364
github.com/grpc-ecosystem/grpc-opentracing/go/otgrpc.OpenTracingServerInterceptor.func1
	/src/vendor/github.com/grpc-ecosystem/grpc-opentracing/go/otgrpc/server.go:57
main.unaryInterceptor.func1
	/src/cmd/buildkitd/main.go:509
github.com/moby/buildkit/api/services/control._Control_Solve_Handler
	/src/api/services/control/control.pb.go:1366
google.golang.org/grpc.(*Server).processUnaryRPC
	/src/vendor/google.golang.org/grpc/server.go:1011
google.golang.org/grpc.(*Server).handleStream
	/src/vendor/google.golang.org/grpc/server.go:1249
google.golang.org/grpc.(*Server).serveStreams.func1.1
	/src/vendor/google.golang.org/grpc/server.go:680
runtime.goexit
	/usr/local/go/src/runtime/asm_amd64.s:1337

tonistiigi · 2019-05-13T04:08:08Z

Please post more logs before this message. And enable debug mode if you haven't already.

msg555 · 2019-05-13T04:13:35Z

Trying that. Without debug mode on the next message was just from startup. Might end up being tomorrow before I have it though.

tonistiigi · 2019-05-13T04:17:51Z

@msg555 It seems some grpc logs may not show up. Please also set GODEBUG=http2debug=1 before starting the daemon when you try again. GODEBUG=http2debug=2 should provide even more logs (probably too much for this).

msg555 · 2019-05-13T05:37:29Z

Let me know if you want more log data, going further back gets into the previous build which perhaps could be relevant.

time="2019-05-13T05:19:54Z" level=debug msg=resolved desc.digest="sha256:9022e911101f01b2854c7a4b2c77f524b998891941da55208e71c0335e6e82c3"
time="2019-05-13T05:19:54Z" level=debug msg=fetch digest="sha256:9022e911101f01b2854c7a4b2c77f524b998891941da55208e71c0335e6e82c3" mediatype=application/vnd.docker.distribution.manifest.list.v2+json size=2029
time="2019-05-13T05:19:54Z" level=debug msg=fetch digest="sha256:962337bd2c94ed20329caf3201963fd81d2892544c4502f1b237f5063e0fe27f" mediatype=application/vnd.docker.distribution.manifest.v2+json size=527
time="2019-05-13T05:19:54Z" level=debug msg=fetch digest="sha256:8bf79a4e725097175c47f89c7b1efffe300bb4fd4e9ac45eea9daba66f81e904" mediatype=application/vnd.docker.container.image.v1+json size=897
time="2019-05-13T05:19:54Z" level=debug msg="load cache for docker-image://docker.io/docker/dockerfile:experimental@sha256:9022e911101f01b2854c7a4b2c77f524b998891941da55208e71c0335e6e82c3 with plxvlc1970pyb51d4yklj3sjj::sha256:d469e8fdff2f0208fb8c23b518279d9d73e5efc9e10be65e71942fc72c38e31a"
time="2019-05-13T05:19:54Z" level=debug msg="serving grpc connection"
2019/05/13 05:19:54 http2: server connection from localhost on 0xc00018a410
time="2019-05-13T05:19:57Z" level=debug msg="removed snapshot" key="buildkit/209/sha256:b5f43d7b0c435f15fd592fc09c45f45c3a30c191a349f4d6ebf387500a812a8a" snapshotter=overlayfs
time="2019-05-13T05:19:57Z" level=debug msg="removed snapshot" key="buildkit/609/sha256:6b001b22a82d460c3db1ce46160420ebefc7aa99809fac5509adc6f2ce36f797" snapshotter=overlayfs
time="2019-05-13T05:19:57Z" level=debug msg="removed snapshot" key="buildkit/612/sha256:1f543bc69d1f84e92fa16312073d5e1e57bd5a4b6eaaa765fa19783db0a7c28a" snapshotter=overlayfs
time="2019-05-13T05:19:57Z" level=debug msg="removed snapshot" key=buildkit/676/zawqwjciz8gwwqur8ev86bft4 snapshotter=overlayfs
time="2019-05-13T05:19:57Z" level=debug msg="removed snapshot" key=buildkit/685/nzz3yx3q65d0yunew11xke21c snapshotter=overlayfs
time="2019-05-13T05:19:57Z" level=debug msg="removed snapshot" key="buildkit/600/sha256:a4883c6087dc6f7231bc36000e939b5ff0ff00b44045175ae55a325a3027dcb2" snapshotter=overlayfs
time="2019-05-13T05:19:57Z" level=debug msg="removed snapshot" key="buildkit/318/sha256:15a9db3cf2d2198816be4fa6c40d2d3b24b32da46c1d4472553db30fba58374d" snapshotter=overlayfs
time="2019-05-13T05:19:57Z" level=debug msg="removed snapshot" key="buildkit/630/sha256:f5f6c2b683ecab2a3958d332f989b2b01b7d28977206babc1d62fabdd86b7352" snapshotter=overlayfs
time="2019-05-13T05:19:57Z" level=debug msg="removed snapshot" key="buildkit/505/sha256:aef1232e79eeed5b0d68e2674004ee7cbf96917389a8c3b13df07ec3d37f3434" snapshotter=overlayfs
time="2019-05-13T05:19:57Z" level=debug msg="removed snapshot" key="buildkit/526/sha256:aefb871400c79f6c9dd93fed55e37346f2a90c42a86a08f2766843491ff30d81" snapshotter=overlayfs
time="2019-05-13T05:19:58Z" level=debug msg="removed snapshot" key="buildkit/539/sha256:201f7aee1111b94d4ce223171691f906be0cc8a23197b8b505352590d97602a4" snapshotter=overlayfs
time="2019-05-13T05:19:58Z" level=debug msg="removed snapshot" key="buildkit/633/sha256:db5cb1547833c2bc9a08afdfa8ee6c392174386c4d0d1011fccd682c8a7ae183" snapshotter=overlayfs
time="2019-05-13T05:19:58Z" level=debug msg="removed snapshot" key="buildkit/265/sha256:70845e1aa88df26903781aec460174f045d5b407edea029d3aa66ff92700d6af" snapshotter=overlayfs
time="2019-05-13T05:19:58Z" level=debug msg="removed snapshot" key="buildkit/615/sha256:d9311c60e42874fd8c0687d441909c7fcc80506a694230b90845ed1ca7aa821a" snapshotter=overlayfs
time="2019-05-13T05:19:58Z" level=debug msg="removed snapshot" key="buildkit/568/sha256:a6bef1dc9af4439dc40d6a2bc20fd20c617bb939b2983064de6b1c5610eba20b" snapshotter=overlayfs
time="2019-05-13T05:19:58Z" level=debug msg="removed snapshot" key="buildkit/491/sha256:775f9a46067274ff7af48851bfae08f390e348de70901426ec0123035ffddcb1" snapshotter=overlayfs
2019/05/13 05:20:04 http2: server: error reading preface from client localhost: timeout waiting for client preface
time="2019-05-13T05:20:09Z" level=debug msg="removed snapshot" key="buildkit/477/sha256:b63e3c6e877a54de024ef4ad41a77978c7fa03d0c721e4cbe4f93ac7cbeb9bc3" snapshotter=overlayfs
time="2019-05-13T05:20:09Z" level=debug msg="snapshot garbage collected" d=14.741400214s snapshotter=overlayfs
time="2019-05-13T05:20:09Z" level=debug msg="> creating x0kgzwgcw48cnln7pqxdggxbs [/bin/dockerfile-frontend]"
time="2019-05-13T05:20:09Z" level=error msg="failed to kill runc x0kgzwgcw48cnln7pqxdggxbs: buildkit-runc did not terminate sucessfully: container \"x0kgzwgcw48cnln7pqxdggxbs\" does not exist\n"
time="2019-05-13T05:20:09Z" level=error msg="failed to kill runc x0kgzwgcw48cnln7pqxdggxbs: buildkit-runc did not terminate sucessfully: container \"x0kgzwgcw48cnln7pqxdggxbs\" does not exist\n"
time="2019-05-13T05:20:09Z" level=error msg="/moby.buildkit.v1.Control/Solve returned error: frontend grpc server closed unexpectedly\ngithub.com/moby/buildkit/frontend/gateway.(*gatewayFrontend).Solve\n\t/src/frontend/gateway/gateway.go:214\ngithub.com/moby/buildkit/solver/llbsolver.(*llbBridge).Solve\n\t/src/solver/llbsolver/bridge.go:110\ngithub.com/moby/buildkit/solver/llbsolver.(*Solver).Solve\n\t/src/solver/llbsolver/solver.go:133\ngithub.com/moby/buildkit/control.(*Controller).Solve\n\t/src/control/control.go:266\ngithub.com/moby/buildkit/api/services/control._Control_Solve_Handler.func1\n\t/src/api/services/control/control.pb.go:1364\ngithub.com/grpc-ecosystem/grpc-opentracing/go/otgrpc.OpenTracingServerInterceptor.func1\n\t/src/vendor/github.com/grpc-ecosystem/grpc-opentracing/go/otgrpc/server.go:57\nmain.unaryInterceptor.func1\n\t/src/cmd/buildkitd/main.go:509\ngithub.com/moby/buildkit/api/services/control._Control_Solve_Handler\n\t/src/api/services/control/control.pb.go:1366\ngoogle.golang.org/grpc.(*Server).processUnaryRPC\n\t/src/vendor/google.golang.org/grpc/server.go:1011\ngoogle.golang.org/grpc.(*Server).handleStream\n\t/src/vendor/google.golang.org/grpc/server.go:1249\ngoogle.golang.org/grpc.(*Server).serveStreams.func1.1\n\t/src/vendor/google.golang.org/grpc/server.go:680\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1337"
time="2019-05-13T05:20:09Z" level=debug msg="session finished: <nil>"
time="2019-05-13T05:20:10Z" level=debug msg="remove snapshot" key=vmqqm6t4np42heurvlh5sg0z6 snapshotter=overlayfs
time="2019-05-13T05:20:10Z" level=debug msg="remove content" key="sha256:a34ac361f0c5081f604e5c1cefb0667acbed804479b7d16f68c3954d0a46a167"
time="2019-05-13T05:20:10Z" level=debug msg="remove content" key="sha256:ad5519ddd71a2644c8ed3bd929b0b78086dc32affb7a49a05c017c22094cd0d5"
time="2019-05-13T05:20:10Z" level=debug msg="schedule snapshotter cleanup" snapshotter=overlayfs
time="2019-05-13T05:20:10Z" level=debug msg="schedule content cleanup"
time="2019-05-13T05:20:10Z" level=debug msg="removed content" digest="sha256:a34ac361f0c5081f604e5c1cefb0667acbed804479b7d16f68c3954d0a46a167"
time="2019-05-13T05:20:10Z" level=debug msg="removed content" digest="sha256:ad5519ddd71a2644c8ed3bd929b0b78086dc32affb7a49a05c017c22094cd0d5"
time="2019-05-13T05:20:10Z" level=debug msg="content garbage collected" d=7.392934ms
time="2019-05-13T05:20:10Z" level=debug msg="removed snapshot" key=buildkit/686/vmqqm6t4np42heurvlh5sg0z6 snapshotter=overlayfs
time="2019-05-13T05:20:10Z" level=debug msg="snapshot garbage collected" d=10.919562ms snapshotter=overlayfs
2019/05/13 05:21:24 http2: Transport closing idle conn 0xc0006d1500 (forSingleUse=false, maxStream=699)
2019/05/13 05:21:24 http2: Transport readFrame error on conn 0xc0006d1500: (*errors.errorString) EOF

tonistiigi · 2019-05-13T17:44:44Z

@msg555 Ok, that looks interesting. Do you have gc configured on this machine? Can you post the config?

msg555 · 2019-05-13T17:47:49Z

I have not set up a GC policy

tonistiigi · 2019-05-13T22:17:02Z

The issue is that there is a 10 sec timeout (seems hardcoded) on grpc for transferring first bytes. In your logs the container that starts the frontend seems to take more than 10 sec to start.

During the same time containerd gc is running. Note that this isn't technically the buildkit gc, buildkit marks objects as unused and then on background containerd gc actually deletes them. In the logs you can see snapshot garbage collected" d=14.741400214s snapshotter=overlayfs. I'm not quite sure what is actually being deleted, unless you ran prune these might be unused snapshots from a previous build. And not sure why it takes so much time to delete them as usually unused snapshots should be close to empty. Maybe this is related to a specific build? Don't see gc cleaned up logs either for buildkit gc.

From these logs my initial thought was that containerd gc that takes 14.7 holds some lock that prevents frontend container from starting. But it looks like it is always called on background and from @dmcgowan the db should not be locked for that time. I tried to add some sleeps in the remove path to confirm this and it did seem that even if I made gc artificially slow it didn't stop creating new containers.

There is probably a way to delay starting the server until container has come up, but I'm still not quite sure why you are hitting this.

It could be that the gc running in parallel is a coincidence in this log. Maybe you can try to get a second one for comparison. It could be that the machine is just so constrained that it reaches the timeout.

Another thing is that although you provide a stacktrace, this is from the time where the timeout had already been reached and all the slow processes had been completed. If you can it would be nice to get a stacktrace from the time when this error was generated. Could you make a change that prints the stack at https://github.com/moby/buildkit/pull/1003/files#diff-35ffd957a392f33dd60921b3168d8fd9R312 line. In case there is a lock that is preventing frontend from starting it should be visible from that trace.

func dumpStack() {
	var (
		buf       []byte
		stackSize int
	)
	bufferLen := 16384
	for stackSize == len(buf) {
		buf = make([]byte, bufferLen)
		stackSize = runtime.Stack(buf, true)
		bufferLen *= 2
	}
	fmt.Printf("%s\n", buf[:stackSize])
}

@dmcgowan

msg555 · 2019-05-14T19:40:24Z

@tonistiigi I've attached the last several seconds of logs from three different failures. They each have different error messages generated but I wouldn't be surprised if they all have the same underlying cause. frontend_grpc_closed_1.log is specifically the same kind of failure we've been talking about so far where the grpc frontend connection times out at the start of a build.

frontend_grpc_closed_1.log
unknown_desc_not_found_1.log
extract_layer_1.log

msg555 · 2019-05-15T20:16:56Z

Tested with #1007 and getting similar issues as before. I basically kept running my build until I hit the familiar frontend grpc closed error. These are all the errors I hit and traces in the meantime.
frontend_grpc_closed_2.log
exit_code1_1.log
exit_code1_2.log
exit_code1_3.log
not_found_2.log
not_found_3.log
not_found_4.log
not_found_5.log
not_found_6.log
not_found_7.log
not_found_8.log

msg555 · 2019-05-16T01:30:14Z

The exit code 1 error seems to be addressed after updating the runc version (I didn't run into it after 20+ failures where it seemed to be a decent proportion of the failures before). I've attached an archive of some additional buildkitd traces that I did run into, however.

buildkitd-logs.zip

tonistiigi · 2019-05-20T21:33:21Z

@msg555 The logs posted for the frontend issue in the last comment seem to be lacking the stactrace debug when the issue appears like it was in #991 (comment)

msg555 · 2019-05-21T20:35:11Z

Ran some more tests on the branch https://github.com/msg555/buildkit/commits/test_052019 (master + async_remove + extra logging) and have two more logs. The incidence rate seems to be way down on this branch (maybe from the async_remove?) but it still does occasionally fail. Here are the two logs I extracted from 30 builds.

frontend_grpc_closed.log
mount_callback_failed.log

I'll start testing on #1013

msg555 · 2019-05-23T15:14:03Z

Failure rate was looking pretty low when running on https://github.com/msg555/buildkit/commits/test_052119.

However, after adding --oci-worker-gc-keepstorage 20000 to buildkitd's invocation I have 100% build failure. Attached is an archive of the traces. All of the faliures produced a message like error: failed to solve: rpc error: code = Unknown desc = not found on the client.
buildkitd-traces.zip

tonistiigi added this to the v0.5.2 milestone May 12, 2019

tonistiigi mentioned this issue May 12, 2019

gateway: handle grpc server errors #1003

Merged

tonistiigi mentioned this issue May 14, 2019

buildkitd: use asyncremove on overlay #1007

Merged

This was referenced May 15, 2019

could not ensure we are a cloned binary: Device or resource busy opencontainers/runc#2059

Closed

update runc to v1.0.0-rc8 #1010

Merged

msg555 mentioned this issue May 19, 2019

Failed to get reader from content store #992

Closed

tonistiigi mentioned this issue May 21, 2019

pull: fix content blobs deletion on pull race #1013

Merged

msg555 mentioned this issue May 21, 2019

Build stalls after idle connection closed #1014

Closed

tonistiigi mentioned this issue Jun 10, 2019

worker: fix gc race on fromremote #1044

Merged

AkihiroSuda closed this as completed in #1044 Jun 26, 2019

xkszltl mentioned this issue Jul 22, 2019

Build hangs on step "load build definition from Dockerfile" #1088

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Build stalls early #991

Build stalls early #991

msg555 commented May 8, 2019

msg555 commented May 8, 2019

msg555 commented May 9, 2019

msg555 commented May 9, 2019 •

edited

Loading

msg555 commented May 10, 2019

tonistiigi commented May 12, 2019

msg555 commented May 13, 2019

tonistiigi commented May 13, 2019

msg555 commented May 13, 2019

tonistiigi commented May 13, 2019

msg555 commented May 13, 2019

tonistiigi commented May 13, 2019

msg555 commented May 13, 2019

tonistiigi commented May 13, 2019

msg555 commented May 14, 2019

msg555 commented May 15, 2019

msg555 commented May 16, 2019

tonistiigi commented May 20, 2019

msg555 commented May 21, 2019

msg555 commented May 23, 2019 •

edited

Loading

Build stalls early #991

Build stalls early #991

Comments

msg555 commented May 8, 2019

msg555 commented May 8, 2019

msg555 commented May 9, 2019

msg555 commented May 9, 2019 • edited Loading

msg555 commented May 10, 2019

tonistiigi commented May 12, 2019

msg555 commented May 13, 2019

tonistiigi commented May 13, 2019

msg555 commented May 13, 2019

tonistiigi commented May 13, 2019

msg555 commented May 13, 2019

tonistiigi commented May 13, 2019

msg555 commented May 13, 2019

tonistiigi commented May 13, 2019

msg555 commented May 14, 2019

msg555 commented May 15, 2019

msg555 commented May 16, 2019

tonistiigi commented May 20, 2019

msg555 commented May 21, 2019

msg555 commented May 23, 2019 • edited Loading

msg555 commented May 9, 2019 •

edited

Loading

msg555 commented May 23, 2019 •

edited

Loading