summaryrefslogtreecommitdiff
path: root/doc/en/logging.rst
blob: 52713854efb2fea2e6d805efdb9d13189dd09598 (plain)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
.. _logging:

Logging
-------




pytest captures log messages of level ``WARNING`` or above automatically and displays them in their own section
for each failed test in the same manner as captured stdout and stderr.

Running without options:

.. code-block:: bash

    pytest

Shows failed tests like so:

.. code-block:: pytest

    ----------------------- Captured stdlog call ----------------------
    test_reporting.py    26 WARNING  text going to logger
    ----------------------- Captured stdout call ----------------------
    text going to stdout
    ----------------------- Captured stderr call ----------------------
    text going to stderr
    ==================== 2 failed in 0.02 seconds =====================

By default each captured log message shows the module, line number, log level
and message.

If desired the log and date format can be specified to
anything that the logging module supports by passing specific formatting options:

.. code-block:: bash

    pytest --log-format="%(asctime)s %(levelname)s %(message)s" \
            --log-date-format="%Y-%m-%d %H:%M:%S"

Shows failed tests like so:

.. code-block:: pytest

    ----------------------- Captured stdlog call ----------------------
    2010-04-10 14:48:44 WARNING text going to logger
    ----------------------- Captured stdout call ----------------------
    text going to stdout
    ----------------------- Captured stderr call ----------------------
    text going to stderr
    ==================== 2 failed in 0.02 seconds =====================

These options can also be customized through ``pytest.ini`` file:

.. code-block:: ini

    [pytest]
    log_format = %(asctime)s %(levelname)s %(message)s
    log_date_format = %Y-%m-%d %H:%M:%S

Further it is possible to disable reporting of captured content (stdout,
stderr and logs) on failed tests completely with:

.. code-block:: bash

    pytest --show-capture=no


caplog fixture
^^^^^^^^^^^^^^

Inside tests it is possible to change the log level for the captured log
messages.  This is supported by the ``caplog`` fixture:

.. code-block:: python

    def test_foo(caplog):
        caplog.set_level(logging.INFO)
        pass

By default the level is set on the root logger,
however as a convenience it is also possible to set the log level of any
logger:

.. code-block:: python

    def test_foo(caplog):
        caplog.set_level(logging.CRITICAL, logger="root.baz")
        pass

The log levels set are restored automatically at the end of the test.

It is also possible to use a context manager to temporarily change the log
level inside a ``with`` block:

.. code-block:: python

    def test_bar(caplog):
        with caplog.at_level(logging.INFO):
            pass

Again, by default the level of the root logger is affected but the level of any
logger can be changed instead with:

.. code-block:: python

    def test_bar(caplog):
        with caplog.at_level(logging.CRITICAL, logger="root.baz"):
            pass

Lastly all the logs sent to the logger during the test run are made available on
the fixture in the form of both the ``logging.LogRecord`` instances and the final log text.
This is useful for when you want to assert on the contents of a message:

.. code-block:: python

    def test_baz(caplog):
        func_under_test()
        for record in caplog.records:
            assert record.levelname != "CRITICAL"
        assert "wally" not in caplog.text

For all the available attributes of the log records see the
``logging.LogRecord`` class.

You can also resort to ``record_tuples`` if all you want to do is to ensure,
that certain messages have been logged under a given logger name with a given
severity and message:

.. code-block:: python

    def test_foo(caplog):
        logging.getLogger().info("boo %s", "arg")

        assert caplog.record_tuples == [("root", logging.INFO, "boo arg")]

You can call ``caplog.clear()`` to reset the captured log records in a test:

.. code-block:: python

    def test_something_with_clearing_records(caplog):
        some_method_that_creates_log_records()
        caplog.clear()
        your_test_method()
        assert ["Foo"] == [rec.message for rec in caplog.records]


The ``caplog.records`` attribute contains records from the current stage only, so
inside the ``setup`` phase it contains only setup logs, same with the ``call`` and
``teardown`` phases.

To access logs from other stages, use the ``caplog.get_records(when)`` method. As an example,
if you want to make sure that tests which use a certain fixture never log any warnings, you can inspect
the records for the ``setup`` and ``call`` stages during teardown like so:

.. code-block:: python

    @pytest.fixture
    def window(caplog):
        window = create_window()
        yield window
        for when in ("setup", "call"):
            messages = [
                x.message for x in caplog.get_records(when) if x.levelno == logging.WARNING
            ]
            if messages:
                pytest.fail(
                    "warning messages encountered during testing: {}".format(messages)
                )



The full API is available at :class:`_pytest.logging.LogCaptureFixture`.


.. _live_logs:

Live Logs
^^^^^^^^^

By setting the :confval:`log_cli` configuration option to ``true``, pytest will output
logging records as they are emitted directly into the console.

You can specify the logging level for which log records with equal or higher
level are printed to the console by passing ``--log-cli-level``. This setting
accepts the logging level names as seen in python's documentation or an integer
as the logging level num.

Additionally, you can also specify ``--log-cli-format`` and
``--log-cli-date-format`` which mirror and default to ``--log-format`` and
``--log-date-format`` if not provided, but are applied only to the console
logging handler.

All of the CLI log options can also be set in the configuration INI file. The
option names are:

* ``log_cli_level``
* ``log_cli_format``
* ``log_cli_date_format``

If you need to record the whole test suite logging calls to a file, you can pass
``--log-file=/path/to/log/file``. This log file is opened in write mode which
means that it will be overwritten at each run tests session.

You can also specify the logging level for the log file by passing
``--log-file-level``. This setting accepts the logging level names as seen in
python's documentation(ie, uppercased level names) or an integer as the logging
level num.

Additionally, you can also specify ``--log-file-format`` and
``--log-file-date-format`` which are equal to ``--log-format`` and
``--log-date-format`` but are applied to the log file logging handler.

All of the log file options can also be set in the configuration INI file. The
option names are:

* ``log_file``
* ``log_file_level``
* ``log_file_format``
* ``log_file_date_format``

You can call ``set_log_path()`` to customize the log_file path dynamically. This functionality
is considered **experimental**.

.. _log_release_notes:

Release notes
^^^^^^^^^^^^^

This feature was introduced as a drop-in replacement for the `pytest-catchlog
<https://pypi.org/project/pytest-catchlog/>`_ plugin and they conflict
with each other. The backward compatibility API with ``pytest-capturelog``
has been dropped when this feature was introduced, so if for that reason you
still need ``pytest-catchlog`` you can disable the internal feature by
adding to your ``pytest.ini``:

.. code-block:: ini

   [pytest]
       addopts=-p no:logging


.. _log_changes_3_4:

Incompatible changes in pytest 3.4
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

This feature was introduced in ``3.3`` and some **incompatible changes** have been
made in ``3.4`` after community feedback:

* Log levels are no longer changed unless explicitly requested by the :confval:`log_level` configuration
  or ``--log-level`` command-line options. This allows users to configure logger objects themselves.
  Setting :confval:`log_level` will set the level that is captured globally so if a specific test requires
  a lower level than this, use the ``caplog.set_level()`` functionality otherwise that test will be prone to
  failure.
* :ref:`Live Logs <live_logs>` is now disabled by default and can be enabled setting the
  :confval:`log_cli` configuration option to ``true``. When enabled, the verbosity is increased so logging for each
  test is visible.
* :ref:`Live Logs <live_logs>` are now sent to ``sys.stdout`` and no longer require the ``-s`` command-line option
  to work.

If you want to partially restore the logging behavior of version ``3.3``, you can add this options to your ``ini``
file:

.. code-block:: ini

    [pytest]
    log_cli=true
    log_level=NOTSET

More details about the discussion that lead to this changes can be read in
issue `#3013 <https://github.com/pytest-dev/pytest/issues/3013>`_.