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

x/tools/gopls: CL 186297 appears to break -rpc.trace log output #33348

Closed
myitcv opened this issue Jul 29, 2019 · 6 comments
Closed

x/tools/gopls: CL 186297 appears to break -rpc.trace log output #33348

myitcv opened this issue Jul 29, 2019 · 6 comments

Comments

@myitcv
Copy link
Member

@myitcv myitcv commented Jul 29, 2019

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

$ go version
go version go1.12.7 linux/amd64
$ go list -m golang.org/x/tools
golang.org/x/tools v0.0.0-20190716194406-502543d2eda9
$ go list -m golang.org/x/tools/gopls
golang.org/x/tools/gopls v0.1.4-0.20190716194406-502543d2eda9

Does this issue reproduce with the latest release?

Yes

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

go env Output
$ go env
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/myitcv/.cache/go-build"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/home/myitcv/gostuff"
GOPROXY=""
GORACE=""
GOROOT="/home/myitcv/gos"
GOTMPDIR=""
GOTOOLDIR="/home/myitcv/gos/pkg/tool/linux_amd64"
GCCGO="gccgo"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/home/myitcv/gostuff/src/github.com/myitcv/govim/go.mod"
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-build039610249=/tmp/go-build -gno-record-gcc-switches"

What did you do?

Somewhere in/around CL 186297 the output from -rpc.trace got broken.

Before:

[Trace - 4:18:52 PM] Sending notification 'initialized' in 70ms.
Params: {}


[Trace - 4:18:52 PM] Sending notification 'textDocument/didOpen' in 45ms.
Params: {"textDocument":{"uri":"file:///tmp/go-test-script854779031/script-function_hover/main.go","languageId":"go","version":0,"text":"package main\n\nimport \"fmt\"\n


[Trace - 4:18:52 PM] Received notification 'window/logMessage' in 0ms.
Params: {"type":4,"message":"packages.Load: found 1 packages"}


[Trace - 4:18:52 PM] Received notification 'window/logMessage' in 0ms.
Params: {"type":4,"message":"packages.Load: package mod.com with files [/tmp/go-test-script854779031/script-function_hover/main.go]"}


[Trace - 4:18:52 PM] Received response 'textDocument/hover - (2)' in 0ms.
Params: {"contents":{"kind":"plaintext","value":"func fmt.Println(a ...interface{}) (n int, err error)"},"range":{"start":{"line":5,"character":5},"end":{"line":5,"chara


[Trace - 4:18:52 PM] Sending notification 'textDocument/hover' in 277ms.
Params: {"textDocument":{"uri":"file:///tmp/go-test-script854779031/script-function_hover/main.go"},"position":{"line":5,"character":5}}


[Trace - 4:18:52 PM] Received notification 'textDocument/publishDiagnostics' in 0ms.
Params: {"uri":"file:///tmp/go-test-script854779031/script-function_hover/main.go","diagnostics":[]}


[Trace - 4:18:52 PM] Received response 'shutdown - (3)' in 0ms.
Params: {}


[Trace - 4:18:52 PM] Sending notification 'shutdown' in 0ms.
Params: {}

After:

[Trace - 4:17:39 PM] Sending notification '???' in 9223372036854ms.
Params: {}


[Trace - 4:17:39 PM] Sending notification '???' in 9223372036854ms.
Params: {}


[Trace - 4:17:39 PM] Sending notification '???' in 9223372036854ms.
Params: {}


[Trace - 4:17:39 PM] Sending notification '???' in 9223372036854ms.
Params: {}


[Trace - 4:17:39 PM] Sending notification '???' in 9223372036854ms.
Params: {}


[Trace - 4:17:39 PM] Received response '??? - (2)' in 0ms.
Params: {"contents":{"kind":"plaintext","value":"func fmt.Println(a ...interface{}) (n int, err error)"},"range":{"start":{"line":5,"character":5},"end":{"line":5,"character":12}}}


[Trace - 4:17:39 PM] Sending notification '???' in 9223372036854ms.
Params: {}


[Trace - 4:17:39 PM] Sending notification '???' in 9223372036854ms.
Params: {}


[Trace - 4:17:39 PM] Received response '??? - (3)' in 0ms.
Params: {}


[Trace - 4:17:39 PM] Sending notification '???' in 9223372036854ms.
Params: {}

What did you expect to see?

The "before" log output

What did you see instead?

The "after" log output


cc @stamblerre @ianthehat

@gopherbot gopherbot added this to the Unreleased milestone Jul 29, 2019
@myitcv myitcv changed the title x/tools/cmd/gopls: CL 186297 appears to break -rpc.trace log output x/tools/gopls: CL 186297 appears to break -rpc.trace log output Jul 29, 2019
@ianthehat

This comment has been minimized.

Copy link

@ianthehat ianthehat commented Jul 29, 2019

The ??? is used as the method name when it is not stored on the context, but I have no idea why it would not be.
I did see a similar error when I was changing all the telementry code, but I fixed it, and saw working logs before I turned them off again.

@ianthehat

This comment has been minimized.

Copy link

@ianthehat ianthehat commented Jul 29, 2019

Also, I just checked and it is working for me at master.
Maybe try with debug pages turned on, there might be some weird interaction where the telementry stuff turns off too much without that?

@myitcv

This comment has been minimized.

Copy link
Member Author

@myitcv myitcv commented Jul 29, 2019

I just tried starting gopls via:

gopls -rpc.trace -logfile /tmp/gopls_log serve --debug=localhost:6060

and saw the same thing in /tmp/gopls_log, i.e. the ???. So for me this appears broken.

@myitcv

This comment has been minimized.

Copy link
Member Author

@myitcv myitcv commented Jul 30, 2019

Strange; this is working in some situations, but not others. I'll try and "bisect" what's causing things to fail.

@stamblerre

This comment has been minimized.

Copy link
Contributor

@stamblerre stamblerre commented Aug 5, 2019

@myitcv: Have you continued to encounter this issue?

@myitcv

This comment has been minimized.

Copy link
Member Author

@myitcv myitcv commented Aug 12, 2019

Very strange. At least with 6d4652c779c4 I'm not seeing this. Will close for now.

@myitcv myitcv closed this Aug 12, 2019
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
4 participants
You can’t perform that action at this time.