Extend Node SDK to allow JSON format output

[microsoft]

Extend Node SDK to allow JSON format output

[octref]

Current progress:

For this config running this language server extension: https://github.com/octref/vscode-language-server-template

  "mls.trace.server": {
    "format": "json",
    "verbosity": "messages",
  }

Log looks like this:

[LSP   - 2:05:03 AM] {"type":"send-request","message":{"jsonrpc":"2.0","id":0,"method":"initialize","params":{"processId":8803,"rootPath":"/Users/pine/Code/work/lsp-inspector/plain","rootUri":"file:///Users/pine/Code/work/lsp-inspector/plain","capabilities":{"workspace":{"applyEdit":true,"workspaceEdit":{"documentChanges":true},"didChangeConfiguration":{"dynamicRegistration":true},"didChangeWatchedFiles":{"dynamicRegistration":true},"symbol":{"dynamicRegistration":true,"symbolKind":{"valueSet":[1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20,21,22,23,24,25,26]}},"executeCommand":{"dynamicRegistration":true},"configuration":true,"workspaceFolders":true},"textDocument":{"publishDiagnostics":{"relatedInformation":true},"synchronization":{"dynamicRegistration":true,"willSave":true,"willSaveWaitUntil":true,"didSave":true},"completion":{"dynamicRegistration":true,"contextSupport":true,"completionItem":{"snippetSupport":true,"commitCharactersSupport":true,"documentationFormat":["markdown","plaintext"],"deprecatedSupport":true},"completionItemKind":{"valueSet":[1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20,21,22,23,24,25]}},"hover":{"dynamicRegistration":true,"contentFormat":["markdown","plaintext"]},"signatureHelp":{"dynamicRegistration":true,"signatureInformation":{"documentationFormat":["markdown","plaintext"]}},"definition":{"dynamicRegistration":true},"references":{"dynamicRegistration":true},"documentHighlight":{"dynamicRegistration":true},"documentSymbol":{"dynamicRegistration":true,"symbolKind":{"valueSet":[1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20,21,22,23,24,25,26]}},"codeAction":{"dynamicRegistration":true,"codeActionLiteralSupport":{"codeActionKind":{"valueSet":["","quickfix","refactor","refactor.extract","refactor.inline","refactor.rewrite","source","source.organizeImports"]}}},"codeLens":{"dynamicRegistration":true},"formatting":{"dynamicRegistration":true},"rangeFormatting":{"dynamicRegistration":true},"onTypeFormatting":{"dynamicRegistration":true},"rename":{"dynamicRegistration":true},"documentLink":{"dynamicRegistration":true},"typeDefinition":{"dynamicRegistration":true},"implementation":{"dynamicRegistration":true},"colorProvider":{"dynamicRegistration":true}}},"trace":"verbose","workspaceFolders":[{"uri":"file:///Users/pine/Code/work/lsp-inspector/plain","name":"plain"}]}},"timestamp":1529658303181}
Debugger listening on ws://127.0.0.1:6006/9a9de78e-7f22-4fb0-8988-85dcb67f7321
For help see https://nodejs.org/en/docs/inspector
[LSP   - 2:05:03 AM] {"type":"receive-response","message":{"jsonrpc":"2.0","id":0,"result":{"capabilities":{"textDocumentSync":1,"completionProvider":{"resolveProvider":true}}}},"timestamp":1529658303218}
[LSP   - 2:05:03 AM] {"type":"send-notification","message":{"jsonrpc":"2.0","method":"initialized","params":{}},"timestamp":1529658303218}
[LSP   - 2:05:03 AM] {"type":"send-notification","message":{"jsonrpc":"2.0","method":"workspace/didChangeConfiguration","params":{"settings":{}}},"timestamp":1529658303218}
[LSP   - 2:05:03 AM] {"type":"send-notification","message":{"jsonrpc":"2.0","method":"textDocument/didOpen","params":{"textDocument":{"uri":"file:///Users/pine/Code/work/lsp-inspector/plain/README.md","languageId":"markdown","version":1,"text":"# LSP Inspector\n\n### Running\n\n- `yarn`\n- `yarn serve`\n\n### Demo\n\nhttp://lsp-inspector.surge.sh\n\n- A log file (log from html Language Server) is loaded by default\n- You can collect other logs and load them. For example:\n  - Set `css.trace.server: \"verbose\"`\n  - Copy everything inside `CSS Language Server` channel into a log file `css.log`\n  - Load it from the web app\n- You can try it on a real-world log file, `./logs/vetur.log`. It contains 330k lines of log generated from 10 minutes of usage.\n\nTypeScript"}}},"timestamp":1529658303219}

For output going to log-folder or going to websocket for streaming, we can do that later.

The motivation behind this format is:

• The new format does not deviate much from the old one

• They still line up with others, for example:

  [Info  - 2:05:03 AM]
  [Warn  - 2:05:03 AM]
  [Error - 2:05:03 AM]
  [Trace - 2:05:03 AM]
  [LSP   - 2:05:03 AM]
  

• Putting all arguments in the same line makes it much easier for the log parser to consume real-world logs. For example as @egamma reported in #10 and here, the Debugger Listening...Please See... message

• As #10 mentioned, vscode-tslint is using connection.trace and this mixes up custom language server logs together with built-in request/response/notifications. Splitting out [LSP] will make it easier to tell them apart.

Later I can update the LSP Inspector to handle this format of log. I suggest that for format: "json", we always make the log single line. This way the log parser can safely skip over lines that do not start with [LSP/Info/Warn/Error/Trace] and not miss anything.

I can make the inspector process Info/Warn/Error/Trace as part of the visualization too. Think that would be helpful.

/cc @dbaeumer

[octref]

https://github.com/Microsoft/language-server-protocol-inspector#log-format

At the end, I decided to decouple the streaming part from the Text/JSON format part. The config currently looks like this:

  "mls.trace.server": {
    "verbosity": "verbose",
    "format": "json"
  },
  "mls.debug.log": {
    "output": "websocket",
    "port": 7000
  },

For the very simple WebSocket streaming implementation, see octref/vscode-language-server-template@4181af8

This way we don't need to introduce another dependency for WebSocket, and users get more control of the WebSocket connection they want to do.