Skip to content

Commit 4e3d482

Browse files
andreyaksenovandreyaksenov
committed
Per-module logging
1 parent 9f423c5 commit 4e3d482

File tree

8 files changed

+393
-11
lines changed

8 files changed

+393
-11
lines changed

‎doc/code_snippets/test/logging/log_existing_c_modules_test.lua

Lines changed: 48 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,48 @@
1+
local fio = require('fio')
2+
local server = require('luatest.server')
3+
local t = require('luatest')
4+
local g = t.group()
5+
6+
g.before_each(function(cg)
7+
cg.server = server:new {
8+
workdir = fio.cwd() .. '/tmp',
9+
box_cfg = { log_level = 'warn',
10+
log_modules = { tarantool = 'info' } }
11+
}
12+
cg.server:start()
13+
cg.server:exec(function()
14+
ffi = require('ffi')
15+
16+
-- Prints 'info' messages --
17+
ffi.C._say(ffi.C.S_INFO, nil, 0, nil, 'Info message from C module')
18+
--[[
19+
[6024] main/103/interactive I> Info message from C module
20+
---
21+
...
22+
--]]
23+
24+
-- Swallows 'debug' messages --
25+
ffi.C._say(ffi.C.S_DEBUG, nil, 0, nil, 'Debug message from C module')
26+
--[[
27+
---
28+
...
29+
--]]
30+
end)
31+
end)
32+
33+
g.after_each(function(cg)
34+
cg.server:stop()
35+
cg.server:drop()
36+
end)
37+
38+
local function find_in_log(cg, str, must_be_present)
39+
t.helpers.retrying({ timeout = 0.3, delay = 0.1 }, function()
40+
local found = cg.server:grep_log(str) ~= nil
41+
t.assert(found == must_be_present)
42+
end)
43+
end
44+
45+
g.test_log_contains_messages = function(cg)
46+
find_in_log(cg, 'Info message from C module', true)
47+
find_in_log(cg, 'Debug message from C module', false)
48+
end

‎doc/code_snippets/test/logging/log_existing_modules_test.lua

Lines changed: 56 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,56 @@
1+
local fio = require('fio')
2+
local server = require('luatest.server')
3+
local t = require('luatest')
4+
local g = t.group()
5+
6+
local run_before_cfg = [[
7+
module1 = require('test.logging.module1')
8+
module2 = require('test.logging.module2')
9+
]]
10+
11+
g.before_each(function(cg)
12+
cg.server = server:new {
13+
env = {
14+
['TARANTOOL_RUN_BEFORE_BOX_CFG'] = run_before_cfg,
15+
},
16+
workdir = fio.cwd() .. '/tmp',
17+
box_cfg = { log_modules = {
18+
['test.logging.module1'] = 'verbose',
19+
['test.logging.module2'] = 'error' }
20+
}
21+
}
22+
cg.server:start()
23+
cg.server:exec(function()
24+
-- Prints 'info' messages --
25+
module1.say_hello()
26+
--[[
27+
[92617] main/103/interactive/test.logging.module1 I> Info message from module1
28+
---
29+
...
30+
--]]
31+
32+
-- Swallows 'info' messages --
33+
module2.say_hello()
34+
--[[
35+
---
36+
...
37+
--]]
38+
end)
39+
end)
40+
41+
g.after_each(function(cg)
42+
cg.server:stop()
43+
cg.server:drop()
44+
end)
45+
46+
local function find_in_log(cg, str, must_be_present)
47+
t.helpers.retrying({ timeout = 0.3, delay = 0.1 }, function()
48+
local found = cg.server:grep_log(str) ~= nil
49+
t.assert(found == must_be_present)
50+
end)
51+
end
52+
53+
g.test_log_contains_messages = function(cg)
54+
find_in_log(cg, 'Info message from module1', true)
55+
find_in_log(cg, 'Info message from module2', false)
56+
end

‎doc/code_snippets/test/logging/log_new_modules_test.lua

Lines changed: 61 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,61 @@
1+
local fio = require('fio')
2+
local server = require('luatest.server')
3+
local t = require('luatest')
4+
local g = t.group()
5+
6+
g.before_each(function(cg)
7+
cg.server = server:new {
8+
workdir = fio.cwd() .. '/tmp',
9+
box_cfg = { log_level = 'warn',
10+
log_modules = {
11+
module1 = 'verbose',
12+
module2 = 'error' }
13+
}
14+
}
15+
cg.server:start()
16+
cg.server:exec(function()
17+
-- Creates new loggers --
18+
module1_log = require('log').new('module1')
19+
module2_log = require('log').new('module2')
20+
21+
-- Prints 'info' messages --
22+
module1_log.info('Info message from module1')
23+
--[[
24+
[16300] main/103/interactive/module1 I> Info message from module1
25+
---
26+
...
27+
--]]
28+
29+
-- Swallows 'debug' messages --
30+
module1_log.debug('Debug message from module1')
31+
--[[
32+
---
33+
...
34+
--]]
35+
36+
-- Swallows 'info' messages --
37+
module2_log.info('Info message from module2')
38+
--[[
39+
---
40+
...
41+
--]]
42+
end)
43+
end)
44+
45+
g.after_each(function(cg)
46+
cg.server:stop()
47+
cg.server:drop()
48+
end)
49+
50+
local function find_in_log(cg, str, must_be_present)
51+
t.helpers.retrying({ timeout = 0.3, delay = 0.1 }, function()
52+
local found = cg.server:grep_log(str) ~= nil
53+
t.assert(found == must_be_present)
54+
end)
55+
end
56+
57+
g.test_log_contains_messages = function(cg)
58+
find_in_log(cg, 'Info message from module1', true)
59+
find_in_log(cg, 'Debug message from module1', false)
60+
find_in_log(cg, 'Info message from module2', false)
61+
end

‎doc/code_snippets/test/logging/log_test.lua

Lines changed: 47 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,47 @@
1+
local fio = require('fio')
2+
local server = require('luatest.server')
3+
local t = require('luatest')
4+
local g = t.group()
5+
6+
g.before_each(function(cg)
7+
cg.server = server:new {
8+
workdir = fio.cwd() .. '/tmp',
9+
box_cfg = { log_level = 'warn' }
10+
}
11+
cg.server:start()
12+
cg.server:exec(function()
13+
log = require('log')
14+
15+
-- Prints 'warn' messages --
16+
log.warn('Warning message')
17+
--[[
18+
2023-07-20 11:03:57.029 [16300] main/103/interactive/tarantool [C]:-1 W> Warning message
19+
---
20+
...
21+
--]]
22+
23+
-- Swallows 'debug' messages --
24+
log.debug('Debug message')
25+
--[[
26+
---
27+
...
28+
--]]
29+
end)
30+
end)
31+
32+
g.after_each(function(cg)
33+
cg.server:stop()
34+
cg.server:drop()
35+
end)
36+
37+
local function find_in_log(cg, str, must_be_present)
38+
t.helpers.retrying({ timeout = 0.3, delay = 0.1 }, function()
39+
local found = cg.server:grep_log(str) ~= nil
40+
t.assert(found == must_be_present)
41+
end)
42+
end
43+
44+
g.test_log_contains_messages = function(cg)
45+
find_in_log(cg, 'Warning message', true)
46+
find_in_log(cg, 'Debug message', false)
47+
end

‎doc/code_snippets/test/logging/module1.lua

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,6 @@
1+
return {
2+
say_hello = function()
3+
local log = require('log')
4+
log.info('Info message from module1')
5+
end
6+
}

‎doc/code_snippets/test/logging/module2.lua

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,6 @@
1+
return {
2+
say_hello = function()
3+
local log = require('log')
4+
log.info('Info message from module2')
5+
end
6+
}

‎doc/reference/configuration/cfg_logging.rst

Lines changed: 108 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -9,6 +9,7 @@ application.
99
* :ref:`log_nonblock <cfg_logging-log_nonblock>`
1010
* :ref:`too_long_threshold <cfg_logging-too_long_threshold>`
1111
* :ref:`log_format <cfg_logging-log_format>`
12+
* :ref:`log_modules <cfg_logging-log_modules>`
1213

1314
.. _cfg_logging-log_level:
1415

@@ -208,6 +209,113 @@ application.
208209
| Environment variable: TT_LOG_FORMAT
209210
| Dynamic: **yes**
210211
212+
213+
.. _cfg_logging-log_modules:
214+
215+
.. confval:: log_modules
216+
217+
Since version :doc:`2.11.0 </release/2.11.0>`.
218+
Configure the specified log levels (:ref:`log_level <cfg_logging-log_level>`) for different modules.
219+
220+
You can specify a logging level for the following module types:
221+
222+
* Modules (files) that use the default logger.
223+
Example: :ref:`Set log levels for files that use the default logger <cfg_logging-logging_example_existing_modules>`.
224+
225+
* Modules that use custom loggers created using the :ref:`log.new() <log-new>` function.
226+
Example: :ref:`Set log levels for modules that use custom loggers <cfg_logging-logging_example_new_modules>`.
227+
228+
* The ``tarantool`` module that enables you to configure the logging level for Tarantool core messages. Specifically, it configures the logging level for messages logged from non-Lua code, including C modules.
229+
Example: :ref:`Set a log level for C modules <cfg_logging-logging_example_tarantool_module>`.
230+
231+
| Type: table
232+
| Default: blank
233+
| Environment variable: TT_LOG_MODULES
234+
| Dynamic: **yes**
235+
|
236+
237+
238+
.. _cfg_logging-logging_example_existing_modules:
239+
240+
**Example 1: Set log levels for files that use the default logger**
241+
242+
Suppose you have two identical modules placed by the following paths: ``test/logging/module1.lua`` and ``test/logging/module2.lua``.
243+
These modules use the default logger and look as follows:
244+
245+
.. literalinclude:: /code_snippets/test/logging/module1.lua
246+
:language: lua
247+
:dedent:
248+
249+
To load these modules in your application, you need to add the corresponding ``require`` directives:
250+
251+
.. literalinclude:: /code_snippets/test/logging/log_existing_modules_test.lua
252+
:language: lua
253+
:lines: 7-8
254+
:dedent:
255+
256+
To configure logging levels, you need to provide module names corresponding to paths to these modules.
257+
In the example below, the ``box_cfg`` variable contains logging settings that can be passed to the ``box.cfg()`` function:
258+
259+
.. literalinclude:: /code_snippets/test/logging/log_existing_modules_test.lua
260+
:language: lua
261+
:lines: 17-20
262+
:dedent:
263+
264+
Given that ``module1`` has the ``verbose`` logging level and ``module2`` has the ``error`` level, calling ``module1.say_hello()`` shows a message but ``module2.say_hello()`` is swallowed:
265+
266+
.. literalinclude:: /code_snippets/test/logging/log_existing_modules_test.lua
267+
:language: lua
268+
:lines: 24-37
269+
:dedent:
270+
271+
.. _cfg_logging-logging_example_new_modules:
272+
273+
**Example 2: Set log levels for modules that use custom loggers**
274+
275+
In the example below, the ``box_cfg`` variable contains logging settings that can be passed to the ``box.cfg()`` function.
276+
This example shows how to set the ``verbose`` level for ``module1`` and the ``error`` level for ``module2``:
277+
278+
.. literalinclude:: /code_snippets/test/logging/log_new_modules_test.lua
279+
:language: lua
280+
:lines: 9-13
281+
:dedent:
282+
283+
To create custom loggers, call the :ref:`log.new() <log-new>` function:
284+
285+
.. literalinclude:: /code_snippets/test/logging/log_new_modules_test.lua
286+
:language: lua
287+
:lines: 17-19
288+
:dedent:
289+
290+
Given that ``module1`` has the ``verbose`` logging level and ``module2`` has the ``error`` level, calling ``module1_log.info()`` shows a message but ``module2_log.info()`` is swallowed:
291+
292+
.. literalinclude:: /code_snippets/test/logging/log_new_modules_test.lua
293+
:language: lua
294+
:lines: 21-41
295+
:dedent:
296+
297+
.. _cfg_logging-logging_example_tarantool_module:
298+
299+
**Example 3: Set a log level for C modules**
300+
301+
In the example below, the ``box_cfg`` variable contains logging settings that can be passed to the ``box.cfg()`` function.
302+
This example shows how to set the ``info`` level for the ``tarantool`` module:
303+
304+
.. literalinclude:: /code_snippets/test/logging/log_existing_c_modules_test.lua
305+
:language: lua
306+
:lines: 9-10
307+
:dedent:
308+
309+
The specified level affects messages logged from C modules:
310+
311+
.. literalinclude:: /code_snippets/test/logging/log_existing_c_modules_test.lua
312+
:language: lua
313+
:lines: 14-29
314+
:dedent:
315+
316+
The example above uses the `LuaJIT ffi library <http://luajit.org/ext_ffi.html>`_ to call C functions provided by the ``say`` module.
317+
318+
211319
.. _cfg_logging-logging_example:
212320

213321
*********************

0 commit comments

Comments
 (0)