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: cache panic inheriting destroyed handle #41415

Closed
findleyr opened this issue Sep 16, 2020 · 9 comments
Closed

x/tools/gopls: cache panic inheriting destroyed handle #41415

findleyr opened this issue Sep 16, 2020 · 9 comments
Labels
FrozenDueToAge gopls Issues related to the Go language server, gopls. Tools This label describes issues relating to any tools in the x/tools repository.
Projects
gopls on-deck
Milestone
gopls/v0.7.4

Comments

@findleyr
Copy link
Contributor

Just got a concerning panic from the generational cache: panic: inheriting destroyed handle "bf90d6e270fcf98967555c6a0aba69594d7e60ab389281fa22a86d7efcbcbe3e" into generation v12/1291

This is running in daemon mode. I'm sure this is less likely to occur in standalone mode.

Logs were not revealing, but I have them if we think they'd be useful.

2020/09/15 15:44:53 Gopls daemon: listening on tcp network, address :8091...         
2020/09/15 15:45:52 Session 1: connected                                                                                                          
2020/09/15 15:45:52 Session 1: got handshake. Logfile: "/tmp/nvimX6R61U/gopls-1993215.log", Debug addr: ""
2020/09/15 16:06:28 Session 1: exited                                                                                                             
2020/09/15 16:06:42 Session 2: connected                                                                                                          
2020/09/15 16:06:42 Session 2: got handshake. Logfile: "/tmp/nvim5tEFoD/gopls-2013699.log", Debug addr: ""
2020/09/15 21:31:10 Session 3: connected                                                                                                          
2020/09/15 21:31:10 Session 3: got handshake. Logfile: "/tmp/nvimlzMyB4/gopls-2211163.log", Debug addr: ""                            
2020/09/15 21:35:04 Session 3: exited                                                                                                             
2020/09/15 21:35:05 Session 4: connected                                                                                                          
2020/09/15 21:35:05 Session 4: got handshake. Logfile: "/tmp/nvimlzMyB4/gopls-2216889.log", Debug addr: ""
2020/09/15 21:38:24 Session 4: exited                                                                                                             
2020/09/15 21:40:30 Session 5: connected                                                                                                          
2020/09/15 21:40:30 Session 5: got handshake. Logfile: "/tmp/nvimISaKHd/gopls-2220366.log", Debug addr: ""
2020/09/15 21:49:27 Session 5: exited                                                                                                             
2020/09/15 21:51:25 Session 6: connected                                 
2020/09/15 21:51:25 Session 6: got handshake. Logfile: "/tmp/nvimoERVLy/gopls-2263969.log", Debug addr: ""
2020/09/15 22:04:31 Session 6: exited                                    
2020/09/15 22:07:49 Session 7: connected                                 
2020/09/15 22:07:49 Session 7: got handshake. Logfile: "/tmp/nvimwdMZ3S/gopls-2323381.log", Debug addr: ""
2020/09/15 22:08:35 Session 7: exited                                    
2020/09/15 22:09:37 Session 8: connected                                 
2020/09/15 22:09:37 Session 8: got handshake. Logfile: "/tmp/nvimMILvvC/gopls-2325071.log", Debug addr: ""
2020/09/15 23:11:39 Session 8: exited 
panic: inheriting destroyed handle "bf90d6e270fcf98967555c6a0aba69594d7e60ab389281fa22a86d7efcbcbe3e" into generation v12/1291
                                                                                                                                                  
goroutine 1194992 [running]:                                            
golang.org/x/tools/internal/memoize.(*Generation).Inherit(0xc0c1c22db0, 0xc034d75ce0)       
        /usr/local/google/home/rfindley/src/tools/internal/memoize/memoize.go:231 +0x1a5                                              
golang.org/x/tools/internal/lsp/cache.(*snapshot).clone(0xc03563e0b0, 0x103b300, 0xc06f7be0c0, 0xc0bcfe4a80, 0xc06f7be000, 0x0)
        /usr/local/google/home/rfindley/src/tools/internal/lsp/cache/snapshot.go:1018 +0x1be7                                             
golang.org/x/tools/internal/lsp/cache.(*View).invalidateContent(0xc000324380, 0x103ad00, 0xc0b29f8090, 0xc0bcfe4a80, 0x0, 0x0, 0x0, 0x0)
        /usr/local/google/home/rfindley/src/tools/internal/lsp/cache/view.go:777 +0x14c                                                           
golang.org/x/tools/internal/lsp/cache.(*Session).DidModifyFiles(0xc046dac540, 0x103ad00, 0xc0b29f8090, 0xc0297c04b0, 0x1, 0x1, 0xc09db740f0, 0xc02
b8d3800, 0xb, 0x10, ...)                                                                                                                          
        /usr/local/google/home/rfindley/src/tools/internal/lsp/cache/session.go:517 +0x8cc
golang.org/x/tools/internal/lsp.(*Server).didModifyFiles(0xc03c669540, 0x103ad00, 0xc0b29f8090, 0xc0297c04b0, 0x1, 0x1, 0x4, 0x0, 0x0)
        /usr/local/google/home/rfindley/src/tools/internal/lsp/text_synchronization.go:191 +0x125
golang.org/x/tools/internal/lsp.(*Server).didClose(0xc03c669540, 0x103ad00, 0xc0b29f8090, 0xc026efb730, 0x0, 0xc03563e9a0)
        /usr/local/google/home/rfindley/src/tools/internal/lsp/text_synchronization.go:168 +0x134
golang.org/x/tools/internal/lsp.(*Server).DidClose(0xc03c669540, 0x103ad00, 0xc0b29f8090, 0xc026efb730, 0xc026efb730, 0x0)
        /usr/local/google/home/rfindley/src/tools/internal/lsp/server_gen.go:52 +0x49
golang.org/x/tools/internal/lsp/protocol.serverDispatch(0x103ad00, 0xc0b29f8090, 0x104e880, 0xc03c669540, 0xc0bcfe49f0, 0x7fc9c0ae4a98, 0xc0b29f80
30, 0x0, 0x1026f40, 0xc03563e840)                                                                                                                 
        /usr/local/google/home/rfindley/src/tools/internal/lsp/protocol/tsserver.go:127 +0x28c7
golang.org/x/tools/internal/lsp/protocol.ServerHandler.func1(0x103ad00, 0xc0b29f8090, 0xc0bcfe49f0, 0x7fc9c0ae4a98, 0xc0b29f8030, 0x18614338c55f, 
0x150a220)                                                               
        /usr/local/google/home/rfindley/src/tools/internal/lsp/protocol/protocol.go:63 +0xc5
golang.org/x/tools/internal/lsp/lsprpc.handshaker.func1(0x103ad00, 0xc0b29f8090, 0xc0bcfe49f0, 0x7fc9c0ae4a98, 0xc0b29f8030, 0x0, 0x0)
        /usr/local/google/home/rfindley/src/tools/internal/lsp/lsprpc/lsprpc.go:557 +0x452
golang.org/x/tools/internal/jsonrpc2.MustReplyHandler.func1(0x103ad00, 0xc0b29f8090, 0xc012f6a460, 0x7fc9c0ae4a98, 0xc0b29f8030, 0xc0529a4540, 0x1
c)                                                                                                                                                
        /usr/local/google/home/rfindley/src/tools/internal/jsonrpc2/handler.go:35 +0xcf
golang.org/x/tools/internal/jsonrpc2.AsyncHandler.func1.2(0xc0b0a04000, 0xc0b29f8b10, 0xc0715ee6d0, 0x103ad00, 0xc0b29f8090, 0xc012f6a460, 0x7fc9c
0ae4a98, 0xc0b29f8030)                                                                                                                            
        /usr/local/google/home/rfindley/src/tools/internal/jsonrpc2/handler.go:103 +0x86
created by golang.org/x/tools/internal/jsonrpc2.AsyncHandler.func1       
        /usr/local/google/home/rfindley/src/tools/internal/jsonrpc2/handler.go:100 +0x173

Perhaps a reasonable action would be to improve the error message above to make this easier to diagnose.

cc @heschik @stamblerre
@gopherbot gopherbot added Tools This label describes issues relating to any tools in the x/tools repository. gopls Issues related to the Go language server, gopls. labels Sep 16, 2020
@gopherbot gopherbot added this to the Unreleased milestone Sep 16, 2020
@heschi
Copy link
Contributor

heschi commented Sep 16, 2020

I'm very open to suggestions on how to improve the error message, but this is fundamentally very tricky stuff :-/

Did this happen as you exited an editor? My best guess is that we tried to deal with a DidClose on a view that had been shut down. That's a client bug, but probably one we should guard against.

@findleyr
Copy link
Contributor Author

I'm very open to suggestions on how to improve the error message

Any metadata describing the handle would be a start. Given how few distinct handles we have, perhaps this could be threaded through.

From our analysis, we think this was in the s.packages loop of snapshot.clone.

@gopherbot
Copy link

Change https://golang.org/cl/255357 mentions this issue: internal/memoize: show key type in panics

gopherbot pushed a commit to golang/tools that referenced this issue Sep 16, 2020
@heschi
internal/memoize: show key type in panics
f128e62 
gopls uses a lot of keys that are just strings, which print without any
type information. Include the type of the key explicitly.

Updates golang/go#41415.

Change-Id: I01cfc685184e7b44c1f562b6536f173da5ae4830
Reviewed-on: https://go-review.googlesource.com/c/tools/+/255357
Trust: Heschi Kreinick <heschi@google.com>
Reviewed-by: Robert Findley <rfindley@google.com>
@stamblerre stamblerre modified the milestones: Unreleased, gopls/v1.0.0 Sep 20, 2020
@stamblerre stamblerre added the WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. label Oct 12, 2020
@stamblerre stamblerre added this to In progress in vscode-go: gopls by default Nov 10, 2020
@gopherbot
Copy link

Timed out in state WaitingForInfo. Closing.

(I am just a bot, though. Please speak up if this is a mistake or you have the requested information.)

vscode-go: gopls by default automation moved this from In progress to Done Nov 12, 2020
@stamblerre
Copy link
Contributor

Based on the fact that we haven't seen this in a month (as far as I know), I think I'm ok with leaving it closed.
@findleyr, @heschik -- do you agree?

@stamblerre stamblerre removed this from the gopls/vscode-go milestone Nov 12, 2020
@findleyr
Copy link
Contributor Author

Agree. I haven't noticed this since (though I have spent less time looking for panics lately). Since we don't have anything actionable here, let's leave it closed until it reoccurs.

@findleyr
Copy link
Contributor Author

FWIW, I just saw this again:

2020/11/17 09:32:29 Session 4: connected
2020/11/17 09:32:29 Session 4: got handshake. Logfile: "/tmp/nvimwRxEYa/gopls-2489451.log", Debug addr: ""
2020/11/17 11:08:11 Session 5: connected
2020/11/17 11:08:11 Session 5: got handshake. Logfile: "/tmp/nvimukRLZW/gopls-2569809.log", Debug addr: ""
2020/11/17 11:10:48 Session 5: exited
2020/11/17 11:13:28 Session 6: connected
2020/11/17 11:13:28 Session 6: got handshake. Logfile: "/tmp/nvimasUFNN/gopls-2574344.log", Debug addr: ""
2020/11/17 17:09:58 Session 4: exited
panic: inheriting destroyed handle "d5da8f7e81ef9f43dd0a5b7f23c8b1d92cc8b408fa28b81acf6aba6979502a1e" (type cache.packageHandleKey) into generation v5/257

goroutine 3299224 [running]:
golang.org/x/tools/internal/memoize.(*Generation).Inherit(0xc05aefee70, 0xc0628464b8, 0x1, 0x1)
        /usr/local/google/home/rfindley/src/tools/internal/memoize/memoize.go:242 +0x225
golang.org/x/tools/internal/lsp/cache.(*snapshot).clone(0xc043c2fa00, 0x105dc60, 0xc08383ebc0, 0xc07c81a6c0, 0x59bb00, 0x0, 0x0)
        /usr/local/google/home/rfindley/src/tools/internal/lsp/cache/snapshot.go:1193 +0x1875
golang.org/x/tools/internal/lsp/cache.(*View).invalidateContent(0xc0001f2780, 0x105d660, 0xc07612e210, 0xc07c81a6c0, 0x0, 0x0, 0x0, 0x0)
        /usr/local/google/home/rfindley/src/tools/internal/lsp/cache/view.go:578 +0x165
golang.org/x/tools/internal/lsp/cache.(*Session).DidModifyFiles(0xc0004770a0, 0x105d660, 0xc07612e210, 0xc056b88500, 0x1, 0x1, 0xc062847278, 0x559f70, 0xe37c80, 0xc0794ad3e0, ...)
        /usr/local/google/home/rfindley/src/tools/internal/lsp/cache/session.go:488 +0x27e
golang.org/x/tools/internal/lsp.(*Server).didModifyFiles(0xc00018a300, 0x105d660, 0xc07612e210, 0xc056b88500, 0x1, 0x1, 0x4, 0x0, 0x0)
        /usr/local/google/home/rfindley/src/tools/internal/lsp/text_synchronization.go:189 +0x105
golang.org/x/tools/internal/lsp.(*Server).didClose(0xc00018a300, 0x105d660, 0xc07612e210, 0xc0794ad3e0, 0x0, 0xc03c087810)
        /usr/local/google/home/rfindley/src/tools/internal/lsp/text_synchronization.go:166 +0x134
golang.org/x/tools/internal/lsp.(*Server).DidClose(0xc00018a300, 0x105d660, 0xc07612e210, 0xc0794ad3e0, 0xc0794ad3e0, 0x0)
        /usr/local/google/home/rfindley/src/tools/internal/lsp/server_gen.go:52 +0x49
golang.org/x/tools/internal/lsp/protocol.serverDispatch(0x105d660, 0xc07612e210, 0x10716a0, 0xc00018a300, 0xc07c81a630, 0x7fd4244a01d8, 0xc07612e1b0, 0x0, 0x1049560, 0xc03c0876b0)
        /usr/local/google/home/rfindley/src/tools/internal/lsp/protocol/tsserver.go:126 +0x2d02
golang.org/x/tools/internal/lsp/protocol.ServerHandler.func1(0x105d660, 0xc07612e210, 0xc07c81a630, 0x7fd4244a01d8, 0xc07612e1b0, 0x4976922dddb7, 0x15387e0)
        /usr/local/google/home/rfindley/src/tools/internal/lsp/protocol/protocol.go:63 +0xc5
golang.org/x/tools/internal/lsp/lsprpc.handshaker.func1(0x105d660, 0xc07612e210, 0xc07c81a630, 0x7fd4244a01d8, 0xc07612e1b0, 0x0, 0x0)
        /usr/local/google/home/rfindley/src/tools/internal/lsp/lsprpc/lsprpc.go:559 +0x452
golang.org/x/tools/internal/jsonrpc2.MustReplyHandler.func1(0x105d660, 0xc07612e210, 0xc056e268a0, 0x7fd4244a01d8, 0xc07612e1b0, 0x0, 0x5bc341)
        /usr/local/google/home/rfindley/src/tools/internal/jsonrpc2/handler.go:35 +0xcf
golang.org/x/tools/internal/jsonrpc2.AsyncHandler.func1.2(0xc08c2c4000, 0xc07612ecc0, 0xc043a3e770, 0x105d660, 0xc07612e210, 0xc056e268a0, 0x7fd4244a01d8, 0xc07612e1b0)
        /usr/local/google/home/rfindley/src/tools/internal/jsonrpc2/handler.go:103 +0x86
created by golang.org/x/tools/internal/jsonrpc2.AsyncHandler.func1
        /usr/local/google/home/rfindley/src/tools/internal/jsonrpc2/handler.go:100 +0x173

Same symptoms as last time. Unfortunately nvim deleted the logs, since they were in the nvim tmpdir...

@heschi heschi reopened this Nov 19, 2020
@heschi
Copy link
Contributor

heschi commented Nov 19, 2020

Also from DidClose. I still suspect this has to do with editor shutdown but still would need a log to investigate.

@stamblerre stamblerre added this to Needs Triage in vscode-go: gopls by default Nov 25, 2020
@stamblerre stamblerre removed the WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. label Nov 25, 2020
@stamblerre stamblerre removed this from Needs Triage in vscode-go: gopls by default Nov 25, 2020
@stamblerre stamblerre removed this from the gopls/unplanned milestone Dec 18, 2020
@stamblerre stamblerre added this to the gopls/v1.0.0 milestone Dec 18, 2020
@stamblerre stamblerre added this to To Do in gopls on-deck Feb 28, 2021
@findleyr
Copy link
Contributor Author

I believe this was fixed by CL 367675.

gopls on-deck automation moved this from To Do to Done Dec 21, 2021
@findleyr findleyr modified the milestones: gopls/later, gopls/v0.7.4 Jul 1, 2022
@golang golang locked and limited conversation to collaborators Jul 1, 2023
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. Tools This label describes issues relating to any tools in the x/tools repository.
Projects
No open projects
gopls on-deck
Done
Milestone
gopls/v0.7.4
Development

No branches or pull requests
4 participants
@stamblerre @gopherbot @heschi @findleyr