From 189fb6203262340e7a59e782be970bcd8ae28e61 Mon Sep 17 00:00:00 2001 From: Lewis Russell Date: Wed, 17 May 2023 11:42:18 +0100 Subject: [PATCH] feat(treesitter): improved logging (#23638) - Add bindings to Treesitter ts_parser_set_logger and ts_parser_logger - Add logfile with path STDPATH('log')/treesitter.c - Rework existing LanguageTree loggin to use logfile - Begin implementing log levels for vim.g.__ts_debug --- runtime/lua/vim/fs.lua | 6 +- runtime/lua/vim/treesitter/_meta.lua | 4 + runtime/lua/vim/treesitter/languagetree.lua | 67 +++++++++++++--- src/nvim/lua/treesitter.c | 89 +++++++++++++++++++++ 4 files changed, 156 insertions(+), 10 deletions(-) diff --git a/runtime/lua/vim/fs.lua b/runtime/lua/vim/fs.lua index 2a51bde263..7f9f3a2bce 100644 --- a/runtime/lua/vim/fs.lua +++ b/runtime/lua/vim/fs.lua @@ -73,10 +73,14 @@ function M.basename(file) end ---@private -local function join_paths(...) +---@param ... string +---@return string +function M._join_paths(...) return (table.concat({ ... }, '/'):gsub('//+', '/')) end +local join_paths = M._join_paths + ---@alias Iterator fun(): string?, string? --- Return an iterator over the files and directories located in {path} diff --git a/runtime/lua/vim/treesitter/_meta.lua b/runtime/lua/vim/treesitter/_meta.lua index c1009f5f5d..9ca4b560c6 100644 --- a/runtime/lua/vim/treesitter/_meta.lua +++ b/runtime/lua/vim/treesitter/_meta.lua @@ -45,6 +45,8 @@ function TSNode:_rawquery(query, captures, start, end_, opts) end ---@return fun(): string, any function TSNode:_rawquery(query, captures, start, end_, opts) end +---@alias TSLoggerCallback fun(logtype: 'parse'|'lex', msg: string) + ---@class TSParser ---@field parse fun(self: TSParser, tree: TSTree?, source: integer|string, include_bytes: boolean?): TSTree, integer[] ---@field reset fun(self: TSParser) @@ -52,6 +54,8 @@ function TSNode:_rawquery(query, captures, start, end_, opts) end ---@field set_included_ranges fun(self: TSParser, ranges: Range6[]) ---@field set_timeout fun(self: TSParser, timeout: integer) ---@field timeout fun(self: TSParser): integer +---@field _set_logger fun(self: TSParser, lex: boolean, parse: boolean, cb: TSLoggerCallback) +---@field _logger fun(self: TSParser): TSLoggerCallback ---@class TSTree ---@field root fun(self: TSTree): TSNode diff --git a/runtime/lua/vim/treesitter/languagetree.lua b/runtime/lua/vim/treesitter/languagetree.lua index 0efe3af85c..6c780f33c4 100644 --- a/runtime/lua/vim/treesitter/languagetree.lua +++ b/runtime/lua/vim/treesitter/languagetree.lua @@ -31,8 +31,17 @@ --- shouldn't be done directly in the change callback anyway as they will be very frequent. Rather --- a plugin that does any kind of analysis on a tree should use a timer to throttle too frequent --- updates. +--- + +-- Debugging: +-- +-- vim.g.__ts_debug levels: +-- - 1. Messages from languagetree.lua +-- - 2. Parse messages from treesitter +-- - 2. Lex messages from treesitter +-- +-- Log file can be found in stdpath('log')/treesitter.log -local api = vim.api local query = require('vim.treesitter.query') local language = require('vim.treesitter.language') local Range = require('vim.treesitter._range') @@ -75,6 +84,8 @@ local TSCallbackNames = { ---@field private _source (integer|string) Buffer or string to parse ---@field private _trees TSTree[] Reference to parsed tree (one for each language) ---@field private _valid boolean|table If the parsed tree is valid +---@field private _logger? fun(logtype: string, msg: string) +---@field private _logfile? file* local LanguageTree = {} ---@class LanguageTreeOpts @@ -114,6 +125,10 @@ function LanguageTree.new(source, lang, opts) _callbacks_rec = {}, }, LanguageTree) + if vim.g.__ts_debug and type(vim.g.__ts_debug) == 'number' then + self:_set_logger() + end + for _, name in pairs(TSCallbackNames) do self._callbacks[name] = {} self._callbacks_rec[name] = {} @@ -122,6 +137,33 @@ function LanguageTree.new(source, lang, opts) return self end +function LanguageTree:_set_logger() + local source = self:source() + source = type(source) == 'string' and 'text' or tostring(source) + + local lang = self:lang() + + local logfilename = vim.fs._join_paths(vim.fn.stdpath('log'), 'treesitter.log') + + local logfile, openerr = io.open(logfilename, 'a+') + + if not logfile or openerr then + error(string.format('Could not open file (%s) for logging: %s', logfilename, openerr)) + return + end + + self._logfile = logfile + + self._logger = function(logtype, msg) + self._logfile:write(string.format('%s:%s:(%s) %s\n', source, lang, logtype, msg)) + self._logfile:flush() + end + + local log_lex = vim.g.__ts_debug >= 3 + local log_parse = vim.g.__ts_debug >= 2 + self._parser:_set_logger(log_lex, log_parse, self._logger) +end + ---@private ---Measure execution time of a function ---@generic R1, R2, R3 @@ -139,7 +181,11 @@ end ---@private ---@vararg any function LanguageTree:_log(...) - if vim.g.__ts_debug == nil then + if not self._logger then + return + end + + if not vim.g.__ts_debug or vim.g.__ts_debug < 1 then return end @@ -150,19 +196,17 @@ function LanguageTree:_log(...) local info = debug.getinfo(2, 'nl') local nregions = #self:included_regions() - local prefix = - string.format('%s:%d: [%s:%d] ', info.name, info.currentline, self:lang(), nregions) + local prefix = string.format('%s:%d: (#regions=%d) ', info.name, info.currentline, nregions) - api.nvim_out_write(prefix) + local msg = { prefix } for _, x in ipairs(args) do if type(x) == 'string' then - api.nvim_out_write(x) + msg[#msg + 1] = x else - api.nvim_out_write(vim.inspect(x, { newline = ' ', indent = '' })) + msg[#msg + 1] = vim.inspect(x, { newline = ' ', indent = '' }) end - api.nvim_out_write(' ') end - api.nvim_out_write('\n') + self._logger('nvim', table.concat(msg, ' ')) end --- Invalidates this parser and all its children @@ -876,6 +920,11 @@ end function LanguageTree:_on_detach(...) self:invalidate(true) self:_do_callback('detach', ...) + if self._logfile then + self._logger('nvim', 'detaching') + self._logger = nil + self._logfile:close() + end end --- Registers callbacks for the |LanguageTree|. diff --git a/src/nvim/lua/treesitter.c b/src/nvim/lua/treesitter.c index 0c16d09b63..96e104cd48 100644 --- a/src/nvim/lua/treesitter.c +++ b/src/nvim/lua/treesitter.c @@ -20,6 +20,7 @@ #include "nvim/api/private/helpers.h" #include "nvim/buffer_defs.h" #include "nvim/globals.h" +#include "nvim/lua/executor.h" #include "nvim/lua/treesitter.h" #include "nvim/macros.h" #include "nvim/map.h" @@ -43,6 +44,13 @@ typedef struct { int max_match_id; } TSLua_cursor; +typedef struct { + LuaRef cb; + lua_State *lstate; + bool lex; + bool parse; +} TSLuaLoggerOpts; + #ifdef INCLUDE_GENERATED_DECLARATIONS # include "lua/treesitter.c.generated.h" #endif @@ -56,6 +64,8 @@ static struct luaL_Reg parser_meta[] = { { "included_ranges", parser_get_ranges }, { "set_timeout", parser_set_timeout }, { "timeout", parser_get_timeout }, + { "_set_logger", parser_set_logger }, + { "_logger", parser_get_logger }, { NULL, NULL } }; @@ -322,6 +332,12 @@ static int parser_gc(lua_State *L) return 0; } + TSLogger logger = ts_parser_logger(*p); + if (logger.log) { + TSLuaLoggerOpts *opts = (TSLuaLoggerOpts *)logger.payload; + xfree(opts); + } + ts_parser_delete(*p); return 0; } @@ -669,9 +685,82 @@ static int parser_get_timeout(lua_State *L) } lua_pushinteger(L, (long)ts_parser_timeout_micros(*p)); + return 1; +} + +static void logger_cb(void *payload, TSLogType logtype, const char *s) +{ + TSLuaLoggerOpts *opts = (TSLuaLoggerOpts *)payload; + if ((!opts->lex && logtype == TSLogTypeLex) + || (!opts->parse && logtype == TSLogTypeParse)) { + return; + } + + lua_State *lstate = opts->lstate; + + nlua_pushref(lstate, opts->cb); + lua_pushstring(lstate, logtype == TSLogTypeParse ? "parse" : "lex"); + lua_pushstring(lstate, s); + if (lua_pcall(lstate, 2, 0, 0)) { + luaL_error(lstate, "Error executing treesitter logger callback"); + } +} + +static int parser_set_logger(lua_State *L) +{ + TSParser **p = parser_check(L, 1); + if (!p) { + return 0; + } + + if (!lua_isboolean(L, 2)) { + return luaL_argerror(L, 2, "boolean expected"); + } + + if (!lua_isboolean(L, 3)) { + return luaL_argerror(L, 3, "boolean expected"); + } + + if (!lua_isfunction(L, 4)) { + return luaL_argerror(L, 4, "function expected"); + } + + TSLuaLoggerOpts *opts = xmalloc(sizeof(TSLuaLoggerOpts)); + + *opts = (TSLuaLoggerOpts){ + .lex = lua_toboolean(L, 2), + .parse = lua_toboolean(L, 3), + .cb = nlua_ref_global(L, 4), + .lstate = L + }; + + TSLogger logger = { + .payload = (void *)opts, + .log = logger_cb + }; + + ts_parser_set_logger(*p, logger); return 0; } +static int parser_get_logger(lua_State *L) +{ + TSParser **p = parser_check(L, 1); + if (!p) { + return 0; + } + + TSLogger logger = ts_parser_logger(*p); + if (logger.log) { + TSLuaLoggerOpts *opts = (TSLuaLoggerOpts *)logger.payload; + nlua_pushref(L, opts->cb); + } else { + lua_pushnil(L); + } + + return 1; +} + // Tree methods /// push tree interface on lua stack.