Skip to content

Commit eb33d35

Browse files
committed
Add test and docs for jid and minion_id in logs
Adds test for jid and minion_id in log format strings to ensure they appear correctly in the master log. Updates documentation to cover minion_id field and to recommend adding minion_id and jid to the log format config.
1 parent a9a0f73 commit eb33d35

File tree

2 files changed

+122
-32
lines changed

2 files changed

+122
-32
lines changed

doc/ref/configuration/logging/index.rst

Lines changed: 29 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -184,6 +184,8 @@ formatting matches those used in :py:func:`time.strftime`.
184184

185185
Default: ``[%(levelname)-8s] %(message)s``
186186

187+
Recommended: ``[%(levelname)-8s]%(jid)s%(minion_id)s %(message)s``
188+
187189
The format of the console logging messages. All standard python logging
188190
:py:class:`~logging.LogRecord` attributes can be used. Salt also provides these
189191
custom LogRecord attributes to colorize console log output:
@@ -205,13 +207,20 @@ custom LogRecord attributes to colorize console log output:
205207
206208
log_fmt_console: '[%(levelname)-8s] %(message)s'
207209
210+
.. note::
211+
212+
It is recommended to include ``%(jid)s`` and ``%(minion_id)s`` in the log
213+
format to identify messages that relate to specific jobs and minions.
214+
208215
.. conf_log:: log_fmt_logfile
209216

210217
``log_fmt_logfile``
211218
-------------------
212219

213220
Default: ``%(asctime)s,%(msecs)03d [%(name)-17s][%(levelname)-8s] %(message)s``
214221

222+
Recommended: ``%(asctime)s,%(msecs)03d [%(name)-17s:%(lineno)-4d][%(levelname)-8s][%(process)d]%(jid)s%(minion_id)s %(message)s``
223+
215224
The format of the log file logging messages. All standard python logging
216225
:py:class:`~logging.LogRecord` attributes can be used. Salt also provides
217226
these custom LogRecord attributes that include padding and enclosing brackets
@@ -227,6 +236,11 @@ these custom LogRecord attributes that include padding and enclosing brackets
227236
228237
log_fmt_logfile: '%(asctime)s,%(msecs)03d [%(name)-17s][%(levelname)-8s] %(message)s'
229238
239+
.. note::
240+
241+
It is recommended to include ``%(jid)s`` and ``%(minion_id)s`` in the log
242+
format to identify messages that relate to specific jobs and minions.
243+
230244
.. conf_log:: log_granular_levels
231245

232246
``log_granular_levels``
@@ -245,12 +259,11 @@ at the ``debug`` level, and sets a custom module to the ``all`` level:
245259
'salt.modules': 'debug'
246260
'salt.loader.saltmaster.ext.module.custom_module': 'all'
247261
248-
.. conf_log:: log_fmt_jid
249-
250262
You can determine what log call name to use here by adding ``%(module)s`` to the
251263
log format. Typically, it is the path of the file which generates the log
252264
without the trailing ``.py`` and with path separators replaced with ``.``
253265

266+
.. conf_log:: log_fmt_jid
254267

255268
``log_fmt_jid``
256269
-------------------
@@ -263,6 +276,20 @@ The format of the JID when added to logging messages.
263276
264277
log_fmt_jid: '[JID: %(jid)s]'
265278
279+
.. conf_log:: log_fmt_minion_id
280+
281+
``log_fmt_minion_id``
282+
----------------------
283+
284+
Default: ``[%(minion_id)s]``
285+
286+
The format of the minion ID when added to logging messages.
287+
288+
.. code-block:: yaml
289+
290+
log_fmt_minion_id: '[%(minion_id)s]'
291+
292+
266293
External Logging Handlers
267294
-------------------------
268295

Lines changed: 93 additions & 30 deletions
Original file line numberDiff line numberDiff line change
@@ -1,32 +1,95 @@
1-
import logging
1+
import pathlib
2+
3+
import pytest
4+
from saltfactories.utils import random_string
25

36
from salt._logging import DFLT_LOG_FMT_JID
4-
from tests.support.helpers import PRE_PYTEST_SKIP
5-
6-
# Using the PRE_PYTEST_SKIP decorator since this test still fails on some platforms.
7-
# Will investigate later.
8-
9-
10-
@PRE_PYTEST_SKIP
11-
def test_jid_in_logs(caplog, salt_call_cli):
12-
"""
13-
Test JID in log_format
14-
"""
15-
jid_formatted_str = DFLT_LOG_FMT_JID.split("%", maxsplit=1)[0]
16-
formatter = logging.Formatter(fmt="%(jid)s %(message)s")
17-
with caplog.at_level(logging.DEBUG):
18-
previous_formatter = caplog.handler.formatter
19-
try:
20-
caplog.handler.setFormatter(formatter)
21-
ret = salt_call_cli.run("test.ping")
22-
assert ret.returncode == 0
23-
assert ret.data is True
24-
25-
assert_error_msg = (
26-
"'{}' not found in log messages:\n>>>>>>>>>{}\n<<<<<<<<<".format(
27-
jid_formatted_str, caplog.text
28-
)
29-
)
30-
assert jid_formatted_str in caplog.text, assert_error_msg
31-
finally:
32-
caplog.handler.setFormatter(previous_formatter)
7+
from salt._logging.impl import DFLT_LOG_FMT_MINION_ID
8+
9+
10+
@pytest.fixture(scope="module")
11+
def log_field_marker():
12+
"""
13+
Marker to make identifying log fields possible without risk of matching
14+
other instances of jid or minion_id in the log messages
15+
"""
16+
return "EXTRA_LOG_FIELD:"
17+
18+
19+
@pytest.fixture(scope="module")
20+
def logging_master(salt_master_factory, log_field_marker):
21+
"""
22+
A logging master fixture with JID and minion_id in log format
23+
"""
24+
log_format = (
25+
f"{log_field_marker}%(jid)s {log_field_marker}%(minion_id)s %(message)s"
26+
)
27+
config_overrides = {
28+
"log_level_logfile": "debug",
29+
"log_fmt_logfile": log_format,
30+
}
31+
logging_master_factory = salt_master_factory.salt_master_daemon(
32+
random_string("master-logging-"),
33+
overrides=config_overrides,
34+
extra_cli_arguments_after_first_start_failure=["--log-level=info"],
35+
)
36+
with logging_master_factory.started():
37+
yield logging_master_factory
38+
39+
40+
@pytest.fixture(scope="module")
41+
def logging_master_logfile(logging_master):
42+
"""
43+
The logging master log file path
44+
"""
45+
assert logging_master.is_running()
46+
return pathlib.Path(logging_master.config["log_file"])
47+
48+
49+
@pytest.fixture(scope="module")
50+
def salt_cli(logging_master):
51+
"""
52+
A ``salt``` CLI fixture
53+
"""
54+
assert logging_master.is_running()
55+
return logging_master.salt_cli(timeout=30)
56+
57+
58+
@pytest.fixture(scope="module")
59+
def logging_minion_id(logging_master):
60+
"""
61+
Random minion id for a salt-minion fixture
62+
"""
63+
return random_string("minion-logging-")
64+
65+
66+
@pytest.fixture
67+
def logging_minion(logging_master, logging_minion_id):
68+
"""
69+
A running salt-minion fixture connected to the logging master
70+
"""
71+
assert logging_master.is_running()
72+
salt_minion_factory = logging_master.salt_minion_daemon(
73+
logging_minion_id,
74+
)
75+
with salt_minion_factory.started():
76+
yield salt_minion_factory
77+
78+
79+
def test_jid_minion_id_in_logs(
80+
logging_master_logfile, log_field_marker, salt_cli, logging_minion
81+
):
82+
"""
83+
Test JID and minion_id appear in master log file in the expected format
84+
"""
85+
ret = salt_cli.run("test.ping", "-v", minion_tgt=logging_minion.id)
86+
assert ret.returncode == 0
87+
assert "Executing job with jid" in ret.stdout
88+
89+
jid_str = DFLT_LOG_FMT_JID % {"jid": ret.stdout.splitlines()[0].split()[-1]}
90+
minion_id_str = DFLT_LOG_FMT_MINION_ID % {"minion_id": logging_minion.id}
91+
92+
log_file_text = logging_master_logfile.read_text()
93+
94+
assert f"{log_field_marker}{jid_str}" in log_file_text
95+
assert f"{log_field_marker}{minion_id_str}" in log_file_text

0 commit comments

Comments
 (0)