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: segfault in sync.Pool when using a shared runtime #24640

Open
otavio opened this Issue Apr 2, 2018 · 21 comments

Comments

Projects
None yet
9 participants
@otavio
Copy link

commented Apr 2, 2018

QPlease answer these questions before submitting your issue. Thanks!

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

1.10

Does this issue reproduce with the latest release?

Yes.

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

Reproducible on ARM and x86_64 under Linux

What did you do?

https://bugzilla.yoctoproject.org/show_bug.cgi?id=12631#c10

@bcmills

This comment has been minimized.

Copy link
Member

commented Apr 2, 2018

The original post from the linked bug report:

The following code:

package main

import (
	"net/http"

	"github.com/sirupsen/logrus"
)

func main() {
	logrus.Info("starting")

	client := &http.Client{}
	r, _ := http.NewRequest("GET", "https://google.com", nil)

	client.Do(r)

	logrus.Info("started")
}

Works when using 1.9.4 and fails with 1.10. However, when using Go from our host to cross build it for same target, it works fine.

@bcmills

This comment has been minimized.

Copy link
Member

commented Apr 2, 2018

On that bug report, Matt Madison (perhaps @madisongh?) notes:

I can reproduce this now on an ARMv7 target, provided the image also includes the ca-certificates package. Also, you have to wait until /dev/random has enough entropy.

I can also reproduce this natively by building go 1.10 from source, building a shared runtime with go install -linkshared -buildmode=shared std, and doing a go get -linkshared github.com/gustavosbarreto/go-crazy. So it's not ARM-specific.

It's a panic due to a segfault, always appearing to happen around a sync.Pool request in logrus's Entry.log function. However, it only seems to happen if the https request is also getting processed in other goroutines. Panic tracebacks always point to the logrus package as the running thread, sometimes with and sometimes without other goroutines being active.

It does seem to happen only when the program is linked against shared runtime, not when linked statically.

Definitely an upstream issue, just not 100% sure that it's really in the Go runtime, or if logrus is misusing the sync package.

And later:

I haven't found an upstream bug report that matches this exactly, and it's hard to know whether the root cause is in the go shared runtime support or in the logrus package.

Some possibly related issues:
#23199
sirupsen/logrus#740
https://bugzilla.redhat.com/show_bug.cgi?format=multiple&id=1561619

@bcmills bcmills changed the title Go 1.10.1 generates invalid code when using a shared runtime runtime: segfault in sync.Pool when using a shared runtime Apr 2, 2018

@bcmills bcmills added this to the Go1.11 milestone Apr 2, 2018

@bcmills

This comment has been minimized.

Copy link
Member

commented Apr 2, 2018

(@aclements, @randall77: any ideas? The initial bugreport theorizes that the compiler may be generating invalid code.)

@otavio

This comment has been minimized.

Copy link
Author

commented Apr 2, 2018

Shouldn't this be tagged for 1.10.2 release? It is a regression after all.

@bcmills

This comment has been minimized.

Copy link
Member

commented Apr 2, 2018

That probably depends on what the root cause turns out to be and how invasive the fix is. But sure, we can tag it for 1.10.2 until we figure that out.

@bcmills bcmills modified the milestones: Go1.11, Go1.10.2 Apr 2, 2018

@bradfitz

This comment has been minimized.

Copy link
Member

commented Apr 4, 2018

Where is the stack trace?

It should be in this bug. I also don't see it in the linked bugzilla bug.

@madisongh

This comment has been minimized.

Copy link

commented Apr 4, 2018

Stack traces from a few sample runs:

Example 1:

panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x2a pc=0x7f45d2d49428]

goroutine 1 [running]:
github.com/gustavosbarreto/go-crazy/vendor/github.com/sirupsen/logrus.Entry.log(0xc4203be230, 0xc4201f2180, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xc400000004, ...)
	/sources/logrus-test/src/github.com/gustavosbarreto/go-crazy/vendor/github.com/sirupsen/logrus/entry.go:99 +0x28c
github.com/gustavosbarreto/go-crazy/vendor/github.com/sirupsen/logrus.(*Entry).Info(0xc4201ba0a0, 0xc420375f58, 0x1, 0x1)
	/sources/logrus-test/src/github.com/gustavosbarreto/go-crazy/vendor/github.com/sirupsen/logrus/entry.go:153 +0xac
github.com/gustavosbarreto/go-crazy/vendor/github.com/sirupsen/logrus.(*Logger).Info(0xc4203be230, 0xc420375f58, 0x1, 0x1)
	/sources/logrus-test/src/github.com/gustavosbarreto/go-crazy/vendor/github.com/sirupsen/logrus/logger.go:189 +0x70
github.com/gustavosbarreto/go-crazy/vendor/github.com/sirupsen/logrus.Info(0xc420375f58, 0x1, 0x1)
	/sources/logrus-test/src/github.com/gustavosbarreto/go-crazy/vendor/github.com/sirupsen/logrus/exported.go:87 +0x50
main.main()
	/sources/logrus-test/src/github.com/gustavosbarreto/go-crazy/main.go:18 +0x10b

Example 2:

runtime: nameOff 0x5 base 0xc4201face0 not in ranges:
	types 0x7fccccb23980 etypes 0x7fccccf5e6e0
	types 0x616040 etypes 0x61b1c8
fatal error: runtime: name offset base pointer out of range

goroutine 1 [running]:
runtime.throw(0x7fcccc8a1815, 0x2e)
	/sources/go-1.10/go/src/runtime/panic.go:619 +0x83 fp=0xc420375cb0 sp=0xc420375c90 pc=0x7fcccc269fe3
runtime.resolveNameOff(0xc4201face0, 0xc400000005, 0x41012f)
	/sources/go-1.10/go/src/runtime/type.go:193 +0x229 fp=0xc420375d18 sp=0xc420375cb0 pc=0x7fcccc298949
runtime.(*_type).nameOff(0xc4201face0, 0xc400000005, 0x7fcccc2c3764)
	/sources/go-1.10/go/src/runtime/type.go:199 +0x35 fp=0xc420375d40 sp=0xc420375d18 pc=0x7fcccc298a35
runtime.(*_type).string(0xc4201face0, 0x7fcccc2c34d6, 0xc42042c240)
	/sources/go-1.10/go/src/runtime/type.go:46 +0x38 fp=0xc420375d68 sp=0xc420375d40 pc=0x7fcccc298438
runtime.panicdottypeE(0xc4201face0, 0x7fccccf0b040, 0x619260)
	/sources/go-1.10/go/src/runtime/iface.go:242 +0x187 fp=0xc420375dc0 sp=0xc420375d68 pc=0x7fcccc248347
github.com/gustavosbarreto/go-crazy/vendor/github.com/sirupsen/logrus.Entry.log(0xc4203be230, 0xc4201de720, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xc400000004, ...)
	/sources/logrus-test/src/github.com/gustavosbarreto/go-crazy/vendor/github.com/sirupsen/logrus/entry.go:99 +0x28c fp=0xc420375e30 sp=0xc420375dc0 pc=0x40e5cc
github.com/gustavosbarreto/go-crazy/vendor/github.com/sirupsen/logrus.(*Entry).Info(0xc4201d74f0, 0xc420375f58, 0x1, 0x1)
	/sources/logrus-test/src/github.com/gustavosbarreto/go-crazy/vendor/github.com/sirupsen/logrus/entry.go:153 +0xac fp=0xc420375ea0 sp=0xc420375e30 pc=0x40ebac
github.com/gustavosbarreto/go-crazy/vendor/github.com/sirupsen/logrus.(*Logger).Info(0xc4203be230, 0xc420375f58, 0x1, 0x1)
	/sources/logrus-test/src/github.com/gustavosbarreto/go-crazy/vendor/github.com/sirupsen/logrus/logger.go:189 +0x70 fp=0xc420375ed8 sp=0xc420375ea0 pc=0x410cb0
github.com/gustavosbarreto/go-crazy/vendor/github.com/sirupsen/logrus.Info(0xc420375f58, 0x1, 0x1)
	/sources/logrus-test/src/github.com/gustavosbarreto/go-crazy/vendor/github.com/sirupsen/logrus/exported.go:87 +0x50 fp=0xc420375f08 sp=0xc420375ed8 pc=0x40fdd0
main.main()
	/sources/logrus-test/src/github.com/gustavosbarreto/go-crazy/main.go:18 +0x10b fp=0xc420375f88 sp=0xc420375f08 pc=0x41450b
runtime.main()
	/sources/go-1.10/go/src/runtime/proc.go:198 +0x24f fp=0xc420375fe0 sp=0xc420375f88 pc=0x7fcccc26c78f
runtime.goexit()
	/sources/go-1.10/go/src/runtime/asm_amd64.s:2361 +0x1 fp=0xc420375fe8 sp=0xc420375fe0 pc=0x7fcccc2a20e1

goroutine 13 [IO wait]:
internal/poll.runtime_pollWait(0x7fccc879fe30, 0x72, 0xc4204f18b8)
	/sources/go-1.10/go/src/runtime/netpoll.go:173 +0x59
internal/poll.(*pollDesc).wait(0xc4204e8198, 0x72, 0xffffffffffffff00, 0x61af80, 0x7fcccd2983c0)
	/sources/go-1.10/go/src/internal/poll/fd_poll_runtime.go:85 +0xa1
internal/poll.(*pollDesc).waitRead(0xc4204e8198, 0xc4200fc000, 0x800, 0x800)
	/sources/go-1.10/go/src/internal/poll/fd_poll_runtime.go:90 +0x3f
internal/poll.(*FD).Read(0xc4204e8180, 0xc4200fc000, 0x800, 0x800, 0x0, 0x0, 0x0)
	/sources/go-1.10/go/src/internal/poll/fd_unix.go:157 +0x17f
net.(*netFD).Read(0xc4204e8180, 0xc4200fc000, 0x800, 0x800, 0xc420382170, 0x7fcccce93b20, 0xc4205bd3c0)
	/sources/go-1.10/go/src/net/fd_unix.go:202 +0x51
net.(*conn).Read(0xc4204b6018, 0xc4200fc000, 0x800, 0x800, 0x0, 0x0, 0x0)
	/sources/go-1.10/go/src/net/net.go:176 +0x6c
crypto/tls.(*block).readFromUntil(0xc4204b2270, 0x7fccc86db000, 0xc4204b6018, 0x5, 0xc4204b6018, 0xc4204b2270)
	/sources/go-1.10/go/src/crypto/tls/conn.go:493 +0x98
crypto/tls.(*Conn).readRecord(0xc420382000, 0x7fccccf3e317, 0xc420382120, 0x7fcccde2dee0)
	/sources/go-1.10/go/src/crypto/tls/conn.go:595 +0xe2
crypto/tls.(*Conn).Read(0xc420382000, 0xc420612000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
	/sources/go-1.10/go/src/crypto/tls/conn.go:1156 +0x102
bufio.(*Reader).Read(0xc4203330e0, 0xc4203c3a64, 0xe45, 0xe45, 0x564, 0x0, 0x0)
	/sources/go-1.10/go/src/bufio/bufio.go:216 +0x250
io.ReadAtLeast(0x7fccccf462e0, 0xc4203330e0, 0xc4203c3500, 0x13a9, 0x13a9, 0x13a9, 0x13a9, 0xc42058e8c0, 0xc42058e910)
	/sources/go-1.10/go/src/io/io.go:309 +0x88
io.ReadFull(0x7fccccf462e0, 0xc4203330e0, 0xc4203c3500, 0x13a9, 0x13a9, 0x13a900080001, 0x7fcc00000001, 0x0)
	/sources/go-1.10/go/src/io/io.go:327 +0x5a
net/http.(*http2Framer).ReadFrame(0xc42058e8c0, 0xc4201de630, 0x0, 0x0, 0x0)
	/sources/go-1.10/go/src/net/http/h2_bundle.go:1783 +0x161
net/http.(*http2clientConnReadLoop).run(0xc4204f1fb8, 0x7fccccf33558, 0xc42045a7b8)
	/sources/go-1.10/go/src/net/http/h2_bundle.go:8028 +0x92
net/http.(*http2ClientConn).readLoop(0xc42015b180)
	/sources/go-1.10/go/src/net/http/h2_bundle.go:7956 +0x6a
created by net/http.(*http2Transport).newClientConn
	/sources/go-1.10/go/src/net/http/h2_bundle.go:7143 +0x699

Example 3:

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

goroutine 1 [running]:
runtime.throw(0x7f0e5b7ec7c8, 0x5)
	/sources/go-1.10/go/src/runtime/panic.go:619 +0x83 fp=0xc420375cf0 sp=0xc420375cd0 pc=0x7f0e5b1d6fe3
runtime.sigpanic()
	/sources/go-1.10/go/src/runtime/signal_unix.go:395 +0x215 fp=0xc420375d40 sp=0xc420375cf0 pc=0x7f0e5b1f0f55
runtime.(*_type).string(0x46524553552d4e54, 0x7f0e5b2304d6, 0xc42042c240)
	/sources/go-1.10/go/src/runtime/type.go:46 +0x28 fp=0xc420375d68 sp=0xc420375d40 pc=0x7f0e5b205428
runtime.panicdottypeE(0x46524553552d4e54, 0x7f0e5be78040, 0x619260)
	/sources/go-1.10/go/src/runtime/iface.go:242 +0x187 fp=0xc420375dc0 sp=0xc420375d68 pc=0x7f0e5b1b5347
github.com/gustavosbarreto/go-crazy/vendor/github.com/sirupsen/logrus.Entry.log(0xc4203be230, 0xc420045470, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xc400000004, ...)
	/sources/logrus-test/src/github.com/gustavosbarreto/go-crazy/vendor/github.com/sirupsen/logrus/entry.go:99 +0x28c fp=0xc420375e30 sp=0xc420375dc0 pc=0x40e5cc
github.com/gustavosbarreto/go-crazy/vendor/github.com/sirupsen/logrus.(*Entry).Info(0xc420591360, 0xc420375f58, 0x1, 0x1)
	/sources/logrus-test/src/github.com/gustavosbarreto/go-crazy/vendor/github.com/sirupsen/logrus/entry.go:153 +0xac fp=0xc420375ea0 sp=0xc420375e30 pc=0x40ebac
github.com/gustavosbarreto/go-crazy/vendor/github.com/sirupsen/logrus.(*Logger).Info(0xc4203be230, 0xc420375f58, 0x1, 0x1)
	/sources/logrus-test/src/github.com/gustavosbarreto/go-crazy/vendor/github.com/sirupsen/logrus/logger.go:189 +0x70 fp=0xc420375ed8 sp=0xc420375ea0 pc=0x410cb0
github.com/gustavosbarreto/go-crazy/vendor/github.com/sirupsen/logrus.Info(0xc420375f58, 0x1, 0x1)
	/sources/logrus-test/src/github.com/gustavosbarreto/go-crazy/vendor/github.com/sirupsen/logrus/exported.go:87 +0x50 fp=0xc420375f08 sp=0xc420375ed8 pc=0x40fdd0
main.main()
	/sources/logrus-test/src/github.com/gustavosbarreto/go-crazy/main.go:18 +0x10b fp=0xc420375f88 sp=0xc420375f08 pc=0x41450b
runtime.main()
	/sources/go-1.10/go/src/runtime/proc.go:198 +0x24f fp=0xc420375fe0 sp=0xc420375f88 pc=0x7f0e5b1d978f
runtime.goexit()
	/sources/go-1.10/go/src/runtime/asm_amd64.s:2361 +0x1 fp=0xc420375fe8 sp=0xc420375fe0 pc=0x7f0e5b20f0e1

goroutine 15 [IO wait]:
internal/poll.runtime_pollWait(0x7f0e5870ef00, 0x72, 0xc4201eb8b8)
	/sources/go-1.10/go/src/runtime/netpoll.go:173 +0x59
internal/poll.(*pollDesc).wait(0xc4204d6118, 0x72, 0xffffffffffffff00, 0x61af80, 0x7f0e5c2053c0)
	/sources/go-1.10/go/src/internal/poll/fd_poll_runtime.go:85 +0xa1
internal/poll.(*pollDesc).waitRead(0xc4204d6118, 0xc4201aa000, 0x800, 0x800)
	/sources/go-1.10/go/src/internal/poll/fd_poll_runtime.go:90 +0x3f
internal/poll.(*FD).Read(0xc4204d6100, 0xc4201aa000, 0x800, 0x800, 0x0, 0x0, 0x0)
	/sources/go-1.10/go/src/internal/poll/fd_unix.go:157 +0x17f
net.(*netFD).Read(0xc4204d6100, 0xc4201aa000, 0x800, 0x800, 0xc420446170, 0x7f0e5be00b20, 0xc420103060)
	/sources/go-1.10/go/src/net/fd_unix.go:202 +0x51
net.(*conn).Read(0xc4203bc018, 0xc4201aa000, 0x800, 0x800, 0x0, 0x0, 0x0)
	/sources/go-1.10/go/src/net/net.go:176 +0x6c
crypto/tls.(*block).readFromUntil(0xc42044c090, 0x7f0e5870f0d8, 0xc4203bc018, 0x5, 0xc4203bc018, 0xc42044c090)
	/sources/go-1.10/go/src/crypto/tls/conn.go:493 +0x98
crypto/tls.(*Conn).readRecord(0xc420446000, 0x7f0e5beab317, 0xc420446120, 0x7f0e5cd9aee0)
	/sources/go-1.10/go/src/crypto/tls/conn.go:595 +0xe2
crypto/tls.(*Conn).Read(0xc420446000, 0xc420194000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
	/sources/go-1.10/go/src/crypto/tls/conn.go:1156 +0x102
bufio.(*Reader).Read(0xc4203e1320, 0xc4203c3a64, 0xdc2, 0xdc2, 0x564, 0x0, 0x0)
	/sources/go-1.10/go/src/bufio/bufio.go:216 +0x250
io.ReadAtLeast(0x7f0e5beb32e0, 0xc4203e1320, 0xc4203c3500, 0x1326, 0x1326, 0x1326, 0x1326, 0xc4201c1b20, 0xc4201c1b70)
	/sources/go-1.10/go/src/io/io.go:309 +0x88
io.ReadFull(0x7f0e5beb32e0, 0xc4203e1320, 0xc4203c3500, 0x1326, 0x1326, 0x132600080001, 0x7f0e00000001, 0x0)
	/sources/go-1.10/go/src/io/io.go:327 +0x5a
net/http.(*http2Framer).ReadFrame(0xc4201c1b20, 0xc420045380, 0x0, 0x0, 0x0)
	/sources/go-1.10/go/src/net/http/h2_bundle.go:1783 +0x161
net/http.(*http2clientConnReadLoop).run(0xc4201ebfb8, 0x7f0e5bea0558, 0xc4204597b8)
	/sources/go-1.10/go/src/net/http/h2_bundle.go:8028 +0x92
net/http.(*http2ClientConn).readLoop(0xc42011b6c0)
	/sources/go-1.10/go/src/net/http/h2_bundle.go:7956 +0x6a
created by net/http.(*http2Transport).newClientConn
	/sources/go-1.10/go/src/net/http/h2_bundle.go:7143 +0x699
@otavio

This comment has been minimized.

Copy link
Author

commented Apr 11, 2018

Any idea how we can debug this?

@ianlancetaylor

This comment has been minimized.

Copy link
Contributor

commented Apr 11, 2018

Have you run the program under the race detector?

@ianlancetaylor

This comment has been minimized.

Copy link
Contributor

commented Apr 11, 2018

In stack trace 3 above it's clear that a value that should be a pointer to a type structure is actually a string. So memory is being corrupted somewhere. The first guesses are always the race detector or invalid use of cgo.

halstead pushed a commit to openembedded/openembedded-core that referenced this issue Apr 13, 2018

distro: default: Change Go default version to 1.9
For the time being, there is a serious bug[1] in Go 1.10 when it comes to
use the shared runtime support which cases problems in multiple projects.

 1. golang/go#24640

It is still unclear if the problem arises from a bug inside the
compiler itself or it makes a real problem more visible. Either way,
using 1.10 as default seems to be a risk so we are changing back to
1.9 for now.

Refs: [YOCTO: #12631]

Signed-off-by: Otavio Salvador <otavio@ossystems.com.br>
Signed-off-by: Ross Burton <ross.burton@intel.com>

gc-plp pushed a commit to gc-plp/poky that referenced this issue Apr 13, 2018

distro: default: Change Go default version to 1.9
For the time being, there is a serious bug[1] in Go 1.10 when it comes to
use the shared runtime support which cases problems in multiple projects.

 1. golang/go#24640

It is still unclear if the problem arises from a bug inside the
compiler itself or it makes a real problem more visible. Either way,
using 1.10 as default seems to be a risk so we are changing back to
1.9 for now.

Refs: [YOCTO: #12631]

(From OE-Core rev: c5b5055d2dc04317a7a64c150046a6435a6805c2)

Signed-off-by: Otavio Salvador <otavio@ossystems.com.br>
Signed-off-by: Ross Burton <ross.burton@intel.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>

jpuhlman added a commit to MontaVista-OpenSourceTechnology/poky that referenced this issue Apr 21, 2018

distro: default: Change Go default version to 1.9
Source: poky
MR: 00000
Type: Integration
Disposition: Merged from poky
ChangeID: f6d8c3f
Description:

For the time being, there is a serious bug[1] in Go 1.10 when it comes to
use the shared runtime support which cases problems in multiple projects.

 1. golang/go#24640

It is still unclear if the problem arises from a bug inside the
compiler itself or it makes a real problem more visible. Either way,
using 1.10 as default seems to be a risk so we are changing back to
1.9 for now.

Refs: [YOCTO: #12631]

(From OE-Core rev: c5b5055d2dc04317a7a64c150046a6435a6805c2)

Signed-off-by: Otavio Salvador <otavio@ossystems.com.br>
Signed-off-by: Ross Burton <ross.burton@intel.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
Signed-off-by: Jeremy Puhlman <jpuhlman@mvista.com>

jpuhlman added a commit to MontaVista-OpenSourceTechnology/poky that referenced this issue Apr 21, 2018

distro: default: Change Go default version to 1.9
Source: poky
MR: 00000
Type: Integration
Disposition: Merged from poky
ChangeID: f6d8c3f
Description:

For the time being, there is a serious bug[1] in Go 1.10 when it comes to
use the shared runtime support which cases problems in multiple projects.

 1. golang/go#24640

It is still unclear if the problem arises from a bug inside the
compiler itself or it makes a real problem more visible. Either way,
using 1.10 as default seems to be a risk so we are changing back to
1.9 for now.

Refs: [YOCTO: #12631]

(From OE-Core rev: c5b5055d2dc04317a7a64c150046a6435a6805c2)

Signed-off-by: Otavio Salvador <otavio@ossystems.com.br>
Signed-off-by: Ross Burton <ross.burton@intel.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
Signed-off-by: Jeremy Puhlman <jpuhlman@mvista.com>
@FiloSottile

This comment has been minimized.

Copy link
Member

commented Apr 24, 2018

@gopherbot please open a backport tracking issue for 1.10.

@gopherbot

This comment has been minimized.

Copy link

commented Apr 24, 2018

Backport issue(s) opened: #25037 (for 1.10).

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

@gopherbot

This comment has been minimized.

Copy link

commented Aug 10, 2018

Timed out in state WaitingForInfo. Closing.

(I am just a bot, though. Please speak up if this is a mistake or you have the requested information.)

@gopherbot gopherbot closed this Aug 10, 2018

@jasonkim

This comment has been minimized.

Copy link

commented Apr 4, 2019

This is still a problem with go 1.11.

@aclements

This comment has been minimized.

Copy link
Member

commented Apr 4, 2019

@jasonkim, we still need more information to debug this. Since it sounds like you can reproduce it, can you provide stack traces and try running under the race detector?

@otavio

This comment has been minimized.

Copy link
Author

commented Apr 5, 2019

We could only get this going disabling the dynamic linking of runtime.

@jasonkim

This comment has been minimized.

Copy link

commented Apr 8, 2019

I tried adding -race to the build/install step and got the following error.

go install: -race is only supported on linux/amd64, linux/ppc64le, freebsd/amd64, netbsd/amd64, darwin/amd64 and windows/amd64

What is there to do for this? I'm assuming since my env is an ARM based, the race detector won't work?

@ianlancetaylor

This comment has been minimized.

Copy link
Contributor

commented Apr 8, 2019

Can you try the same program on amd64 with the race detector?

Either way, can you provide stack traces? We don't have enough information here to identify the problem.

@ianlancetaylor ianlancetaylor reopened this Apr 8, 2019

@jasonkim

This comment has been minimized.

Copy link

commented Apr 9, 2019

Here's a couple logs I saw during my testing. These are pretty representative as all the other ones I saw were pretty much the same. It seems to occur when mqtt is connecting (in go routine?) and log happens at/near the same time.
I've scrubbed some of the details, but should still make sense.

Log 1

hub_1      | panic: runtime error: invalid memory address or nil pointer dereference
hub_1      | [signal SIGSEGV: segmentation violation code=0x1 addr=0x20 pc=0x557d72]
hub_1      |
hub_1      | goroutine 1 [running]:
hub_1      | github.com/sirupsen/logrus.(*Entry).write(0xc42007ee10)
hub_1      | 	/go/src/github.com/sirupsen/logrus/entry.go:128 +0x42
hub_1      | github.com/sirupsen/logrus.Entry.log(0xc42007eaf0, 0xc420077f50, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x4, ...)
hub_1      | 	/go/src/github.com/sirupsen/logrus/entry.go:104 +0x1a6
hub_1      | github.com/sirupsen/logrus.(*Entry).Info(0xc42007edc0, 0xc420163638, 0x1, 0x1)
hub_1      | 	/go/src/github.com/sirupsen/logrus/entry.go:153 +0xac
hub_1      | github.com/sirupsen/logrus.(*Entry).Infoln(0xc42007edc0, 0xc4200f4dc0, 0x2, 0x2)
hub_1      | 	/go/src/github.com/sirupsen/logrus/entry.go:244 +0xe0
hub_1      | github.com/sirupsen/logrus.(*Entry).Println(0xc42007edc0, 0xc4200f4dc0, 0x2, 0x2)
hub_1      | 	/go/src/github.com/sirupsen/logrus/entry.go:249 +0x49
hub_1      | github.com/sirupsen/logrus.(*Logger).Println(0xc42007eaf0, 0xc4200f4dc0, 0x2, 0x2)
hub_1      | 	/go/src/github.com/sirupsen/logrus/logger.go:259 +0x5c
hub_1      | github.com/eclipse/paho%2emqtt%2egolang.(*client).Connect(0xc420148380, 0xef7e80, 0xc420148380)
hub_1      | 	/go/src/github.com/eclipse/paho.mqtt.golang/client.go:189 +0xfb
hub_1      | b/hub/api/mqtt.(*Client).connect(0xc4200103c0, 0x0, 0x0)
hub_1      | 	/go/src/b/hub/api/mqtt/mqtt.go:123 +0x1e7
hub_1      | b/hub/api/mqtt.(*Client).waitForConnection(0xc4200103c0)
hub_1      | 	/go/src/b/hub/api/mqtt/mqtt.go:88 +0x78
hub_1      | b/hub/api/mqtt.(*Client).Start(0xc4200103c0)
hub_1      | 	/go/src/b/hub/api/mqtt/mqtt.go:82 +0x2b
hub_1      | main.main()
hub_1      | 	/go/src/b/cmd/hub/main.go:59 +0x129

Log 2

Apr 04 21:23:52 [macaddr] thing1[2407]: fatal error: panic while printing panic value
Apr 04 21:23:52 [macaddr] thing1[2407]: [signal SIGSEGV: segmentation violation code=0x1 addr=0x218 pc=0xb6177fcc]
Apr 04 21:23:52 [macaddr] thing1[2407]: goroutine 1 [running]:
Apr 04 21:23:52 [macaddr] thing1[2407]: runtime.throw(0xb674fb2f, 0x20)
Apr 04 21:23:52 [macaddr] thing1[2407]:         /usr/lib/go/src/runtime/panic.go:608 +0x64 fp=0x856d7af4 sp=0x856d7ae0 pc=0xb6145920
Apr 04 21:23:52 [macaddr] thing1[2407]: runtime.preprintpanics.func1()
Apr 04 21:23:52 [macaddr] thing1[2407]:         /usr/lib/go/src/runtime/panic.go:415 +0x44 fp=0x856d7b04 sp=0x856d7af4 pc=0xb617d9cc
Apr 04 21:23:52 [macaddr] thing1[2407]: runtime.call16(0x0, 0xb6b411b0, 0x0, 0x0, 0x0)
Apr 04 21:23:52 [macaddr] thing1[2407]:         /usr/lib/go/src/runtime/asm_arm.s:519 +0x4c fp=0x856d7b18 sp=0x856d7b04 pc=0xb617f75c
Apr 04 21:23:52 [macaddr] thing1[2407]: panic(0xb6ab77f8, 0xb6f55aa0)
Apr 04 21:23:52 [macaddr] thing1[2407]:         /usr/lib/go/src/runtime/panic.go:513 +0x1bc fp=0x856d7b60 sp=0x856d7b18 pc=0xb6145448
Apr 04 21:23:52 [macaddr] thing1[2407]: runtime.panicmem()
Apr 04 21:23:52 [macaddr] thing1[2407]:         /usr/lib/go/src/runtime/panic.go:82 +0x74 fp=0x856d7b6c sp=0x856d7b60 pc=0xb6144234
Apr 04 21:23:52 [macaddr] thing1[2407]: runtime.sigpanic()
Apr 04 21:23:52 [macaddr] thing1[2407]:         /usr/lib/go/src/runtime/signal_unix.go:390 +0xec fp=0x856d7b90 sp=0x856d7b6c pc=0xb6161cc8
Apr 04 21:23:52 [macaddr] thing1[2407]: runtime.(*_type).string(0x200, 0xb69150d3, 0xd)
Apr 04 21:23:52 [macaddr] thing1[2407]:         /usr/lib/go/src/runtime/type.go:46 +0x14 fp=0x856d7ba4 sp=0x856d7b94 pc=0xb6177fcc
Apr 04 21:23:52 [macaddr] thing1[2407]: runtime.(*TypeAssertionError).Error(0x85868300, 0xb6abad68, 0x85868300)
Apr 04 21:23:52 [macaddr] thing1[2407]:         /usr/lib/go/src/runtime/error.go:39 +0x6c fp=0x856d7c5c sp=0x856d7ba4 pc=0xb6114530
Apr 04 21:23:52 [macaddr] thing1[2407]: runtime.preprintpanics(0x856d7ccc)
Apr 04 21:23:52 [macaddr] thing1[2407]:         /usr/lib/go/src/runtime/panic.go:421 +0xac fp=0x856d7c98 sp=0x856d7c5c pc=0xb6145040
Apr 04 21:23:52 [macaddr] thing1[2407]: panic(0xb6abad68, 0x85868300)
Apr 04 21:23:52 [macaddr] thing1[2407]:         /usr/lib/go/src/runtime/panic.go:554 +0x2ec fp=0x856d7ce0 sp=0x856d7c98 pc=0xb6145578
Apr 04 21:23:52 [macaddr] thing1[2407]: runtime.panicdottypeE(0x200, 0xb6b259b8, 0x4316e0)
Apr 04 21:23:52 [macaddr] thing1[2407]:         /usr/lib/go/src/runtime/iface.go:248 +0xe8 fp=0x856d7cec sp=0x856d7ce0 pc=0xb6119848
Apr 04 21:23:52 [macaddr] thing1[2407]: github.com/sirupsen/logrus.Entry.log(0x85658120, 0x858682e0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
Apr 04 21:23:52 [macaddr] thing1[2407]:         /src/firmware/machine-type-1/tmp/work/cortexa9hf-neon-poky-linux-gnueabi/papertrail/1.0-r5/build/src/github.com/sirupsen/logrus/entry.go:101 +0x564 fp=0x856d7d6c sp=0x856d7cec pc=0x4252f8
Apr 04 21:23:52 [macaddr] thing1[2407]: github.com/sirupsen/logrus.(*Entry).Error(0x854f8ea0, 0x856d7dd4, 0x1, 0x1)
Apr 04 21:23:52 [macaddr] thing1[2407]:         /src/firmware/machine-type-1/tmp/work/cortexa9hf-neon-poky-linux-gnueabi/papertrail/1.0-r5/build/src/github.com/sirupsen/logrus/entry.go:156 +0x88 fp=0x856d7dac sp=0x856d7d6c pc=0x425664
Apr 04 21:23:52 [macaddr] thing1[2407]: github.com/sirupsen/logrus.(*Entry).Errorf(0x854f8ea0, 0x42b884, 0x44, 0x856d7ea8, 0x1, 0x1)
Apr 04 21:23:52 [macaddr] thing1[2407]:         /src/firmware/machine-type-1/tmp/work/cortexa9hf-neon-poky-linux-gnueabi/papertrail/1.0-r5/build/src/github.com/sirupsen/logrus/entry.go:204 +0xc0 fp=0x856d7ddc sp=0x856d7dac pc=0x425c14
Apr 04 21:23:52 [macaddr] thing1[2407]: github.com/sirupsen/logrus.(*Logger).Errorf(0x85658120, 0x42b884, 0x44, 0x856d7ea8, 0x1, 0x1)
Apr 04 21:23:52 [macaddr] thing1[2407]:         /src/firmware/machine-type-1/tmp/work/cortexa9hf-neon-poky-linux-gnueabi/papertrail/1.0-r5/build/src/github.com/sirupsen/logrus/logger.go:155 +0x64 fp=0x856d7dfc sp=0x856d7ddc pc=0x426f58
Apr 04 21:23:52 [macaddr] thing1[2407]: github.com/sirupsen/logrus.Errorf(0x42b884, 0x44, 0x856d7ea8, 0x1, 0x1)
Apr 04 21:23:52 [macaddr] thing1[2407]:         /src/firmware/machine-type-1/tmp/work/cortexa9hf-neon-poky-linux-gnueabi/papertrail/1.0-r5/build/src/github.com/sirupsen/logrus/exported.go:142 +0x50 fp=0x856d7e18 sp=0x856d7dfc pc=0x4264b4
Apr 04 21:23:52 [macaddr] thing1[2407]: main.main()
Apr 04 21:23:52 [macaddr] thing1[2407]:         /src/firmware/machine-type-1/tmp/work/cortexa9hf-neon-poky-linux-gnueabi/papertrail/1.0-r5/build/src/b/cmd/thing1/main.go:79 +0x20c fp=0x856d7fc4 sp=0x856d7e18 pc=0x42a9c8
Apr 04 21:23:52 [macaddr] thing1[2407]: runtime.main()
Apr 04 21:23:52 [macaddr] thing1[2407]:         /usr/lib/go/src/runtime/proc.go:201 +0x2bc fp=0x856d7fe4 sp=0x856d7fc4 pc=0xb61482c0
Apr 04 21:23:52 [macaddr] thing1[2407]: runtime.goexit()
Apr 04 21:23:52 [macaddr] thing1[2407]:         /usr/lib/go/src/runtime/asm_arm.s:867 +0x4 fp=0x856d7fe4 sp=0x856d7fe4 pc=0xb6181240
Apr 04 21:23:52 [macaddr] thing1[2407]: goroutine 26 [select]:
Apr 04 21:23:52 [macaddr] thing1[2407]: github.com/papertrail/remote_syslog2/syslog.(*Logger).writeLoop(0x8548d320)
Apr 04 21:23:52 [macaddr] thing1[2407]:         /src/firmware/machine-type-1/tmp/work/cortexa9hf-neon-poky-linux-gnueabi/papertrail/1.0-r5/build/src/github.com/papertrail/remote_syslog2/syslog/syslog.go:216 +0xe8
Apr 04 21:23:52 [macaddr] thing1[2407]: created by github.com/papertrail/remote_syslog2/syslog.Dial
Apr 04 21:23:52 [macaddr] thing1[2407]:         /src/firmware/machine-type-1/tmp/work/cortexa9hf-neon-poky-linux-gnueabi/papertrail/1.0-r5/build/src/github.com/papertrail/remote_syslog2/syslog/syslog.go:125 +0x204
Apr 04 21:23:52 [macaddr] systemd[1]: papertrail.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Apr 04 21:23:52 [macaddr] systemd[1]: papertrail.service: Failed with result 'exit-code'.
Apr 04 21:23:55 [macaddr] thing2[2373]: fatal error: unexpected signal during runtime execution
Apr 04 21:23:55 [macaddr] thing2[2373]: [signal SIGSEGV: segmentation violation code=0x2 addr=0xb6a7f050 pc=0xb60d9274]
Apr 04 21:23:55 [macaddr] thing2[2373]: goroutine 1 [running]:
Apr 04 21:23:55 [macaddr] thing2[2373]: runtime.throw(0xb668d592, 0x2a)
Apr 04 21:23:55 [macaddr] thing2[2373]:         /usr/lib/go/src/runtime/panic.go:608 +0x64 fp=0x852dd888 sp=0x852dd874 pc=0xb607b920
Apr 04 21:23:55 [macaddr] thing2[2373]: runtime.sigpanic()
Apr 04 21:23:55 [macaddr] thing2[2373]:         /usr/lib/go/src/runtime/signal_unix.go:374 +0x254 fp=0x852dd8ac sp=0x852dd888 pc=0xb6097e30
Apr 04 21:23:55 [macaddr] thing2[2373]: sync.(*Pool).Get(0x8500c080, 0xbf21bb02, 0x8544c120)
Apr 04 21:23:55 [macaddr] thing2[2373]:         /usr/lib/go/src/sync/pool.go:130 +0x38 fp=0x852dd8d0 sp=0x852dd8b0 pc=0xb60d9274
Apr 04 21:23:55 [macaddr] thing2[2373]: github.com/sirupsen/logrus.Entry.log(0x8524e090, 0x8513d040, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
Apr 04 21:23:55 [macaddr] thing2[2373]:         /src/firmware/machine-type-1/tmp/work/cortexa9hf-neon-poky-linux-gnueabi/hub/git-r3/build/src/github.com/sirupsen/logrus/entry.go:101 +0x128 fp=0x852dd950 sp=0x852dd8d0 pc=0x5d8304
Apr 04 21:23:55 [macaddr] thing2[2373]: github.com/sirupsen/logrus.(*Entry).Error(0x8544c0f0, 0x852dd9b8, 0x1, 0x1)
Apr 04 21:23:55 [macaddr] thing2[2373]:         /src/firmware/machine-type-1/tmp/work/cortexa9hf-neon-poky-linux-gnueabi/hub/git-r3/build/src/github.com/sirupsen/logrus/entry.go:156 +0x88 fp=0x852dd990 sp=0x852dd950 pc=0x5d8aac
Apr 04 21:23:55 [macaddr] thing2[2373]: github.com/sirupsen/logrus.(*Entry).Errorf(0x8544c0f0, 0x7db02a, 0x1c, 0x852ddad4, 0x3, 0x3)
Apr 04 21:23:55 [macaddr] thing2[2373]:         /src/firmware/machine-type-1/tmp/work/cortexa9hf-neon-poky-linux-gnueabi/hub/git-r3/build/src/github.com/sirupsen/logrus/entry.go:204 +0xc0 fp=0x852dd9c0 sp=0x852dd990 pc=0x5d905c
Apr 04 21:23:55 [macaddr] thing2[2373]: github.com/sirupsen/logrus.(*Logger).Errorf(0x8524e090, 0x7db02a, 0x1c, 0x852ddad4, 0x3, 0x3)
Apr 04 21:23:55 [macaddr] thing2[2373]:         /src/firmware/machine-type-1/tmp/work/cortexa9hf-neon-poky-linux-gnueabi/hub/git-r3/build/src/github.com/sirupsen/logrus/logger.go:155 +0x64 fp=0x852dd9e0 sp=0x852dd9c0 pc=0x5da598
Apr 04 21:23:55 [macaddr] thing2[2373]: github.com/sirupsen/logrus.Errorf(0x7db02a, 0x1c, 0x852ddad4, 0x3, 0x3)
Apr 04 21:23:55 [macaddr] thing2[2373]:         /src/firmware/machine-type-1/tmp/work/cortexa9hf-neon-poky-linux-gnueabi/hub/git-r3/build/src/github.com/sirupsen/logrus/exported.go:142 +0x50 fp=0x852dd9fc sp=0x852dd9e0 pc=0x5d9a8c
Apr 04 21:23:55 [macaddr] thing2[2373]: b/hub/api/http.request(0x7d7539, 0x4, 0x851fa190, 0xe, 0x8a2710, 0x8546a1a0, 0x0, 0x0, 0x0, 0x0)
Apr 04 21:23:55 [macaddr] thing2[2373]:         /src/firmware/machine-type-1/tmp/work/cortexa9hf-neon-poky-linux-gnueabi/hub/git-r3/build/src/b/hub/api/http/httpclient.go:158 +0x5d8 fp=0x852ddb44 sp=0x852dd9fc pc=0x628664
Apr 04 21:23:55 [macaddr] thing2[2373]: b/hub/api/http.(*Client).CreateHub(0x8513d400, 0x851fc600, 0x11, 0x85460000, 0x1c3, 0x800, 0x8524fb90)
Apr 04 21:23:55 [macaddr] thing2[2373]:         /src/firmware/machine-type-1/tmp/work/cortexa9hf-neon-poky-linux-gnueabi/hub/git-r3/build/src/b/hub/api/http/httpclient.go:54 +0x94 fp=0x852ddb80 sp=0x852ddb44 pc=0x6275fc
Apr 04 21:23:55 [macaddr] thing2[2373]: b/hub/api/mqtt.(*Client).createHub(0x8524cf00, 0x1a, 0x0)
Apr 04 21:23:55 [macaddr] thing2[2373]:         /src/firmware/machine-type-1/tmp/work/cortexa9hf-neon-poky-linux-gnueabi/hub/git-r3/build/src/b/hub/api/mqtt/mqtt.go:170 +0x5c fp=0x852ddbb0 sp=0x852ddb80 pc=0x682840
Apr 04 21:23:55 [macaddr] thing2[2373]: b/hub/api/mqtt.(*Client).connect(0x8524cf00, 0x0, 0x0)
Apr 04 21:23:55 [macaddr] thing2[2373]:         /src/firmware/machine-type-1/tmp/work/cortexa9hf-neon-poky-linux-gnueabi/hub/git-r3/build/src/b/hub/api/mqtt/mqtt.go:111 +0xd0 fp=0x852ddc20 sp=0x852ddbb0 pc=0x682088
Apr 04 21:23:55 [macaddr] thing2[2373]: b/hub/api/mqtt.(*Client).waitForConnection(0x8524cf00)
Apr 04 21:23:55 [macaddr] thing2[2373]:         /src/firmware/machine-type-1/tmp/work/cortexa9hf-neon-poky-linux-gnueabi/hub/git-r3/build/src/b/hub/api/mqtt/mqtt.go:91 +0x60 fp=0x852ddc38 sp=0x852ddc20 pc=0x681f60
Apr 04 21:23:55 [macaddr] thing2[2373]: b/hub/api/mqtt.(*Client).Start(0x8524cf00)
Apr 04 21:23:55 [macaddr] thing2[2373]:         /src/firmware/machine-type-1/tmp/work/cortexa9hf-neon-poky-linux-gnueabi/hub/git-r3/build/src/b/hub/api/mqtt/mqtt.go:85 +0x1c fp=0x852ddc40 sp=0x852ddc38 pc=0x681ef0
Apr 04 21:23:55 [macaddr] thing2[2373]: main.main()
Apr 04 21:23:55 [macaddr] thing2[2373]:         /src/firmware/machine-type-1/tmp/work/cortexa9hf-neon-poky-linux-gnueabi/hub/git-r3/build/src/b/cmd/hub/main.go:59 +0x118 fp=0x852ddfc4 sp=0x852ddc40 pc=0x7cf3dc
Apr 04 21:23:55 [macaddr] thing2[2373]: runtime.main()
Apr 04 21:23:55 [macaddr] thing2[2373]:         /usr/lib/go/src/runtime/proc.go:201 +0x2bc fp=0x852ddfe4 sp=0x852ddfc4 pc=0xb607e2c0
Apr 04 21:23:55 [macaddr] thing2[2373]: runtime.goexit()
Apr 04 21:23:55 [macaddr] thing2[2373]:         /usr/lib/go/src/runtime/asm_arm.s:867 +0x4 fp=0x852ddfe4 sp=0x852ddfe4 pc=0xb60b7240
Apr 04 21:23:55 [macaddr] thing2[2373]: goroutine 5 [syscall]:
Apr 04 21:23:55 [macaddr] thing2[2373]: os/signal.signal_recv(0x0)
Apr 04 21:23:55 [macaddr] thing2[2373]:         /usr/lib/go/src/runtime/sigqueue.go:139 +0x180
Apr 04 21:23:55 [macaddr] thing2[2373]: os/signal.loop()
Apr 04 21:23:55 [macaddr] thing2[2373]:         /usr/lib/go/src/os/signal/signal_unix.go:23 +0x14
Apr 04 21:23:55 [macaddr] thing2[2373]: created by os/signal.init.0
Apr 04 21:23:55 [macaddr] thing2[2373]:         /usr/lib/go/src/os/signal/signal_unix.go:29 +0x38
Apr 04 21:23:55 [macaddr] thing2[2373]: goroutine 20 [IO wait]:
Apr 04 21:23:55 [macaddr] thing2[2373]: internal/poll.runtime_pollWait(0xa513dfc0, 0x72, 0xb610d2c0)
Apr 04 21:23:55 [macaddr] thing2[2373]:         /usr/lib/go/src/runtime/netpoll.go:173 +0x44
Apr 04 21:23:55 [macaddr] thing2[2373]: internal/poll.(*pollDesc).wait(0x851f8424, 0x72, 0xffffff00, 0x8cb138, 0xb6e99700)
Apr 04 21:23:55 [macaddr] thing2[2373]:         /usr/lib/go/src/internal/poll/fd_poll_runtime.go:85 +0x9c
Apr 04 21:23:55 [macaddr] thing2[2373]: internal/poll.(*pollDesc).waitRead(0x851f8424, 0x8530e000, 0x1000, 0x1000)
Apr 04 21:23:55 [macaddr] thing2[2373]:         /usr/lib/go/src/internal/poll/fd_poll_runtime.go:90 +0x2c
Apr 04 21:23:55 [macaddr] thing2[2373]: internal/poll.(*FD).Read(0x851f8410, 0x8530e000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
Apr 04 21:23:55 [macaddr] thing2[2373]:         /usr/lib/go/src/internal/poll/fd_unix.go:169 +0x15c
Apr 04 21:23:55 [macaddr] thing2[2373]: net.(*netFD).Read(0x851f8410, 0x8530e000, 0x1000, 0x1000, 0x0, 0x4, 0x851fc4e0)
Apr 04 21:23:55 [macaddr] thing2[2373]:         /usr/lib/go/src/net/fd_unix.go:202 +0x38
Apr 04 21:23:55 [macaddr] systemd[1]: thing2.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Apr 04 21:23:55 [macaddr] thing2[2373]: net.(*conn).Read(0x85466030, 0x8530e000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
Apr 04 21:23:55 [macaddr] thing2[2373]:         /usr/lib/go/src/net/net.go:177 +0x58
Apr 04 21:23:55 [macaddr] thing2[2373]: net/http.(*persistConn).Read(0x854620a0, 0x8530e000, 0x1000, 0x1000, 0x854620a0, 0x0, 0x0)
Apr 04 21:23:55 [macaddr] thing2[2373]:         /usr/lib/go/src/net/http/transport.go:1497 +0x17c
Apr 04 21:23:55 [macaddr] thing2[2373]: bufio.(*Reader).fill(0x8544c060)
Apr 04 21:23:55 [macaddr] thing2[2373]:         /usr/lib/go/src/bufio/bufio.go:100 +0x10c
Apr 04 21:23:55 [macaddr] thing2[2373]: bufio.(*Reader).Peek(0x8544c060, 0x1, 0x2, 0x0, 0x0, 0x85448080, 0x0)
Apr 04 21:23:55 [macaddr] thing2[2373]:         /usr/lib/go/src/bufio/bufio.go:132 +0x2c
Apr 04 21:23:55 [macaddr] thing2[2373]: net/http.(*persistConn).readLoop(0x854620a0)
Apr 04 21:23:55 [macaddr] thing2[2373]:         /usr/lib/go/src/net/http/transport.go:1645 +0x1bc
Apr 04 21:23:55 [macaddr] thing2[2373]: created by net/http.(*Transport).dialConn
Apr 04 21:23:55 [macaddr] thing2[2373]:         /usr/lib/go/src/net/http/transport.go:1338 +0x980
Apr 04 21:23:55 [macaddr] thing2[2373]: goroutine 21 [select]:
Apr 04 21:23:55 [macaddr] thing2[2373]: net/http.(*persistConn).writeLoop(0x854620a0)
Apr 04 21:23:55 [macaddr] thing2[2373]:         /usr/lib/go/src/net/http/transport.go:1885 +0xd0
Apr 04 21:23:55 [macaddr] thing2[2373]: created by net/http.(*Transport).dialConn
Apr 04 21:23:55 [macaddr] thing2[2373]:         /usr/lib/go/src/net/http/transport.go:1339 +0x9a4

I don't have amd64 machine to test on (in fact we only have 1-2 arm type machines). I am planning to test it on my local env (OS X) but will have to figure out my build and how to run it with race detector. Will report back when I do.

@jasonkim

This comment has been minimized.

Copy link

commented Apr 9, 2019

I wasn't able to repro on my OS X (with or without -race), but it's possible that I'm running it differently than how it's run in our deployed env.

@ianlancetaylor ianlancetaylor modified the milestones: Go1.12, Go1.13 Apr 10, 2019

@jasonkim

This comment has been minimized.

Copy link

commented Apr 11, 2019

There's some repro steps in the original ticket. It may help with debugging.

I can reproduce this now on an ARMv7 target, provided the image also includes the ca-certificates package.  Also, you have to wait until /dev/random has enough entropy.

I can also reproduce this natively by building go 1.10 from source, building a shared runtime with 'go install -linkshared -buildmode=shared std',  and doing a 'go get -linkshared github.com/gustavosbarreto/go-crazy'.  So it's not ARM-specific.

It's a panic due to a segfault, always appearing to happen around a sync.Pool request in logrus's Entry.log function.  However, it only seems to happen if the https request is also getting processed in other goroutines.  Panic tracebacks always point to the logrus package as the running thread, sometimes with and sometimes without other goroutines being active.

It does seem to happen only when the program is linked against shared runtime, not when linked statically.

Definitely an upstream issue, just not 100% sure that it's really in the Go runtime, or if logrus is misusing the sync package.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.