Skip to content

Commit b4db7db

Browse files
echasnovskiechasnovski
committed
feat(misc): add in-memory logging functionality
1 parent 7d6fcfd commit b4db7db

File tree

4 files changed

+338
-0
lines changed

4 files changed

+338
-0
lines changed

‎CHANGELOG.md‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -169,6 +169,8 @@ There are following change types:
169169

170170
- Update `zoom()` to return whether current buffer is zoomed in. By @loichyan, PR #1954.
171171

172+
- Add `log_add()` and related functions (`log_get()`, `log_show()`, `log_clear()`) to work with a special in-memory log array. Useful when debugging Lua code (instead of `print()`).
173+
172174
## mini.pick
173175

174176
### Evolve

‎doc/mini-misc.txt‎

Lines changed: 71 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,9 @@ Features the following functions:
88
- |MiniMisc.bench_time()| to benchmark function execution time.
99
Useful in combination with `stat_summary()`.
1010

11+
- |MiniMisc.log_add()| and `log_xxx()` helper functions to work with a special
12+
in-memory log array. Useful when debugging Lua code (instead of `print()`).
13+
1114
- |MiniMisc.put()| and |MiniMisc.put_text()| to pretty print its arguments
1215
into command line and current buffer respectively.
1316

@@ -91,6 +94,74 @@ Parameters ~
9194
{win_id} `(number|nil)` Window identifier (see |win_getid()|) for which gutter
9295
width is computed. Default: 0 for current.
9396

97+
------------------------------------------------------------------------------
98+
*MiniMisc.log_add()*
99+
`MiniMisc.log_add`({desc}, {state}, {opts})
100+
Add an entry to the in-memory log array
101+
102+
Useful when trying to debug a Lua code (like Neovim config or plugin).
103+
Use this instead of ad-hoc `print()` statements.
104+
105+
Each entry is a table with the following fields:
106+
- <desc> `(any)` - entry description, usually a string describing a place
107+
in the code.
108+
- <state> `(any)` - data about current state. Usually a table with string fields.
109+
- <timestamp> `(number)` - a timestamp of when the entry was added, as the number
110+
milliseconds since the log initiated (after |MiniMisc.setup()|
111+
or |MiniMisc.log_clear()|). Useful during profiling.
112+
113+
Parameters ~
114+
{desc} `(any)` Entry description.
115+
{state} `(any)` Data about current state. Usually a table with string fields.
116+
{opts} `(table|nil)` Options. Possible fields:
117+
- <deepcopy> - (boolean) Whether to apply |vim.deepcopy| to the {state}.
118+
Usually helpful to record the exact state during code execution and avoid
119+
side effects of tables being changed in-place. Default `true`.
120+
121+
Usage ~
122+
>lua
123+
local t = { a = 1 }
124+
MiniMisc.log_add('before', { t = t }) -- Will show `t={a=1}` state
125+
t.a = t.a + 1
126+
MiniMisc.log_add('after', { t = t }) -- Will show `t={a=2}` state
127+
128+
-- Use `:lua MiniMisc.log_show()` or `:=MiniMisc.log_get()` to see the log
129+
<
130+
131+
See also ~
132+
- |MiniMisc.log_get()| to get log array
133+
- |MiniMisc.log_show()| to show log in the current window in a scratch buffer
134+
- |MiniMisc.log_clear()| to clear the log array
135+
136+
------------------------------------------------------------------------------
137+
*MiniMisc.log_get()*
138+
`MiniMisc.log_get`()
139+
Get log array
140+
141+
Return ~
142+
`(table[])` Log array. Returned as is, without |vim.deepcopy()|.
143+
144+
See also ~
145+
- |MiniMisc.log_add()| to add to log array
146+
147+
------------------------------------------------------------------------------
148+
*MiniMisc.log_show()*
149+
`MiniMisc.log_show`()
150+
Show log array in a scratch buffer
151+
152+
See also ~
153+
- |MiniMisc.log_add()| to add to log array
154+
155+
------------------------------------------------------------------------------
156+
*MiniMisc.log_clear()*
157+
`MiniMisc.log_clear`()
158+
Clear log array
159+
160+
This also sets a new starting point for entry timestamps.
161+
162+
See also ~
163+
- |MiniMisc.log_add()| to add to log array
164+
94165
------------------------------------------------------------------------------
95166
*MiniMisc.put()*
96167
`MiniMisc.put`({...})

‎lua/mini/misc.lua‎

Lines changed: 82 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -6,6 +6,9 @@
66
--- - |MiniMisc.bench_time()| to benchmark function execution time.
77
--- Useful in combination with `stat_summary()`.
88
---
9+
--- - |MiniMisc.log_add()| and `log_xxx()` helper functions to work with a special
10+
--- in-memory log array. Useful when debugging Lua code (instead of `print()`).
11+
---
912
--- - |MiniMisc.put()| and |MiniMisc.put_text()| to pretty print its arguments
1013
--- into command line and current buffer respectively.
1114
---
@@ -106,6 +109,85 @@ MiniMisc.get_gutter_width = function(win_id)
106109
return vim.fn.getwininfo(win_id)[1].textoff
107110
end
108111

112+
--- Add an entry to the in-memory log array
113+
---
114+
--- Useful when trying to debug a Lua code (like Neovim config or plugin).
115+
--- Use this instead of ad-hoc `print()` statements.
116+
---
117+
--- Each entry is a table with the following fields:
118+
--- - <desc> `(any)` - entry description, usually a string describing a place
119+
--- in the code.
120+
--- - <state> `(any)` - data about current state. Usually a table with string fields.
121+
--- - <timestamp> `(number)` - a timestamp of when the entry was added, as the number
122+
--- milliseconds since the log initiated (after |MiniMisc.setup()|
123+
--- or |MiniMisc.log_clear()|). Useful during profiling.
124+
---
125+
---@param desc any Entry description.
126+
---@param state any Data about current state. Usually a table with string fields.
127+
---@param opts table|nil Options. Possible fields:
128+
--- - <deepcopy> - (boolean) Whether to apply |vim.deepcopy| to the {state}.
129+
--- Usually helpful to record the exact state during code execution and avoid
130+
--- side effects of tables being changed in-place. Default `true`.
131+
---
132+
---@usage >lua
133+
--- local t = { a = 1 }
134+
--- MiniMisc.log_add('before', { t = t }) -- Will show `t={a=1}` state
135+
--- t.a = t.a + 1
136+
--- MiniMisc.log_add('after', { t = t }) -- Will show `t={a=2}` state
137+
---
138+
--- -- Use `:lua MiniMisc.log_show()` or `:=MiniMisc.log_get()` to see the log
139+
--- <
140+
---
141+
---@seealso - |MiniMisc.log_get()| to get log array
142+
--- - |MiniMisc.log_show()| to show log in the current window in a scratch buffer
143+
--- - |MiniMisc.log_clear()| to clear the log array
144+
MiniMisc.log_add = function(desc, state, opts)
145+
opts = vim.tbl_extend('force', { deepcopy = true }, opts or {})
146+
local entry = {
147+
desc = desc,
148+
state = opts.deepcopy and vim.deepcopy(state) or state,
149+
timestamp = 0.000001 * (vim.loop.hrtime() - H.log_cache.start_htime),
150+
}
151+
table.insert(H.log_cache.log, entry)
152+
end
153+
154+
--- Get log array
155+
---
156+
---@return table[] Log array. Returned as is, without |vim.deepcopy()|.
157+
---
158+
---@seealso - |MiniMisc.log_add()| to add to log array
159+
MiniMisc.log_get = function() return H.log_cache.log end
160+
161+
--- Show log array in a scratch buffer
162+
---
163+
---@seealso - |MiniMisc.log_add()| to add to log array
164+
MiniMisc.log_show = function()
165+
local buf_id = H.log_cache.buf_id
166+
if buf_id == nil or not vim.api.nvim_buf_is_valid(buf_id) then
167+
buf_id = vim.api.nvim_create_buf(true, true)
168+
H.log_cache.buf_id = buf_id
169+
end
170+
local lines = vim.split(vim.inspect(H.log_cache.log), '\n')
171+
vim.api.nvim_buf_set_lines(buf_id, 0, -1, false, lines)
172+
173+
local buf_wins = vim.fn.win_findbuf(buf_id)
174+
if buf_wins[1] == nil then return vim.api.nvim_win_set_buf(0, buf_id) end
175+
vim.api.nvim_set_current_win(buf_wins[1])
176+
end
177+
178+
--- Clear log array
179+
---
180+
--- This also sets a new starting point for entry timestamps.
181+
---
182+
---@seealso - |MiniMisc.log_add()| to add to log array
183+
MiniMisc.log_clear = function()
184+
H.log_cache.log = {}
185+
H.log_cache.start_htime = vim.loop.hrtime()
186+
H.notify('Cleared log')
187+
end
188+
189+
H.log_cache = { log = {}, start_htime = vim.loop.hrtime(), buf_id = nil }
190+
109191
--- Print Lua objects in command line
110192
---
111193
---@param ... any Any number of objects to be printed each on separate line.

‎tests/test_misc.lua‎

Lines changed: 183 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -146,6 +146,189 @@ T['get_gutter_width()']['respects `win_id` argument'] = function()
146146
eq(child.lua_get('MiniMisc.get_gutter_width(...)', { windows[2] }), 0)
147147
end
148148

149+
T['log_add()'] = new_set()
150+
151+
local validate_log = function(ref_log)
152+
local log = child.lua_get('MiniMisc.log_get()')
153+
eq(#log, #ref_log)
154+
155+
-- Validate timestamp and non-timestamp data separately
156+
local log_small, prev_timestamp = {}, 0
157+
for i, l in ipairs(log) do
158+
log_small[i] = vim.deepcopy(l)
159+
log_small[i].timestamp = nil
160+
161+
eq(type(l.timestamp), 'number')
162+
eq(prev_timestamp < l.timestamp, true)
163+
prev_timestamp = l.timestamp
164+
end
165+
eq(log_small, ref_log)
166+
end
167+
168+
T['log_add()']['works'] = function()
169+
child.lua([[
170+
local t = { a = 1 }
171+
MiniMisc.log_add('before', t)
172+
MiniMisc.log_add('before nodeepcopy', t, { deepcopy = false })
173+
t.a = t.a + 1
174+
MiniMisc.log_add('after', t)
175+
176+
MiniMisc.log_add('types 1', { 1, 'text', { x = true } })
177+
MiniMisc.log_add('types 2', true)
178+
MiniMisc.log_add('types 3', nil)
179+
180+
MiniMisc.log_add(1, 'number desc')
181+
MiniMisc.log_add(nil, 'no desc')
182+
]])
183+
184+
validate_log({
185+
{ desc = 'before', state = { a = 1 } },
186+
{ desc = 'before nodeepcopy', state = { a = 2 } },
187+
{ desc = 'after', state = { a = 2 } },
188+
{ desc = 'types 1', state = { 1, 'text', { x = true } } },
189+
{ desc = 'types 2', state = true },
190+
{ desc = 'types 3' },
191+
{ desc = 1, state = 'number desc' },
192+
{ state = 'no desc' },
193+
})
194+
195+
-- Should allow function in log entry
196+
local fun_in_log = child.lua([[
197+
MiniMisc.log_add('func 1', function() return 1 end)
198+
MiniMisc.log_add('func 2', { f = function() return 2 end })
199+
200+
local log = MiniMisc.log_get()
201+
return { log[#log - 1].state(), log[#log].state.f() }
202+
]])
203+
eq(fun_in_log, { 1, 2 })
204+
205+
-- Should properly set timestamps
206+
child.lua('_G.small_time = ' .. vim.inspect(small_time))
207+
local diff = child.lua([[
208+
MiniMisc.log_add('ts 1', 1)
209+
vim.loop.sleep(10 * _G.small_time)
210+
MiniMisc.log_add('ts 2', 2)
211+
212+
local log = MiniMisc.log_get()
213+
return log[#log].timestamp - log[#log - 1].timestamp
214+
]])
215+
eq((9 * small_time) < diff and diff < (11 * small_time), true)
216+
end
217+
218+
T['log_get()'] = new_set()
219+
220+
T['log_get()']['works'] = function()
221+
-- Most of the testing is done in tests for other functions
222+
local log = child.lua([[
223+
MiniMisc.log_add('desc', { a = 1 })
224+
return MiniMisc.log_get()
225+
]])
226+
eq(type(log), 'table')
227+
eq(vim.tbl_count(log), 1)
228+
local entry_names = vim.tbl_keys(log[1])
229+
230+
table.sort(entry_names)
231+
eq(entry_names, { 'desc', 'state', 'timestamp' })
232+
233+
eq(log[1].desc, 'desc')
234+
eq(log[1].state, { a = 1 })
235+
eq(type(log[1].timestamp), 'number')
236+
eq(log[1].timestamp > 0, true)
237+
end
238+
239+
T['log_show()'] = new_set()
240+
241+
T['log_show()']['works'] = function()
242+
-- Set up windows
243+
local buf_id_other = child.api.nvim_get_current_buf()
244+
local win_id_other = child.api.nvim_get_current_win()
245+
child.cmd('vert split')
246+
local win_id = child.api.nvim_get_current_win()
247+
248+
-- Should start showing log in a new scratch buffer in the current window
249+
child.lua('MiniMisc.log_add("desc", { a = 1 })')
250+
child.lua('MiniMisc.log_show()')
251+
local buf_id_log = child.api.nvim_get_current_buf()
252+
253+
local validate_wins = function()
254+
eq(child.api.nvim_win_get_buf(win_id), buf_id_log)
255+
eq(child.api.nvim_win_get_buf(win_id_other), buf_id_other)
256+
eq(child.api.nvim_get_current_win(), win_id)
257+
eq(buf_id_log == buf_id_other, false)
258+
end
259+
260+
local validate_lines = function(ref_lines)
261+
local log_lines = child.api.nvim_buf_get_lines(buf_id_log, 0, -1, false)
262+
local mock_ts = 12.33
263+
for i = 1, #log_lines do
264+
log_lines[i] = log_lines[i]:gsub('timestamp = %d+%.%d+', function()
265+
mock_ts = mock_ts + 0.01
266+
return 'timestamp = ' .. mock_ts
267+
end)
268+
end
269+
eq(log_lines, ref_lines)
270+
end
271+
272+
validate_wins()
273+
274+
local ref_lines = {
275+
'{ {',
276+
' desc = "desc",',
277+
' state = {',
278+
' a = 1',
279+
' },',
280+
' timestamp = 12.34',
281+
' } }',
282+
}
283+
validate_lines(ref_lines)
284+
285+
-- Should reuse buffer and window
286+
child.api.nvim_set_current_win(win_id_other)
287+
child.lua('MiniMisc.log_add("desc", { b = 2 })')
288+
child.lua('MiniMisc.log_show()')
289+
validate_wins()
290+
291+
ref_lines = {
292+
'{ {',
293+
' desc = "desc",',
294+
' state = {',
295+
' a = 1',
296+
' },',
297+
' timestamp = 12.34',
298+
' }, {',
299+
' desc = "desc",',
300+
' state = {',
301+
' b = 2',
302+
' },',
303+
' timestamp = 12.35',
304+
' } }',
305+
}
306+
validate_lines(ref_lines)
307+
end
308+
309+
T['log_clear()'] = new_set()
310+
311+
T['log_clear()']['works'] = function()
312+
child.lua('_G.notify_log = {}; vim.notify = function(...) table.insert(_G.notify_log, { ... }) end')
313+
child.lua('_G.small_time = ' .. vim.inspect(small_time))
314+
local log = child.lua([[
315+
MiniMisc.log_add('desc 1', 1)
316+
vim.loop.sleep(10 * _G.small_time)
317+
MiniMisc.log_add('desc 2', 2)
318+
319+
MiniMisc.log_clear()
320+
MiniMisc.log_add('after clear', 3)
321+
322+
return MiniMisc.log_get()
323+
]])
324+
325+
validate_log({ { desc = 'after clear', state = 3 } })
326+
-- Should restart start value for timestamps
327+
eq(log[1].timestamp < small_time, true)
328+
329+
eq(child.lua_get('_G.notify_log'), { { '(mini.misc) Cleared log' } })
330+
end
331+
149332
local validate_put = {
150333
put = function(args, reference_output)
151334
local capture = child.cmd_capture(('lua MiniMisc.put(%s)'):format(args))

0 commit comments

Comments
 (0)