Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Server:grep_log() doesn't work with stopped server #397

Open
locker opened this issue Oct 22, 2024 · 1 comment
Open

Server:grep_log() doesn't work with stopped server #397

locker opened this issue Oct 22, 2024 · 1 comment
Labels
bug Something isn't working

Comments

@locker
Copy link
Member

locker commented Oct 22, 2024

Consider the following test case:

local t = require('luatest')
local server = require('luatest.server')

local g = t.group()

g.before_each(function(cg)
    cg.server = server.new()
    cg.server:start()
end)

g.after_each(function(cg)
    cg.server:drop()
end)

g.test_grep_log = function(cg)
    server:exec(function() require('log').info('test grep_log') end)
    t.assert(server:grep_log('test grep_log'))
    server:stop()
    t.assert(server:grep_log('test grep_log'))
end

It fails with:

Tarantool version is 3.3.0-entrypoint-169-gd8ebc818c936
Started on Tue Oct 22 14:10:17 2024
    server.test_grep_log_offline ... (0.126s) error
/home/vlad/src/tarantool/luatest/luatest/server.lua:883: net_box is not connected
=========================================================

Tests with errors:
------------------

1) server.test_grep_log_offline
/home/vlad/src/tarantool/luatest/luatest/server.lua:883: net_box is not connected
stack traceback:
        ...
        [C]: in function 'xpcall'
artifacts:
        server -> /tmp/t/artifacts/server-PvqKU6hNIooc
Ran 1 tests in 0.444 seconds, 0 succeeded, 1 errored, 29 not selected

=========================================================
Failed tests:

server.test_grep_log_offline

It's possible to work around this issue by explicitly passing the path to the log file in opts.filename but it's inconvenient. Server:grep_log() should work even if the server is stopped, at least with the default instance.

@locker locker added the bug Something isn't working label Oct 22, 2024
@Totktonada
Copy link
Member

BTW, I've created a helper for my own test. Maybe it worth to consider it for inclusion into <luatest.server object>:exec().

-- Execute the given function on the given server and collect logs
-- produced during its execution.
--
-- Comparing to <server object>:exec() it has a limited
-- functionality:
--
-- * no arguments passing
-- * no return value receiving
-- * no luatest upvalue autorebinding
-- * no check that there are no other upvalues
--
-- Though, it is enough for the test cases below.
--
-- It would be nice to integrate the log capturing functionality
-- right into <server object>:exec() in a future. It would also be
-- nice to support logging to stderr, not just file, because
-- luatest anyway captures it.
--
-- Unlike <server object>:grep_log() this function is bounded to
-- a particular given function and leans on unique log markers, so
-- it is suitable in a situation, when several testing scenarios
-- are producing a similar output.
--
-- Also, it just feels more user-friendly.
local function log_capturing_exec(server, f)
    -- Generate markers to issue them before/after the execution
    -- of the provided function and look them up inside logs
    -- later.
    local start_marker = digest.urandom(40):hex()
    local end_marker = digest.urandom(40):hex()

    -- Execute the provided function (and issue the markers
    -- before/after it).
    local func_body = string.dump(f)
    server:exec(function(func_body, start_marker, end_marker)
        local log = require('log')
        local func = loadstring(func_body)
        log.info(start_marker)
        func()
        log.info(end_marker)
    end, {func_body, start_marker, end_marker})

    -- Determine a path to the log file of the given server.
    local file = fio.pathjoin(server.chdir, 'var/log', server.alias,
        'tarantool.log')

    -- Cut off a text between start and end markers: the outout
    -- of the provided function.
    local raw_log = t.helpers.retrying({timeout = 60}, function()
        -- Read the log file.
        local fh = assert(fio.open(file, {'O_RDONLY'}))
        local data = fh:read()
        fh:close()

        -- Look up positions of the start and the end markers.
        --
        -- We need the last position of the start marker and the
        -- first position of the end marker.
        local _, s = data:find(('%s\n'):format(start_marker))
        assert(s ~= nil, ('no test start marker: %s'):format(start_marker))
        local e = data:find(('\n[^\n]+%s'):format(end_marker), s)
        assert(e ~= nil, ('no test end marker: %s'):format(end_marker))

        -- All the text between them is what we're searching for.
        return data:sub(s + 1, e - 1)
    end)

    -- Split per line.
    --
    -- Remove all the columns except the log level and the
    -- message.
    local res = {}
    for _, line in ipairs(raw_log:split('\n')) do
        table.insert(res, line:match('.> .*$'))
    end
    return res
end

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

2 participants