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.

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

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
Labels
FrozenDueToAge gopls Issues related to the Go language server, gopls. WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided.
Milestone
Unreleased

Comments

@myitcv
Copy link
Member

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
@myitcv myitcv added NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. gopls Issues related to the Go language server, gopls. labels Jul 29, 2019
@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
Copy link

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

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

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

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 stamblerre added the WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. label Aug 5, 2019
@stamblerre
Copy link
Contributor

@myitcv: Have you continued to encounter this issue?

@stamblerre stamblerre removed the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Aug 6, 2019
@myitcv
Copy link
Member Author

myitcv commented Aug 12, 2019

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

@myitcv myitcv closed this as completed Aug 12, 2019
@golang golang locked and limited conversation to collaborators Aug 11, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge gopls Issues related to the Go language server, gopls. WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided.
Projects
None yet
Milestone
Unreleased
Development

No branches or pull requests
4 participants
@ianthehat @myitcv @stamblerre @gopherbot