runtime/race: tracebacks missing symbol/file names

[prattmic]

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

tip, cce6769

Does this issue reproduce with the latest release?

No, not in 1.20

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

go env Output

$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/usr/local/google/home/mpratt/.cache/go-build"
GOENV="/usr/local/google/home/mpratt/.config/go/env"
GOEXE=""
GOEXPERIMENT=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/usr/local/google/home/mpratt/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/usr/local/google/home/mpratt/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/lib/google-golang"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/lib/google-golang/pkg/tool/linux_amd64"
GOVCS=""
GOVERSION="go1.21-20230317-RC01 cl/517508637 +f53a95fe39"
GCCGO="gccgo"
GOAMD64="v1"
AR="ar"
CC="clang"
CXX="clang++"
CGO_ENABLED="1"
GOMOD="/usr/local/google/home/mpratt/src/go/src/go.mod"
GOWORK=""
CGO_CFLAGS="-O2 -g"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-O2 -g"
CGO_FFLAGS="-O2 -g"
CGO_LDFLAGS="-O2 -g"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -Wl,--no-gc-sections -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build2742874043=/tmp/go-build -gno-record-gcc-switches"

What did you do?

Run this program in race mode:

package main

import (
        "sync"
)

func main() {
        for {                        
                var wg sync.WaitGroup
                go func() {
                        wg.Add(1)
                        wg.Done()
                }()
                wg.Wait()
        }                                 
}

What did you expect to see?

==================
WARNING: DATA RACE
Write at 0x00c000461d58 by main goroutine:
  runtime.racewrite()
      <autogenerated>:1 +0x24
  main.main()
      /tmp/race/main.go:14 +0x35

Previous read at 0x00c000461d58 by goroutine 2011:
  runtime.raceread()
      <autogenerated>:1 +0x24
  main.main.func1()
      /tmp/race/main.go:11 +0x35

Goroutine 2011 (finished) created at:
  main.main()
      /tmp/race/main.go:10 +0x2b
==================

What did you see instead?

==================           
WARNING: DATA RACE 
Write at 0x00c000531198 by main goroutine:
  ??()
      -:0 +0x49f39e                  
  main.main()
      /tmp/race/main.go:14 +0x30
                                                                       
Previous read at 0x00c000531198 by goroutine 21825:
  ??()
      -:0 +0x49f35e
  main.main.func1()        
      /tmp/race/main.go:11 +0x33
                                                                       
Goroutine 21825 (finished) created at:    
  main.main()        
      /tmp/race/main.go:10 +0x26
==================

The reported PC is in racewrite.abi0:

000000000049f380 <runtime.racewrite.abi0>:
  49f380:       55                      push   %rbp
  49f381:       48 89 e5                mov    %rsp,%rbp
  49f384:       48 83 ec 08             sub    $0x8,%rsp
  49f388:       48 8b 44 24 18          mov    0x18(%rsp),%rax
  49f38d:       45 0f 57 ff             xorps  %xmm15,%xmm15
  49f391:       64 4c 8b 34 25 f8 ff    mov    %fs:0xfffffffffffffff8,%r14
  49f398:       ff ff 
  49f39a:       e8 c1 eb ff ff          call   49df60 <runtime.racewrite>
  49f39f:       48 83 c4 08             add    $0x8,%rsp
  49f3a3:       5d                      pop    %rbp

cc @golang/runtime @aclements @cherrymui

[cherrymui]

The symbolizer ignore wrappers https://cs.opensource.google/go/go/+/master:src/runtime/race.go;l=179 . But if the symbolizer is given a PC that is in a wrapper, we should probably just give it the wrapper symbol.

Maybe we could avoid wrapper PCs in the first place? Not sure if it is possible. For this particular case, I thought the compiler should directly call the ABIInternal runtime.racewrite without wrapper. Not sure why it isn't the case...

[cherrymui]

CL https://golang.org/cl/495478 tries to remove some wrapper PCs. It looks reasonable to me, but it doesn't work...

[gopherbot]

Change https://go.dev/cl/495478 mentions this issue: runtime: mark RaceRead, etc. ABIInternal

[cherrymui]

It looks like the 1.20 symbolization code tries to skip the wrapper if the wrapper is inlined. It will use the wrapper symbol if it is an outlined wrapper. It seems the code at tip skips wrapper even if it is not inlined, so it fails to symbolize the PC?

[aclements]

Bisect blames 166e5ee

cd $GOROOT
cat >/tmp/x.go <<EOF
package main

import (
	"sync"
)

func main() {
	for i := 0; i < 100000; i++ {
		var wg sync.WaitGroup
		go func() {
			wg.Add(1)
			wg.Done()
		}()
		wg.Wait()
	}
}
EOF
cat >do-bisect <<EOF
#!/bin/zsh

set -e

rm -f src/time/tzdata/zzipdata.go

cd src
./make.bash || exit 125
for ((i = 0; i < 100; i++)); do
    echo -n .
    go run -race /tmp/x.go >& /tmp/out || true
    if grep -q "DATA RACE" /tmp/out; then
        if grep -q '??()' /tmp/out; then
            echo " fail"
            exit 1
        fi
        echo " pass"
        exit 0
    fi
done
echo

echo "FAILED TO REPRODUCE"
exit 125
EOF

git bisect start master $(git merge-base master origin/release-branch.go1.20)
git bisect run ./do-bisect

[gopherbot]

Change https://go.dev/cl/497235 mentions this issue: runtime: symbolize wrappers as a last resort in race tracebacks