Skip to content

runtime/race: tracebacks missing symbol/file names #60245

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.

Sign up for GitHub

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

Jump to bottom
Closed
prattmic opened this issue May 16, 2023 · 6 comments
Closed

runtime/race: tracebacks missing symbol/file names #60245

prattmic opened this issue May 16, 2023 · 6 comments
Assignees
@aclements
Labels
compiler/runtime Issues related to the Go compiler and/or runtime. FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. release-blocker
Milestone
Go1.21

Comments

@prattmic
Copy link
Member

prattmic commented May 16, 2023 •
edited
Loading

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
@prattmic prattmic added NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. release-blocker labels May 16, 2023
@prattmic prattmic added this to the Go1.21 milestone May 16, 2023
@gopherbot gopherbot added the compiler/runtime Issues related to the Go compiler and/or runtime. label May 16, 2023
@cherrymui
Copy link
Member

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
Copy link
Member

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

@gopherbot
Copy link
Contributor

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

@cherrymui
Copy link
Member

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
Copy link
Member

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
Copy link
Contributor

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

@github-project-automation github-project-automation bot moved this from Todo to Done in Go Compiler / Runtime May 23, 2023
@golang golang locked and limited conversation to collaborators May 22, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees

@aclements aclements

Labels
compiler/runtime Issues related to the Go compiler and/or runtime. FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. release-blocker
Projects
None yet
Milestone
Go1.21
Development

No branches or pull requests
4 participants
@prattmic @aclements @gopherbot @cherrymui