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: unexpected return pc for os/signal.loop called from 0x0 #35005

Open
mega-bran opened this issue Oct 19, 2019 · 4 comments

Comments

@mega-bran
Copy link

@mega-bran mega-bran commented Oct 19, 2019

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

go version go1.13 linux/amd64

Does this issue reproduce with the latest release?

Yes

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

go env Output
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/root/.cache/go-build"
GOENV="/root/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/local/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"
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 -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build556391308=/tmp/go-build -gno-record-gcc-switches"

What did you do?

I'm building a module which is supposed to work with another program (https://github.com/heroiclabs/nakama). The program runs fine as long as I don't load the module and crashes with below error while loading the module.
The program even starts loading the module (I know it because I can see the logs from module) but crashes instantly.

What did you expect to see?

Not crash

What did you see instead?

{"level":"warn","ts":"2019-10-19T06:03:25.728Z","msg":"WARNING: insecure default parameter value, change this for production!","param":"console.signing_key"}
{"level":"info","ts":"2019-10-19T06:03:25.730Z","msg":"Nakama starting"}
{"level":"info","ts":"2019-10-19T06:03:25.731Z","msg":"Node","name":"nakama-node-1","version":"2.7.0+d5e0b5bb","runtime":"go1.13","cpu":1,"proc":1}
{"level":"info","ts":"2019-10-19T06:03:25.731Z","msg":"Data directory","path":"/nakama/data"}
{"level":"info","ts":"2019-10-19T06:03:25.732Z","msg":"Database connections","dsns":["nakama:nakama@10.89.192.3:5432/nakama"]}
{"level":"debug","ts":"2019-10-19T06:03:25.733Z","msg":"Complete database connection URL","raw_url":"postgresql://nakama:nakama@10.89.192.3:5432/nakama?sslmode=disable"}
{"level":"info","ts":"2019-10-19T06:03:25.744Z","msg":"Database information","version":"PostgreSQL 11.5 on x86_64-pc-linux-gnu, compiled by gcc (Debian 7.3.0-5) 7.3.0, 64-bit"}
{"level":"info","ts":"2019-10-19T06:03:25.750Z","msg":"Initializing leaderboard rank cache"}
{"level":"info","ts":"2019-10-19T06:03:25.751Z","msg":"Leaderboard rank cache initialization completed successfully","cached":[],"skipped":[]}
{"level":"info","ts":"2019-10-19T06:03:25.752Z","msg":"Initialising runtime","path":"/nakama/data/modules"}
{"level":"info","ts":"2019-10-19T06:03:25.752Z","msg":"Initialising runtime event queue processor"}
{"level":"info","ts":"2019-10-19T06:03:25.753Z","msg":"Runtime event queue processor started","size":8192,"workers":8}
{"level":"info","ts":"2019-10-19T06:03:25.754Z","msg":"Initialising Go runtime provider","path":"/nakama/data/modules"}
{"level":"info","ts":"2019-10-19T06:03:25.794Z","msg":"My module"}
{"level":"info","ts":"2019-10-19T06:03:25.795Z","msg":"env variables%!(EXTRA map[string]string=map[env:staging])"}
runtime: unexpected return pc for os/signal.loop called from 0x0
stack: frame={sp:0xc00005e7c0, fp:0xc00005e7e0} stack=[0xc00005e000,0xc00005e800)
000000c00005e6c0:  0000000000000000  0000000000000000
000000c00005e6d0:  0000000000000000  0000000000a04046 <runtime.futexsleep+70>
000000c00005e6e0:  00000000029a7c00  0000000000000080
000000c00005e6f0:  0000000000000000  0000000000000000
000000c00005e700:  0000000000000000  000000c00005e768
000000c00005e710:  000000c000001980  0000000000000000
000000c00005e720:  000000c00005e758  00000000009e3286 <runtime.notetsleep_internal+134>
000000c00005e730:  00000000029a7c00  0000000000000000
000000c00005e740:  0000000000000000  0000000000000000
000000c00005e750:  0000000000000000  0000000000000000
000000c00005e760:  0000000000000000  0000000000000000
000000c00005e770:  0000000000000000  0000000000000000
000000c00005e780:  0000000000000000  0000000000000000
000000c00005e790:  0000000000a1d57c <os/signal.signal_recv+156>  00000000029a7c00
000000c00005e7a0:  ffffffffffffffff  0000000000000000
000000c00005e7b0:  000000c00005e7d0  0000000000d0f0e2 <os/signal.loop+34>
000000c00005e7c0: <0000000000000000  0000000000000000
000000c00005e7d0:  0000000000000000 !0000000000000000
000000c00005e7e0: >0000000000000000  0000000000000000
000000c00005e7f0:  0000000000000000  0000000000000000
fatal error: unknown caller pc

runtime stack:
runtime.throw(0x1ac7719, 0x11)
        runtime/panic.go:774 +0x72
runtime.gentraceback(0xffffffffffffffff, 0xffffffffffffffff, 0x0, 0xc000001980, 0x0, 0x0, 0x7fffffff, 0x7ffdfd5a6340, 0x0, 0x0, ...)
        runtime/traceback.go:273 +0x19e5
runtime.scanstack(0xc000001980, 0xc00004b270)
        runtime/mgcmark.go:711 +0x15d
runtime.scang(0xc000001980, 0xc00004b270)
        runtime/proc.go:886 +0x1e3
runtime.markroot.func1()
        runtime/mgcmark.go:221 +0x6d
runtime.markroot(0xc00004b270, 0xb)
        runtime/mgcmark.go:202 +0x2f3
runtime.gcDrain(0xc00004b270, 0xb)
        runtime/mgcmark.go:915 +0x110
runtime.gcBgMarkWorker.func2()
        runtime/mgc.go:1925 +0x185
runtime.systemstack(0xa332a4)
        runtime/asm_amd64.s:370 +0x66
runtime.mstart()
        runtime/proc.go:1146

goroutine 9 [GC worker (idle)]:
runtime.systemstack_switch()
        runtime/asm_amd64.s:330 fp=0xc00005ff60 sp=0xc00005ff58 pc=0xa333a0
runtime.gcBgMarkWorker(0xc00004a000)
        runtime/mgc.go:1891 +0x1bd fp=0xc00005ffd8 sp=0xc00005ff60 pc=0x9f472d
runtime.goexit()
        runtime/asm_amd64.s:1357 +0x1 fp=0xc00005ffe0 sp=0xc00005ffd8 pc=0xa35471
created by runtime.gcBgMarkStartWorkers
        runtime/mgc.go:1785 +0x77

goroutine 1 [runnable]:
bytes.makeSlice(0x902, 0x0, 0x0, 0x0)
        bytes/buffer.go:229 +0x77
bytes.(*Buffer).grow(0xc0007321e0, 0x902, 0x1a0c740)
        bytes/buffer.go:142 +0x15b
bytes.(*Buffer).Write(0xc0007321e0, 0xc000723500, 0x902, 0x903, 0x18dce00, 0x1a0c740, 0x1)
        bytes/buffer.go:172 +0xdd
bytes.(*Reader).WriteTo(0xc0007321b0, 0x1fbc5e0, 0xc0007321e0, 0x7f097c77fba0, 0xc0007321b0, 0x7f097b294601)
        bytes/reader.go:144 +0xa1
io.copyBuffer(0x1fbc5e0, 0xc0007321e0, 0x1fbc620, 0xc0007321b0, 0x0, 0x0, 0x0, 0xc02f80ac1f, 0x2f80ac1f7b65d9bc, 0xc0003ba898)
        io/io.go:384 +0x34f
io.Copy(...)
        io/io.go:364
github.com/gobuffalo/packd.(*virtualFile).write(0xc000725880, 0x1a0c740, 0xc0007321b0, 0x0, 0xc0003ba8f8, 0x7f097b294d9a)
        github.com/gobuffalo/packd@v0.3.0/file.go:76 +0x2e5
github.com/gobuffalo/packd.buildFile(0xc0003867e0, 0x13, 0x1fbc620, 0xc0007321b0, 0xc000620d80, 0xc000732150, 0xc000723500)
        github.com/gobuffalo/packd@v0.3.0/file.go:121 +0xef
github.com/gobuffalo/packd.NewFile(...)
        github.com/gobuffalo/packd@v0.3.0/file.go:97
github.com/gobuffalo/packr.Box.find(0x7f097ba75f64, 0x6, 0xc000398c00, 0x30, 0xc000620d80, 0xc000732150, 0xc0003867e0, 0x13, 0xc0003baa90, 0x7f097b364e66, ...)
        github.com/gobuffalo/packr@v1.30.1/box.go:160 +0x2c6
github.com/gobuffalo/packr.Box.Find(0x7f097ba75f64, 0x6, 0xc000398c00, 0x30, 0xc000620d80, 0x0, 0xc0003867e0, 0x13, 0xc0003bab50, 0x7f097b75fa00, ...)
        github.com/gobuffalo/packr@v1.30.1/box.go:108 +0x76
getmega.com/multiplay/pkg/thirdparty/google.readFile(...)
        getmega.com/multiplay@/pkg/thirdparty/google/default_application_credentials.go:15
getmega.com/multiplay/pkg/thirdparty/google.SetupDefaultCredentials(0xc000619440)
        getmega.com/multiplay@/pkg/thirdparty/google/default_application_credentials.go:22 +0x105
plugin/unnamed-979dcbb6301160304f8e5e9973563ccbab186d50.InitModule(0x1feb900, 0xc000620600, 0x20001c0, 0xc000010b20, 0xc00003e540, 0x200fe20, 0xc0005680e0, 0x20145c0, 0xc00003e6c0, 0xc0006d4380, ...)
        getmega.com/multiplay@/init_module.go:35 +0xbc
github.com/heroiclabs/nakama/v2/server.NewRuntimeProviderGo(0xc0000fd860, 0xc0000fd860, 0xc00003e540, 0x28bfb80, 0x2001fe0, 0xc0005fe1e0, 0xc000562410, 0x1ffc760, 0xc00001fd40, 0x1ff5bc0, ...)
        github.com/heroiclabs/nakama/v2@/server/runtime_go.go:1830 +0xc11
github.com/heroiclabs/nakama/v2/server.NewRuntime(0xc0000fd860, 0xc0000fd860, 0xc00003e540, 0x28bfb80, 0x2981af0, 0x2001fe0, 0xc0005fe1e0, 0xc000562410, 0x1ffc760, 0xc00001fd40, ...)
        github.com/heroiclabs/nakama/v2@/server/runtime.go:442 +0x6a8
main.main()
        main.go:130 +0x1356

goroutine 6 [syscall (scan)]:
os/signal.signal_recv(0x0)
        runtime/sigqueue.go:147 +0x9c
runtime: unexpected return pc for os/signal.loop called from 0x0
stack: frame={sp:0xc00005e7c0, fp:0xc00005e7e0} stack=[0xc00005e000,0xc00005e800)
000000c00005e6c0:  0000000000000000  0000000000000000
000000c00005e6d0:  0000000000000000  0000000000a04046 <runtime.futexsleep+70>
000000c00005e6e0:  00000000029a7c00  0000000000000080
000000c00005e6f0:  0000000000000000  0000000000000000
000000c00005e700:  0000000000000000  000000c00005e768
000000c00005e710:  000000c000001980  0000000000000000
000000c00005e720:  000000c00005e758  00000000009e3286 <runtime.notetsleep_internal+134>
000000c00005e730:  00000000029a7c00  0000000000000000
000000c00005e740:  0000000000000000  0000000000000000
000000c00005e750:  0000000000000000  0000000000000000
000000c00005e760:  0000000000000000  0000000000000000
000000c00005e770:  0000000000000000  0000000000000000
000000c00005e780:  0000000000000000  0000000000000000
000000c00005e790:  0000000000a1d57c <os/signal.signal_recv+156>  00000000029a7c00
000000c00005e7a0:  ffffffffffffffff  0000000000000000
000000c00005e7b0:  000000c00005e7d0  0000000000d0f0e2 <os/signal.loop+34>
000000c00005e7c0: <0000000000000000  0000000000000000
000000c00005e7d0:  0000000000000000 !0000000000000000
000000c00005e7e0: >0000000000000000  0000000000000000
000000c00005e7f0:  0000000000000000  0000000000000000
os/signal.loop()
        os/signal/signal_unix.go:23 +0x22
created by os/signal.init.0
        os/signal/signal_unix.go:29 +0x41

goroutine 8 [select]:
go.opencensus.io/stats/view.(*worker).start(0xc00003ca50)
        go.opencensus.io@v0.22.1/stats/view/worker.go:154 +0x100
created by go.opencensus.io/stats/view.init.0
        go.opencensus.io@v0.22.1/stats/view/worker.go:32 +0x57

goroutine 30 [select]:
github.com/heroiclabs/nakama/v2/server.NewRuntimeEventQueue.func1(0xc0006204e0)
        github.com/heroiclabs/nakama/v2@/server/runtime_event.go:43 +0xda
created by github.com/heroiclabs/nakama/v2/server.NewRuntimeEventQueue
        github.com/heroiclabs/nakama/v2@/server/runtime_event.go:41 +0x100
goroutine 31 [select]:
github.com/heroiclabs/nakama/v2/server.NewRuntimeEventQueue.func1(0xc0006204e0)
        github.com/heroiclabs/nakama/v2@/server/runtime_event.go:43 +0xda
created by github.com/heroiclabs/nakama/v2/server.NewRuntimeEventQueue
        github.com/heroiclabs/nakama/v2@/server/runtime_event.go:41 +0x100
goroutine 25 [select]:
database/sql.(*DB).connectionCleaner(0xc00003e540, 0x34630b8a000)
        database/sql/sql.go:950 +0x370
created by database/sql.(*DB).startCleanerLocked
        database/sql/sql.go:937 +0xa7
goroutine 29 [select]:
github.com/heroiclabs/nakama/v2/server.StartLocalTracker.func1(0xc0005dbdd0)
        github.com/heroiclabs/nakama/v2@/server/tracker.go:191 +0xeb
created by github.com/heroiclabs/nakama/v2/server.StartLocalTracker
        github.com/heroiclabs/nakama/v2@/server/tracker.go:188 +0x1cb
goroutine 15 [select]:
github.com/blevesearch/bleve/index.AnalysisWorker(0xc000396c60, 0xc000396cc0)
        github.com/blevesearch/bleve@v0.0.0-20190613153557-26d2099fa968/index/analysis.go:102 +0x102
created by github.com/blevesearch/bleve/index.NewAnalysisQueue
        github.com/blevesearch/bleve@v0.0.0-20190613153557-26d2099fa968/index/analysis.go:94 +0xc8
goroutine 16 [select]:
github.com/blevesearch/bleve/index.AnalysisWorker(0xc000396c60, 0xc000396cc0)
        github.com/blevesearch/bleve@v0.0.0-20190613153557-26d2099fa968/index/analysis.go:102 +0x102
created by github.com/blevesearch/bleve/index.NewAnalysisQueue
        github.com/blevesearch/bleve@v0.0.0-20190613153557-26d2099fa968/index/analysis.go:94 +0xc8
goroutine 18 [select]:
github.com/blevesearch/bleve/index.AnalysisWorker(0xc000396c60, 0xc000396cc0)
        github.com/blevesearch/bleve@v0.0.0-20190613153557-26d2099fa968/index/analysis.go:102 +0x102
created by github.com/blevesearch/bleve/index.NewAnalysisQueue
        github.com/blevesearch/bleve@v0.0.0-20190613153557-26d2099fa968/index/analysis.go:94 +0xc8
goroutine 19 [select]:
github.com/blevesearch/bleve/index.AnalysisWorker(0xc000396c60, 0xc000396cc0)
        github.com/blevesearch/bleve@v0.0.0-20190613153557-26d2099fa968/index/analysis.go:102 +0x102
created by github.com/blevesearch/bleve/index.NewAnalysisQueue
        github.com/blevesearch/bleve@v0.0.0-20190613153557-26d2099fa968/index/analysis.go:94 +0xc8
goroutine 22 [select]:
database/sql.(*DB).connectionOpener(0xc00003e540, 0x1feb840, 0xc000618a00)
        database/sql/sql.go:1052 +0xe8
created by database/sql.OpenDB
        database/sql/sql.go:722 +0x15d

goroutine 23 [select]:
database/sql.(*DB).connectionResetter(0xc00003e540, 0x1feb840, 0xc000618a00)
        database/sql/sql.go:1065 +0xfb
created by database/sql.OpenDB
        database/sql/sql.go:723 +0x193
goroutine 32 [select]:
github.com/heroiclabs/nakama/v2/server.NewRuntimeEventQueue.func1(0xc0006204e0)
        github.com/heroiclabs/nakama/v2@/server/runtime_event.go:43 +0xda
created by github.com/heroiclabs/nakama/v2/server.NewRuntimeEventQueue
        github.com/heroiclabs/nakama/v2@/server/runtime_event.go:41 +0x100
goroutine 33 [select]:
github.com/heroiclabs/nakama/v2/server.NewRuntimeEventQueue.func1(0xc0006204e0)
        github.com/heroiclabs/nakama/v2@/server/runtime_event.go:43 +0xda
created by github.com/heroiclabs/nakama/v2/server.NewRuntimeEventQueue
        github.com/heroiclabs/nakama/v2@/server/runtime_event.go:41 +0x100
goroutine 34 [select]:
github.com/heroiclabs/nakama/v2/server.NewRuntimeEventQueue.func1(0xc0006204e0)
        github.com/heroiclabs/nakama/v2@/server/runtime_event.go:43 +0xda
created by github.com/heroiclabs/nakama/v2/server.NewRuntimeEventQueue
        github.com/heroiclabs/nakama/v2@/server/runtime_event.go:41 +0x100
goroutine 35 [select]:
github.com/heroiclabs/nakama/v2/server.NewRuntimeEventQueue.func1(0xc0006204e0)
        github.com/heroiclabs/nakama/v2@/server/runtime_event.go:43 +0xda
created by github.com/heroiclabs/nakama/v2/server.NewRuntimeEventQueue
        github.com/heroiclabs/nakama/v2@/server/runtime_event.go:41 +0x100
goroutine 36 [select]:
github.com/heroiclabs/nakama/v2/server.NewRuntimeEventQueue.func1(0xc0006204e0)
        github.com/heroiclabs/nakama/v2@/server/runtime_event.go:43 +0xda
created by github.com/heroiclabs/nakama/v2/server.NewRuntimeEventQueue
        github.com/heroiclabs/nakama/v2@/server/runtime_event.go:41 +0x100
goroutine 37 [select]:
github.com/heroiclabs/nakama/v2/server.NewRuntimeEventQueue.func1(0xc0006204e0)
        github.com/heroiclabs/nakama/v2@/server/runtime_event.go:43 +0xda
created by github.com/heroiclabs/nakama/v2/server.NewRuntimeEventQueue
        github.com/heroiclabs/nakama/v2@/server/runtime_event.go:41 +0x100
@dmitshur

This comment has been minimized.

Copy link
Member

@dmitshur dmitshur commented Oct 21, 2019

Hello, thanks for the report.

It will be very helpful to try to create a smaller snippet that can reproduce this issue in order to find the root problem. Are you able to narrow it down further?

If not, can you share more complete steps to reproduce the problem, if possible? What commands did you run in order to get the crash?

@novabyte

This comment has been minimized.

Copy link

@novabyte novabyte commented Oct 24, 2019

@dmitshur There's more information on the Nakama issue tracker under this ticket:
heroiclabs/nakama#388

Here's what we've been able to determine with our investigation so far:

  • The problem occurs with Alpine 3.10 when a Go plugin is loaded by the binary built with Go 1.13.0+. We've not tested with earlier versions of Go because we use --trimpath to ensure that the module based builds don't get confused with their dependencies.
  • The problem does not occur under Debian-based container base images.
  • I've been able to observe the problem on Ubuntu and Windows as the host environments running the latest version of Docker engine.
  • I cannot reproduce the issue at all on macOS (10.14.5 Mojave).
  • The issue does not occur with an earlier release of Alpine (3.9.4).

The current theory is that there's an issue with how shared objects are loaded by the Go runtime in containers that use the most recent version of musl libc within Alpine Linux. Though only when the host OS is Windows or Ubuntu (only Linux distro I tried). 🤷‍♂

Does this provide more context? I don't know whether the Go team considers musl libc a no-go with the Go runtime. Please advise on what the recommended course of action is for Go projects that are packaged with Alpine Linux or other non-GNU libc core libraries.

@joshgarnett

This comment has been minimized.

Copy link

@joshgarnett joshgarnett commented Oct 24, 2019

@dmitshur I just put together a simple project that reproduces this at https://github.com/joshgarnett/nakama-2.7.0-go-1.13-crash

@dmitshur

This comment has been minimized.

Copy link
Member

@dmitshur dmitshur commented Oct 25, 2019

Thanks for doing that.

/cc @aclements @randall77

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
4 participants
You can’t perform that action at this time.