Merge pull request #669 from bash-lsp/logging

Logger setup

Author: skovhus

.eslintrc.js

@@ -27,12 +27,7 @@ module.exports = {
         ignoreRestSiblings: true,
       },
     ],
-    'no-console': [
-      'error',
-      {
-        allow: ['warn', 'error'],
-      },
-    ],
+    'no-console': ['error'],
     'prefer-destructuring': [
       'error',
       {

README.md

@@ -4,7 +4,7 @@ Bash language server that brings an IDE-like experience for bash scripts to most
 
 We strongly recommend that you install [shellcheck][shellcheck] to enable linting: https://github.com/koalaman/shellcheck#installing
 
-Documentation around configuration can be found in the [config.ts](https://github.com/bash-lsp/bash-language-server/blob/main/server/src/config.ts) file.
+Documentation around configuration variables can be found in the [config.ts](https://github.com/bash-lsp/bash-language-server/blob/main/server/src/config.ts) file.
 
 ## Features
 
@@ -24,6 +24,10 @@ To be implemented:
 
 ## Installation
 
+Usually you want to install a client for your editor (see the section below).
+
+But if you want to install the server binary:
+
 ```bash
 npm i -g bash-language-server
 ```
@@ -34,6 +38,12 @@ On Fedora based distros:
 dnf install -y nodejs-bash-language-server
 ```
 
+To verify that everything is working:
+
+```bash
+bash-language-server --help
+```
+
 If you encounter installation errors, ensure you have node version 14 or newer (`node --version`).
 
 ### Clients
@@ -68,7 +78,7 @@ endif
 For Vim 8 or Neovim using [YouCompleteMe](https://github.com/ycm-core/YouCompleteMe), add the following to `.vimrc`:
 
 ```vim
-let g:ycm_language_server = 
+let g:ycm_language_server =
             \ [
             \   {
             \       'name': 'bash',
@@ -148,6 +158,11 @@ Add the configuration to your `.emacs.d/init.el`
   (sh-mode . lsp))
 ```
 
+## Logging
+
+The minimum logging level for the server can be adjusted using the `BASH_IDE_LOG_LEVEL` environment variable
+and through the general [workspace configuration](https://github.com/bash-lsp/bash-language-server/blob/main/server/src/config.ts).
+
 ## Development Guide
 
 Please see [docs/development-guide][dev-guide] for more information.

server/CHANGELOG.md

@@ -1,5 +1,9 @@
 # Bash Language Server
 
+## 4.3.0
+
+- Add centralized and configurable logger that can be controlled using the `BASH_IDE_LOG_LEVEL` environment variable and workspace configuration. https://github.com/bash-lsp/bash-language-server/pull/669
+
 ## 4.2.5
 
 - Fix a critical bug causing memory leaks and high CPU usage for workspaces with many files https://github.com/bash-lsp/bash-language-server/pull/661

server/package.json

@@ -3,7 +3,7 @@
   "description": "A language server for Bash",
   "author": "Mads Hartmann",
   "license": "MIT",
-  "version": "4.2.5",
+  "version": "4.3.0",
   "main": "./out/server.js",
   "typings": "./out/server.d.ts",
   "bin": {

server/src/__tests__/analyzer.test.ts

@@ -6,26 +6,30 @@ import {
   FIXTURE_URI,
   REPO_ROOT_FOLDER,
 } from '../../../testing/fixtures'
-import { getMockConnection } from '../../../testing/mocks'
 import Analyzer from '../analyser'
 import { getDefaultConfiguration } from '../config'
 import { initializeParser } from '../parser'
 import * as fsUtil from '../util/fs'
+import { Logger } from '../util/logger'
 
 let analyzer: Analyzer
 
 const CURRENT_URI = 'dummy-uri.sh'
-const mockConsole = getMockConnection().console
 
 // if you add a .sh file to testing/fixtures, update this value
 const FIXTURE_FILES_MATCHING_GLOB = 15
 
 const defaultConfig = getDefaultConfiguration()
 
+jest.spyOn(Logger.prototype, 'log').mockImplementation(() => {
+  // noop
+})
+const loggerInfo = jest.spyOn(Logger.prototype, 'info')
+const loggerWarn = jest.spyOn(Logger.prototype, 'warn')
+
 beforeAll(async () => {
   const parser = await initializeParser()
   analyzer = new Analyzer({
-    console: mockConsole,
     parser,
     workspaceFolder: FIXTURE_FOLDER,
   })
@@ -93,9 +97,7 @@ describe('findDeclarationLocations', () => {
     const { uri } = document
 
     const parser = await initializeParser()
-    const connection = getMockConnection()
     const newAnalyzer = new Analyzer({
-      console: connection.console,
       parser,
       workspaceFolder: REPO_ROOT_FOLDER,
     })
@@ -242,10 +244,8 @@ describe('getDeclarationsForUri', () => {
 describe('findAllSourcedUris', () => {
   it('returns references to sourced files', async () => {
     const parser = await initializeParser()
-    const connection = getMockConnection()
 
     const newAnalyzer = new Analyzer({
-      console: connection.console,
       parser,
       workspaceFolder: pathToFileURL(REPO_ROOT_FOLDER).href,
     })
@@ -266,10 +266,8 @@ describe('findAllSourcedUris', () => {
 
   it('returns references to sourced files without file extension', async () => {
     const parser = await initializeParser()
-    const connection = getMockConnection()
 
     const newAnalyzer = new Analyzer({
-      console: connection.console,
       parser,
       workspaceFolder: FIXTURE_FOLDER,
     })
@@ -344,10 +342,8 @@ describe('commandNameAtPoint', () => {
 describe('findDeclarationsMatchingWord', () => {
   it('returns a list of symbols across the workspace when includeAllWorkspaceSymbols is true', async () => {
     const parser = await initializeParser()
-    const connection = getMockConnection()
 
     const analyzer = new Analyzer({
-      console: connection.console,
       parser,
       includeAllWorkspaceSymbols: true,
       workspaceFolder: FIXTURE_FOLDER,
@@ -456,10 +452,8 @@ describe('findDeclarationsMatchingWord', () => {
 
   it('returns a list of symbols accessible to the uri when includeAllWorkspaceSymbols is false', async () => {
     const parser = await initializeParser()
-    const connection = getMockConnection()
 
     const analyzer = new Analyzer({
-      console: connection.console,
       parser,
       includeAllWorkspaceSymbols: false,
       workspaceFolder: FIXTURE_FOLDER,
@@ -510,10 +504,8 @@ describe('findDeclarationsMatchingWord', () => {
 
   it('returns symbols depending on the scope', async () => {
     const parser = await initializeParser()
-    const connection = getMockConnection()
 
     const analyzer = new Analyzer({
-      console: connection.console,
       parser,
       includeAllWorkspaceSymbols: false,
       workspaceFolder: FIXTURE_FOLDER,
@@ -721,10 +713,7 @@ describe('initiateBackgroundAnalysis', () => {
 
     jest.spyOn(Date, 'now').mockImplementation(() => 0)
 
-    const connection = getMockConnection()
-
     const newAnalyzer = new Analyzer({
-      console: connection.console,
       parser,
       workspaceFolder: FIXTURE_FOLDER,
     })
@@ -733,13 +722,12 @@ describe('initiateBackgroundAnalysis', () => {
       globPattern: defaultConfig.globPattern,
     })
 
-    expect(connection.window.showWarningMessage).not.toHaveBeenCalled()
-    expect(connection.console.warn).not.toHaveBeenCalled()
+    expect(loggerWarn).not.toHaveBeenCalled()
 
     // Intro, stats on glob, one file skipped due to shebang, and outro
     expect(filesParsed).toEqual(FIXTURE_FILES_MATCHING_GLOB)
 
-    expect(connection.console.log).toHaveBeenNthCalledWith(
+    expect(loggerInfo).toHaveBeenNthCalledWith(
       1,
       expect.stringContaining('BackgroundAnalysis: resolving glob'),
     )
@@ -752,10 +740,7 @@ describe('initiateBackgroundAnalysis', () => {
 
     const parser = await initializeParser()
 
-    const connection = getMockConnection()
-
     const newAnalyzer = new Analyzer({
-      console: connection.console,
       parser,
       workspaceFolder: FIXTURE_FOLDER,
     })
@@ -764,8 +749,7 @@ describe('initiateBackgroundAnalysis', () => {
       globPattern: defaultConfig.globPattern,
     })
 
-    expect(connection.window.showWarningMessage).not.toHaveBeenCalled()
-    expect(connection.console.warn).toHaveBeenCalledWith(expect.stringContaining('BOOM'))
+    expect(loggerWarn).toHaveBeenCalledWith(expect.stringContaining('BOOM'))
     expect(filesParsed).toEqual(0)
   })
 
@@ -774,10 +758,7 @@ describe('initiateBackgroundAnalysis', () => {
 
     jest.spyOn(Date, 'now').mockImplementation(() => 0)
 
-    const connection = getMockConnection()
-
     const newAnalyzer = new Analyzer({
-      console: connection.console,
       parser,
       workspaceFolder: FIXTURE_FOLDER,
     })
@@ -786,8 +767,7 @@ describe('initiateBackgroundAnalysis', () => {
       globPattern: defaultConfig.globPattern,
     })
 
-    expect(connection.window.showWarningMessage).not.toHaveBeenCalled()
-    expect(connection.console.warn).not.toHaveBeenCalled()
+    expect(loggerWarn).not.toHaveBeenCalled()
 
     expect(filesParsed).toEqual(0)
   })
@@ -799,10 +779,8 @@ describe('getAllVariables', () => {
     const { uri } = document
 
     const parser = await initializeParser()
-    const connection = getMockConnection()
 
     const newAnalyzer = new Analyzer({
-      console: connection.console,
       parser,
       workspaceFolder: REPO_ROOT_FOLDER,
     })

server/src/__tests__/config.test.ts

@@ -1,4 +1,5 @@
 import { ConfigSchema, getConfigFromEnvironmentVariables } from '../config'
+import { LOG_LEVEL_ENV_VAR } from '../util/logger'
 
 describe('ConfigSchema', () => {
   it('returns a default', () => {
@@ -9,6 +10,7 @@ describe('ConfigSchema', () => {
         "globPattern": "**/*@(.sh|.inc|.bash|.command)",
         "highlightParsingErrors": false,
         "includeAllWorkspaceSymbols": false,
+        "logLevel": "info",
         "shellcheckArguments": Array [],
         "shellcheckPath": "shellcheck",
       }
@@ -32,6 +34,7 @@ describe('ConfigSchema', () => {
         "globPattern": "**/*@(.sh)",
         "highlightParsingErrors": true,
         "includeAllWorkspaceSymbols": true,
+        "logLevel": "info",
         "shellcheckArguments": Array [
           "-e",
           "SC2001",
@@ -62,6 +65,7 @@ describe('getConfigFromEnvironmentVariables', () => {
         "globPattern": "**/*@(.sh|.inc|.bash|.command)",
         "highlightParsingErrors": false,
         "includeAllWorkspaceSymbols": false,
+        "logLevel": "info",
         "shellcheckArguments": Array [],
         "shellcheckPath": "shellcheck",
       }
@@ -80,6 +84,7 @@ describe('getConfigFromEnvironmentVariables', () => {
         "globPattern": "**/*@(.sh|.inc|.bash|.command)",
         "highlightParsingErrors": false,
         "includeAllWorkspaceSymbols": false,
+        "logLevel": "info",
         "shellcheckArguments": Array [],
         "shellcheckPath": "",
       }
@@ -93,6 +98,7 @@ describe('getConfigFromEnvironmentVariables', () => {
       EXPLAINSHELL_ENDPOINT: 'localhost:8080',
       GLOB_PATTERN: '*.*',
       BACKGROUND_ANALYSIS_MAX_FILES: '1',
+      [LOG_LEVEL_ENV_VAR]: 'error',
     }
     const { config } = getConfigFromEnvironmentVariables()
     expect(config).toMatchInlineSnapshot(`
@@ -102,6 +108,7 @@ describe('getConfigFromEnvironmentVariables', () => {
         "globPattern": "*.*",
         "highlightParsingErrors": false,
         "includeAllWorkspaceSymbols": false,
+        "logLevel": "error",
         "shellcheckArguments": Array [
           "-e",
           "SC2001",

server/src/__tests__/server.test.ts

@@ -14,13 +14,18 @@ import {
 import { getMockConnection } from '../../../testing/mocks'
 import LspServer from '../server'
 import { CompletionItemDataType } from '../types'
+import { Logger } from '../util/logger'
 
 // Skip ShellCheck throttle delay in test cases
 jest.spyOn(global, 'setTimeout').mockImplementation((fn) => {
   fn()
   return 0 as any
 })
 
+jest.spyOn(Logger.prototype, 'log').mockImplementation(() => {
+  // noop
+})
+
 async function initializeServer(
   { rootPath }: { rootPath?: string } = { rootPath: pathToFileURL(FIXTURE_FOLDER).href },
 ) {
@@ -480,6 +485,7 @@ describe('server', () => {
     )
 
     if (getOptionsResult.status !== 0) {
+      // eslint-disable-next-line no-console
       console.warn('Skipping onCompletion test as get-options.sh failed')
       return
     }