Merge pull request #65 from rudotriton/logging-and-various

Add logging

README.md

@@ -176,5 +176,7 @@ require("harpoon").setup({
 
 ```
 
+## Debugging
+Harpoon writes logs to a `harpoon.log` file that resides in Neovim's cache path. (`:echo stdpath("cache")` to find where that is for you.)
 
-
+By default, logging is enabled for warnings and above. This can be changed by setting `vim.g.harpoon_log_level` variable to one of the following log levels: `trace`, `debug`, `info`, `warn`, `error`, or `fatal`. Note that this would have to be done **before** harpoon's `setup` call. Alternatively, it can be more convenient to launch Neovim with an environment variable, e.g. `> HARPOON_LOG=trace nvim`. In case both, `vim.g` and an environment variable are used, the log level set by the environment variable overrules. Supplying an invalid log level defaults back to warnings.

lua/harpoon/dev.lua

@@ -9,4 +9,22 @@ M.reload = function()
     require("plenary.reload").reload_module("harpoon");
 end
 
+local function set_log_level()
+    local log_levels = { "trace", "debug", "info", "warn", "error", "fatal" }
+    local log_level = vim.env.HARPOON_LOG or vim.g.harpoon_log_level
+
+    for _, level in pairs(log_levels) do
+        if level == log_level then
+            return log_level
+        end
+    end
+
+    return "warn" -- default, if user hasn't set to one from log_levels
+end
+
+M.log = require("plenary.log").new({
+    plugin = "harpoon",
+    level = set_log_level(),
+})
+
 return M

lua/harpoon/init.lua

@@ -1,7 +1,9 @@
 local Path = require("plenary.path")
+local utils = require("harpoon.utils")
+local log = require("harpoon.dev").log
+
 local config_path = vim.fn.stdpath("config")
 local data_path = vim.fn.stdpath("data")
-local utils = require("harpoon.utils")
 local user_config = string.format("%s/harpoon.json", config_path)
 local cache_config = string.format("%s/harpoon.json", data_path)
 
@@ -44,6 +46,7 @@ local function merge_table_impl(t1, t2)
 end
 
 local function merge_tables(...)
+    log.trace("_merge_tables()")
     local out = {}
     for i = 1, select("#",...) do
         merge_table_impl(out, select(i, ...))
@@ -52,8 +55,10 @@ local function merge_tables(...)
 end
 
 local function ensure_correct_config(config)
+    log.trace("_ensure_correct_config()")
     local projects = config.projects
     if projects[vim.loop.cwd()] == nil then
+        log.debug("ensure_correct_config(): No config found for:", vim.loop.cwd())
         projects[vim.loop.cwd()] = {
             mark = {
                 marks = {}
@@ -66,10 +71,12 @@ local function ensure_correct_config(config)
 
     local proj = projects[vim.loop.cwd()]
     if proj.mark == nil then
+        log.debug("ensure_correct_config(): No marks found for", vim.loop.cwd())
         proj.mark = {marks = {}}
     end
 
     if proj.term == nil then
+        log.debug("ensure_correct_config(): No terminal commands found for", vim.loop.cwd())
         proj.term = {cmds = {}}
     end
 
@@ -90,6 +97,8 @@ local function ensure_correct_config(config)
 end
 
 local function expand_dir(config)
+    log.trace("_expand_dir(): Config pre-expansion:", config)
+
     local projects = config.projects or {}
     for k in pairs(projects) do
         local expanded_path = Path.new(k):expand()
@@ -99,32 +108,39 @@ local function expand_dir(config)
         end
     end
 
+    log.trace("_expand_dir(): Config post-expansion:", config)
     return config
 end
 
 M.save = function()
-    Path:new(cache_config):write(vim.fn.json_encode(HarpoonConfig), 'w')
+    log.trace("save(): Saving cache config to", cache_config)
+    Path:new(cache_config):write(vim.fn.json_encode(HarpoonConfig), "w")
 end
 
 local function read_config(local_config)
+    log.trace("_read_config():", local_config)
     return vim.fn.json_decode(Path:new(local_config):read())
 end
 
 -- 1. saved.  Where do we save?
 M.setup = function(config)
+    log.trace("setup(): Setting up...")
 
     if not config then
         config = {}
     end
 
     local ok, u_config = pcall(read_config, user_config)
-    local ok2, c_config = pcall(read_config, cache_config)
 
     if not ok then
+        log.debug("setup(): No user config present at", user_config)
         u_config = {}
     end
 
+    local ok2, c_config = pcall(read_config, cache_config)
+
     if not ok2 then
+        log.debug("setup(): No cache config present at", cache_config)
         c_config = {}
     end
 
@@ -143,21 +159,26 @@ M.setup = function(config)
     ensure_correct_config(complete_config)
 
     HarpoonConfig = complete_config
+    log.debug("setup(): Complete config", HarpoonConfig)
 end
 
 M.get_global_settings = function()
+    log.trace("get_global_settings()")
     return HarpoonConfig.global_settings
 end
 
 M.get_term_config = function()
+    log.trace("get_term_config()")
     return ensure_correct_config(HarpoonConfig).projects[vim.loop.cwd()].term
 end
 
 M.get_mark_config = function()
+    log.trace("get_mark_config()")
     return ensure_correct_config(HarpoonConfig).projects[vim.loop.cwd()].mark
 end
 
 M.get_menu_config = function()
+    log.trace("get_menu_config()")
     return HarpoonConfig.menu or {}
 end
 

lua/harpoon/mark.lua

@@ -1,5 +1,6 @@
-local harpoon = require('harpoon')
+local harpoon = require("harpoon")
-local utils = require('harpoon.utils')
+local utils = require("harpoon.utils")
+local log = require("harpoon.dev").log
 
 -- I think that I may have to organize this better.  I am not the biggest fan
 -- of procedural all the things
@@ -9,20 +10,24 @@ local callbacks = {}
 -- I am trying to avoid over engineering the whole thing.  We will likely only
 -- need one event emitted
 local function emit_changed()
+    log.trace("_emit_changed()")
     if harpoon.get_global_settings().save_on_change then
         harpoon.save()
     end
 
     if not callbacks["changed"] then
+        log.trace("_emit_changed(): no callbacks for 'changed', returning")
         return
     end
 
-    for _, cb in pairs(callbacks) do
+    for idx, cb in pairs(callbacks["changed"]) do
+        log.trace(string.format("_emit_changed(): Running callback #%d for 'changed'", idx))
         cb()
     end
 end
 
 local function filter_empty_string(list)
+    log.trace("_filter_empty_string()")
     local next = {}
     for idx = 1, #list do
         if list[idx] ~= "" then
@@ -34,6 +39,7 @@ local function filter_empty_string(list)
 end
 
 local function get_first_empty_slot()
+    log.trace("_get_first_empty_slot()")
     for idx = 1, M.get_length() do
         local filename = M.get_marked_file_name(idx)
         if filename == "" then
@@ -45,6 +51,7 @@ local function get_first_empty_slot()
 end
 
 local function get_buf_name(id)
+    log.trace("_get_buf_name():", id)
     if id == nil then
         return utils.normalize_path(vim.fn.bufname(vim.fn.bufnr()))
     elseif type(id) == "string" then
@@ -63,6 +70,12 @@ end
 
 local function create_mark(filename)
     local cursor_pos = vim.fn.getcurpos()
+    log.trace(string.format(
+        "_create_mark(): Creating mark at row: %d, col: %d for %s",
+        cursor_pos[2],
+        cursor_pos[4],
+        filename
+    ))
     return {
         filename = filename,
         row = cursor_pos[2],
@@ -71,24 +84,31 @@ local function create_mark(filename)
 end
 
 local function mark_exists(buf_name)
+    log.trace("_mark_exists()")
     for idx = 1, M.get_length() do
         if M.get_marked_file_name(idx) == buf_name then
+            log.debug("_mark_exists(): Mark exists", buf_name)
             return true
         end
     end
 
+    log.debug("_mark_exists(): Mark doesn't exist", buf_name)
     return false
 end
 
 local function validate_buf_name(buf_name)
+    log.trace("_validate_buf_name():", buf_name)
     if buf_name == "" or buf_name == nil then
+        log.error("_validate_buf_name(): Not a valid name for a mark,", buf_name)
         error("Couldn't find a valid file name to mark, sorry.")
         return
     end
 end
 
 M.get_index_of = function(item)
+    log.trace("get_index_of():", item)
     if item == nil then
+        log.error("get_index_of(): Function has been supplied with a nil value.")
         error("You have provided a nil value to Harpoon, please provide a string rep of the file or the file idx.")
         return
     end
@@ -104,6 +124,7 @@ M.get_index_of = function(item)
         return nil
     end
 
+    -- TODO move this to a "harpoon_" prefix or global config?
     if vim.g.manage_a_mark_zero_index then
         item = item + 1
     end
@@ -112,10 +133,12 @@ M.get_index_of = function(item)
         return item
     end
 
+    log.debug("get_index_of(): No item found,", item)
     return nil
 end
 
 M.status = function()
+    log.trace("status()")
     local idx = M.get_index_of(get_buf_name())
 
     if M.valid_index(idx) then
@@ -125,6 +148,7 @@ M.status = function()
 end
 
 M.valid_index = function(idx)
+    log.trace("valid_index():", idx)
     if idx == nil then
         return false
     end
@@ -135,6 +159,7 @@ end
 
 M.add_file = function(file_name_or_buf_id)
     local buf_name = get_buf_name(file_name_or_buf_id)
+    log.trace("add_file():", buf_name)
 
     if M.valid_index(M.get_index_of(buf_name)) then
         -- we don't alter file layout.
@@ -149,8 +174,9 @@ M.add_file = function(file_name_or_buf_id)
     emit_changed();
 end
 
--- dont_emit_on_changed should only be used internally
+-- _emit_on_changed == false should only be used internally
 M.remove_empty_tail = function(_emit_on_changed)
+    log.trace("remove_empty_tail()")
     _emit_on_changed = _emit_on_changed == nil or _emit_on_changed
     local config = harpoon.get_mark_config()
     local found = false
@@ -173,6 +199,7 @@ M.remove_empty_tail = function(_emit_on_changed)
 end
 
 M.store_offset = function()
+    log.trace("store_offset()")
     local ok, res = pcall(function()
         local buf_name = get_buf_name()
         local idx = M.get_index_of(buf_name)
@@ -181,13 +208,13 @@ M.store_offset = function()
         end
 
         local cursor_pos = vim.fn.getcurpos()
+        log.debug(string.format("store_offset(): Stored row: %d, col: %d", cursor_pos[2], cursor_pos[3]))
         harpoon.get_mark_config().marks[idx].row = cursor_pos[2]
         harpoon.get_mark_config().marks[idx].col = cursor_pos[3]
     end)
 
     if not ok then
-        -- TODO: Developer logs?
+        log.warn("store_offset(): Could not store offset:", res)
-        print("M.store_offset#pcall failed:", res)
     end
 
     emit_changed()
@@ -196,8 +223,10 @@ end
 M.rm_file = function(file_name_or_buf_id)
     local buf_name = get_buf_name(file_name_or_buf_id)
     local idx = M.get_index_of(buf_name)
+    log.trace("rm_file(): Removing mark at id", idx)
 
     if not M.valid_index(idx) then
+        log.debug("rm_file(): No mark exists for id", file_name_or_buf_id)
         return
     end
 
@@ -208,11 +237,13 @@ end
 
 M.clear_all = function()
     harpoon.get_mark_config().marks = {}
+    log.trace("clear_all(): Clearing all marks.")
     emit_changed()
 end
 
 --- ENTERPRISE PROGRAMMING
 M.get_marked_file = function(idxOrName)
+    log.trace("get_marked_file():", idxOrName)
     if type(idxOrName) == "string" then
         idxOrName = M.get_index_of(idxOrName)
     end
@@ -221,10 +252,12 @@ end
 
 M.get_marked_file_name = function(idx)
     local mark = harpoon.get_mark_config().marks[idx]
+    log.trace("get_marked_file_name():", mark and mark.filename)
     return mark and mark.filename
 end
 
 M.get_length = function()
+    log.trace("get_length()")
     return table.maxn(harpoon.get_mark_config().marks)
 end
 
@@ -233,6 +266,8 @@ M.set_current_at = function(idx)
     local buf_name = get_buf_name()
     local current_idx = M.get_index_of(buf_name)
 
+    log.trace("set_current_at(): Setting id", idx, buf_name)
+
     -- Remove it if it already exists
     if M.valid_index(current_idx) then
         config.marks[current_idx] = create_mark("")
@@ -250,6 +285,7 @@ M.set_current_at = function(idx)
 end
 
 M.to_quickfix_list = function()
+    log.trace("to_quickfix_list(): Sending marks to quickfix list.")
     local config = harpoon.get_mark_config()
     local file_list = filter_empty_string(config.marks)
     local qf_list = {}
@@ -262,10 +298,12 @@ M.to_quickfix_list = function()
             col = mark.col,
         }
     end
+    log.debug("to_quickfix_list(): qf_list:", qf_list)
     vim.fn.setqflist(qf_list)
 end
 
 M.set_mark_list = function(new_list)
+    log.trace("set_mark_list(): New list:", new_list)
 
     local config = harpoon.get_mark_config()
 
@@ -286,28 +324,35 @@ end
 
 M.toggle_file = function(file_name_or_buf_id)
     local buf_name = get_buf_name(file_name_or_buf_id)
+    log.trace("toggle_file():", buf_name)
 
     validate_buf_name(buf_name)
 
     if (mark_exists(buf_name)) then
         M.rm_file(buf_name)
         print("Mark removed")
+        log.debug("toggle_file(): Mark removed")
     else
         M.add_file(buf_name)
-        print("Mark Added")
+        print("Mark added")
+        log.debug("toggle_file(): Mark added")
     end
 end
 
 M.get_current_index = function()
+    log.trace("get_current_index()")
     return M.get_index_of(vim.fn.bufname(vim.fn.bufnr()))
 end
 
 M.on = function(event, cb)
+    log.trace("on():", event)
     if not callbacks[event] then
+        log.debug("on(): no callbacks yet for", event)
         callbacks[event] = {}
     end
 
     table.insert(callbacks[event], cb)
+    log.debug("on(): All callbacks:", callbacks)
 end
 
 return M

lua/harpoon/term.lua

@@ -1,10 +1,12 @@
 local harpoon = require('harpoon')
 local Path = require("plenary.path")
+local log = require("harpoon.dev").log
 
 local M = {}
 local terminals = {}
 
 local function create_terminal()
+    log.trace("_create_terminal()")
     local current_id = vim.fn.bufnr()
 
     vim.cmd(":terminal")
@@ -12,13 +14,14 @@ local function create_terminal()
     local term_id  = vim.b.terminal_job_id
 
     if term_id == nil then
-        -- TODO: Throw an erro?
+        log.error("_create_terminal(): term_id is nil")
+        -- TODO: Throw an error?
         return nil
     end
 
     -- Make sure the term buffer has "hidden" set so it doesn't get thrown
     -- away and cause an error
-    vim.api.nvim_buf_set_option(bufh, 'bufhidden', 'hide')
+    vim.api.nvim_buf_set_option(buf_id, 'bufhidden', 'hide')
 
     -- Resets the buffer back to the old one
     vim.api.nvim_set_current_buf(current_id)
@@ -29,7 +32,8 @@ function getCmd(idx)
     return
 end
 
-function find_terminal(idx)
+local function find_terminal(idx)
+    log.trace("_find_terminal(): Terminal:", idx)
     local term_handle = terminals[idx]
     if not term_handle or not vim.api.nvim_buf_is_valid(term_handle.buf_id) then
         local buf_id, term_id = create_terminal()
@@ -47,12 +51,14 @@ function find_terminal(idx)
 end
 
 M.gotoTerminal = function(idx)
+    log.trace("gotoTerminal(): Terminal:", idx)
     local term_handle = find_terminal(idx)
 
     vim.api.nvim_set_current_buf(term_handle.buf_id)
 end
 
 M.sendCommand = function(idx, cmd, ...)
+    log.trace("sendCommand(): Terminal:", idx)
     local term_handle = find_terminal(idx)
 
     if type(cmd) == "number" then
@@ -60,6 +66,7 @@ M.sendCommand = function(idx, cmd, ...)
     end
 
     if cmd then
+        log.debug("sendCommand:", cmd)
         vim.fn.chansend(term_handle.term_id, string.format(cmd, ...))
     end
 end

lua/harpoon/ui.lua

@@ -1,6 +1,7 @@
 local harpoon = require('harpoon')
 local popup = require('popup')
 local Marked = require('harpoon.mark')
+local log = require("harpoon.dev").log
 
 local M = {}
 
@@ -8,6 +9,7 @@ Harpoon_win_id = nil
 Harpoon_bufh = nil
 
 local function create_window()
+    log.trace("_create_window()")
     local config = harpoon.get_menu_config()
     local width = config.width or 60
     local height = config.height or 10
@@ -33,11 +35,13 @@ local function create_window()
 end
 
 local function get_menu_items()
+    log.trace("_get_menu_items()")
     local lines = vim.api.nvim_buf_get_lines(Harpoon_bufh, 0, -1, true)
     local indices = {}
 
     for idx = 1, #lines do
         local space_location = string.find(lines[idx], ' ')
+        log.debug("_get_menu_items():", idx, space_location)
 
         if space_location ~= nil then
             table.insert(indices, string.sub(lines[idx], space_location + 1))
@@ -47,11 +51,10 @@ local function get_menu_items()
     return indices
 end
 
-local save_changes = function()
+
-    Marked.set_mark_list(get_menu_items())
-end
 
 M.toggle_quick_menu = function()
+    log.trace("toggle_quick_menu()")
     if Harpoon_win_id ~= nil and vim.api.nvim_win_is_valid(Harpoon_win_id) then
         local global_config = harpoon.get_global_settings()
 
@@ -91,12 +94,15 @@ M.toggle_quick_menu = function()
 end
 
 M.on_menu_save = function()
-    save_changes()
+    log.trace("on_menu_save()")
+    Marked.set_mark_list(get_menu_items())
 end
 
 M.nav_file = function(id)
+    log.trace("nav_file(): Navigating to", id)
     local idx = Marked.get_index_of(id)
     if not Marked.valid_index(idx) then
+        log.debug("nav_file(): No mark exists for id", id)
         return
     end
 
@@ -105,8 +111,9 @@ M.nav_file = function(id)
     local set_row = not vim.api.nvim_buf_is_loaded(buf_id)
 
     vim.api.nvim_set_current_buf(buf_id)
-    if set_row and mark.row then
+    if set_row and mark.row and mark.col then
         vim.cmd(string.format(":call cursor(%d, %d)", mark.row, mark.col))
+        log.debug(string.format("nav_file(): Setting cursor to row: %d, col: %d", mark.row, mark.col))
     end
 end
 
@@ -157,6 +164,7 @@ function M.close_notification(bufnr)
 end
 
 M.nav_next = function()
+    log.trace("nav_next()")
     local current_index = Marked.get_current_index()
     local number_of_items = Marked.get_length()
 
@@ -173,6 +181,7 @@ M.nav_next = function()
 end
 
 M.nav_prev = function()
+    log.trace("nav_prev()")
     local current_index = Marked.get_current_index()
     local number_of_items = Marked.get_length()