runtime: segmentation fault on linux/arm when GODEBUG=sbrk=1

[mischief]

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

$ go version
go version go1.12.5 linux/amd64

Does this issue reproduce with the latest release?

i can reproduce with go version devel +5bc46cb712 Wed Jul 17 17:34:32 2019 +0000 linux/amd64.

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

go env Output

$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/mischief/.cache/go-build"
GOENV="/home/mischief/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/mischief/code/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/home/mischief/src/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/home/mischief/src/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/home/mischief/src/go/src/go.mod"
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-build205075811=/tmp/go-build -gno-record-gcc-switches"

What did you do?

i compiled this code (example code from log/syslog) https://play.golang.org/p/at82pgxjDf1 with GOARCH=arm GOARM=7 from linux/amd64, and executed it on a arm system.

if i execute the program normally, it succeeds. if i execute the program with GODEBUG=sbrk=1, the program will panic:

# ./syslogger 
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x4 pc=0x123d0]

goroutine 1 [running]:
internal/poll.(*fdMutex).rwlock(0x66c63024, 0xabe00, 0x66c64a50)
        /home/mischief/src/go/src/internal/poll/fd_mutex.go:132 +0x68
internal/poll.(*FD).writeLock(...)
        /home/mischief/src/go/src/internal/poll/fd_mutex.go:239
internal/poll.(*FD).Write(0x66c63024, 0x66c64a90, 0x4a, 0x80, 0x0, 0x0, 0x0)
        /home/mischief/src/go/src/internal/poll/fd_unix.go:255 +0x40
net.(*netFD).Write(0x66c63024, 0x66c64a90, 0x4a, 0x80, 0x115245, 0x0, 0xa4b40)
        /home/mischief/src/go/src/net/fd_unix.go:220 +0x38
net.(*conn).Write(0x66c64208, 0x66c64a90, 0x4a, 0x80, 0x0, 0x0, 0x0)
        /home/mischief/src/go/src/net/net.go:189 +0x58
fmt.Fprintf(0x66c64968, 0x66c64208, 0x115239, 0x13, 0x204fe30, 0x6, 0x6, 0x66c64930, 0xf, 0x0)
        /home/mischief/src/go/src/fmt/print.go:205 +0x78
log/syslog.(*netConn).writeString(0x66c6420c, 0x1c, 0x66c62f80, 0x4, 0x1130c4, 0x7, 0x66c644e0, 0x26, 0x11298e, 0x1, ...)
        /home/mischief/src/go/src/log/syslog/syslog.go:289 +0x1d8
log/syslog.(*Writer).write(0x66c62f84, 0x1c, 0x66c644e0, 0x26, 0x26, 0x66c644b0, 0x0)
        /home/mischief/src/go/src/log/syslog/syslog.go:273 +0xa8
log/syslog.(*Writer).writeAndRetry(0x66c62f84, 0x1c, 0x66c644e0, 0x26, 0x0, 0x0, 0x0)
        /home/mischief/src/go/src/log/syslog/syslog.go:254 +0x134
log/syslog.(*Writer).Write(0x66c62f84, 0x66c644b0, 0x26, 0x30, 0x0, 0x0, 0x205afc0)
        /home/mischief/src/go/src/log/syslog/syslog.go:175 +0x64
fmt.Fprintf(0x135228, 0x66c62f84, 0x119201, 0x26, 0x0, 0x0, 0x0, 0x66c62f84, 0x0, 0x0)
        /home/mischief/src/go/src/fmt/print.go:205 +0x78
main.main()
        /home/mischief/code/go/src/github.com/mischief/crap/cmd/syslogger/main.go:14 +0xcc

What did you expect to see?

no panic.

What did you see instead?

a panic.

[ianlancetaylor]

@aclements @mknyszek Do we expect GODEBUG=sbrk=1 to work?

[aclements]

Not especially, no.

That said, the panic is actually an unaligned 64-bit atomic access to fdMutex.state. I'm pretty sure that's because sbrk mode takes the alignment from the type if it can, and the alignment of uint64s is only 4 bytes on 32-bit (issue #599, sigh). The type is large enough that with the normal allocator it will always be at least 8 byte aligned, but sbrk mode has weaker alignment.

[gopherbot]

Change https://golang.org/cl/186919 mentions this issue: runtime: align allocations harder in GODEBUG=sbrk=1 mode

[mischief]

this still occurs with cl 186919 (go version devel +f518a96e00 Fri Jul 19 20:08:48 2019 +0000 linux/amd64). is that expected because of #599?

[aclements]

No, that commit should have fixed it... Could you post an updated traceback (or a few so I can look for patterns)?

Also, what's the reason for using sbrk mode? Do you actually need it, or was this just an experiment? I can't even recall the last time we used that to debug something, so another option is to just remove it.

[mischief]

@aclements i was interested in sbrk mode because i was experimenting with putting hard caps on memory use for go programs. we have an old (3 series right now, maybe 4.4 soon 😢) kernel, and it seems that setrlimit(2) with RLIMIT_DATA does not apply to mmap until linux 4.7.

[mischief]

here's syslog.test executing natively on arm, cross-compiled with go version devel +f518a96e00 Fri Jul 19 20:08:48 2019 +0000 linux/amd64.

# ls -l syslog.test
-rwxr-xr-x 1 root root 3880115 Jul 22 17:46 syslog.test
# file syslog.test
syslog.test: ELF 32-bit LSB executable, ARM, EABI5 version 1 (SYSV), statically linked, not stripped
# ./syslog.test
PASS
# export GODEBUG=sbrk=1
# ./syslog.test
--- FAIL: TestFlap (5.00s)
panic: runtime error: invalid memory address or nil pointer dereference [recovered]
        panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x4 pc=0x123d0]

goroutine 34 [running]:
testing.tRunner.func1(0x66c7c278)
        /home/mischief/src/go/src/testing/testing.go:874 +0x360
panic(0x172310, 0x2b07c8)
        /home/mischief/src/go/src/runtime/panic.go:679 +0x194
internal/poll.(*fdMutex).rwlock(0x66c7dc34, 0x0, 0x66c7e250)
        /home/mischief/src/go/src/internal/poll/fd_mutex.go:132 +0x68
internal/poll.(*FD).writeLock(...)
        /home/mischief/src/go/src/internal/poll/fd_mutex.go:239
internal/poll.(*FD).Write(0x66c7dc34, 0x66c7e290, 0x37, 0x40, 0x0, 0x0, 0x0)
        /home/mischief/src/go/src/internal/poll/fd_unix.go:255 +0x40
net.(*netFD).Write(0x66c7dc34, 0x66c7e290, 0x37, 0x40, 0x19811f, 0x0, 0xb8d0c)
        /home/mischief/src/go/src/net/fd_unix.go:220 +0x38
net.(*conn).Write(0x66c7de28, 0x66c7e290, 0x37, 0x40, 0x0, 0x0, 0x0)
        /home/mischief/src/go/src/net/net.go:189 +0x58
fmt.Fprintf(0x66c7df98, 0x66c7de28, 0x19811f, 0x16, 0x144fdc4, 0x7, 0x7, 0x66c7df50, 0x14, 0x0)
        /home/mischief/src/go/src/fmt/print.go:205 +0x78
log/syslog.(*netConn).writeString(0x66c7de2c, 0xe, 0x66c7db90, 0x4, 0x195953, 0xb, 0x1942e3, 0x5, 0x193f1c, 0x1, ...)
        /home/mischief/src/go/src/log/syslog/syslog.go:295 +0x3c8
log/syslog.(*Writer).write(0x66c7db94, 0xe, 0x1942e3, 0x5, 0x0, 0x0, 0x4)
        /home/mischief/src/go/src/log/syslog/syslog.go:273 +0xa8
log/syslog.(*Writer).writeAndRetry(0x66c7db94, 0x6, 0x1942e3, 0x5, 0x0, 0x0, 0x0)
        /home/mischief/src/go/src/log/syslog/syslog.go:254 +0x134
log/syslog.(*Writer).Info(...)
        /home/mischief/src/go/src/log/syslog/syslog.go:236
log/syslog.TestFlap(0x66c7c278)
        /home/mischief/src/go/src/log/syslog/syslog_test.go:184 +0x1ec
testing.tRunner(0x66c7c278, 0x19ee18)
        /home/mischief/src/go/src/testing/testing.go:909 +0xa8
created by testing.(*T).Run
        /home/mischief/src/go/src/testing/testing.go:960 +0x2ac
#

[aclements]

@mischief, sbrk=1 mode isn't going to help with hard caps on memory use. sbrk=1 mode means that nothing ever gets freed or garbage collected, so the heap size just grows monotonically. However, it does not actually mean Go uses the brk system call, so RLIMIT_DATA shouldn't have any effect on Go processes prior to Linux 4.7.

Even as of Linux 4.7, RLIMIT_DATA doesn't make much more sense than RLIMIT_AS. All of these memory rlimits apply to mapped address space, but mapped address space costs nothing, so it doesn't make much sense to limit it. That said, Go does try to be somewhat conservative with address space, but will grab 64MiB at a time and never returns address space to the OS (even if it is returning memory to the OS).

The only effective way to limit a process' physical memory use on Linux that I'm aware of is to use memory cgroups.

What is the output of go version syslog.test?

(For my own reference, the implementation and description of the RLIMIT_DATA change is in torvalds/linux@8463833)

[nick-owens-eero]

$ go version syslog.test 
syslog.test: devel +f518a96e00 Fri Jul 19 20:08:48 2019 +0000

[mischief]

FYI this still crashes with an alignment error, but it seems that GODEBUG=sbrk=1 is not really something to be supported, so i will just close this out.

mischief@beast:~/code/go $ vim syslog.go
mischief@beast:~/code/go $ go version
go version go1.21.4 linux/amd64
mischief@beast:~/code/go $ GOARCH=arm GOARM=7 go build syslog.go
mischief@beast:~/code/go $ qemu-arm ./syslog
2023/12/11 19:02:30 dial tcp [::1]:1234: connect: connection refused
mischief@beast:~/code/go $ GODEBUG=sbrk=1 qemu-arm ./syslog
panic: unaligned 64-bit atomic operation

goroutine 17 [running]:
runtime/internal/atomic.panicUnaligned()
        /usr/lib/go/src/runtime/internal/atomic/unaligned.go:8 +0x24
runtime/internal/atomic.Load64(0x3789170c)
        /usr/lib/go/src/runtime/internal/atomic/atomic_arm.s:280 +0x14
internal/poll.(*fdMutex).increfAndClose(0x3789170c)
        /usr/lib/go/src/internal/poll/fd_mutex.go:73 +0x20
internal/poll.(*FD).Close(0x3789170c)
        /usr/lib/go/src/internal/poll/fd_unix.go:91 +0x20
net.(*netFD).Close(0x3789170c)
        /usr/lib/go/src/net/fd_posix.go:37 +0x44
net.(*conn).Close(0x378917d0)
        /usr/lib/go/src/net/net.go:203 +0x30
net.srcAddrs({0x37891680, 0x2, 0x2})
        /usr/lib/go/src/net/addrselect.go:54 +0x1f8
net.sortByRFC6724({0x37891680, 0x2, 0x2})
        /usr/lib/go/src/net/addrselect.go:18 +0x38
net.goLookupIPFiles({0x111c97, 0x9})
        /usr/lib/go/src/net/dnsclient_unix.go:583 +0x2a8
net.(*Resolver).goLookupIPCNAMEOrder(0x1c7d40, {0x137ad4, 0x3788df10}, {0x1104bc, 0x3}, {0x111c97, 0x9}, 0x1, 0x3788e1f4)
        /usr/lib/go/src/net/dnsclient_unix.go:598 +0x6c
net.(*Resolver).lookupIP(0x1c7d40, {0x137ad4, 0x3788df10}, {0x1104bc, 0x3}, {0x111c97, 0x9})
        /usr/lib/go/src/net/lookup_unix.go:72 +0x120
net.glob..func1({0x137ad4, 0x3788df10}, 0x3788def8, {0x1104bc, 0x3}, {0x111c97, 0x9})
        /usr/lib/go/src/net/hook.go:23 +0x4c
net.(*Resolver).lookupIPAddr.func1()
        /usr/lib/go/src/net/lookup.go:324 +0x5c
internal/singleflight.(*Group).doCall(0x1c7d48, 0x3788dfe8, {0x3788df50, 0xd}, 0x3788df60)
        /usr/lib/go/src/internal/singleflight/singleflight.go:93 +0x1c
created by internal/singleflight.(*Group).DoChan in goroutine 1
        /usr/lib/go/src/internal/singleflight/singleflight.go:86 +0x324