Capture logs also from setup and teardown stages #7
Conversation
|
It's a bit late at my home now, I'll try to fix test failures later this week. |
abusalimov
force-pushed
the
catch-all
branch
from
3928caf
to
5ca95c5
Compare
|
I reviewed your work so far and I really like what you did so far! It also appears that merging this change set will also fix #3 since you dropped the code that relied on the deprecated
Yep, it looks like this is caused by https://github.com/pytest-dev/pytest/blob/2093889ac2f346c232ca86540a9802de58cb6f5b/_pytest/runner.py#L229. I would say that this wart shouldn't prevent me from merging and releasing it though. I would say it's their problem and their responsibility to fix it.
It looks to me that the merge request also contains larger changes to the API of this plugin. I would say that this API change alone justifies a 2.0 release. So while we are at it we can also pull up the requirements for the dependencies in a new major version. It appears to me that the Merge Request still lacks a few tests though regarding the original purpose of the request: Capturing logs from setup and tear down stages. It would be nice to have this functionality covered by tests. Please tell me what you think about it. Thanks! |
|
Hi, Thanks for reviewing and sorry for lots for "fixup" and "wip" commits, the I'm on vacation at the moment, so I'm not able to finish the work right
Yep, it also lacks proper documentation for new features like capturing Please do not merge until I fix that. I'll let you know, when everything Regards, |
| logger. | ||
| def __init__(self, handler): | ||
| # Do not call LineMatcher.__init__(), | ||
| # it attempts to assign to self.lines, which is a property. |
There was a problem hiding this comment.
I wonder if inheriting from LineMatcher is a good idea in general - it might change in future pytest versions in ways which might break this - why not just copy fnmatch_lines from there and remove the magic we don't need here (like _getlines)?
There was a problem hiding this comment.
I think it depends on whenever LineMatcher has been declared as public API whenever it should be reused or not. Duplicating code is something I'm not very fond of. And since it actually has been documented I would say it's okaish unless you still would say it's still a big no. Your words have more weight compared to mine in this field since you're the one with more experience in py.test development.
There was a problem hiding this comment.
Good point - I didn't notice it was actually documented. I still think it's probably intended for internal pytest use and the documentation is intended for hooks returning a LineMatcher - but hey, what can possibly go wrong.
On a second thought, I'd say let's keep this and see if it breaks - which, after all, is unlikely.
There was a problem hiding this comment.
My thought on reusing LineMatcher:
Pros.
- It is (widely?) used by plugins for self-testing (catchlog itself, for example); the API is unlikely to change
- Even if the API changes, that won't affect the main functionality provided by catchlog
- The logic provided by
LineMatcheris somewhat hardly related to catchlog to copy-paste the code - Reusing code is generally a better option
Cons.
- The code of
LineMatcheris a bit dirty, IMO; the API could be more friendly for subclasses - It is a dependency, yet not explicit
My opinion: it would be cool to have line matching feature in the core capturing module of pytest (not pytester), i.e. to be able to make assertions about captured stdout/stderr as well.
Let's throw away this feature for now (at least from this PR), and try to think about that in more wide context: (maybe?) move LineMatcher from pytester to the capture plugin, realize what we want to have there, provide backward compatibility, etc.
Anyway, this again is a pytest issue / feature request. But once we have that feature for capsys, there would be no doubts to provide the same API for caplog.
|
I submitted a PR for pytest to remove the hardcoded |
Very nice! Thanks for the fix. This will make it more appealing from an aesthetic point of view. |
This change may be arguable, however there're no reasons to use
'unicode_literals' is this particular module, esp. since core pytest
also does not use it.
Moreover using 'unicode_literals' in Python 2 restricts usage of some
functions of the standard library that expect _native_ strings (i.e.
non-unicode in case of Python 2).
More on this:
http://python-future.org/unicode_literals.html
|
The pytest PR will probably be moved to the I tried this branch with my project, and with some adjustments to my logfail.py which fails tests on logging messages if I definitely prefer the newer api ( I don't think it'll take much - |
|
|
||
| This only affects logs collected by this funcarg. To control | ||
| captured logs that are reported for failed tests use the | ||
| ``logging_at_level()`` context manager. |
There was a problem hiding this comment.
What's the rationale for dropping the logger/handler argument? Just a cleaner API?
There was a problem hiding this comment.
That's mainly because there're separate handler instances used for reporting and inspection now. And naively changing a level of a logger through a at_level call on some recorder would affect all attached handlers, i.e. other recorders. This looks wrong to me, despite there used to be the same behavior before.
Honestly, I don't know what to do about that. It is possible to use a separate recorder for a certain foo.bar logger on some level, and even adjust the level in the middle of recording:
with caplog.recording(logging.INFO, logger='foo.bar') as rec1, \
caplog.recording(logging.INFO, logger='some.other.module') as rec2:
# Capture INFO and above.
...
with rec1.at_level(logging.WARNING):
# Capture only WARNING and below.
# This doesn't affect a level of rec2 though.
...
But there's no way to change a level on, say, foo.bar.baz logger, except for caplog.logging_at_level(), which changes the level of the logger itself, affecting other recorders, including log reporting on failure.
I'll think about that. May be we could use log Filters for that purpose. I'd like to preserve backward compatibility after all.
That comes from my WIP commit, so that's definitely not a final solution. Thank's for the good point anyway. Like as you suggested, I plan to subclass the
Not a problem too.
Looks nice! I was thinking about such feature, i.e. add a It seems that things are bit more complicated than I thought. And I've just discovered that there is a discussions on this topic in #1. |
Note subclassing import collections
class CallableList(collections.MutableSequence):
def __getitem__(self, key):
return self._data[key]
def __setitem__(self, key, val):
self._data[key] = val
def __delitem__(self, key):
del self._data[key]
def __len__(self):
return len(self._data)
def insert(self, index, obj):
self._data.insert(index, obj)
def __call__(self):
return self._datathere's also a more complete version as class UserList(MutableSequence):
"""A more or less complete user-defined wrapper around list objects."""
def __init__(self, initlist=None):
self.data = []
if initlist is not None:
# XXX should this accept an arbitrary sequence?
if type(initlist) == type(self.data):
self.data[:] = initlist
elif isinstance(initlist, UserList):
self.data[:] = initlist.data[:]
else:
self.data = list(initlist)
def __repr__(self): return repr(self.data)
def __lt__(self, other): return self.data < self.__cast(other)
def __le__(self, other): return self.data <= self.__cast(other)
def __eq__(self, other): return self.data == self.__cast(other)
def __ne__(self, other): return self.data != self.__cast(other)
def __gt__(self, other): return self.data > self.__cast(other)
def __ge__(self, other): return self.data >= self.__cast(other)
def __cast(self, other):
return other.data if isinstance(other, UserList) else other
def __contains__(self, item): return item in self.data
def __len__(self): return len(self.data)
def __getitem__(self, i): return self.data[i]
def __setitem__(self, i, item): self.data[i] = item
def __delitem__(self, i): del self.data[i]
def __add__(self, other):
if isinstance(other, UserList):
return self.__class__(self.data + other.data)
elif isinstance(other, type(self.data)):
return self.__class__(self.data + other)
return self.__class__(self.data + list(other))
def __radd__(self, other):
if isinstance(other, UserList):
return self.__class__(other.data + self.data)
elif isinstance(other, type(self.data)):
return self.__class__(other + self.data)
return self.__class__(list(other) + self.data)
def __iadd__(self, other):
if isinstance(other, UserList):
self.data += other.data
elif isinstance(other, type(self.data)):
self.data += other
else:
self.data += list(other)
return self
def __mul__(self, n):
return self.__class__(self.data*n)
__rmul__ = __mul__
def __imul__(self, n):
self.data *= n
return self
def append(self, item): self.data.append(item)
def insert(self, i, item): self.data.insert(i, item)
def pop(self, i=-1): return self.data.pop(i)
def remove(self, item): self.data.remove(item)
def clear(self): self.data.clear()
def copy(self): return self.__class__(self)
def count(self, item): return self.data.count(item)
def index(self, item, *args): return self.data.index(item, *args)
def reverse(self): self.data.reverse()
def sort(self, *args, **kwds): self.data.sort(*args, **kwds)
def extend(self, other):
if isinstance(other, UserList):
self.data.extend(other.data)
else:
self.data.extend(other)
I'd be glad if something like this was built into
I have lots of tests which call functions in a "wrong" way, which causes them for example to log errors. In this case, I don't want to fail a test. As these tests already use |
|
Another possibility for backwards compatibility would be to have a |
|
I would rather suggest/prefer to solve this problem by simply adhering to semver and going straight to a 2.0 version with this feature and explicitly state the API break. |
|
@eisensheng I believe it's worth trying to preserve backward compatibility, at least for some time. @The-Compiler had a good point on this:
It is easier to pull down than to build, after all. |
That's also fine by me. I appreciate your enthusiasm. 👍 |
|
@eisensheng @The-Compiler Hey guys, I force-pushed the branch leaving out any changes besides the topic (including API-breaking changes) and reorganizing the changeset a little bit. Please, review! 🏁 |
Take advantage of `@pytest.mark.hookwrapper` facility and use more
idiomatic pytest_runtest_call(item) hook for performing capturing (in
fact, the same is used by the core 'pytest.capture' module).
Instead of messing around `report.longrepr` internals and since we
don't have a `report` instance at the moment of executing
pytest_runtest_call() anyway (it used to be created within a more late
pytest_runtest_makereport() hook), use a higher-level
item.add_report_section() method to attach log output to a report.
However, there is a drawback that now reports show sections named like
'Captured stdlog ...' ('std' is hardcoded). This is an issue of the
pytest itself addressed in pytest-dev/pytest#1052. That PR also
contains a discussion on deprecating Item.add_report_section(),
however the same approach is still used by 'pytest.capture', so it
should be fine to use it here as well.
This change also removes the use of the deprecated '__multicall__', so
that fixes eisensheng#3.
| @@ -87,7 +87,7 @@ Inside tests it is possible to change the log level for the captured | |||
| log messages. This is supported by the ``caplog`` funcarg:: | |||
|
|
|||
| def test_foo(caplog): | |||
| caplog.setLevel(logging.INFO) | |||
| caplog.set_level(logging.INFO) | |||
There was a problem hiding this comment.
Those documentation changes seem wrong as the API is still the old one.
|
LGTM apart from the comment above. 😄 |
|
Dammit, I reviewed the Pull Request on a per commit base and now the comments aren't visible from here. I am still somewhat inexperienced with github from this point of view after all. Sorry! I hope the code review wasn't too destructive, I still like the over all code quality in terms of readability, semantics and how everything is well documented. |
|
@eisensheng your comments are actually visible here, just not with context - but that's available when clicking on the commit id. I agree with the |
Also reuse logging_at_level() context manager replacing CatchLogLevel used by caplog.at_level(). This doesn't introduce any change in logic.
Just define three almost identical hooks for that:
pytest_runtest_setup(item)
pytest_runtest_call(item)
pytest_runtest_teardown(item)
Also add tests for that.
abusalimov
force-pushed
the
catch-all
branch
3 times, most recently
from
3bd6576
to
61274e0
Compare
|
Hi guys, I've fixed most of the review comments (hackish hooks and PEP8 blank lines). However, I have a problem with running tests on Python 3.5. Please see builds 19 (904b138) and 20 (83eb180). The symptoms are quite similar to these described in pytest-dev/pytest#1008, because Travis uses pytest-2.8.0 for Python 3.5 and pytest-2.6.4 for the rest. The problem is reproduced irrespective to using tox or invoking py.test directly. @The-Compiler could you help me, please? Honestly, I'm a bit stuck. |
|
@The-Compiler I've just discovered, that replacing diff --git a/test_pytest_catchlog.py b/test_pytest_catchlog.py
index d5b7cfd..d406c45 100644
--- a/test_pytest_catchlog.py
+++ b/test_pytest_catchlog.py
@@ -1,6 +1,6 @@
import py
-pytest_plugins = 'pytester', 'catchlog'
+pytest_plugins = 'pytester', 'pytest_catchlog'
def test_nothing_logged(testdir):
@@ -8,7 +8,7 @@ def test_nothing_logged(testdir):
import sys
import logging
- pytest_plugins = 'catchlog'
+ pytest_plugins = 'pytest_catchlog'
def test_foo():
sys.stdout.write('text going to stdout')But this makes older version to fail with the following error: Shouldn't this be considered as a pytest-core regression? |
|
Interesting... it looks to me like something about passing plugins to subprocesses run via The thing is: |
|
Thanks for the pointer @The-Compiler, I will take a look when I have some spare time.
I agree, you shouldn't need to add |
|
@The-Compiler @nicoddemus thank you, guys! Everything seems to be fine now. |
What's the benefit of that? |
A good reason to use tox is that it also allows to test the installation process of the given package. While this plugin is not a huge process and there aren't many things that can go wrong I still would say that we can benefit from this feature set. But since this project is that small I guess it can be overlooked since there isn't much that can go wrong during installation so it comes close to YAGNI. So I'm kind of so-so on this topic since both arguments are balanced in my head. Either way is fine with me. |
|
@The-Compiler Well, mostly a matter of personal preferences. tox is good for testing against multiple Python versions at once during the development, but Travis already provides properly initialized isolated venvs for that. Running tox inside Travis creates a new (unnecessary) venv plus clutters the log output. I know that having a single point for defining test command is a good thing, but, come on, this is just a single
@eisensheng IMO this is a good reason to not use tox in favor of the explicit |
| @@ -139,10 +180,13 @@ def emit(self, record): | |||
| class CatchLogFuncArg(object): | |||
There was a problem hiding this comment.
"FuncArg" is basically the old concept of fixtures - see reasoning for fixture/funcarg evolution - so I don't think this should be called funcarg anymore now that we use fixtures instead of pytest_funcarg__capturelog (also see the docstring of __init__).
There was a problem hiding this comment.
@The-Compiler Thanks. I thought that "funcarg" and "fixtures" are roughly synonymous, the one just being a modern alternative to the other.
How do I call this class? CatchLogFixture / CatchLog / Caplog / CaplogObject?
/cc @eisensheng
There was a problem hiding this comment.
I'd just call it CatchLog or maybe LogCatcher. Though pytest calls the object behind the capsys/capfd fixtures CaptureFixture, so CatchLogFixture or LogCaptureFixture would certainly work as well.
There was a problem hiding this comment.
I decided to pick LogCaptureFixture since the word catch sounds a bit weird for me.
|
Looks good to me apart from the nitpick I commented on. You convinced me about the tox thing, it's probably easier for such a simple project (in terms of installing it and running tests) indeed. |
.. and CatchLogHandler -> LogCaptureHandler
|
@eisensheng Is something still holding this back, or did you just not get to merging this yet? Would be nice to (finally) have this in and move on 😉 |
|
Sorry for the late response, I stay until late at the office during the week so I only have time during the weekend for private projects. I'll look over it again after I was able to catch some sleep and merge it right away. 😉 As far as I can remember everything should be fine now though. |
Capture logs also from setup and teardown stages
Now for failing tests that log anything during setup/teardown, the corresponding output is reported in separate sections.
Example:
Issues and drawbacks:
Outputs weird Captured stdlog ... captions - should be better fixed it pytest, I think(UPD: addressed in Don't hardcode 'std' for captured stdout/stderr. pytest-dev/pytest#1052)Please let me know if you believe these issues must be addressed before merging.