diff --git a/README.md b/README.md index 5d156237..77526b80 100644 --- a/README.md +++ b/README.md @@ -87,9 +87,21 @@ require('copilot').setup({ cvs = false, ["."] = false, }, + logger = { + log_to_file = false, + file = vim.fn.stdpath("log") .. "/copilot-lua.log", + file_log_level = vim.log.levels.WARN, + print_log = true, + print_log_level = vim.log.levels.WARN, + trace_lsp = "off", -- "off" | "messages" | "verbose" + trace_lsp_progress = false, + }, copilot_node_command = 'node', -- Node.js version must be > 18.x - copilot_model = "", -- Current LSP default is gpt-35-turbo, supports gpt-4o-copilot workspace_folders = {}, + copilot_model = "", -- Current LSP default is gpt-35-turbo, supports gpt-4o-copilot + root_dir = function() + return vim.fs.dirname(vim.fs.find(".git", { upward = true })[1]) + end, server_opts_overrides = {}, }) ``` @@ -180,6 +192,32 @@ require("copilot").setup { } ``` +### logger + +When `log_to_file` is true, logs will be written to the `file` for anything of `file_log_level` or higher. +When `print_log` is true, logs will be printed to NeoVim (using `notify`) for anything of `print_log_level` or higher. +File logging is done asynchronously to minimize performance impacts, however there is still some overhead. + +Log levels used are the ones defined in `vim.log`: + +```lua +vim.log = { + levels = { + TRACE = 0, + DEBUG = 1, + INFO = 2, + WARN = 3, + ERROR = 4, + OFF = 5, + }, +} +``` + +`trace_lsp` can either be `off`, `messages` which will output the LSP messages, or `verbose` which adds additonal information to the message. +When `trace_lsp_progress` is true, LSP progress messages will also be logged. + +Careful turning on all logging features as the log files may get very large over time, and are not pruned by the application. + ### copilot_node_command Use this field to provide the path to a specific node version such as one installed by nvm. Node.js version must be 18.x or newer. @@ -228,6 +266,11 @@ workspace_folders = { They can also be added runtime, using the command `:Copilot workspace add [folderpath]` where `[folderpath]` is the workspace folder. +### root_dir + +This allows changing the function that gets the root folder, the default looks for a parent folder that contains the folder `.git`. +If none is found, it will use the current working directory. + ## Commands `copilot.lua` defines the `:Copilot` command that can perform various actions. It has completion support, so try it out. diff --git a/lua/copilot/auth.lua b/lua/copilot/auth.lua index b91baefe..4b5106b4 100644 --- a/lua/copilot/auth.lua +++ b/lua/copilot/auth.lua @@ -1,5 +1,6 @@ local api = require("copilot.api") local c = require("copilot.client") +local logger = require("copilot.logger") local M = {} @@ -145,7 +146,7 @@ local function find_config_path() if vim.fn.isdirectory(config) > 0 then return config else - print("Error: could not find config path") + logger.error("could not find config path") end end end diff --git a/lua/copilot/client.lua b/lua/copilot/client.lua index 82ba4b23..c501e0be 100644 --- a/lua/copilot/client.lua +++ b/lua/copilot/client.lua @@ -1,6 +1,7 @@ local api = require("copilot.api") local config = require("copilot.config") local util = require("copilot.util") +local logger = require("copilot.logger") local is_disabled = false @@ -9,6 +10,7 @@ local M = { id = nil, --- @class copilot_capabilities:lsp.ClientCapabilities --- @field copilot table<'openURL', boolean> + --- @field workspace table<'workspaceFolders', boolean> capabilities = nil, config = nil, node_version = nil, @@ -21,7 +23,8 @@ local M = { local function store_client_id(id) if M.id and M.id ~= id then if vim.lsp.get_client_by_id(M.id) then - error("unexpectedly started multiple copilot servers") + logger.error("unexpectedly started multiple copilot servers") + return end end @@ -92,7 +95,7 @@ end ---@param force? boolean function M.buf_attach(force) if is_disabled then - print("[Copilot] Offline") + logger.warn("copilot is disabled") return end @@ -101,20 +104,23 @@ function M.buf_attach(force) end if not M.config then - vim.notify("[Copilot] Cannot attach: configuration not initialized", vim.log.levels.ERROR) + logger.error("cannot attach: configuration not initialized") return end + -- In case it has changed, we update it + M.config.root_dir = config.get_root_dir() + local ok, client_id_or_err = pcall(lsp_start, M.config) if not ok then - vim.notify(string.format("[Copilot] Failed to start LSP client: %s", client_id_or_err), vim.log.levels.ERROR) + logger.error(string.format("failed to start LSP client: %s", client_id_or_err)) return end if client_id_or_err then store_client_id(client_id_or_err) else - vim.notify("[Copilot] LSP client failed to start (no client ID returned)", vim.log.levels.ERROR) + logger.error("LSP client failed to start (no client ID returned)") end end @@ -135,7 +141,7 @@ end ---@param callback fun(client:table):nil function M.use_client(callback) if is_disabled then - print("[Copilot] Offline") + logger.warn("copilot is offline") return end @@ -143,13 +149,14 @@ function M.use_client(callback) if not client then if not M.config then - error("copilot.setup is not called yet") + logger.error("copilot.setup is not called yet") + return end local client_id, err = vim.lsp.start_client(M.config) if not client_id then - error(string.format("[Copilot] Error starting LSP Client: %s", err)) + logger.error(string.format("error starting LSP client: %s", err)) return end @@ -166,7 +173,7 @@ function M.use_client(callback) local timer, err, _ = vim.loop.new_timer() if not timer then - error(string.format("[Copilot] Error creating timer: %s", err)) + logger.error(string.format("error creating timer: %s", err)) return end @@ -188,7 +195,7 @@ local function prepare_client_config(overrides) if vim.fn.executable(node) ~= 1 then local err = string.format("copilot_node_command(%s) is not executable", node) - vim.notify("[Copilot] " .. err, vim.log.levels.ERROR) + logger.error(err) M.startup_error = err return end @@ -196,7 +203,7 @@ local function prepare_client_config(overrides) local agent_path = vim.api.nvim_get_runtime_file("copilot/dist/language-server.js", false)[1] if not agent_path or vim.fn.filereadable(agent_path) == 0 then local err = string.format("Could not find language-server.js (bad install?) : %s", tostring(agent_path)) - vim.notify("[Copilot] " .. err, vim.log.levels.ERROR) + logger.error(err) M.startup_error = err return end @@ -218,11 +225,7 @@ local function prepare_client_config(overrides) ["copilot/openURL"] = api.handlers["copilot/openURL"], } - local root_dir = vim.loop.cwd() - if not root_dir then - root_dir = vim.fn.getcwd() - end - + local root_dir = config.get_root_dir() local workspace_folders = { --- @type workspace_folder { @@ -247,6 +250,7 @@ local function prepare_client_config(overrides) end end + -- LSP config, not to be confused with config.lua return vim.tbl_deep_extend("force", { cmd = { node, @@ -272,11 +276,14 @@ local function prepare_client_config(overrides) set_editor_info_params.authProvider = provider_url and { url = provider_url, } or nil + + logger.debug("data for setEditorInfo LSP call", set_editor_info_params) api.set_editor_info(client, set_editor_info_params, function(err) if err then - vim.notify(string.format("[copilot] setEditorInfo failure: %s", err), vim.log.levels.ERROR) + logger.error(string.format("setEditorInfo failure: %s", err)) end end) + logger.trace("setEditorInfo has been called") M.initialized = true end) end, @@ -299,6 +306,7 @@ local function prepare_client_config(overrides) copilotIntegrationId = "vscode-chat", }, workspace_folders = workspace_folders, + trace = config.get("trace") or "off", }, overrides) end @@ -339,12 +347,12 @@ end function M.add_workspace_folder(folder_path) if type(folder_path) ~= "string" then - vim.notify("[Copilot] Workspace folder path must be a string", vim.log.levels.ERROR) + logger.error("workspace folder path must be a string") return false end if vim.fn.isdirectory(folder_path) ~= 1 then - vim.notify("[Copilot] Invalid workspace folder: " .. folder_path, vim.log.levels.ERROR) + logger.error("invalid workspace folder: " .. folder_path) return false end @@ -379,9 +387,9 @@ function M.add_workspace_folder(folder_path) removed = {}, }, }) - vim.notify("[Copilot] Added workspace folder: " .. folder_path, vim.log.levels.INFO) + logger.notify("added workspace folder: " .. folder_path) else - vim.notify("[Copilot] Workspace folder added for next session: " .. folder_path, vim.log.levels.INFO) + logger.notify("workspace folder will be added on next session: " .. folder_path) end return true diff --git a/lua/copilot/config.lua b/lua/copilot/config.lua index 5cda088a..00805c7f 100644 --- a/lua/copilot/config.lua +++ b/lua/copilot/config.lua @@ -1,3 +1,5 @@ +local logger = require("copilot.logger") + ---@class copilot_config local default_config = { ---@class copilot_config_panel @@ -33,6 +35,17 @@ local default_config = { dismiss = "", }, }, + ---@class copilot_config_logging + logger = { + log_to_file = false, + file = vim.fn.stdpath("log") .. "/copilot-lua.log", + file_log_level = vim.log.levels.WARN, + print_log = true, + print_log_level = vim.log.levels.WARN, + ---@type string<'off'|'messages'|'verbose'> + trace_lsp = "off", + trace_lsp_progress = false, + }, ---@deprecated ft_disable = nil, ---@type table @@ -45,15 +58,20 @@ local default_config = { server_opts_overrides = {}, ---@type string|nil copilot_model = nil, + ---@type function|string + root_dir = function() + return vim.fs.dirname(vim.fs.find(".git", { upward = true })[1]) + end, } local mod = { + ---@type copilot_config config = nil, } function mod.setup(opts) if mod.config then - vim.notify("[Copilot] config is already set", vim.log.levels.WARN) + logger.warn("config is already set") return mod.config end @@ -76,7 +94,8 @@ end ---@param key? string function mod.get(key) if not mod.config then - error("[Copilot] not initialized") + logger.error("not initialized") + return end if key then @@ -90,10 +109,33 @@ end ---@param value any function mod.set(key, value) if not mod.config then - error("[Copilot] not initialized") + logger.error("not initialized") + return end mod.config[key] = value end +function mod.get_root_dir() + if not mod.config then + error("[Copilot] not initialized") + end + + local config_root_dir = mod.config.root_dir + local root_dir --[[@as string]] + + if type(config_root_dir) == "function" then + root_dir = config_root_dir() + else + root_dir = config_root_dir + end + + if not root_dir or root_dir == "" then + root_dir = "." + end + + root_dir = vim.fn.fnamemodify(root_dir, ":p:h") + return root_dir +end + return mod diff --git a/lua/copilot/init.lua b/lua/copilot/init.lua index bd41b8f3..a295ec74 100644 --- a/lua/copilot/init.lua +++ b/lua/copilot/init.lua @@ -1,6 +1,8 @@ local M = { setup_done = false } local config = require("copilot.config") local highlight = require("copilot.highlight") +local logger = require("copilot.logger") +local client = require("copilot.client") local create_cmds = function() vim.api.nvim_create_user_command("CopilotDetach", function() @@ -39,6 +41,11 @@ M.setup = function(opts) end require("copilot.command").enable() + logger.setup(conf.logger) + + logger.debug("active plugin config:", config) + -- logged here to ensure the logger is setup + logger.debug("active LSP config (may change runtime):", client.config) M.setup_done = true end diff --git a/lua/copilot/logger.lua b/lua/copilot/logger.lua new file mode 100644 index 00000000..053cfd88 --- /dev/null +++ b/lua/copilot/logger.lua @@ -0,0 +1,175 @@ +local uv = vim.uv + +---@class logger +local mod = { + log_to_file = false, + log_file = vim.fn.stdpath("log") .. "/copilot-lua.log", + file_log_level = vim.log.levels.WARN, + print_log = true, + print_log_level = vim.log.levels.WARN, +} + +local log_level_names = { + [vim.log.levels.ERROR] = "ERROR", --4 + [vim.log.levels.WARN] = "WARN", --3 + [vim.log.levels.INFO] = "INFO", --2 + [vim.log.levels.DEBUG] = "DEBUG", --1 + [vim.log.levels.TRACE] = "TRACE", --0 +} + +---@return string timestamp +local function get_timestamp_with_ms() + local seconds = os.time() + local milliseconds = math.floor((os.clock() % 1) * 1000) + return string.format("%s.%03d", os.date("%Y-%m-%d %H:%M:%S", seconds), milliseconds) +end + +---@param log_level integer --vim.log.levels +---@param msg string +---@param data any +---@return string log_msg +local function format_log(log_level, msg, data) + local log_level_name = log_level_names[log_level] + local log_msg = string.format("%s [%s]: %s", get_timestamp_with_ms(), log_level_name, msg) + + if data then + log_msg = string.format("%s\n%s", log_msg, vim.inspect(data)) + end + + return log_msg +end + +---@param log_level integer -- one of the vim.log.levels +---@param msg string +---@param data any +local function notify_log(log_level, msg, data) + local log_msg = format_log(log_level, msg, data) + vim.notify(log_msg, log_level) +end + +---@param log_level integer -- one of the vim.log.levels +---@param log_file string +---@param msg string +---@param data any +local function write_log(log_level, log_file, msg, data) + local log_msg = format_log(log_level, msg, data) .. "\n" + + uv.fs_open(log_file, "a", tonumber("644", 8), function(err, fd) + if err then + notify_log(vim.log.levels.ERROR, "Failed to open log file: " .. err) + return + end + + uv.fs_write(fd, log_msg, -1, function(write_err) + if write_err then + notify_log(vim.log.levels.ERROR, "Failed to write to log file: " .. write_err) + end + + uv.fs_close(fd) + end) + end) +end + +---@param log_level integer -- one of the vim.log.levels +---@param msg string +---@param data any +---@param force_print boolean +function mod.log(log_level, msg, data, force_print) + if mod.log_to_file and (mod.file_log_level <= log_level) then + write_log(log_level, mod.log_file, msg, data) + end + + if force_print or (mod.print_log and (mod.print_log_level <= log_level)) then + notify_log(log_level, msg, data) + end +end + +---@param msg string +---@param data any +function mod.debug(msg, data) + mod.log(vim.log.levels.DEBUG, msg, data, false) +end + +---@param msg string +---@param data any +function mod.trace(msg, data) + mod.log(vim.log.levels.TRACE, msg, data, false) +end + +---@param msg string +---@param data any +function mod.error(msg, data) + mod.log(vim.log.levels.ERROR, msg, data, false) +end + +---@param msg string +---@param data any +function mod.warn(msg, data) + mod.log(vim.log.levels.WARN, msg, data, false) +end + +---@param msg string +---@param data any +function mod.info(msg, data) + mod.log(vim.log.levels.INFO, msg, data, false) +end + +---@param msg string +---@param data any +function mod.notify(msg, data) + mod.log(vim.log.levels.INFO, msg, data, true) +end + +---@param conf copilot_config_logging +function mod.setup(conf) + mod.log_file = conf.file + mod.file_log_level = conf.file_log_level + mod.print_log_level = conf.print_log_level + mod.log_to_file = conf.log_to_file + mod.print_log = conf.print_log + + if conf.trace_lsp ~= "off" then + vim.lsp.handlers["$/logTrace"] = function(_, result, _) + if not result then + return + end + + mod.trace(string.format("LSP trace - %s", result.message), result.verbose) + end + end + + if conf.trace_lsp_progress then + vim.lsp.handlers["$/progress"] = function(_, result, _) + if not result then + return + end + + mod.trace(string.format("LSP progress - token %s", result.token), result.value) + end + end + + vim.lsp.handlers["window/logMessage"] = function(_, result, _) + if not result then + return + end + + local message = string.format("LSP message: %s", result.message) + local message_type = result.type --[[@as integer]] + + if message_type == 1 then + mod.error(message) + elseif message_type == 2 then + mod.warn(message) + elseif message_type == 3 then + mod.info(message) + elseif message_type == 4 then + mod.info(message) + elseif message_type == 5 then + mod.debug(message) + else + mod.trace(message) + end + end +end + +return mod diff --git a/lua/copilot/panel.lua b/lua/copilot/panel.lua index 7105a406..4ed21b27 100644 --- a/lua/copilot/panel.lua +++ b/lua/copilot/panel.lua @@ -3,6 +3,7 @@ local c = require("copilot.client") local config = require("copilot.config") local hl_group = require("copilot.highlight").group local util = require("copilot.util") +local logger = require("copilot.logger") local mod = {} @@ -337,7 +338,7 @@ function panel:ensure_winid() local split_info = split_map[position] if not split_info then - print("Error: " .. position .. " is not a valid position") + logger.error(string.format("%s is not a valid position", position)) return end @@ -446,7 +447,7 @@ function panel:refresh() elseif result.status == "Error" then self.state.status = "error" self.state.error = result.message - print(self.state.error) + logger.error(self.state.error) end self:unlock():refresh_header():lock() @@ -482,7 +483,7 @@ function panel:refresh() if err then self.state.status = "error" self.state.error = err - print(self.state.error) + logger.error(self.state.error) return end @@ -505,10 +506,7 @@ function panel:init() if not c.buf_is_attached(0) then local should_attach, no_attach_reason = util.should_attach() - vim.notify( - string.format("[Copilot] %s", should_attach and ("Disabled manually for " .. vim.bo.filetype) or no_attach_reason), - vim.log.levels.ERROR - ) + logger.error(string.format("%s", should_attach and "Disabled manually for " .. vim.bo.filetype or no_attach_reason)) return end @@ -548,7 +546,7 @@ end function mod.open(layout) local client = c.get() if not client then - print("Error, copilot not running") + logger.error("copilot is not running") return end diff --git a/lua/copilot/suggestion.lua b/lua/copilot/suggestion.lua index 0bf1accc..57966234 100644 --- a/lua/copilot/suggestion.lua +++ b/lua/copilot/suggestion.lua @@ -3,6 +3,7 @@ local c = require("copilot.client") local config = require("copilot.config") local hl_group = require("copilot.highlight").group local util = require("copilot.util") +local logger = require("copilot.logger") local _, has_nvim_0_10_x = pcall(function() return vim.version().minor >= 10 @@ -196,11 +197,11 @@ local function get_current_suggestion(ctx) local ok, choice = pcall(function() if - not vim.fn.mode():match("^[iR]") - or (copilot.hide_during_completion and vim.fn.pumvisible() == 1) - or vim.b.copilot_suggestion_hidden - or not ctx.suggestions - or #ctx.suggestions == 0 + not vim.fn.mode():match("^[iR]") + or (copilot.hide_during_completion and vim.fn.pumvisible() == 1) + or vim.b.copilot_suggestion_hidden + or not ctx.suggestions + or #ctx.suggestions == 0 then return nil end @@ -250,7 +251,7 @@ local function update_preview(ctx) local cursor_col = vim.fn.col(".") displayLines[1] = - string.sub(string.sub(suggestion.text, 1, (string.find(suggestion.text, "\n", 1, true) or 0) - 1), cursor_col) + string.sub(string.sub(suggestion.text, 1, (string.find(suggestion.text, "\n", 1, true) or 0) - 1), cursor_col) local extmark = { id = copilot.extmark_id, @@ -311,7 +312,7 @@ end ---@param data copilot_get_completions_data local function handle_trigger_request(err, data) if err then - print(err) + logger.error(err) end local ctx = get_ctx() ctx.suggestions = data and data.completions or {} @@ -337,7 +338,7 @@ local function get_suggestions_cycling_callback(ctx, err, data) ctx.cycling_callbacks = nil if err then - print(err) + logger.error(err) return end @@ -467,10 +468,7 @@ function mod.accept(modifier) ) end) if not ok then - vim.notify( - table.concat({ "[Copilot] failed to notify_accepted for: " .. suggestion.text, "Error: " .. err }, "\n\n"), - vim.log.levels.ERROR - ) + logger.error(string.format("failed to notify_accepted for: %s, Error: %s", suggestion.text)) end end) @@ -486,7 +484,7 @@ function mod.accept(modifier) -- Hack for 'autoindent', makes the indent persist. Check `:help 'autoindent'`. vim.schedule_wrap(function() vim.api.nvim_feedkeys(vim.api.nvim_replace_termcodes("", true, false, true), "n", false) - local bufnr = vim.api.nvim_get_current_buf() + local bufnr = vim.api.nvim_get_current_buf() local encoding = vim.api.nvim_get_option_value("fileencoding", { buf = bufnr }) ~= "" and vim.api.nvim_get_option_value("fileencoding", { buf = bufnr }) or vim.api.nvim_get_option_value("encoding", { scope = "global" }) @@ -678,7 +676,6 @@ function mod.setup() create_autocmds() copilot.debounce = opts.debounce - copilot.setup_done = true end diff --git a/lua/copilot/util.lua b/lua/copilot/util.lua index 68817836..ab416966 100644 --- a/lua/copilot/util.lua +++ b/lua/copilot/util.lua @@ -1,4 +1,5 @@ local config = require("copilot.config") +local logger = require("copilot.logger") local unpack = unpack or table.unpack local M = {} @@ -291,7 +292,7 @@ M.get_plugin_path = function() if vim.fn.filereadable(copilot_path) ~= 0 then return vim.fn.fnamemodify(copilot_path, ":h:h:h") else - print("[Copilot] could not read" .. copilot_path) + logger.error("could not read" .. copilot_path) end end diff --git a/lua/copilot/workspace.lua b/lua/copilot/workspace.lua index c8f722de..dd5173e3 100644 --- a/lua/copilot/workspace.lua +++ b/lua/copilot/workspace.lua @@ -1,3 +1,6 @@ +local logger = require("copilot.logger") +local client = require("copilot.client") + local mod = {} ---@class workspace_folder ---@field uri string The URI of the workspace folder @@ -5,12 +8,12 @@ local mod = {} function mod.add(opts) local folder = opts.args if not folder or folder == "" then - error("Folder is required to add a workspace_folder") + logger.error("folder is required to add a workspace_folder") + return end folder = vim.fn.fnamemodify(folder, ":p") - - require("copilot.client").add_workspace_folder(folder) + client.add_workspace_folder(folder) end return mod