🩻
VSCodeでgoplsの挙動をキャプチャする方法
これは
GoのLanguage ServerであるgoplsをVSCodeからデバッグするための情報を書いた記事。
VSCodeでGoのコーディングをしていると、定義ジャンプや入力補完に遅延が発生するトラブルが発生することがある。VSCodeのGo公式拡張機能は、内部でgoplsを使用しているためボトルネックとなっていることが多い。そのボトルネックをVSCode上で特定する方法を記載する。
結論
何か問題が発生したときは、VSCodeを再起動すること。
goplsはディスク上のインデックスとメモリ内キャッシュのハイブリッド活用だが、大体の原因はメモリ内のキャッシュ状態がおかしいことに起因するため、手っ取り早くVSCodeを再起動してメモリを解放してみよう。
デバッグ情報
ここからは、解決を急いておらずgoplsの内部動作の様子を知りたい人向けに、VSCodeのGo拡張機能のバックエンドで動作するgoplsのデバッグログを確認する方法を記載する。
VSCodeのSetting.jsonを開き、以下の設定をする。
setting.json
"go.languageServerFlags": [
"-rpc.trace", // LSPのトレースログを出力
"serve",
"--debug=localhost:6060", // デバッグ情報へのアクセスを有効にする
],
"go.trace.server": "verbose", // VSCodeとLSPサーバー間のやり取りを詳細にログに記録
goplsの起動オプションをvscodeのsetting.jsonで指定している。
やっているのはコメントの通り。6060番ポートを指定してgoplsのデバッグサーバーを開いている。
するとlocalhostの6060番ポートで、次のような goplsのデバッグ画面が表示される。
具体例
ここからは、具体例として、入力補完が行われる場合にどのような処理がgoplsで発生するかをざっくりとトレースしていく。
以下のようなサンプルコードで、fmt.Printを期待して、「fmt.Pri」と入力したときのことを考える。
VSCodeとgopls間のLSP(Language Server Protocol)通信をキャプチャするには、[RPC]タブを開く。
すると、method（補完、定義参照などのメッセージの種類）ごとにstatsが表示される。
さらに、[trace]を開くと、それぞれのmethodの直近のtraceを見ることができる。
次に示すのは、以下のようなサンプルコードで、fmt.Priと入力したときのログ(表示されるパスは個人によって異なる)。
00:06:37.898 end textDocument/completion (+102.553167ms) method="textDocument/completion" direction="in" id="#223"
00:06:37.898 event (+102.551917ms) label= status.code="OK"
00:06:37.795 start queued
00:06:37.796 end queued (+204.5µs)
00:06:37.796 start lsp.Server.completion URI=file:///Users/sho-hata/go/src/github.com/sho-hata/tparagen/testdata/t/t_test.go
00:06:37.896 end lsp.Server.completion (+100.659292ms) URI=file:///Users/sho-hata/go/src/github.com/sho-hata/tparagen/testdata/t/t_test.go
00:06:37.796 start completion.Completion
00:06:37.896 end completion.Completion (+100.596042ms)
00:06:37.796 start cache.forEachPackage packages=1
00:06:37.797 end cache.forEachPackage (+1.621167ms) packages=1
00:06:37.796 start cache.ParseGoSrc file="/Users/sho-hata/go/src/github.com/sho-hata/tparagen/testdata/t/t_test.go"
00:06:37.796 end cache.ParseGoSrc (+127.833µs) file="/Users/sho-hata/go/src/github.com/sho-hata/tparagen/testdata/t/t_test.go"
00:06:37.797 start cache.typeCheckBatch.checkPackage package="github.com/sho-hata/tparagen/testdata/t [github.com/sho-hata/tparagen/testdata/t.test]"
00:06:37.797 end cache.typeCheckBatch.checkPackage (+429.042µs) package="github.com/sho-hata/tparagen/testdata/t [github.com/sho-hata/tparagen/testdata/t.test]"
00:06:37.797 start cache.importsState.runProcessEnvFunc
00:06:37.798 end cache.importsState.runProcessEnvFunc (+29.75µs)
00:06:37.798 start cache.ParseGoSrc file="/opt/homebrew/Cellar/go/1.22.1/libexec/src/fmt/print.go"
00:06:37.799 end cache.ParseGoSrc (+816.584µs) file="/opt/homebrew/Cellar/go/1.22.1/libexec/src/fmt/print.go"
00:06:37.799 start cache.importsState.runProcessEnvFunc
00:06:37.896 end cache.importsState.runProcessEnvFunc (+96.938167ms)
00:06:37.799 start imports.ModuleResolver.scan
00:06:37.896 end imports.ModuleResolver.scan (+96.825208ms)
ここで、
start cache.ParseGoSrc file="/opt/homebrew/Cellar/go/1.22.1/libexec/src/fmt/print.go"
とある。
「fmt.」から推測された関数が属するfmtパッケージのprint.goファイルに存在するシンボルをgoplsのキャッシュ層にキャッシュしていることがわかる。
そして、タブボタンを押下し、「fmt.Print()」という推測結果を補完する。
すると、go.modや対象のファイルといったキャッシュが更新され、さらに、Diagnostics（コードの解析結果としてエラーや警告などをエディタ上にハイライトする機能）を更新するリクエストが飛んでいることがわかる。
0:32:18.666 start Server.publishDiagnostics
00:32:18.666 end Server.publishDiagnostics (+152.083µs)
00:32:18.666 start textDocument/publishDiagnostics method="textDocument/publishDiagnostics" direction="out"
00:32:18.666 end textDocument/publishDiagnostics (+112.708µs) method="textDocument/publishDiagnostics" direction="out"
00:32:18.666 event (+21.814208ms) label= status.code="OK"
00:32:19.647 start Server.diagnose snapshot=81 directory=file:///Users/sho-hata/go/src/github.com/sho-hata/tparagen
00:32:19.672 end Server.diagnose (+24.787042ms) snapshot=81 directory=file:///Users/sho-hata/go/src/github.com/sho-hata/tparagen
00:32:19.647 start work.Diagnostics snapshot=81 directory=file:///Users/sho-hata/go/src/github.com/sho-hata/tparagen
00:32:19.647 end work.Diagnostics (+20.542µs) snapshot=81 directory=file:///Users/sho-hata/go/src/github.com/sho-hata/tparagen
00:32:19.647 start mod.Diagnostics snapshot=81 directory=file:///Users/sho-hata/go/src/github.com/sho-hata/tparagen
00:32:19.647 end mod.Diagnostics (+60.209µs) snapshot=81 directory=file:///Users/sho-hata/go/src/github.com/sho-hata/tparagen
00:32:19.647 start mod.UpgradeDiagnostics snapshot=81 directory=file:///Users/sho-hata/go/src/github.com/sho-hata/tparagen
00:32:19.647 end mod.UpgradeDiagnostics (+97.958µs) snapshot=81 directory=file:///Users/sho-hata/go/src/github.com/sho-hata/tparagen
00:32:19.647 start mod.VulnerabilityDiagnostics snapshot=81 directory=file:///Users/sho-hata/go/src/github.com/sho-hata/tparagen
00:32:19.647 end mod.VulnerabilityDiagnostics (+45.417µs) snapshot=81 directory=file:///Users/sho-hata/go/src/github.com/sho-hata/tparagen
00:32:19.648 start snapshot.Analyze package="github.com/sho-hata/tparagen/cmd/tparagen"
00:32:19.648 start cache.snapshot.PackageDiagnostics
00:32:19.648 start mod.Diagnostics snapshot=81 directory=file:///Users/sho-hata/go/src/github.com/sho-hata/tparagen
00:32:19.649 end mod.Diagnostics (+852.167µs) snapshot=81 directory=file:///Users/sho-hata/go/src/github.com/sho-hata/tparagen
00:32:19.649 start cache.snapshot.ModTidy
00:32:19.649 end cache.snapshot.ModTidy (+89.25µs)
00:32:19.649 end cache.snapshot.PackageDiagnostics (+1.15875ms)
00:32:19.648 start cache.forEachPackage packages=3
00:32:19.649 end cache.forEachPackage (+1.071667ms) packages=3
00:32:19.672 end snapshot.Analyze (+23.499166ms) package="github.com/sho-hata/tparagen/cmd/tparagen"
00:32:19.656 start cache.ParseGoSrc file="/Users/sho-hata/go/src/github.com/sho-hata/tparagen/cmd/tparagen/main.go"
00:32:19.656 end cache.ParseGoSrc (+260.041µs) file="/Users/sho-hata/go/src/github.com/sho-hata/tparagen/cmd/tparagen/main.go"
00:32:19.672 start Server.publishDiagnostics
00:32:19.672 end Server.publishDiagnostics (+25.667µs)
それでは良いGoコーディングの旅を。
参考
Discussion