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

cmd/compile: DWARF Incorrect slice len #48405

Open
mahdi-hm opened this issue Sep 15, 2021 · 6 comments
Open

cmd/compile: DWARF Incorrect slice len #48405

mahdi-hm opened this issue Sep 15, 2021 · 6 comments
Assignees

Comments

@mahdi-hm
Copy link

@mahdi-hm mahdi-hm commented Sep 15, 2021

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

$ go version
go version go1.17.1 linux/amd64

Does this issue reproduce with the latest release?

No, this issue appeared after 1.14.9

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

go env Output
$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/mahdi/.cache/go-build"
GOENV="/home/mahdi/.config/go/env"
GOEXE=""
GOEXPERIMENT=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/home/mahdi/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/mahdi/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/home/mahdi/go1.17.1/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/home/mahdi/go1.17.1/go/pkg/tool/linux_amd64"
GOVCS=""
GOVERSION="go1.17.1"
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 -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build271877701=/tmp/go-build -gno-record-gcc-switches"

What did you do?

Consider below source code:

package main

import "fmt"

// Create a new type of 'deck' which is a slice of strings
type deck []string

func newDeck() deck {
	cards := deck{}

	cardSuits := []string{"Spades", "Diamonds", "Hearts", "Clubs"}
	cardValues := []string{"Ace", "Two", "Three", "Four"}

	for _, suit := range cardSuits {
		for _, value := range cardValues {
			cards = append(cards, value+" of "+suit)
		}
	}
	
	return cards
}

func (d deck) print() {
	for i, card := range d {
		fmt.Println(i, card)
	}
}

func main() {

	cards := newDeck()

	cards.print()
}

Now, compile the code and run debugger on final exe. set breakpoint on line 12 of newDeck function and then try to see the local variable:

go build deck.go
dlv exec ./deck
(dlv) break main.newDeck:12

What did you expect to see?

the slice length is 16 and I expect to see this after running locals commad:
cards = main.deck len: 16, cap: 16, [...]

What did you see instead?

cards = main.deck len: 15, cap: 16, [...]

There is also an interesting behavior here. If you try to print the length of that slice the debugger shows the length correctly:

    15:                 for _, value := range cardValues {
    16:                         cards = append(cards, value+" of "+suit)
    17:                 }
    18:         }
    19:         println("cards len=", len(cards))
=>  20:         return cards
    21: }
    22:
    23: func (d deck) print() {
    24:         for i, card := range d {
    25:                 fmt.Println(i, card)
(dlv) locals
cards = main.deck len: 16, cap: 16, [...]
cardSuits = (unreadable empty OP stack)
cardValues = (unreadable empty OP stack)
@hyangah
Copy link
Contributor

@hyangah hyangah commented Sep 15, 2021

Please compile with go build -gcflags=all="-N -l" command for debugging.
https://golang.org/doc/gdb#Introduction
Or dlv debug will handle that for you.

@mahdi-hm
Copy link
Author

@mahdi-hm mahdi-hm commented Sep 15, 2021

Please compile with go build -gcflags=all="-N -l" command for debugging.
https://golang.org/doc/gdb#Introduction
Or dlv debug will handle that for you.

Thanks that worked for delve but actually we are working on different debugger project in IBM zOS and this issue pops up. Is there any reason that normal build creates this issue?

@hyangah
Copy link
Contributor

@hyangah hyangah commented Sep 16, 2021

Is there any reason that normal build creates this issue?
Maybe missing info during registerization/optimization?
cc @thanm

@randall77
Copy link
Contributor

@randall77 randall77 commented Sep 16, 2021

My guess is the length gets spilled to a stack location, which is where Delve thinks the value lives.
But at the breakpoint involved, the length has been loaded into a register, incremented, and not stored back to the stack location.

I'm not sure what the state of our dwarf info is for optimized code. Do we emit dwarf entries for things that live in registers?

@thanm
Copy link
Contributor

@thanm thanm commented Sep 16, 2021

@randall77 we do emit DWARF entries for things that live in registers, so in theory a correct debug location should be possible even if different parts of the slice are in registers/mem. With that said, getting the locations right 100% of the time is a difficult problem.

I'll take a closer look at the code+DWARF and see if I can see anything useful.

@thanm thanm self-assigned this Sep 16, 2021
@thanm
Copy link
Contributor

@thanm thanm commented Sep 16, 2021

I looked at the variable locations being emitted for "cards". They are pretty clearly damaged/incorrect, but it is hard to see exactly what the root cause is. The DWARF variable DIE looks like

 <2><78913>: Abbrev Number: 11 (DW_TAG_variable)
    <78914>   DW_AT_name        : cards
    <7891a>   DW_AT_decl_line   : 9
    <7891b>   DW_AT_type        : <0x68e50>
    <7891f>   DW_AT_location    : 0x8f2f9 (location list)

and the location list is

    0008f2f9 ffffffffffffffff 000000000047e240 (base address)
    0008f309 000000000047e3c8 000000000047e3cb (DW_OP_fbreg: -176; DW_OP_piece: 8; DW_OP_fbreg: -224; DW_OP_piece: 8; DW_OP_fbreg: -216; DW_OP_piece: 8)
    0008f32a 000000000047e3cb 000000000047e3f6 (DW_OP_reg4 (rsi); DW_OP_piece: 8; DW_OP_reg3 (rbx); DW_OP_piece: 8; DW_OP_reg2 (rcx); DW_OP_piece: 8)
    0008f345 000000000047e3f6 000000000047e42d (DW_OP_fbreg: -176; DW_OP_piece: 8; DW_OP_fbreg: -224; DW_OP_piece: 8; DW_OP_fbreg: -216; DW_OP_piece: 8)
    0008f366 000000000047e42d 000000000047e458 (DW_OP_reg4 (rsi); DW_OP_piece: 8; DW_OP_fbreg: -224; DW_OP_piece: 8; DW_OP_reg2 (rcx); DW_OP_piece: 8)
    0008f383 000000000047e458 000000000047e52a (DW_OP_fbreg: -176; DW_OP_piece: 8; DW_OP_fbreg: -224; DW_OP_piece: 8; DW_OP_fbreg: -216; DW_OP_piece: 8)
    0008f3a4 <End of list>

From looking at the locations above it is clear that the location-tracking code has detected that the variable is partially in memory/registers at various points in the procedure, but it is clearly getting the location wrong for the epilog. The code before the return looks like

  47e505:	mov    %rdx,%rax
  47e508:	mov    %rsi,%rbx
  47e50b:	mov    %rdi,%rcx
  47e50e:	mov    0x118(%rsp),%rbp
  47e516:	add    $0x120,%rsp
  47e51d:	ret    

So the correct location should be rdx/rsi/rdi, but that is obviously not happening. I'll add this to my collection of things to look at for future improvements, time permitting.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

None yet
5 participants