runtime: vdso __kernel_clock_gettime not called on linux/arm64

[wkozaczuk]

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

go version go1.17.7 linux/arm64

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="arm64"
GOBIN=""
GOCACHE="/home/wkozaczuk/.cache/go-build"
GOENV="/home/wkozaczuk/.config/go/env"
GOEXE=""
GOEXPERIMENT=""
GOFLAGS=""
GOHOSTARCH="arm64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/home/wkozaczuk/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/wkozaczuk/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/home/wkozaczuk/go/1.17.7/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/home/wkozaczuk/go/1.17.7/go/pkg/tool/linux_arm64"
GOVCS=""
GOVERSION="go1.17.7"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/dev/null"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build2816176477=/tmp/go-build -gno-record-gcc-switches"

What did you do?

Ran a simple httpserver:

package main

import (
	"io"
	"net/http"
	"runtime"
        "fmt"
	"os"
)

func hello(w http.ResponseWriter, r *http.Request) {
	hostname, err := os.Hostname()
        if( err == nil ) {
		io.WriteString(w, "Hello world from " + runtime.Version() + " at " + hostname)
        }
}

func main() {
	fmt.Printf("Go version: %s, listening on port 8000 ...\n", runtime.Version());
	http.HandleFunc("/", hello)
	http.ListenAndServe(":8000", nil)
}

What did you expect to see?

I expected Golang runtime to use VDSO calls instead of the clock_gettime syscalls.

What did you see instead?

I instead see the clock_gettime syscalls being made:

strace -F ./apps/golang-pie-httpserver/httpserver.so 2>&1 | grep clock_gettime
clock_gettime(CLOCK_MONOTONIC, {tv_sec=1359948, tv_nsec=348917386}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=1359948, tv_nsec=349885347}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=1359948, tv_nsec=349931433}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=1359948, tv_nsec=349964351}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=1359948, tv_nsec=349996311}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=1359948, tv_nsec=350031937}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=1359948, tv_nsec=350066939}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=1359948, tv_nsec=350101107}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=1359948, tv_nsec=350136192}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=1359948, tv_nsec=350171319}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=1359948, tv_nsec=350206446}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=1359948, tv_nsec=350241239}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=1359948, tv_nsec=350276115}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=1359948, tv_nsec=350310700}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=1359948, tv_nsec=350344785}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=1359948, tv_nsec=350538794}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=1359948, tv_nsec=350574963}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=1359948, tv_nsec=350804307}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=1359948, tv_nsec=356139845}) = 0
[pid 67110] clock_gettime(CLOCK_MONOTONIC,  <unfinished ...>
[pid 67110] <... clock_gettime resumed>{tv_sec=1359948, tv_nsec=356757665}) = 0
[pid 67110] clock_gettime(CLOCK_MONOTONIC,  <unfinished ...>
[pid 67110] <... clock_gettime resumed>{tv_sec=1359948, tv_nsec=356851711}) = 0
[pid 67110] clock_gettime(CLOCK_MONOTONIC,  <unfinished ...>
[pid 67110] <... clock_gettime resumed>{tv_sec=1359948, tv_nsec=357587954}) = 0
[pid 67111] clock_gettime(CLOCK_MONOTONIC,  <unfinished ...>
[pid 67111] <... clock_gettime resumed>{tv_sec=1359948, tv_nsec=357776754}) = 0
[pid 67111] clock_gettime(CLOCK_MONOTONIC,  <unfinished ...>
[pid 67111] <... clock_gettime resumed>{tv_sec=1359948, tv_nsec=357917177}) = 0
[pid 67111] clock_gettime(CLOCK_MONOTONIC,  <unfinished ...>
[pid 67111] <... clock_gettime resumed>{tv_sec=1359948, tv_nsec=358231983}) = 0
[pid 67111] clock_gettime(CLOCK_MONOTONIC,  <unfinished ...>
[pid 67111] <... clock_gettime resumed>{tv_sec=1359948, tv_nsec=358445535}) = 0
[pid 67111] clock_gettime(CLOCK_MONOTONIC,  <unfinished ...>
[pid 67111] <... clock_gettime resumed>{tv_sec=1359948, tv_nsec=358829344}) = 0
[pid 67112] clock_gettime(CLOCK_MONOTONIC,  <unfinished ...>

I believe there is a simple bug in vdso_linux_arm64.go where it uses wrong hash values (of __vdso_clock_gettime) instead of __kernel_clock_gettime.

The correct values should be 0xb0cd725, 0xdfa941fd

like in this code snippet:

var vdsoSymbolKeys = []vdsoSymbolKey{
//	{"__kernel_clock_gettime", 0xd35ec75, 0x6e43a318, &vdsoClockgettimeSym}, WRONG
	{"__kernel_clock_gettime", 0xb0cd725, 0xdfa941fd, &vdsoClockgettimeSym},
}

For comparison look at

go/src/runtime/vdso_linux_ppc64x.go

Line 18 in 071aed2

{"__kernel_clock_gettime", 0xb0cd725, 0xdfa941fd, &vdsoClockgettimeSym},

[prattmic]

Nice find! This all sounds correct to me, at least at a quick glance. Would you like to send a CL to fix this?

[prattmic]

cc @golang/runtime

[aclements]

I wonder if there's a reasonable way to write a test for this. From a runtime test, it's easy to see if the runtime found clock_gettime, but we can't just always run that test. It might be reasonable to only run the test on the builders, since we control that environment (t.Skip when os.Getenv("GO_BUILDER_NAME") == ""). A more end-to-end test could actually use syscall.Ptrace* to check a subprocess, and then it could also check a simple cgo subprocess as a baseline, but ptrace is such a pain that that's probably not worth the effort.

[ianlancetaylor]

Just a note that I've written a test for this that simply invokes strace. But the test still fails on linux-arm64 after updating the values, and I haven't figured out why yet.

[cherrymui]

It is possible that the builder doesn't have VDSO enabled (e.g. in its kernel configuration). I remember that there were some builders that don't have VDSO enabled, but I don't remember which one.

[mengzhuo]

If your kernel don't support vdso __kernel_clock_gettime will fallback to syscall.
https://github.com/torvalds/linux/blob/1c59d383390f970b891b503b7f79b63a02db2ec5/arch/arm64/include/asm/vdso/gettimeofday.h#L36-L50

The function name __kernel_clock_gettime is hard-coded into kernel instead of other architectures __vdso_clock_gettime, you can check the "aarch64 functions" section of linux kernel vdso manual by man 7 vdso .

Here is an online version: https://man7.org/linux/man-pages/man7/vdso.7.html

You can also dump your vdso into file and read it with readelf --all
Here is a example from random linux/arm64 program.

Symbol table '.dynsym' contains 7 entries:
   Num:    Value          Size Type    Bind   Vis      Ndx Name
     0: 0000000000000000     0 NOTYPE  LOCAL  DEFAULT  UND
     1: 0000000000000300     0 SECTION LOCAL  DEFAULT    7
     2: 0000000000000000     0 OBJECT  GLOBAL DEFAULT  ABS LINUX_2.6.39
     3: 0000000000000634    80 FUNC    GLOBAL DEFAULT    7 __kernel_clock_getres@@LINUX_2.6.39
     4: 0000000000000688     8 FUNC    GLOBAL DEFAULT    7 __kernel_rt_sigreturn@@LINUX_2.6.39
     5: 0000000000000300   164 FUNC    GLOBAL DEFAULT    7 __kernel_gettimeofday@@LINUX_2.6.39
     6: 00000000000003a4   656 FUNC    GLOBAL DEFAULT    7 __kernel_clock_gettime@@LINUX_2.6.39

As for the hashes, I can confirm that old DT_HASH works at least on Linux 4.15.0-70-generic, although it may has bug with new DT_GNU_HASH.

[gopherbot]

Change https://go.dev/cl/523955 mentions this issue: runtime: correct linux-arm64 vdso hash codes

[ianlancetaylor]

The VDSO does work on the arm64 builder, it was a bug in my test.