test: always dump logs on failure #11886

Whenever `eq()`, `ok()`, etc. fails, include log tail in the failure
message. This helps to correlate log messages with a particular test
failure.
This commit is contained in:
Justin M. Keyes 2020-02-16 23:30:24 -08:00 committed by GitHub
parent 03f245c0b8
commit b353a5c05f
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
2 changed files with 48 additions and 42 deletions

View File

@ -6,7 +6,6 @@ local buf_lines = helpers.buf_lines
local dedent = helpers.dedent
local exec_lua = helpers.exec_lua
local eq = helpers.eq
local eq_dumplog = helpers.eq_dumplog
local pesc = helpers.pesc
local insert = helpers.insert
local retry = helpers.retry
@ -207,8 +206,8 @@ describe('LSP', function()
end;
-- If the program timed out, then code will be nil.
on_exit = function(code, signal)
eq_dumplog(fake_lsp_logfile, 0, code, "exit code")
eq_dumplog(fake_lsp_logfile, 0, signal, "exit signal")
eq(0, code, "exit code", fake_lsp_logfile)
eq(0, signal, "exit signal", fake_lsp_logfile)
end;
-- Note that NIL must be used here.
-- on_callback(err, method, result, client_id)
@ -229,8 +228,8 @@ describe('LSP', function()
client.stop()
end;
on_exit = function(code, signal)
eq_dumplog(fake_lsp_logfile, 101, code, "exit code") -- See fake-lsp-server.lua
eq_dumplog(fake_lsp_logfile, 0, signal, "exit signal")
eq(101, code, "exit code", fake_lsp_logfile) -- See fake-lsp-server.lua
eq(0, signal, "exit signal", fake_lsp_logfile)
assert_log(pesc([[assert_eq failed: left == "\"shutdown\"", right == "\"test\""]]),
fake_lsp_logfile)
end;
@ -253,8 +252,8 @@ describe('LSP', function()
client.notify('exit')
end;
on_exit = function(code, signal)
eq_dumplog(fake_lsp_logfile, 0, code, "exit code")
eq_dumplog(fake_lsp_logfile, 0, signal, "exit signal")
eq(0, code, "exit code", fake_lsp_logfile)
eq(0, signal, "exit signal", fake_lsp_logfile)
end;
on_callback = function(...)
eq(table.remove(expected_callbacks), {...}, "expected callback")
@ -272,8 +271,8 @@ describe('LSP', function()
client.stop()
end;
on_exit = function(code, signal)
eq_dumplog(fake_lsp_logfile, 0, code, "exit code")
eq_dumplog(fake_lsp_logfile, 0, signal, "exit signal")
eq(0, code, "exit code", fake_lsp_logfile)
eq(0, signal, "exit signal", fake_lsp_logfile)
end;
on_callback = function(...)
eq(table.remove(expected_callbacks), {...}, "expected callback")
@ -312,8 +311,8 @@ describe('LSP', function()
client.notify('finish')
end;
on_exit = function(code, signal)
eq_dumplog(fake_lsp_logfile, 0, code, "exit code")
eq_dumplog(fake_lsp_logfile, 0, signal, "exit signal")
eq(0, code, "exit code", fake_lsp_logfile)
eq(0, signal, "exit signal", fake_lsp_logfile)
end;
on_callback = function(err, method, params, client_id)
eq(table.remove(expected_callbacks), {err, method, params, client_id}, "expected callback")
@ -355,8 +354,8 @@ describe('LSP', function()
]]
end;
on_exit = function(code, signal)
eq_dumplog(fake_lsp_logfile, 0, code, "exit code")
eq_dumplog(fake_lsp_logfile, 0, signal, "exit signal")
eq(0, code, "exit code", fake_lsp_logfile)
eq(0, signal, "exit signal", fake_lsp_logfile)
end;
on_callback = function(err, method, params, client_id)
if method == 'start' then
@ -398,8 +397,8 @@ describe('LSP', function()
]]
end;
on_exit = function(code, signal)
eq_dumplog(fake_lsp_logfile, 0, code, "exit code")
eq_dumplog(fake_lsp_logfile, 0, signal, "exit signal")
eq(0, code, "exit code", fake_lsp_logfile)
eq(0, signal, "exit signal", fake_lsp_logfile)
end;
on_callback = function(err, method, params, client_id)
if method == 'start' then
@ -441,8 +440,8 @@ describe('LSP', function()
]]
end;
on_exit = function(code, signal)
eq_dumplog(fake_lsp_logfile, 0, code, "exit code")
eq_dumplog(fake_lsp_logfile, 0, signal, "exit signal")
eq(0, code, "exit code", fake_lsp_logfile)
eq(0, signal, "exit signal", fake_lsp_logfile)
end;
on_callback = function(err, method, params, client_id)
if method == 'start' then
@ -490,8 +489,8 @@ describe('LSP', function()
]]
end;
on_exit = function(code, signal)
eq_dumplog(fake_lsp_logfile, 0, code, "exit code")
eq_dumplog(fake_lsp_logfile, 0, signal, "exit signal")
eq(0, code, "exit code", fake_lsp_logfile)
eq(0, signal, "exit signal", fake_lsp_logfile)
end;
on_callback = function(err, method, params, client_id)
if method == 'start' then
@ -539,8 +538,8 @@ describe('LSP', function()
]]
end;
on_exit = function(code, signal)
eq_dumplog(fake_lsp_logfile, 0, code, "exit code")
eq_dumplog(fake_lsp_logfile, 0, signal, "exit signal")
eq(0, code, "exit code", fake_lsp_logfile)
eq(0, signal, "exit signal", fake_lsp_logfile)
end;
on_callback = function(err, method, params, client_id)
if method == 'start' then
@ -588,8 +587,8 @@ describe('LSP', function()
]]
end;
on_exit = function(code, signal)
eq_dumplog(fake_lsp_logfile, 0, code, "exit code")
eq_dumplog(fake_lsp_logfile, 0, signal, "exit signal")
eq(0, code, "exit code", fake_lsp_logfile)
eq(0, signal, "exit signal", fake_lsp_logfile)
end;
on_callback = function(err, method, params, client_id)
if method == 'start' then
@ -632,8 +631,8 @@ describe('LSP', function()
]]
end;
on_exit = function(code, signal)
eq_dumplog(fake_lsp_logfile, 0, code, "exit code")
eq_dumplog(fake_lsp_logfile, 0, signal, "exit signal")
eq(0, code, "exit code", fake_lsp_logfile)
eq(0, signal, "exit signal", fake_lsp_logfile)
end;
on_callback = function(err, method, params, client_id)
if method == 'start' then
@ -683,8 +682,8 @@ describe('LSP', function()
]]
end;
on_exit = function(code, signal)
eq_dumplog(fake_lsp_logfile, 0, code, "exit code")
eq_dumplog(fake_lsp_logfile, 0, signal, "exit signal")
eq(0, code, "exit code", fake_lsp_logfile)
eq(0, signal, "exit signal", fake_lsp_logfile)
end;
on_callback = function(err, method, params, client_id)
if method == 'start' then
@ -726,8 +725,8 @@ describe('LSP', function()
client.stop(true)
end;
on_exit = function(code, signal)
eq_dumplog(fake_lsp_logfile, 0, code, "exit code")
eq_dumplog(fake_lsp_logfile, 0, signal, "exit signal")
eq(0, code, "exit code", fake_lsp_logfile)
eq(0, signal, "exit signal", fake_lsp_logfile)
end;
on_callback = function(err, method, params, client_id)
eq(table.remove(expected_callbacks), {err, method, params, client_id}, "expected callback")

View File

@ -55,25 +55,32 @@ local check_logs_useless_lines = {
['See README_MISSING_SYSCALL_OR_IOCTL for guidance']=3,
}
function module.eq(expected, actual, context)
return assert.are.same(expected, actual, context)
end
-- Like eq(), but includes tail of `logfile` in failure message.
function module.eq_dumplog(logfile, expected, actual, context)
local status, rv = pcall(module.eq, expected, actual, context)
if not status then
--- Invokes `fn` and includes the tail of `logfile` in the error message if it
--- fails.
---
--@param logfile Log file, defaults to $NVIM_LOG_FILE or '.nvimlog'
--@param fn Function to invoke
--@param ... Function arguments
local function dumplog(logfile, fn, ...)
-- module.validate({
-- logfile={logfile,'s',true},
-- fn={fn,'f',false},
-- })
local status, rv = pcall(fn, ...)
if status == false then
logfile = logfile or os.getenv('NVIM_LOG_FILE') or '.nvimlog'
local logtail = module.read_nvim_log(logfile)
error(string.format('%s\n%s', rv, logtail))
end
end
function module.neq(expected, actual, context)
return assert.are_not.same(expected, actual, context)
function module.eq(expected, actual, context, logfile)
return dumplog(logfile, assert.are.same, expected, actual, context)
end
function module.ok(res, msg)
return assert.is_true(res, msg)
function module.neq(expected, actual, context, logfile)
return dumplog(logfile, assert.are_not.same, expected, actual, context)
end
function module.near(actual, expected, tolerance)
return assert.is.near(actual, expected, tolerance)
function module.ok(res, msg, logfile)
return dumplog(logfile, assert.is_true, res, msg)
end
function module.matches(pat, actual)
if nil ~= string.match(actual, pat) then