From b353a5c05f026f46aeef0843007ba9c553533248 Mon Sep 17 00:00:00 2001 From: "Justin M. Keyes" Date: Sun, 16 Feb 2020 23:30:24 -0800 Subject: [PATCH] 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. --- test/functional/plugin/lsp_spec.lua | 57 ++++++++++++++--------------- test/helpers.lua | 33 ++++++++++------- 2 files changed, 48 insertions(+), 42 deletions(-) diff --git a/test/functional/plugin/lsp_spec.lua b/test/functional/plugin/lsp_spec.lua index 03e516d6f6..ba1eb2113e 100644 --- a/test/functional/plugin/lsp_spec.lua +++ b/test/functional/plugin/lsp_spec.lua @@ -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") diff --git a/test/helpers.lua b/test/helpers.lua index a31a7733bf..72b1bdcadd 100644 --- a/test/helpers.lua +++ b/test/helpers.lua @@ -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