2019-12-02 10:52:29 -07:00
|
|
|
# Replaying Logs
|
|
|
|
|
2019-12-10 10:11:53 -07:00
|
|
|
The LSP log replayer takes a log from a gopls session, starts up an instance of gopls,
|
2019-12-02 10:52:29 -07:00
|
|
|
and tries to replay the session. It produces a log from the replayed session and reports
|
|
|
|
some comparative statistics of the two logs.
|
|
|
|
|
|
|
|
```replay -log <logfile>```
|
|
|
|
|
|
|
|
The `logfile` should be the log produced by gopls. It will have a name like
|
|
|
|
`/tmp/gopls-89775` or, on a Mac, `$TMPDIR/gopls-29388`.
|
|
|
|
|
|
|
|
If `replay` cannot find a copy of gopls to execute, use `-cmd <path to gopls>`.
|
|
|
|
It looks in the same places where `go install` would put its output,
|
|
|
|
namely `$GOBIN/gopls`, `$GOPATH/bin/gopls`, `$HOME/go/bin/gopls`.
|
|
|
|
|
|
|
|
The log for the replayed session is saved in `/tmp/seen`.
|
|
|
|
|
2020-06-17 09:28:48 -06:00
|
|
|
There is also a boolean argument `-cmp` which compares the log file
|
2019-12-02 10:52:29 -07:00
|
|
|
with `/tmp/seen` without invoking gopls and rerunning the session.
|
|
|
|
|
|
|
|
The output is fairly cryptic, and generated by logging. Ideas for better output would be welcome.
|
|
|
|
Here's an example, with intermingled comments:
|
|
|
|
|
|
|
|
```
|
|
|
|
main.go:50: old 1856, hist:[10:177 30:1 100:0 300:3 1000:4 ]
|
|
|
|
```
|
|
|
|
This says that the original log had 1856 records in it. The histogram is
|
|
|
|
counting how long RPCs took, in milliseconds. In this case 177 took no more
|
|
|
|
than 10ms, and 4 took between 300ms and 1000ms.
|
|
|
|
```
|
|
|
|
main.go:53: calling mimic
|
|
|
|
main.go:293: mimic 1856
|
|
|
|
```
|
|
|
|
This is a reminder that it's replaying in a new session, with a log file
|
|
|
|
containing 1856 records
|
|
|
|
```
|
|
|
|
main.go:61: new 1846, hist:[10:181 30:1 100:1 300:1 1000:1 ]
|
|
|
|
```
|
|
|
|
The new session produced 1846 log records (that's 10 fewer),
|
|
|
|
and a vaguely similar histogram.
|
|
|
|
```
|
|
|
|
main.go:96: old: clrequest:578 clresponse:185 svrequest:2 svresponse:2 toserver:244 toclient:460 reporterr:385
|
|
|
|
main.go:96: new: clrequest:571 clresponse:185 svrequest:2 svresponse:2 toserver:241 toclient:460 reporterr:385
|
|
|
|
```
|
|
|
|
The first line is for the original log, the second for the new log. The new log has 7 fewer RPC requests
|
|
|
|
from the client *clrequest* (578 vs 571), the same number of client responses *clresponse*, 3 fewer
|
|
|
|
notifications *toserver* from the client, the same number from the server *toclient* to the client, and
|
|
|
|
the same number of errors *reporterr*. (That's mysterious, but a look at the ends of the log files shows
|
|
|
|
that the original session ended with several RPCs that don't show up, for whatever reason, in the new session.)
|
|
|
|
|
2019-12-10 10:11:53 -07:00
|
|
|
Finally, there are counts of the various notifications seen, in the new log and the old log, and
|
2019-12-02 10:52:29 -07:00
|
|
|
which direction they went. (The 3 fewer notifications in the summary above can be seen here to be from cancels
|
|
|
|
and a didChange.)
|
|
|
|
```
|
|
|
|
main.go:107: counts of notifications
|
|
|
|
main.go:110: '$/cancelRequest'. new toserver 1
|
|
|
|
main.go:110: '$/cancelRequest'. old toserver 3
|
|
|
|
main.go:110: 'initialized'. new toserver 1
|
|
|
|
main.go:110: 'initialized'. old toserver 1
|
|
|
|
main.go:110: 'textDocument/didChange'. new toserver 231
|
|
|
|
main.go:110: 'textDocument/didChange'. old toserver 232
|
|
|
|
main.go:110: 'textDocument/didOpen'. new toserver 1
|
|
|
|
main.go:110: 'textDocument/didOpen'. old toserver 1
|
|
|
|
main.go:110: 'textDocument/didSave'. new toserver 7
|
|
|
|
main.go:110: 'textDocument/didSave'. old toserver 7
|
|
|
|
main.go:110: 'textDocument/publishDiagnostics'. new toclient 182
|
|
|
|
main.go:110: 'textDocument/publishDiagnostics'. old toclient 182
|
|
|
|
main.go:110: 'window/logMessage'. new toclient 278
|
|
|
|
main.go:110: 'window/logMessage'. old toclient 278
|
|
|
|
```
|
|
|
|
### Caveats
|
|
|
|
Replay cannot restore the exact environment gopls saw for the original session.
|
|
|
|
For instance, the first didOpen message in the new session will see the file
|
|
|
|
as it was left by the original session.
|
|
|
|
|
|
|
|
Gopls invokes various tools, and the environment they see could have changed too.
|
|
|
|
|
|
|
|
Replay will use the gopls it finds (or is given). It has no way of using
|
2019-12-10 10:11:53 -07:00
|
|
|
the same version that created the original session.
|