Skip to content

Configure logging format #478

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

Closed
myxo opened this issue Jan 1, 2022 · 13 comments
Closed

Configure logging format #478

myxo opened this issue Jan 1, 2022 · 13 comments

Comments

@myxo
Copy link

myxo commented Jan 1, 2022

Hi. I would like to have a possibility to set logging format. Didn't find anything about it in documentation. Tried to modify format from logging library or pytest settings, but it didn't change output in html (maybe i didn't find the right knob?). My versions:

Packages | {"pluggy": "1.0.0", "py": "1.11.0", "pytest": "6.2.5"}
Platform | Linux-4.19.104-microsoft-standard-x86_64-with-glibc2.29
Plugins | {"html": "3.1.1", "metadata": "1.11.0"}
Python | 3.8.10

So for now this code

import logging
def test_one():
    logging.warning('from test_one')

def test_two():
    logging.warning('from test_two')

generate
18

And I want something like
[2022-01-02 01:00:24,052] WARNING from test_one
[2022-01-02 01:00:24,052] WARNING from test_two

@fenchu
Copy link

fenchu commented Jan 14, 2022

you need to configure your logging, this one is a good starting point:
https://alexandra-zaharia.github.io/posts/make-your-own-custom-color-formatter-with-python-logging/
just add it to your own module (not call it logging.py) and import it or directly in the test

@myxo
Copy link
Author

myxo commented Jan 16, 2022

Not sure if it's working now. Here is my minimal example

import logging
import pytest

def test_one():
    # put configuration here, so it definitely run
    logging.basicConfig(level = logging.DEBUG,format = '[%(asctime)s] %(levelname)s - %(message)s')
    logging.warning('from test_one')

if __name__ == '__main__':
    test_one()

If I just run function, it's logged properly

> python3 test.py
[2022-01-16 20:30:29,233] WARNING - from test_one

But if I run it in pytest, logs in report does not change

> pytest test.py --html=report.html --self-contained-html

23

@Gea1
Copy link

Gea1 commented Dec 14, 2022

Hello,

I have the same issue. I'd need to see the datetime information from each log message in the test report, as seen in the console. There is a comment from @BeyondEvil in issue #314 314#issuecomment-659253438 that seems to highlight that, since you are getting captured logs from pytest, you don't have access to the timestamp data.

Is there any known workaround to achieve prints with date time information inside the pytest-html report? Is there any plan to add this feature?

Thank you!

@cainmagi
Copy link

Not sure if it's working now. Here is my minimal example

import logging
import pytest

def test_one():
    # put configuration here, so it definitely run
    logging.basicConfig(level = logging.DEBUG,format = '[%(asctime)s] %(levelname)s - %(message)s')
    logging.warning('from test_one')

if __name__ == '__main__':
    test_one()

If I just run function, it's logged properly

> python3 test.py
[2022-01-16 20:30:29,233] WARNING - from test_one

But if I run it in pytest, logs in report does not change

> pytest test.py --html=report.html --self-contained-html

Hello,

I have the same issue. I'd need to see the datetime information from each log message in the test report, as seen in the console. There is a comment from @BeyondEvil in issue #314 314#issuecomment-659253438 that seems to highlight that, since you are getting captured logs from pytest, you don't have access to the timestamp data.

Is there any known workaround to achieve prints with date time information inside the pytest-html report? Is there any plan to add this feature?

Thank you!

This issue is not caused by pytest-html

You should not use logging in codes. Instead, you need to add a pytest.ini file like this:

image

An example of pytest.ini

[pytest]
log_cli=true
log_level=DEBUG
log_format = %(filename)s - %(funcName)s @ %(asctime)s: %(levelname)s %(message)s
log_date_format = %Y-%m-%d %H:%M:%S

After that, run pytest, you will find something changed.

@chansonjoy
Copy link

The issue I saw is somehow the pytest-html dump the live log formatting from pytest and does it's own thing.

I have setup the live log in pyproject.toml as the following
[tool.pytest.ini_options]
log_cli = true
log_cli_level = "INFO"
log_cli_format = "%(asctime)s [%(levelname)8s] %(message)s (%(filename)s:%(lineno)s)"
log_cli_date_format = "%Y-%m-%d %H:%M:%S"

It works perfectly fine when run the command in the console:
2023-10-16_123131
However in the html report the format become like the following. Notice that it not only drop the timestamp but also move the file name, line number information around
2023-10-16_123500

@BeyondEvil
Copy link
Contributor

The plugin doesn't do any manipulation of the logs.

Could you provide a reproducible example?

@chansonjoy
Copy link

The plugin doesn't do any manipulation of the logs.

Could you provide a reproducible example?

Environment
Packages {"pluggy": "1.0.0", "py": "1.11.0", "pytest": "7.1.2"}
Platform Windows-10-10.0.19042-SP0
Plugins {"dependency": "0.5.1", "excel": "1.5.0", "html": "3.1.1", "metadata": "2.0.1", "repeat": "0.9.1"}
Python 3.10.1

pytest setting in pyproject.toml
[tool.pytest.ini_options]
log_cli = true
log_cli_level = "INFO"
log_cli_format = "%(asctime)s [%(levelname)8s] %(message)s (%(filename)s:%(lineno)s)"
log_cli_date_format = "%Y-%m-%d %H:%M:%S"

testpaths = ["auto_tests"]
addopts = "-rsxX -l -s --tb=short --capture=tee-sys --html=report/html/report.html --self-contained-html --junitxml=report/junit_xml/report.xml"

The result is the format of the capture in the report.html is different from what actually print out in the console.

@BeyondEvil
Copy link
Contributor

I see the issue between the live log and the captured log even in v4.

But I don't think this is an issue with the plugin as we only basically copy and paste what we get from pytest:

here and here

Do note that the captured log in the report matches what's in the captured log that is in the console. We don't add live log to the report.

@jeffwright13
Copy link
Collaborator

@chansonjoy - aren't your options -s and --capture=tee-sys mutually exclusive? pytest --help shows:

  --capture=method      Per-test capturing method: one of fd|sys|no|tee-sys
  -s                    Shortcut for --capture=no

I'm not sure what to expect with that.

In any case, I've never used pyproject.toml to specify my pytest ini options. I always just use plain pytest.ini. Can you try that to see if you get the same behavior you reported?

@chansonjoy
Copy link

[pytest]

you are absolutely right. I think the later "--capture=tee-sys" overwrite the "-s" though. Anyway, I tried simplify the parameters and put them in pytest.ini as:

[pytest]
log_cli = true
log_cli_level = INFO
log_cli_format = %(asctime)s [%(levelname)8s] %(message)s (%(filename)s:%(lineno)s)
log_cli_date_format = %Y-%m-%d %H:%M:%S

testpaths = auto_tests
addopts = --capture=tee-sys --html=report/html/report.html

The print from the report.html still different from print from the terminal as the following side by side comparison:

2023-11-08_160512

@jeffwright13
Copy link
Collaborator

Right - so a couple of things.

  1. There is 100% parity between what you see in the console and what you see in the HTML report, except for the timestamps, and the order of the different parts of the messages. It might be that the log_cli_format and log_cli_date_format specifiers only apply to the way the log messages are rendered in the live logs. In any case, I believe pytest-html is showing you what the captured log messages from pytest are rendering. If you scroll down further in your console, you should see those messages, and they should be shown w/o timestamps. Is that the case?
  2. You will not get 'live logs' information with pytest-html. As @BeyondEvil mentioned, "Do note that the captured log in the report matches what's in the captured log that is in the console. We don't add live log to the report." The place to see live logs is either on the terminal, as above, or with another plugin like pytest-tui or pytest-oof (disclaimer: both are mine, and pls note, I am not trying to take anything away from pytest-html - in fact, I use pytest-html way more than my own, both personally and at work).
  3. There is definitely a way to get timestamps into the captured logs...I have it set up on one of my test machines, and can provide info here if anyone wants it. I just don't recall off the top of my head how it's done.

@chansonjoy
Copy link

Right - so a couple of things.

  1. There is 100% parity between what you see in the console and what you see in the HTML report, except for the timestamps, and the order of the different parts of the messages. It might be that the log_cli_format and log_cli_date_format specifiers only apply to the way the log messages are rendered in the live logs. In any case, I believe pytest-html is showing you what the captured log messages from pytest are rendering. If you scroll down further in your console, you should see those messages, and they should be shown w/o timestamps. Is that the case?
  2. You will not get 'live logs' information with pytest-html. As @BeyondEvil mentioned, "Do note that the captured log in the report matches what's in the captured log that is in the console. We don't add live log to the report." The place to see live logs is either on the terminal, as above, or with another plugin like pytest-tui or pytest-oof (disclaimer: both are mine, and pls note, I am not trying to take anything away from pytest-html - in fact, I use pytest-html way more than my own, both personally and at work).
  3. There is definitely a way to get timestamps into the captured logs...I have it set up on one of my test machines, and can provide info here if anyone wants it. I just don't recall off the top of my head how it's done.

@jeffwright13 @BeyondEvil

Thanks for pointing out the difference between live log and captured log.

From this link it seems to me pytest will automatically add a log handler which is passed to the pytest-html according to @BeyondEvil. This logger format can be set in the pytest.ini or pyproject.toml. And I believe this log handler emit to the sys.stdout by default.

The following is my setup in pyproject.toml. which finally get the print in console and html identical.
[tool.pytest.ini_options]
log_level = "INFO"
log_format = "%(asctime)s [%(levelname)8s] %(message)s (%(filename)s:%(lineno)s)"
log_date_format = "%Y-%m-%d %H:%M:%S"
log_cli = true

Notice that from above setting, I only need to set log_cli to true to turn on the live log. because the default pyest sys.stdout logger already been formatted previously.

And then in the test code, just get a logger from the module without any formatting needed.
mylogger= logging.getLogger(__ name __)

The following is the result
2023-11-09_104044

@BeyondEvil
Copy link
Contributor

I'm going to close this now. Please feel free to reopen if there's still an issue.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

7 participants