Debugger: invalid frame; invalid return values

[juliandroid]

Gogland (1.0 Preview) 1.0 EAP
Build #GO-163.12024.32, built on February 10, 2017
Gogland EAP User
Expiration date: May 11, 2017
JRE: 1.8.0_112-release-b726 amd64
JVM: OpenJDK 64-Bit Server VM by JetBrains s.r.o
go version go1.8 linux/amd64
Linux hostn 4.10.2-1-ARCH #1 SMP PREEMPT Mon Mar 13 17:13:41 CET 2017 x86_64 GNU/Linux

• What are you trying to do?
  Set a breakpoint at line "43: return". Run debugger. Inspect method's return values. Step out to the caller. Follow the code.

• What happens?
  Option 1) Step out (invalid frame comes). Step out again. Return values are lost (n and err). From this point debugging is pointless.
  Option 2) Step over, instead - it doesn't work correctly. Jumps at wrong position (basically don't stop at the caller's line).

Code sample:

package main

import (
	"io"
	"io/ioutil"
	"log"
	"net/rpc"
	"os"
	"strings"
	"time"

	"github.com/powerman/rpc-codec/jsonrpc2"
)

type ExampleSvc struct{}

func (*ExampleSvc) MapLen(m map[string]string, res *int) error {
	*res = len(m)
	return nil
}

const json = `{"jsonrpc":"2.0","id":0,"method":"ExampleSvc.MapLen","params":{"a":"10","b":"20"}}`

type Reader struct {
	r io.Reader
}

func (r *Reader) Read(p []byte) (n int, err error) {
	n, err = r.r.Read(p)

	sr, ok := r.r.(*strings.Reader)
	if !ok {
		panic("Unexpected Reader!")
	}

	if n > 1 {
		sr.UnreadByte()
		p[n] = '\x00'
		n--
	}

	log.Println("Read:", n, err)
	return
}

func main() {
	s := rpc.NewServer()
	s.Register(&ExampleSvc{})

	s.ServeRequest(jsonrpc2.NewServerCodec(struct {
		io.Reader
		io.Writer
		io.Closer
	}{
		Reader: &Reader{strings.NewReader(json)},
		Writer: os.Stdout,
		Closer: ioutil.NopCloser(nil),
	}, nil))
	time.Sleep(100 * time.Millisecond)
}

Or include a screenshot / video of the issue.

[dlsniper]

@derekparker / @aarzilli is this a known one? Should I open an issue against delve? Thank you.

[aarzilli]

open an issue.

[juliandroid]

On the first screenshot, the "n" value is correctly reported to 82. After Step Out (screenshot 2) the "n" value is bogus. "err" is not reported at all !!!

If you follow the second option, i.e. to Step Over at the "return" line instead of Step Out, the debugger stops again, but at line 31: sr, ok := r.r.(*strings.Reader)
for unknown reason.

Sometimes, If I just hit twice "Resume Program" twice (for each stop at the "return" line) I get crash with the following error:

null
java.lang.NullPointerException
at gnu.trove.TObjectLongHashMap.put(TObjectLongHashMap.java:142)
at com.intellij.xdebugger.impl.ui.tree.nodes.XValueNodeImpl$1.computed(XValueNodeImpl.java:145)
at com.goide.dlv.DlvXValue$3.run(DlvXValue.java:164)
at com.intellij.openapi.application.impl.ApplicationImpl.runReadAction(ApplicationImpl.java:884)
at com.goide.dlv.DlvXValue.a(DlvXValue.java:187)
at com.intellij.openapi.application.impl.ApplicationImpl$2.run(ApplicationImpl.java:309)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)

Last thing, that I've noticed (see my first screenshot), at line 31, is that the reported value "ok: false" is and never should be false. This line always succeed (which is confirmed by the fact that the message "panic("Unexpected Reader!")" is never displayed).

[ignatov]

@juliandroid NullPointerException is a platform issue, already fixed in 2017.1.

[aarzilli]

1. The thing that appears as "invalid frame" in gogland is actually a valid frame, just weird because it references autogenerated code, dlv will report it correctly as:

 1  0x00000000006c87d0 in go.(*struct { io.Reader; io.Writer; io.Closer }).Read
    at <autogenerated>:1

gogland should do the same, imho

2. If you add a panic right before that return statement the stacktrace that go prints is the same:

goroutine 1 [running]:
main.(*Reader).Read(0xc420112100, 0xc42012a000, 0x200, 0x200, 0xe, 0x7f3b39299278, 0x450390)
	/home/a/temp/invalidstackframe.go:43 +0x264
go.(*struct { io.Reader; io.Writer; io.Closer }).Read(0xc4201105d0, 0xc42012a000, 0x200, 0x200, 0x0, 0x200, 0x1)
	<autogenerated>:1 +0x6b
encoding/json.(*Decoder).refill(0xc420126000, 0x20, 0x18)
	/usr/local/go18/src/encoding/json/stream.go:152 +0x109

3. Once you are stopped on the return if you stepout once (or next once) you end up in the autogenerated code, we don't have line information and the debug_info entry for the function is empty so there's really nothing we can show for that code, I don't know why gogland is showing anything here, it shouldn't and it's not getting it from delve. One other stepout or next will get you back to user code where n and err are visible, assuming you didn't fall foul of cmd/go: -gcflags and cached packages golang/go#19340 (which you probably did).

[aarzilli]

we don't have line information and the debug_info entry for the function is empty so there's really nothing we can show for that code, I don't know why gogland is showing anything here, it shouldn't and it's not getting it from delve

I take this back, we do have a debug_info entry for the autogenerated function and it does have n and err as variables, the reason that n is not updated after a stepout is because the return value hasn't been copied into it yet.

[aarzilli]

PPS. there's an additional problem with where the breakpoint for line :43 is placed, the compiler misnumbers the instructions and the breakpoint ends up at the top of the function. There has been work over line number assignment in the development branch of go and this problem seems fixed on tip.

[juliandroid]

One other stepout or next will get you back to user code where n and err are visible, assuming you didn't fall foul of golang/go#19340

Not sure, but currently what I see in Gogland is that after stopping at line 43 and hitting:
Step Out, Step Out again and then Step Over (i.e going to line 153: dec.buf = dec.buf[0 : len(dec.buf)+n]) then I still don't have valid "n" and "err" .
Hit new Step Out and then Step Over (new you are at line 128: err = dec.refill()), n is still missing at Variables window, although the "n" variable now a totally new one :)
Currently the debugging is impossible :)