Skip to content

Fix stage caplog records not clear #10051

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.

Sign up for GitHub

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

Merged
merged 4 commits into from
Jul 8, 2022
Merged

Fix stage caplog records not clear #10051

Show file tree
Hide file tree
Changes from 3 commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
c7e784f
Fix stage caplog records not clear
Jun 15, 2022
f29f79e
Use records.clear() in LogCaptureHandler when caplog.clear()
Jun 24, 2022
aa83fa3
Update changelog/9877.bugfix.rst
EmptyRabbit Jul 7, 2022
8726597
Update changelog/9877.bugfix.rst
nicoddemus Jul 7, 2022
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions AUTHORS
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -363,5 +363,6 @@ Yuval Shimon
Zac Hatfield-Dodds
Zachary Kneupper
Zachary OBrien
Zhouxin Qiu
Zoltán Máté
Zsolt Cserna
1 change: 1 addition & 0 deletions changelog/9877.bugfix.rst
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1 @@
ensure ``caplog.get_records(when)`` returns current/correct data after invoking ``caplog.clear()``
7 changes: 5 additions & 2 deletions src/_pytest/logging.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -40,7 +40,6 @@
else:
logging_StreamHandler = logging.StreamHandler


DEFAULT_LOG_FORMAT = "%(levelname)-8s %(name)s:%(filename)s:%(lineno)d %(message)s"
DEFAULT_LOG_DATE_FORMAT = "%H:%M:%S"
_ANSI_ESCAPE_SEQ = re.compile(r"\x1b\[[\d;]+m")
Expand Down Expand Up @@ -345,6 +344,10 @@ def reset(self) -> None:
self.records = []
self.stream = StringIO()

def clear(self) -> None:
self.records.clear()
Copy link
Member

@RonnyPfannschmidt RonnyPfannschmidt Jun 28, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

without moving the cleared items to a storage we cannot perceed

Copy link
Contributor Author

@EmptyRabbit EmptyRabbit Jun 28, 2022 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

do you mean cleared items some place is useful?

Copy link
Member

@RonnyPfannschmidt RonnyPfannschmidt Jun 28, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Basically clear removes all data, afterwards it's done, even from pytest internal store

Copy link
Contributor Author

@EmptyRabbit EmptyRabbit Jun 29, 2022 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

yes, caplog data will be discarded when clear, but another caplog_handler seems like storage all log records captured on stage

    def _runtest_for(self, item: nodes.Item, when: str) -> Generator[None, None, None]:
        """Implement the internals of the pytest_runtest_xxx() hooks."""
        with catching_logs(
            self.caplog_handler,
            level=self.log_level,
        ) as caplog_handler, catching_logs(
            self.report_handler,
            level=self.log_level,
        ) as report_handler:
            caplog_handler.reset()
            report_handler.reset()
            item.stash[caplog_records_key][when] = caplog_handler.records
            item.stash[caplog_handler_key] = caplog_handler

            yield

            log = report_handler.stream.getvalue().strip()
            item.add_report_section(when, "log", log)

Copy link
Contributor Author

@EmptyRabbit EmptyRabbit Jul 1, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is there a hidden problem if not keep any cleared items in caplog object? I will keep learning the pytest frame to be familiar with the code logic！

self.stream = StringIO()
Copy link
Member

@RonnyPfannschmidt RonnyPfannschmidt Jun 28, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

do we actually use the streams, and if yes, how do we reconcile their usage

Copy link
Contributor Author

@EmptyRabbit EmptyRabbit Jun 28, 2022 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

caplog.text use stream to show content , and another handler is updated to "Captured log call" sections after stage finished. Since stream is not storage in item.stash, so I think it not a must unique.

Thank you for sharing your thoughtful idea, learning a lot


def handleError(self, record: logging.LogRecord) -> None:
if logging.raiseExceptions:
# Fail the test if the log message is bad (emit failed).
Expand Down Expand Up @@ -440,7 +443,7 @@ def messages(self) -> List[str]:

def clear(self) -> None:
"""Reset the list of log records and the captured log text."""
self.handler.reset()
self.handler.clear()

def set_level(self, level: Union[int, str], logger: Optional[str] = None) -> None:
"""Set the level of a logger for the duration of a test.
Expand Down
18 changes: 18 additions & 0 deletions testing/logging/test_fixture.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -172,6 +172,24 @@ def test_caplog_captures_for_all_stages(caplog, logging_during_setup_and_teardow
assert set(caplog._item.stash[caplog_records_key]) == {"setup", "call"}


def test_clear_for_call_stage(caplog, logging_during_setup_and_teardown):
logger.info("a_call_log")
assert [x.message for x in caplog.get_records("call")] == ["a_call_log"]
assert [x.message for x in caplog.get_records("setup")] == ["a_setup_log"]
assert set(caplog._item.stash[caplog_records_key]) == {"setup", "call"}

caplog.clear()

assert caplog.get_records("call") == []
Copy link
Member

@RonnyPfannschmidt RonnyPfannschmidt Jun 28, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

i believe we need a distinction between current records and all records

Copy link
Contributor Author

@EmptyRabbit EmptyRabbit Jun 28, 2022 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

if want all records, should call caplog.get_records("setup"/"call"/"teardown") three times.....

Copy link
Member

@RonnyPfannschmidt RonnyPfannschmidt Jul 1, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@EmptyRabbit what i meant is, that right now we throw records from call away on clear, those wont return

Copy link
Contributor Author

@EmptyRabbit EmptyRabbit Jul 5, 2022 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@RonnyPfannschmidt but those wont return records is useless for user, they hope to clear

when call caplog.get_records('setup') on call stage, it should be the same as get caplog.records on setup stage

if use self.records=[], will have bug like this:

def test_caplog_clear(caplog):
    logging.error('captured one log')
    assert caplog.messages == ['captured one log']
    assert [x.getMessage() for x in caplog.get_records('call')] == ['captured one log']

    caplog.clear()

    logging.error('captured two log')
    assert caplog.messages == ['captured two log']
    assert [x.getMessage() for x in caplog.get_records('call')] == ['captured two log']
    # ['captured one log'] != ['captured two log'], second log not be collected to item.stash

if we need keep all handler cleared records, it seems like a new feature.

Copy link
Member

@RonnyPfannschmidt RonnyPfannschmidt Jul 5, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ok, as im looking at this now again, it seems that i messed up

i missed the relation between the caplog handler and the report handler

so the thing i thought was missing, was in reality supported by the other handler

as such i beleive my concern does no longer stand and the new feature is a followup idea

Copy link
Contributor Author

@EmptyRabbit EmptyRabbit Jul 5, 2022 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

approved，Exciting！

find wrong people mentioned to at last comment , updated. sorry..

assert [x.message for x in caplog.get_records("setup")] == ["a_setup_log"]
assert set(caplog._item.stash[caplog_records_key]) == {"setup", "call"}

logging.info("a_call_log_after_clear")
assert [x.message for x in caplog.get_records("call")] == ["a_call_log_after_clear"]
assert [x.message for x in caplog.get_records("setup")] == ["a_setup_log"]
assert set(caplog._item.stash[caplog_records_key]) == {"setup", "call"}


def test_ini_controls_global_log_level(pytester: Pytester) -> None:
pytester.makepyfile(
"""
Expand Down