tfserver.log

Launching language server: /home/audc/.vscode-server/data/User/globalStorage/hashicorp.terraform/bin/terraform-ls serve
2022/02/09 08:01:31 serve_command.go:162: Starting terraform-ls 0.25.2
2022/02/09 08:01:31 service.go:90: Preparing new session ...
2022/02/09 08:01:31 langserver.go:94: Starting server (pid 1892347; concurrency: 2) ...
2022/02/09 08:01:31 opts.go:254: Received request batch of size 1 (qlen=0)
2022/02/09 08:01:31 opts.go:254: Dequeued request batch of length 1 (qlen=0)
2022/02/09 08:01:31 rpc_logger.go:29: Incoming request for "initialize" (ID 0): {"processId":1892272,"clientInfo":{"name":"Visual Studio Code","version":"1.64.1"},"locale":"en","rootPath":"/home/user/test","rootUri":"file:///home/user/test","capabilities":{"workspace":{"applyEdit":true,"workspaceEdit":{"documentChanges":true,"resourceOperations":["create","rename","delete"],"failureHandling":"textOnlyTransactional","normalizesLineEndings":true,"changeAnnotationSupport":{"groupsOnLabel":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]},"tagSupport":{"valueSet":[1]}},"codeLens":{"refreshSupport":true},"executeCommand":{"dynamicRegistration":true},"configuration":true,"workspaceFolders":true,"semanticTokens":{"refreshSupport":true},"fileOperations":{"dynamicRegistration":true,"didCreate":true,"didRename":true,"didDelete":true,"willCreate":true,"willRename":true,"willDelete":true}},"textDocument":{"publishDiagnostics":{"relatedInformation":true,"versionSupport":false,"tagSupport":{"valueSet":[1,2]},"codeDescriptionSupport":true,"dataSupport":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,"preselectSupport":true,"tagSupport":{"valueSet":[1]},"insertReplaceSupport":true,"resolveSupport":{"properties":["documentation","detail","additionalTextEdits"]},"insertTextModeSupport":{"valueSet":[1,2]}},"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"],"parameterInformation":{"labelOffsetSupport":true},"activeParameterSupport":true},"contextSupport":true},"definition":{"dynamicRegistration":true,"linkSupport":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]},"hierarchicalDocumentSymbolSupport":true,"tagSupport":{"valueSet":[1]},"labelSupport":true},"codeAction":{"dynamicRegistration":true,"isPreferredSupport":true,"disabledSupport":true,"dataSupport":true,"resolveSupport":{"properties":["edit"]},"codeActionLiteralSupport":{"codeActionKind":{"valueSet":["","quickfix","refactor","refactor.extract","refactor.inline","refactor.rewrite","source","source.organizeImports"]}},"honorsChangeAnnotations":false},"codeLens":{"dynamicRegistration":true},"formatting":{"dynamicRegistration":true},"rangeFormatting":{"dynamicRegistration":true},"onTypeFormatting":{"dynamicRegistration":true},"rename":{"dynamicRegistration":true,"prepareSupport":true,"prepareSupportDefaultBehavior":1,"honorsChangeAnnotations":true},"documentLink":{"dynamicRegistration":true,"tooltipSupport":true},"typeDefinition":{"dynamicRegistration":true,"linkSupport":true},"implementation":{"dynamicRegistration":true,"linkSupport":true},"colorProvider":{"dynamicRegistration":true},"foldingRange":{"dynamicRegistration":true,"rangeLimit":5000,"lineFoldingOnly":true},"declaration":{"dynamicRegistration":true,"linkSupport":true},"selectionRange":{"dynamicRegistration":true},"callHierarchy":{"dynamicRegistration":true},"semanticTokens":{"dynamicRegistration":true,"tokenTypes":["namespace","type","class","enum","interface","struct","typeParameter","parameter","variable","property","enumMember","event","function","method","macro","keyword","modifier","comment","string","number","regexp","operator"],"tokenModifiers":["declaration","definition","readonly","static","deprecated","abstract","async","modification","documentation","defaultLibrary"],"formats":["relative"],"requests":{"range":true,"full":{"delta":true}},"multilineTokenSupport":false,"overlappingTokenSupport":false},"linkedEditingRange":{"dynamicRegistration":true}},"window":{"showMessage":{"messageActionItem":{"additionalPropertiesSupport":true}},"showDocument":{"support":true},"workDoneProgress":true},"general":{"regularExpressions":{"engine":"ECMAScript","version":"ES2020"},"markdown":{"parser":"marked","version":"1.1.0"}},"experimental":{"telemetryVersion":1}},"initializationOptions":{"commandPrefix":"8","experimentalFeatures":{}},"trace":"off","workspaceFolders":[{"uri":"file:///home/user/test","name":"test"}]}
2022/02/09 08:01:31 initialize.go:76: enabling telemetry (version: 1)
2022/02/09 08:01:31 initialize.go:81: telemetry enabled (version: 1)
2022/02/09 08:01:36 watcher.go:283: watching for changes ...
2022/02/09 08:01:36 opts.go:254: Posting server notification "telemetry/event" {"v":1,"name":"initialize","properties":{"experimentalCapabilities.referenceCountCodeLens":false,"lsVersion":"0.25.2","options.commandPrefix":true,"options.excludeModulePaths":false,"options.experimentalFeatures.prefillRequiredFields":false,"options.experimentalFeatures.validateOnSave":false,"options.ignoreDirectoryNames":false,"options.rootModulePaths":false,"options.terraformExecPath":false,"options.terraformExecTimeout":"","options.terraformLogFilePath":false,"root_uri":"dir"}}
2022/02/09 08:01:36 rpc_logger.go:50: Response to "initialize" (ID 0): {"capabilities":{"textDocumentSync":{"openClose":true,"change":2,"save":{}},"completionProvider":{"triggerCharacters":[".","["],"completionItem":{}},"hoverProvider":true,"signatureHelpProvider":{},"declarationProvider":{},"definitionProvider":true,"referencesProvider":true,"documentSymbolProvider":true,"codeActionProvider":{"codeActionKinds":["source.formatAll.terraform"]},"codeLensProvider":{},"documentLinkProvider":{},"workspaceSymbolProvider":true,"documentFormattingProvider":true,"documentOnTypeFormattingProvider":{"firstTriggerCharacter":""},"executeCommandProvider":{"commands":["8.terraform-ls.module.callers","8.terraform-ls.module.calls","8.terraform-ls.module.providers","8.terraform-ls.rootmodules","8.terraform-ls.terraform.init","8.terraform-ls.terraform.validate"],"workDoneProgress":true},"semanticTokensProvider":{"legend":{"tokenTypes":["type","string","property","keyword","number","parameter","variable"],"tokenModifiers":["deprecated","modification"]},"full":true},"workspace":{"workspaceFolders":{"supported":true,"changeNotifications":"workspace/didChangeWorkspaceFolders"}}},"serverInfo":{"name":"terraform-ls","version":"0.25.2"}}
2022/02/09 08:01:36 opts.go:254: Completed 1 requests [5.016234831s elapsed]
2022/02/09 08:01:36 walker.go:191: asynchronously walking through /home/user/test
2022/02/09 08:01:36 walker.go:249: found module /home/user/test
2022/02/09 08:01:36 module_manager.go:66: MM: adding new module: /home/user/test
2022/02/09 08:01:36 module_loader.go:185: ML: enqueing "OpTypeParseModuleConfiguration" module operation: "/home/user/test"
2022/02/09 08:01:36 module_loader.go:185: ML: enqueing "OpTypeParseVariables" module operation: "/home/user/test"
2022/02/09 08:01:36 module_loader.go:185: ML: enqueing "OpTypeGetTerraformVersion" module operation: "/home/user/test"
2022/02/09 08:01:36 module_loader.go:185: ML: enqueing "OpTypeParseModuleManifest" module operation: "/home/user/test"
2022/02/09 08:01:36 opts.go:254: Posting server notification "telemetry/event" {"v":1,"name":"moduleData","properties":{"moduleId":"68d0febe-30f1-d3b3-e8ad-b38bd570feeb"}}
2022/02/09 08:01:36 module_loader.go:120: ML: executing "OpTypeParseModuleConfiguration" for "/home/user/test"
2022/02/09 08:01:36 module_loader.go:172: ML: finished "OpTypeParseModuleConfiguration" for "/home/user/test"
2022/02/09 08:01:36 opts.go:254: Received request batch of size 1 (qlen=0)
2022/02/09 08:01:36 opts.go:254: Received request batch of size 1 (qlen=1)
2022/02/09 08:01:36 opts.go:254: Dequeued request batch of length 1 (qlen=1)
2022/02/09 08:01:36 opts.go:254: Dequeued request batch of length 1 (qlen=0)
2022/02/09 08:01:36 rpc_logger.go:29: Incoming notification for "initialized": {}
2022/02/09 08:01:36 rpc_logger.go:29: Incoming notification for "textDocument/didOpen": {"textDocument":{"uri":"file:///home/user/test/test.tf","languageId":"terraform","version":1,"text":"variable \"some-var\" {\n  default = \"value\"\n}\n\nmodule \"foo-mod\" {\n  source = \"./foo\"\n  foo = var.some-var\n}\n\nmodule \"bar\" {\n  source = \"./foo\"\n  foo = module.foo-mod.result-val\n}\n"}}
2022/02/09 08:01:36 did_open.go:44: opened module: /home/user/test
2022/02/09 08:01:36 module_loader.go:185: ML: enqueing "OpTypeParseModuleConfiguration" module operation: "/home/user/test"
2022/02/09 08:01:36 walker.go:321: walking of /home/user/test finished
2022/02/09 08:01:36 walker.go:197: async walking through /home/user/test finished
2022/02/09 08:01:36 module_loader.go:120: ML: executing "OpTypeParseModuleManifest" for "/home/user/test"
2022/02/09 08:01:36 module_loader.go:185: ML: enqueing "OpTypeParseVariables" module operation: "/home/user/test"
2022/02/09 08:01:36 module_loader.go:185: ML: enqueing "OpTypeLoadModuleMetadata" module operation: "/home/user/test"
2022/02/09 08:01:36 module_loader.go:120: ML: executing "OpTypeGetTerraformVersion" for "/home/user/test"
2022/02/09 08:01:36 module_loader.go:185: ML: enqueing "OpTypeDecodeReferenceTargets" module operation: "/home/user/test"
2022/02/09 08:01:36 module_loader.go:185: ML: enqueing "OpTypeDecodeReferenceOrigins" module operation: "/home/user/test"
2022/02/09 08:01:36 watcher.go:75: adding module for watching: /home/user/test
2022/02/09 08:01:36 module_loader.go:172: ML: finished "OpTypeParseModuleManifest" for "/home/user/test"
2022/02/09 08:01:36 module_manager.go:66: MM: adding new module: /home/user/test/foo
2022/02/09 08:01:36 module_loader.go:185: ML: enqueing "OpTypeParseModuleConfiguration" module operation: "/home/user/test/foo"
2022/02/09 08:01:36 opts.go:254: Posting server notification "telemetry/event" {"v":1,"name":"moduleData","properties":{"moduleId":"929fc680-b572-b131-f65c-3bf545701825"}}
2022/02/09 08:01:36 module_loader.go:172: ML: finished "OpTypeGetTerraformVersion" for "/home/user/test"
2022/02/09 08:01:36 opts.go:254: Posting server notification "telemetry/event" {"v":1,"name":"moduleData","properties":{"moduleId":"68d0febe-30f1-d3b3-e8ad-b38bd570feeb","tfVersion":"1.1.5"}}
2022/02/09 08:01:36 module_loader.go:185: ML: enqueing "OpTypeLoadModuleMetadata" module operation: "/home/user/test/foo"
2022/02/09 08:01:36 module_loader.go:120: ML: executing "OpTypeDecodeReferenceOrigins" for "/home/user/test"
2022/02/09 08:01:36 module_loader.go:185: ML: enqueing "OpTypeParseVariables" module operation: "/home/user/test/foo"
2022/02/09 08:01:36 module_loader.go:185: ML: enqueing "OpTypeDecodeReferenceTargets" module operation: "/home/user/test/foo"
2022/02/09 08:01:36 module_loader.go:185: ML: enqueing "OpTypeDecodeReferenceOrigins" module operation: "/home/user/test/foo"
2022/02/09 08:01:36 module_manager.go:66: MM: adding new module: /home/user/test/foo
2022/02/09 08:01:36 module_loader.go:185: ML: enqueing "OpTypeParseModuleConfiguration" module operation: "/home/user/test/foo"
2022/02/09 08:01:36 module_loader.go:185: ML: enqueing "OpTypeLoadModuleMetadata" module operation: "/home/user/test/foo"
2022/02/09 08:01:36 module_loader.go:185: ML: enqueing "OpTypeParseVariables" module operation: "/home/user/test/foo"
2022/02/09 08:01:36 module_loader.go:185: ML: enqueing "OpTypeDecodeReferenceTargets" module operation: "/home/user/test/foo"
2022/02/09 08:01:36 module_loader.go:185: ML: enqueing "OpTypeDecodeReferenceOrigins" module operation: "/home/user/test/foo"
2022/02/09 08:01:36 module_loader.go:185: ML: enqueing "OpTypeDecodeReferenceTargets" module operation: "/home/user/test"
2022/02/09 08:01:36 module_loader.go:185: ML: enqueing "OpTypeDecodeReferenceOrigins" module operation: "/home/user/test"
2022/02/09 08:01:36 module_loader.go:120: ML: executing "OpTypeParseVariables" for "/home/user/test"
2022/02/09 08:01:36 module_loader.go:172: ML: finished "OpTypeParseVariables" for "/home/user/test"
2022/02/09 08:01:36 module_loader.go:172: ML: finished "OpTypeDecodeReferenceOrigins" for "/home/user/test"
2022/02/09 08:01:36 opts.go:254: Received request batch of size 1 (qlen=0)
2022/02/09 08:01:36 opts.go:254: Dequeued request batch of length 1 (qlen=0)
2022/02/09 08:01:36 rpc_logger.go:29: Incoming request for "textDocument/documentSymbol" (ID 1): {"textDocument":{"uri":"file:///home/user/test/test.tf"}}
2022/02/09 08:01:36 rpc_logger.go:50: Response to "textDocument/documentSymbol" (ID 1): [{"name":"variable \"some-var\"","kind":5,"range":{"start":{"line":0,"character":0},"end":{"line":2,"character":1}},"selectionRange":{"start":{"line":0,"character":0},"end":{"line":2,"character":1}},"children":[{"name":"default","kind":15,"range":{"start":{"line":1,"character":2},"end":{"line":1,"character":19}},"selectionRange":{"start":{"line":1,"character":2},"end":{"line":1,"character":19}}}]},{"name":"module \"foo-mod\"","kind":5,"range":{"start":{"line":4,"character":0},"end":{"line":7,"character":1}},"selectionRange":{"start":{"line":4,"character":0},"end":{"line":7,"character":1}},"children":[{"name":"source","kind":15,"range":{"start":{"line":5,"character":2},"end":{"line":5,"character":18}},"selectionRange":{"start":{"line":5,"character":2},"end":{"line":5,"character":18}}},{"name":"foo","kind":14,"range":{"start":{"line":6,"character":2},"end":{"line":6,"character":20}},"selectionRange":{"start":{"line":6,"character":2},"end":{"line":6,"character":20}}}]},{"name":"module \"bar\"","kind":5,"range":{"start":{"line":9,"character":0},"end":{"line":12,"character":1}},"selectionRange":{"start":{"line":9,"character":0},"end":{"line":12,"character":1}},"children":[{"name":"source","kind":15,"range":{"start":{"line":10,"character":2},"end":{"line":10,"character":18}},"selectionRange":{"start":{"line":10,"character":2},"end":{"line":10,"character":18}}},{"name":"foo","kind":14,"range":{"start":{"line":11,"character":2},"end":{"line":11,"character":33}},"selectionRange":{"start":{"line":11,"character":2},"end":{"line":11,"character":33}}}]}]
2022/02/09 08:01:36 opts.go:254: Completed 1 requests [2.34661ms elapsed]
2022/02/09 08:01:36 opts.go:254: Received request batch of size 1 (qlen=0)
2022/02/09 08:01:36 opts.go:254: Dequeued request batch of length 1 (qlen=0)
2022/02/09 08:01:36 rpc_logger.go:29: Incoming request for "textDocument/documentLink" (ID 2): {"textDocument":{"uri":"file:///home/user/test/test.tf"}}
2022/02/09 08:01:36 rpc_logger.go:50: Response to "textDocument/documentLink" (ID 2): []
2022/02/09 08:01:36 opts.go:254: Completed 1 requests [1.786108ms elapsed]
2022/02/09 08:01:36 module_loader.go:120: ML: executing "OpTypeDecodeReferenceOrigins" for "/home/user/test"
2022/02/09 08:01:37 module_loader.go:172: ML: finished "OpTypeDecodeReferenceOrigins" for "/home/user/test"
2022/02/09 08:01:37 module_loader.go:120: ML: executing "OpTypeDecodeReferenceTargets" for "/home/user/test"
2022/02/09 08:01:37 module_loader.go:120: ML: executing "OpTypeParseModuleConfiguration" for "/home/user/test"
2022/02/09 08:01:37 module_loader.go:172: ML: finished "OpTypeDecodeReferenceTargets" for "/home/user/test"
2022/02/09 08:01:37 module_loader.go:120: ML: executing "OpTypeLoadModuleMetadata" for "/home/user/test"
2022/02/09 08:01:37 module_loader.go:172: ML: finished "OpTypeLoadModuleMetadata" for "/home/user/test"
2022/02/09 08:01:37 module_loader.go:172: ML: finished "OpTypeParseModuleConfiguration" for "/home/user/test"
2022/02/09 08:01:37 module_loader.go:120: ML: executing "OpTypeParseVariables" for "/home/user/test/foo"
2022/02/09 08:01:37 module_loader.go:172: ML: finished "OpTypeParseVariables" for "/home/user/test/foo"
2022/02/09 08:01:37 module_loader.go:120: ML: executing "OpTypeDecodeReferenceOrigins" for "/home/user/test/foo"
2022/02/09 08:01:37 module_loader.go:172: ML: finished "OpTypeDecodeReferenceOrigins" for "/home/user/test/foo"
2022/02/09 08:01:37 module_loader.go:120: ML: executing "OpTypeLoadModuleMetadata" for "/home/user/test/foo"
2022/02/09 08:01:37 module_loader.go:172: ML: finished "OpTypeLoadModuleMetadata" for "/home/user/test/foo"
2022/02/09 08:01:37 opts.go:254: Received request batch of size 1 (qlen=0)
2022/02/09 08:01:37 opts.go:254: Dequeued request batch of length 1 (qlen=0)
2022/02/09 08:01:37 rpc_logger.go:29: Incoming request for "textDocument/semanticTokens/full" (ID 3): {"textDocument":{"uri":"file:///home/user/test/test.tf"}}
2022/02/09 08:01:37 rpc_logger.go:50: Response to "textDocument/semanticTokens/full" (ID 3): {"data":[0,0,8,0,0,0,9,10,1,2,1,2,7,2,2,3,0,6,0,0,0,7,9,1,0,1,2,6,2,0,0,9,7,1,0,4,0,6,0,0,0,7,5,1,0,1,2,6,2,0,0,9,7,1,0]}
2022/02/09 08:01:37 opts.go:254: Completed 1 requests [1.631307ms elapsed]
2022/02/09 08:01:37 module_loader.go:120: ML: executing "OpTypeDecodeReferenceTargets" for "/home/user/test/foo"
2022/02/09 08:01:37 module_loader.go:172: ML: finished "OpTypeDecodeReferenceTargets" for "/home/user/test/foo"
2022/02/09 08:01:37 module_loader.go:120: ML: executing "OpTypeParseModuleConfiguration" for "/home/user/test/foo"
2022/02/09 08:01:37 module_loader.go:172: ML: finished "OpTypeParseModuleConfiguration" for "/home/user/test/foo"
2022/02/09 08:01:37 opts.go:254: Received request batch of size 1 (qlen=0)
2022/02/09 08:01:37 opts.go:254: Dequeued request batch of length 1 (qlen=0)
2022/02/09 08:01:37 rpc_logger.go:29: Incoming request for "textDocument/codeLens" (ID 4): {"textDocument":{"uri":"file:///home/user/test/test.tf"}}
2022/02/09 08:01:37 rpc_logger.go:50: Response to "textDocument/codeLens" (ID 4): []
2022/02/09 08:01:37 opts.go:254: Completed 1 requests [1.998008ms elapsed]
2022/02/09 08:01:37 opts.go:254: Received request batch of size 1 (qlen=0)
2022/02/09 08:01:37 opts.go:254: Dequeued request batch of length 1 (qlen=0)
2022/02/09 08:01:37 rpc_logger.go:29: Incoming request for "textDocument/codeLens" (ID 5): {"textDocument":{"uri":"file:///home/user/test/test.tf"}}
2022/02/09 08:01:37 rpc_logger.go:50: Response to "textDocument/codeLens" (ID 5): []
2022/02/09 08:01:37 opts.go:254: Completed 1 requests [1.810308ms elapsed]
2022/02/09 08:01:41 opts.go:254: Received request batch of size 1 (qlen=0)
2022/02/09 08:01:41 opts.go:254: Dequeued request batch of length 1 (qlen=0)
2022/02/09 08:01:41 rpc_logger.go:29: Incoming request for "textDocument/codeLens" (ID 6): {"textDocument":{"uri":"file:///home/user/test/test.tf"}}
2022/02/09 08:01:41 rpc_logger.go:50: Response to "textDocument/codeLens" (ID 6): []
2022/02/09 08:01:41 opts.go:254: Completed 1 requests [2.521112ms elapsed]
2022/02/09 08:01:41 opts.go:254: Received request batch of size 1 (qlen=0)
2022/02/09 08:01:41 opts.go:254: Dequeued request batch of length 1 (qlen=0)
2022/02/09 08:01:41 rpc_logger.go:29: Incoming request for "textDocument/codeLens" (ID 7): {"textDocument":{"uri":"file:///home/user/test/test.tf"}}
2022/02/09 08:01:41 rpc_logger.go:50: Response to "textDocument/codeLens" (ID 7): []
2022/02/09 08:01:41 opts.go:254: Completed 1 requests [1.841208ms elapsed]
2022/02/09 08:01:41 opts.go:254: Received request batch of size 1 (qlen=0)
2022/02/09 08:01:41 opts.go:254: Dequeued request batch of length 1 (qlen=0)
2022/02/09 08:01:41 rpc_logger.go:29: Incoming request for "workspace/executeCommand" (ID 8): {"command":"8.terraform-ls.module.callers","arguments":["uri=file:///home/user/test"]}
2022/02/09 08:01:41 rpc_logger.go:50: Response to "workspace/executeCommand" (ID 8): {"v":0,"callers":[]}
2022/02/09 08:01:41 opts.go:254: Completed 1 requests [321.601µs elapsed]
2022/02/09 08:01:47 opts.go:254: Received request batch of size 1 (qlen=0)
2022/02/09 08:01:47 opts.go:254: Dequeued request batch of length 1 (qlen=0)
2022/02/09 08:01:47 rpc_logger.go:29: Incoming request for "workspace/executeCommand" (ID 9): {"command":"8.terraform-ls.module.callers","arguments":["uri=file:///home/user/test"]}
2022/02/09 08:01:47 rpc_logger.go:50: Response to "workspace/executeCommand" (ID 9): {"v":0,"callers":[]}
2022/02/09 08:01:47 opts.go:254: Completed 1 requests [1.289005ms elapsed]
2022/02/09 08:01:48 opts.go:254: Received request batch of size 1 (qlen=0)
2022/02/09 08:01:48 opts.go:254: Dequeued request batch of length 1 (qlen=0)
2022/02/09 08:01:48 rpc_logger.go:29: Incoming request for "workspace/executeCommand" (ID 10): {"command":"8.terraform-ls.module.callers","arguments":["uri=file:///home/user/test"]}
2022/02/09 08:01:48 rpc_logger.go:50: Response to "workspace/executeCommand" (ID 10): {"v":0,"callers":[]}
2022/02/09 08:01:48 opts.go:254: Completed 1 requests [243.201µs elapsed]
2022/02/09 08:02:06 opts.go:254: Received request batch of size 1 (qlen=0)
2022/02/09 08:02:06 opts.go:254: Dequeued request batch of length 1 (qlen=0)
2022/02/09 08:02:06 rpc_logger.go:29: Incoming request for "textDocument/codeLens" (ID 11): {"textDocument":{"uri":"file:///home/user/test/test.tf"}}
2022/02/09 08:02:06 rpc_logger.go:50: Response to "textDocument/codeLens" (ID 11): []
2022/02/09 08:02:06 opts.go:254: Completed 1 requests [2.213009ms elapsed]
2022/02/09 08:02:07 opts.go:254: Received request batch of size 1 (qlen=0)
2022/02/09 08:02:07 opts.go:254: Dequeued request batch of length 1 (qlen=0)
2022/02/09 08:02:07 rpc_logger.go:29: Incoming request for "textDocument/codeLens" (ID 12): {"textDocument":{"uri":"file:///home/user/test/test.tf"}}
2022/02/09 08:02:07 rpc_logger.go:50: Response to "textDocument/codeLens" (ID 12): []
2022/02/09 08:02:07 opts.go:254: Completed 1 requests [2.29561ms elapsed]
2022/02/09 08:03:20 opts.go:254: Received request batch of size 1 (qlen=0)
2022/02/09 08:03:20 opts.go:254: Dequeued request batch of length 1 (qlen=0)
2022/02/09 08:03:20 rpc_logger.go:29: Incoming request for "workspace/executeCommand" (ID 13): {"command":"8.terraform-ls.module.callers","arguments":["uri=file:///home/user/test"]}
2022/02/09 08:03:20 rpc_logger.go:50: Response to "workspace/executeCommand" (ID 13): {"v":0,"callers":[]}
2022/02/09 08:03:20 opts.go:254: Completed 1 requests [866.304µs elapsed]
2022/02/09 08:03:23 module_loader.go:185: ML: enqueing "OpTypeParseModuleManifest" module operation: "/home/user/test"
2022/02/09 08:03:23 module_loader.go:120: ML: executing "OpTypeParseModuleManifest" for "/home/user/test"
2022/02/09 08:03:23 module_loader.go:172: ML: finished "OpTypeParseModuleManifest" for "/home/user/test"
2022/02/09 08:03:23 module_manager.go:66: MM: adding new module: /home/user/test/foo
2022/02/09 08:03:23 module_loader.go:185: ML: enqueing "OpTypeParseModuleConfiguration" module operation: "/home/user/test/foo"
2022/02/09 08:03:23 module_loader.go:185: ML: enqueing "OpTypeLoadModuleMetadata" module operation: "/home/user/test/foo"
2022/02/09 08:03:23 module_loader.go:185: ML: enqueing "OpTypeParseVariables" module operation: "/home/user/test/foo"
2022/02/09 08:03:23 module_loader.go:185: ML: enqueing "OpTypeDecodeReferenceTargets" module operation: "/home/user/test/foo"
2022/02/09 08:03:23 module_loader.go:120: ML: executing "OpTypeParseModuleConfiguration" for "/home/user/test/foo"
2022/02/09 08:03:23 module_loader.go:172: ML: finished "OpTypeParseModuleConfiguration" for "/home/user/test/foo"
2022/02/09 08:03:23 module_loader.go:185: ML: enqueing "OpTypeDecodeReferenceOrigins" module operation: "/home/user/test/foo"
2022/02/09 08:03:23 module_loader.go:120: ML: executing "OpTypeParseVariables" for "/home/user/test/foo"
2022/02/09 08:03:23 module_loader.go:172: ML: finished "OpTypeParseVariables" for "/home/user/test/foo"
2022/02/09 08:03:23 watcher.go:75: adding module for watching: /home/user/test/foo
2022/02/09 08:03:23 module_loader.go:120: ML: executing "OpTypeLoadModuleMetadata" for "/home/user/test/foo"
2022/02/09 08:03:23 module_loader.go:172: ML: finished "OpTypeLoadModuleMetadata" for "/home/user/test/foo"
2022/02/09 08:03:23 module_manager.go:66: MM: adding new module: /home/user/test/foo
2022/02/09 08:03:23 module_loader.go:185: ML: enqueing "OpTypeParseModuleConfiguration" module operation: "/home/user/test/foo"
2022/02/09 08:03:23 module_loader.go:185: ML: enqueing "OpTypeLoadModuleMetadata" module operation: "/home/user/test/foo"
2022/02/09 08:03:23 module_loader.go:120: ML: executing "OpTypeDecodeReferenceTargets" for "/home/user/test/foo"
2022/02/09 08:03:23 module_loader.go:172: ML: finished "OpTypeDecodeReferenceTargets" for "/home/user/test/foo"
2022/02/09 08:03:23 module_loader.go:120: ML: executing "OpTypeDecodeReferenceOrigins" for "/home/user/test/foo"
2022/02/09 08:03:23 module_loader.go:185: ML: enqueing "OpTypeParseVariables" module operation: "/home/user/test/foo"
2022/02/09 08:03:23 module_loader.go:172: ML: finished "OpTypeDecodeReferenceOrigins" for "/home/user/test/foo"
2022/02/09 08:03:23 module_loader.go:185: ML: enqueing "OpTypeDecodeReferenceTargets" module operation: "/home/user/test/foo"
2022/02/09 08:03:23 module_loader.go:185: ML: enqueing "OpTypeDecodeReferenceOrigins" module operation: "/home/user/test/foo"
2022/02/09 08:03:23 module_loader.go:120: ML: executing "OpTypeParseModuleConfiguration" for "/home/user/test/foo"
2022/02/09 08:03:23 module_loader.go:172: ML: finished "OpTypeParseModuleConfiguration" for "/home/user/test/foo"
2022/02/09 08:03:24 module_loader.go:120: ML: executing "OpTypeLoadModuleMetadata" for "/home/user/test/foo"
2022/02/09 08:03:24 module_loader.go:172: ML: finished "OpTypeLoadModuleMetadata" for "/home/user/test/foo"
2022/02/09 08:03:24 watcher.go:75: adding module for watching: /home/user/test/foo
2022/02/09 08:03:24 module_loader.go:185: ML: enqueing "OpTypeDecodeReferenceTargets" module operation: "/home/user/test"
2022/02/09 08:03:24 module_loader.go:185: ML: enqueing "OpTypeDecodeReferenceOrigins" module operation: "/home/user/test"
2022/02/09 08:03:24 module_loader.go:120: ML: executing "OpTypeDecodeReferenceOrigins" for "/home/user/test/foo"
2022/02/09 08:03:24 module_loader.go:172: ML: finished "OpTypeDecodeReferenceOrigins" for "/home/user/test/foo"
2022/02/09 08:03:24 module_loader.go:120: ML: executing "OpTypeDecodeReferenceTargets" for "/home/user/test"
2022/02/09 08:03:24 module_loader.go:120: ML: executing "OpTypeDecodeReferenceTargets" for "/home/user/test/foo"
2022/02/09 08:03:24 module_loader.go:172: ML: finished "OpTypeDecodeReferenceTargets" for "/home/user/test/foo"
2022/02/09 08:03:24 module_loader.go:172: ML: finished "OpTypeDecodeReferenceTargets" for "/home/user/test"
2022/02/09 08:03:24 module_loader.go:120: ML: executing "OpTypeParseVariables" for "/home/user/test/foo"
2022/02/09 08:03:24 module_loader.go:172: ML: finished "OpTypeParseVariables" for "/home/user/test/foo"
2022/02/09 08:03:24 module_loader.go:120: ML: executing "OpTypeDecodeReferenceOrigins" for "/home/user/test"
2022/02/09 08:03:24 module_loader.go:172: ML: finished "OpTypeDecodeReferenceOrigins" for "/home/user/test"
2022/02/09 08:03:26 opts.go:254: Received request batch of size 1 (qlen=0)
2022/02/09 08:03:26 opts.go:254: Dequeued request batch of length 1 (qlen=0)
2022/02/09 08:03:26 rpc_logger.go:29: Incoming notification for "textDocument/didClose": {"textDocument":{"uri":"file:///home/user/test/test.tf"}}
2022/02/09 08:03:27 opts.go:254: Received request batch of size 1 (qlen=0)
2022/02/09 08:03:27 opts.go:254: Dequeued request batch of length 1 (qlen=0)
2022/02/09 08:03:27 rpc_logger.go:29: Incoming notification for "textDocument/didOpen": {"textDocument":{"uri":"file:///home/user/test/test.tf","languageId":"terraform","version":1,"text":"variable \"some-var\" {\n  default = \"value\"\n}\n\nmodule \"foo-mod\" {\n  source = \"./foo\"\n  foo = var.some-var\n}\n\nmodule \"bar\" {\n  source = \"./foo\"\n  foo = module.foo-mod.result-val\n}\n"}}
2022/02/09 08:03:27 did_open.go:44: opened module: /home/user/test
2022/02/09 08:03:27 module_loader.go:185: ML: enqueing "OpTypeParseModuleConfiguration" module operation: "/home/user/test"
2022/02/09 08:03:27 opts.go:254: Received request batch of size 1 (qlen=0)
2022/02/09 08:03:27 module_loader.go:185: ML: enqueing "OpTypeParseVariables" module operation: "/home/user/test"
2022/02/09 08:03:27 module_loader.go:185: ML: enqueing "OpTypeLoadModuleMetadata" module operation: "/home/user/test"
2022/02/09 08:03:27 module_loader.go:185: ML: enqueing "OpTypeDecodeReferenceTargets" module operation: "/home/user/test"
2022/02/09 08:03:27 module_loader.go:185: ML: enqueing "OpTypeDecodeReferenceOrigins" module operation: "/home/user/test"
2022/02/09 08:03:27 module_loader.go:120: ML: executing "OpTypeParseVariables" for "/home/user/test"
2022/02/09 08:03:27 module_loader.go:120: ML: executing "OpTypeParseModuleConfiguration" for "/home/user/test"
2022/02/09 08:03:27 opts.go:254: Dequeued request batch of length 1 (qlen=0)
2022/02/09 08:03:27 rpc_logger.go:29: Incoming request for "textDocument/documentLink" (ID 14): {"textDocument":{"uri":"file:///home/user/test/test.tf"}}
2022/02/09 08:03:27 module_loader.go:172: ML: finished "OpTypeParseVariables" for "/home/user/test"
2022/02/09 08:03:27 module_loader.go:172: ML: finished "OpTypeParseModuleConfiguration" for "/home/user/test"
2022/02/09 08:03:27 rpc_logger.go:50: Response to "textDocument/documentLink" (ID 14): []
2022/02/09 08:03:27 opts.go:254: Completed 1 requests [1.800908ms elapsed]
2022/02/09 08:03:27 opts.go:254: Received request batch of size 1 (qlen=0)
2022/02/09 08:03:27 opts.go:254: Dequeued request batch of length 1 (qlen=0)
2022/02/09 08:03:27 rpc_logger.go:29: Incoming request for "workspace/executeCommand" (ID 15): {"command":"8.terraform-ls.module.callers","arguments":["uri=file:///home/user/test"]}
2022/02/09 08:03:27 rpc_logger.go:50: Response to "workspace/executeCommand" (ID 15): {"v":0,"callers":[]}
2022/02/09 08:03:27 opts.go:254: Completed 1 requests [142µs elapsed]
2022/02/09 08:03:27 opts.go:254: Received request batch of size 1 (qlen=0)
2022/02/09 08:03:27 opts.go:254: Dequeued request batch of length 1 (qlen=0)
2022/02/09 08:03:27 rpc_logger.go:29: Incoming request for "textDocument/documentSymbol" (ID 16): {"textDocument":{"uri":"file:///home/user/test/test.tf"}}
2022/02/09 08:03:27 rpc_logger.go:50: Response to "textDocument/documentSymbol" (ID 16): [{"name":"variable \"some-var\"","kind":5,"range":{"start":{"line":0,"character":0},"end":{"line":2,"character":1}},"selectionRange":{"start":{"line":0,"character":0},"end":{"line":2,"character":1}},"children":[{"name":"default","kind":15,"range":{"start":{"line":1,"character":2},"end":{"line":1,"character":19}},"selectionRange":{"start":{"line":1,"character":2},"end":{"line":1,"character":19}}}]},{"name":"module \"foo-mod\"","kind":5,"range":{"start":{"line":4,"character":0},"end":{"line":7,"character":1}},"selectionRange":{"start":{"line":4,"character":0},"end":{"line":7,"character":1}},"children":[{"name":"source","kind":15,"range":{"start":{"line":5,"character":2},"end":{"line":5,"character":18}},"selectionRange":{"start":{"line":5,"character":2},"end":{"line":5,"character":18}}},{"name":"foo","kind":14,"range":{"start":{"line":6,"character":2},"end":{"line":6,"character":20}},"selectionRange":{"start":{"line":6,"character":2},"end":{"line":6,"character":20}}}]},{"name":"module \"bar\"","kind":5,"range":{"start":{"line":9,"character":0},"end":{"line":12,"character":1}},"selectionRange":{"start":{"line":9,"character":0},"end":{"line":12,"character":1}},"children":[{"name":"source","kind":15,"range":{"start":{"line":10,"character":2},"end":{"line":10,"character":18}},"selectionRange":{"start":{"line":10,"character":2},"end":{"line":10,"character":18}}},{"name":"foo","kind":14,"range":{"start":{"line":11,"character":2},"end":{"line":11,"character":33}},"selectionRange":{"start":{"line":11,"character":2},"end":{"line":11,"character":33}}}]}]
2022/02/09 08:03:27 opts.go:254: Completed 1 requests [1.864909ms elapsed]
2022/02/09 08:03:27 opts.go:254: Received request batch of size 1 (qlen=0)
2022/02/09 08:03:27 opts.go:254: Dequeued request batch of length 1 (qlen=0)
2022/02/09 08:03:27 rpc_logger.go:29: Incoming request for "textDocument/semanticTokens/full" (ID 17): {"textDocument":{"uri":"file:///home/user/test/test.tf"}}
2022/02/09 08:03:27 rpc_logger.go:50: Response to "textDocument/semanticTokens/full" (ID 17): {"data":[0,0,8,0,0,0,9,10,1,2,1,2,7,2,2,3,0,6,0,0,0,7,9,1,0,1,2,6,2,0,0,9,7,1,0,1,2,3,2,2,0,6,3,6,0,0,4,8,6,0,3,0,6,0,0,0,7,5,1,0,1,2,6,2,0,0,9,7,1,0,1,2,3,2,2,0,6,6,6,0,0,7,7,6,0,0,8,10,6,0]}
2022/02/09 08:03:27 opts.go:254: Completed 1 requests [10.340646ms elapsed]
2022/02/09 08:03:27 module_loader.go:120: ML: executing "OpTypeDecodeReferenceTargets" for "/home/user/test"
2022/02/09 08:03:27 module_loader.go:120: ML: executing "OpTypeDecodeReferenceOrigins" for "/home/user/test"
2022/02/09 08:03:27 module_loader.go:172: ML: finished "OpTypeDecodeReferenceTargets" for "/home/user/test"
2022/02/09 08:03:27 module_loader.go:172: ML: finished "OpTypeDecodeReferenceOrigins" for "/home/user/test"
2022/02/09 08:03:27 module_loader.go:120: ML: executing "OpTypeLoadModuleMetadata" for "/home/user/test"
2022/02/09 08:03:27 module_loader.go:172: ML: finished "OpTypeLoadModuleMetadata" for "/home/user/test"
2022/02/09 08:03:28 opts.go:254: Received request batch of size 1 (qlen=0)
2022/02/09 08:03:28 opts.go:254: Dequeued request batch of length 1 (qlen=0)
2022/02/09 08:03:28 rpc_logger.go:29: Incoming request for "textDocument/codeLens" (ID 18): {"textDocument":{"uri":"file:///home/user/test/test.tf"}}
2022/02/09 08:03:28 rpc_logger.go:50: Response to "textDocument/codeLens" (ID 18): []
2022/02/09 08:03:28 opts.go:254: Completed 1 requests [2.402911ms elapsed]
2022/02/09 08:03:28 opts.go:254: Received request batch of size 1 (qlen=0)
2022/02/09 08:03:28 opts.go:254: Dequeued request batch of length 1 (qlen=0)
2022/02/09 08:03:28 rpc_logger.go:29: Incoming request for "textDocument/codeLens" (ID 19): {"textDocument":{"uri":"file:///home/user/test/test.tf"}}
2022/02/09 08:03:28 rpc_logger.go:50: Response to "textDocument/codeLens" (ID 19): []
2022/02/09 08:03:28 opts.go:254: Completed 1 requests [2.02811ms elapsed]
2022/02/09 08:03:32 opts.go:254: Received request batch of size 1 (qlen=0)
2022/02/09 08:03:32 opts.go:254: Dequeued request batch of length 1 (qlen=0)
2022/02/09 08:03:32 rpc_logger.go:29: Incoming request for "workspace/executeCommand" (ID 20): {"command":"8.terraform-ls.module.callers","arguments":["uri=file:///home/user/test"]}
2022/02/09 08:03:32 rpc_logger.go:50: Response to "workspace/executeCommand" (ID 20): {"v":0,"callers":[]}
2022/02/09 08:03:32 opts.go:254: Completed 1 requests [208.801µs elapsed]