From 892bab640beea955ecb9172b21dd4a1b5521d2d7 Mon Sep 17 00:00:00 2001 From: Marc Jakobi Date: Mon, 11 Dec 2023 03:11:33 +0100 Subject: [PATCH] feat: logging + `:Rocks log` command --- README.md | 5 ++ doc/rocks.txt | 12 ++-- lua/rocks/commands.lua | 6 ++ lua/rocks/log.lua | 131 +++++++++++++++++++++++++++++++++++++++ lua/rocks/luarocks.lua | 22 ++++--- lua/rocks/operations.lua | 85 ++++++++++++------------- lua/rocks/state.lua | 7 ++- 7 files changed, 212 insertions(+), 56 deletions(-) create mode 100644 lua/rocks/log.lua diff --git a/README.md b/README.md index e4c2a595..4b9a8bf2 100644 --- a/README.md +++ b/README.md @@ -118,6 +118,11 @@ that are no longer needed, run the `:Rocks prune [rock]` command. The `:Rocks edit` command opens the `rocks.toml` file for manual editing. Make sure to run `:Rocks sync` when you are done. +### Troubleshooting + +The `:Rocks log` command opens a log file for the current session, +which contains the `luarocks` stderr output, among other logs. + ## :waning_crescent_moon: Lua API This plugin provides a Lua API for extensibility. diff --git a/doc/rocks.txt b/doc/rocks.txt index 2a322a9c..9e1775ae 100644 --- a/doc/rocks.txt +++ b/doc/rocks.txt @@ -22,12 +22,14 @@ rocks.nvim commands *rocks.commands* command action ------------------------------------------------------------------------------ - install [rock] [version?] install {rock} with optional {version}. - prune [rock] uninstall {rock} and its stale dependencies, + install [rock] [version?] Install {rock} with optional {version}. + prune [rock] Uninstall {rock} and its stale dependencies, and remove it from rocks.toml. - sync synchronize installed rocks with rocks.toml. - update search for updated rocks and install them. - edit edit the rocks.toml file. + sync Synchronize installed rocks with rocks.toml. + It may take more than one sync to prune all rocks that can be pruned. + update Search for updated rocks and install them. + edit Edit the rocks.toml file. + log Open the log file. ============================================================================== diff --git a/lua/rocks/commands.lua b/lua/rocks/commands.lua index 525baec6..c9996ac3 100644 --- a/lua/rocks/commands.lua +++ b/lua/rocks/commands.lua @@ -14,6 +14,7 @@ --- It may take more than one sync to prune all rocks that can be pruned. --- update Search for updated rocks and install them. --- edit Edit the rocks.toml file. +--- log Open the log file. --- ---@brief ]] --- @@ -122,6 +123,11 @@ local rocks_command_tbl = { vim.cmd.e(require("rocks.config.internal").config_path) end, }, + log = { + impl = function(_) + require("rocks.log").open_logfile() + end, + }, } local function rocks(opts) diff --git a/lua/rocks/log.lua b/lua/rocks/log.lua new file mode 100644 index 00000000..32df9b3f --- /dev/null +++ b/lua/rocks/log.lua @@ -0,0 +1,131 @@ +---@mod rocks.log rocks.nvim logging +--- +---@brief [[ +--- +---The internal logging interface for rocks.nvim +--- +---@brief ]] + +-- Copyright (C) 2023 Neorocks Org. +-- +-- Version: 0.1.0 +-- License: GPLv3 +-- Created: 12 Dec 2023 +-- Updated: 12 Dec 2023 +-- Homepage: https://github.com/nvim-neorocks/rocks.nvim +-- Maintainer: NTBBloodbath + +local log = { + -- NOTE: These functions are initialised as empty for type checking purposes + -- and implemented later. + trace = function(_) end, + debug = function(_) end, + info = function(_) end, + warn = function(_) end, + error = function(_) end, +} + +local LARGE = 1e9 + +local log_date_format = "%F %H:%M:%S" + +local function format_log(arg) + return vim.inspect(arg) +end + +---For now, we have a log file per session +local logfilename = vim.fn.tempname() .. "-rocks-nvim.log" + +---Get the rocks.nvim log file path. +---@return string filepath +function log.get_logfile() + return logfilename +end + +---Open the rocks.nvim log file. +function log.open_logfile() + vim.cmd.e(log.get_logfile()) +end + +local logfile, openerr +--- @private +--- Opens log file. Returns true if file is open, false on error +--- @return boolean +local function open_logfile() + -- Try to open file only once + if logfile then + return true + end + if openerr then + return false + end + + logfile, openerr = io.open(log.get_logfile(), "a+") + if not logfile then + local err_msg = string.format("Failed to open rocks.nvim log file: %s", openerr) + vim.notify(err_msg, vim.log.levels.ERROR) + return false + end + + local log_info = vim.uv.fs_stat(log.get_logfile()) + if log_info and log_info.size > LARGE then + local warn_msg = + string.format("rocks.nvim log is large (%d MB): %s", log_info.size / (1000 * 1000), log.get_logfile()) + vim.notify(warn_msg, vim.log.levels.WARN) + end + + -- Start message for logging + logfile:write(string.format("[START][%s] rocks.nvim logging initiated\n", os.date(log_date_format))) + return true +end + +--- Set the log level +--- @param level (string|integer) The log level +--- @see vim.log.levels +function log.set_level(level) + local log_levels = vim.deepcopy(vim.log.levels) + vim.tbl_add_reverse_lookup(log_levels) + if type(level) == "string" then + log.level = assert(log_levels[string.upper(level)], string.format("rocks.nvim: Invalid log level: %q", level)) + else + assert(log_levels[level], string.format("rocks.nvim: Invalid log level: %d", level)) + log.level = level + end + vim.lsp.set_log_level(log.level) +end + +for level, levelnr in pairs(vim.log.levels) do + log[level:lower()] = function(...) + if log.level == vim.log.levels.OFF or not open_logfile() then + return false + end + local argc = select("#", ...) + if levelnr < log.level then + return false + end + if argc == 0 then + return true + end + local info = debug.getinfo(2, "Sl") + local fileinfo = string.format("%s:%s", info.short_src, info.currentline) + local parts = { + table.concat({ level, "|", os.date(log_date_format), "|", fileinfo, "|" }, " "), + } + for i = 1, argc do + local arg = select(i, ...) + if arg == nil then + table.insert(parts, "") + elseif type(arg) == "string" then + table.insert(parts, arg) + else + table.insert(parts, format_log(arg)) + end + end + logfile:write(table.concat(parts, " "), "\n") + logfile:flush() + end +end + +log.set_level(vim.log.levels.INFO) + +return log diff --git a/lua/rocks/luarocks.lua b/lua/rocks/luarocks.lua index 6ca78cf0..836ac86f 100644 --- a/lua/rocks/luarocks.lua +++ b/lua/rocks/luarocks.lua @@ -19,6 +19,7 @@ local luarocks = {} local constants = require("rocks.constants") local config = require("rocks.config.internal") +local log = require("rocks.log") local nio = require("nio") ---@class LuarocksCliOpts: SystemOpts @@ -36,16 +37,22 @@ lock.set(true) -- initialise as unlocked luarocks.cli = function(args, on_exit, opts) opts = opts or {} opts.synchronized = opts.synchronized ~= nil and opts.synchronized or false - local on_exit_wrapped = on_exit and vim.schedule_wrap(on_exit) + local on_exit_wrapped = vim.schedule_wrap(function(sc) + if opts.synchronized then + pcall(lock.set, true) + end + ---@cast sc vim.SystemCompleted + if sc.code ~= 0 then + log.error("luarocks CLI FAILED") + log.error(sc.stderr) + end + if on_exit then + on_exit(sc) + end + end) if opts.synchronized then lock.wait() lock = nio.control.future() - on_exit_wrapped = vim.schedule_wrap(function(...) - pcall(lock.set, true) - if on_exit then - on_exit(...) - end - end) end local luarocks_cmd = vim.list_extend({ config.luarocks_binary, @@ -53,6 +60,7 @@ luarocks.cli = function(args, on_exit, opts) "--tree=" .. config.rocks_path, "--server='https://nvim-neorocks.github.io/rocks-binaries/'", }, args) + log.info(luarocks_cmd) return vim.system(luarocks_cmd, opts, on_exit_wrapped) end diff --git a/lua/rocks/operations.lua b/lua/rocks/operations.lua index a90fbf68..57a47320 100644 --- a/lua/rocks/operations.lua +++ b/lua/rocks/operations.lua @@ -17,6 +17,7 @@ ---@brief ]] local constants = require("rocks.constants") +local log = require("rocks.log") local fs = require("rocks.fs") local config = require("rocks.config.internal") local state = require("rocks.state") @@ -46,10 +47,10 @@ end ---@return Future operations.install = function(name, version, progress_handle) state.invalidate_cache() + local message = version and ("Installing: %s -> %s"):format(name, version) or ("Installing: %s"):format(name) + log.info(message) if progress_handle then - progress_handle:report({ - message = version and ("Installing: %s -> %s"):format(name, version) or ("Installing: %s"):format(name), - }) + progress_handle:report({ message = message }) end -- TODO(vhyrro): Input checking on name and version local future = nio.control.future() @@ -68,12 +69,12 @@ operations.install = function(name, version, progress_handle) local systemObj = luarocks.cli(install_cmd, function(sc) ---@cast sc vim.SystemCompleted if sc.code ~= 0 then - future.set_error(sc.stderr) + message = ("Failed to install %s"):format(name) + log.error(message) if progress_handle then - progress_handle:report({ - message = ("Failed to install %s: %s"):format(name, sc.stderr), - }) + progress_handle:report({ message = message }) end + future.set_error(sc.stderr) else ---@type Rock local installed_rock = { @@ -83,10 +84,10 @@ operations.install = function(name, version, progress_handle) -- We also exclude `-` from the version match. version = sc.stdout:match(name:gsub("%p", "%%%1") .. "%s+([^-%s]+)"), } + message = ("Installed: %s -> %s"):format(installed_rock.name, installed_rock.version) + log.info(message) if progress_handle then - progress_handle:report({ - message = ("Installed: %s -> %s"):format(installed_rock.name, installed_rock.version), - }) + progress_handle:report({ message = message }) end future.set(installed_rock) end @@ -105,10 +106,10 @@ end ---@return Future operations.remove = function(name, progress_handle) state.invalidate_cache() + local message = ("Uninstalling: %s"):format(name) + log.info(message) if progress_handle then - progress_handle:report({ - message = ("Uninstalling: %s"):format(name), - }) + progress_handle:report({ message = message }) end local future = nio.control.future() local systemObj = luarocks.cli({ @@ -117,14 +118,13 @@ operations.remove = function(name, progress_handle) }, function(sc) ---@cast sc vim.SystemCompleted if sc.code ~= 0 then - future.set_error(sc.stderr) + message = ("Failed to remove %s."):format(name) if progress_handle then - progress_handle:report({ - message = ("Failed to remove %s: %s"):format(name, sc.stderr), - }) + progress_handle:report({ message = message }) end + future.set_error(sc.stderr) else - -- TODO: Raise an error with set_error on the future if something goes wrong + log.info(("Uninstalled: %s"):format(name)) future.set(sc) end end) @@ -167,6 +167,7 @@ end) --- - Uninstalls unneeded rocks ---@param user_rocks? { [string]: Rock|string } loaded from rocks.toml if `nil` operations.sync = function(user_rocks) + log.info("syncing...") nio.run(function() local progress_handle = progress.handle.create({ title = "Syncing", @@ -257,16 +258,13 @@ operations.sync = function(user_rocks) else future = operations.install(user_rocks[key].name, user_rocks[key].version) end - local success, ret = pcall(future.wait) + local success = pcall(future.wait) ct = ct + 1 nio.scheduler() if not success then - -- TODO: Keep track of failures: #55 - progress_handle:report({ - percentage = get_progress_percentage(), - }) - report_error(("Failed to install %s: %s"):format(key, vim.inspect(ret))) + progress_handle:report({ percentage = get_progress_percentage() }) + report_error(("Failed to install %s."):format(key)) end progress_handle:report({ message = ("Installed: %s"):format(key), @@ -283,7 +281,7 @@ operations.sync = function(user_rocks) }) local future = operations.install(user_rocks[key].name, user_rocks[key].version) - local success, ret = pcall(future.wait) + local success = pcall(future.wait) ct = ct + 1 nio.scheduler() @@ -292,13 +290,12 @@ operations.sync = function(user_rocks) percentage = get_progress_percentage(), }) report_error( - is_downgrading and ("Failed to downgrade %s: %s"):format(key, vim.inspect(ret)) - or ("Failed to upgrade %s: %s"):format(key, vim.inspect(ret)) + is_downgrading and ("Failed to downgrade %s"):format(key) or ("Failed to upgrade %s"):format(key) ) end progress_handle:report({ - message = is_downgrading and ("Downgraded: %s"):format(key) or ("Upgraded: %s"):format(key), percentage = get_progress_percentage(), + message = is_downgrading and ("Downgraded: %s"):format(key) or ("Upgraded: %s"):format(key), }) end @@ -326,8 +323,10 @@ operations.sync = function(user_rocks) action_count = #to_install + #to_updowngrade + #prunable_rocks if ct == 0 and vim.tbl_isempty(prunable_rocks) then + local message = "Everything is in-sync!" + log.info(message) nio.scheduler() - progress_handle:report({ message = "Everything is in-sync!", percentage = 100 }) + progress_handle:report({ message = message, percentage = 100 }) progress_handle:finish() return end @@ -337,9 +336,7 @@ operations.sync = function(user_rocks) -- Prune rocks sequentially, to prevent conflicts for _, key in ipairs(prunable_rocks) do nio.scheduler() - progress_handle:report({ - message = ("Removing: %s"):format(key), - }) + progress_handle:report({ message = ("Removing: %s"):format(key) }) local success = operations.remove_recursive(installed_rocks[key].name, user_rock_names) @@ -350,7 +347,7 @@ operations.sync = function(user_rocks) progress_handle:report({ percentage = get_progress_percentage(), }) - report_error(("Failed to remove %s"):format(key)) + report_error(("Failed to remove %s."):format(key)) else progress_handle:report({ message = ("Removed: %s"):format(key), @@ -360,9 +357,11 @@ operations.sync = function(user_rocks) end if not vim.tbl_isempty(error_handles) then + local message = "Sync completed with errors!" + log.error(message) progress_handle:report({ title = "Error", - message = "Sync completed with errors!", + message = message, percentage = 100, }) progress_handle:cancel() @@ -408,7 +407,7 @@ operations.update = function() if not success then has_errors = true progress_handle:report({ - message = ("Failed to update %s: %s"):format(rock.name, vim.inspect(ret)), + message = ("Failed to update %s."):format(rock.name), percentage = math.floor(ct / #actions * 100), }) return @@ -429,9 +428,11 @@ operations.update = function() end nio.scheduler() if has_errors then + local message = "Update completed with errors!" + log.error(message) progress_handle:report({ title = "Error", - message = "Update completed with errors!", + message = message, percentage = 100, }) progress_handle:cancel() @@ -453,17 +454,16 @@ operations.add = function(rock_name, version) nio.run(function() local future = operations.install(rock_name, version) - local success, result = pcall(future.wait) + local success, installed_rock = pcall(future.wait) vim.schedule(function() if not success then progress_handle:report({ - title = "Installation failed", - message = vim.inspect(result), + title = "Error", + message = ("Installation of %s failed"):format(rock_name), }) progress_handle:cancel() return end - local installed_rock = result progress_handle:report({ title = "Installation successful", message = ("%s -> %s"):format(installed_rock.name, installed_rock.version), @@ -519,10 +519,11 @@ operations.prune = function(rock_name) if success then progress_handle:finish() else + local message = "Prune completed with errors!" + log.error(message) progress_handle:report({ title = "Error", - message = "Prune completed with errors!", - percentage = 100, + message = message, }) progress_handle:cancel() end diff --git a/lua/rocks/state.lua b/lua/rocks/state.lua index 0af61222..76b14655 100644 --- a/lua/rocks/state.lua +++ b/lua/rocks/state.lua @@ -23,6 +23,7 @@ local _removable_rock_cache = nil local luarocks = require("rocks.luarocks") local fzy = require("rocks.fzy") +local log = require("rocks.log") local nio = require("nio") ---@type async fun(): {[string]: Rock} @@ -100,7 +101,9 @@ state.rock_dependencies = nio.create(function(rock) rock_name, }, function(obj) if obj.code ~= 0 then - future.set_error(("Could not get dependencies for rock %s: %s"):format(rock_name, obj.stderr)) + local message = ("Could not get dependencies for rock %s: %s"):format(rock_name, obj.stderr) + log.error(message) + future.set_error(message) else future.set(obj.stdout) end @@ -108,7 +111,7 @@ state.rock_dependencies = nio.create(function(rock) local success, result = pcall(future.wait) if not success then - -- TODO: Log error + log.error(result) return {} end