filter_record_tuples() implementation

[TBeijen]

I find myself often using the following construct when asserting if a certain log message has been recorded:

import logging

def test_things(caplog):
    # things
    assert list(filter(lambda r: r[0] == 'my.module' and r[1] == logging.WARNING, caplog.record_tuples))

Some of the drawbacks:

• Lot of repetition of constructs not part of the test, e.g. the need to wrap the filter result in list to be able to assert the length
• Need to import logging merely to obtain the log level

I propose an extension to caplog that looks like this:

def test_things(caplog):
    # things
    assert caplog.filter_record_tuples('my.module', caplog.WARNING)

Please let me know your thoughts. Do I need to create an issue for this proposal?

Edit:

• Changed caplogs.levels.WARNING into caplog.WARNING
• Removed references to deprecated 'WARN' (Will not include it in levels exposed)
• Removed 'Work in Progress' from PR

[abusalimov]

ise specially - a typo?

[abusalimov]

@TBeijen Thanks for submitting this and happy New Year! 🎄

I like the idea in general, and I though about adding somewhat similar too. And if we finally agree on introducing this, I would also suggest to add a caplog.filter_records() method too, to be consistent with the caplog.records and caplog.record_tuples properties.

[TBeijen]

@abusalimov Happy NY too!

Thanks for the swift reply. Implementing caplog.filter_records() had crossed my mind also. I doubted a bit as caplog.record_tuples seems intended for use in test asserts and wasn't sure of typical use cases of caplog.records. Will add.

On a sidenote: I'm now removing the .levels part so it will be caplog.WARNING etc.. The levels part didn't seem to add much and logging has it levels exposed as direct attributes also so this might be more intuitive.

[TBeijen]

Done. See Readme change for features implemented.

I've disabled travis builds on pypy3, see (travis-ci/travis-ci#6277 (comment))

I must say that after all I'm not so sure of the need to add filter_records as well. I couldn't come up with a use case where it would have any advantages over filter_record_tuples so I'd rather remove it (keeping things simple, YAGNI).

[abusalimov]

Is it caplog.levels.INFO or just caplog.INFO after all?

[TBeijen]

Overlooked that. :/ It's caplog.INFO. Fixed now.

[abusalimov]

Although this is pretty straightforward and simple to understand, I'm not quite sure that hard-coding the exact levels is the best choice here. Users may define their own log levels, and AFAIR the logging module explicitly allows that (please correct me if I'm wrong).

What about dispatching every UPPER-case property access to the logging module? Something like this:

    __getattr__(self, name):
        if name == name.upper():
            return getattr(logging, name)
        return getattr(super(...), name)

[TBeijen]

Good to consider custom log levels. I did some digging (and by that learning). The logging module indeed allows registering log levels via logging.addLevelName(lvl, name, but... levels are registered in a 'protected' dict and not exposed as attributes. A level is just an integer and the purpose of registering of levels by label is only to have that label appear in log records.

There is a logging.getLevelName(lvl) method but not a getAllLevels().

Commands below summarize how custom levels work. Note that in python3 there's no _levelNames but instead there are _levelToName and _nameToLevel.

>>> import sys
>>> sys.version_info
sys.version_info(major=2, minor=7, micro=12, releaselevel='final', serial=0)
>>> import logging
>>> logging.basicConfig(format='%(levelname)s:%(message)s')
>>> logging.addLevelName(45, 'custom')
>>> logging.getLevelName(45)
'custom'
>>> logging.log(30, 'message')
WARNING:message
>>> logging.log(45, 'message')
custom:message
>>> logging.log(46, 'message')
Level 46:message
>>> logging.WARNING
30
>>> logging.custom
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
AttributeError: 'module' object has no attribute 'custom'
>>> logging._levelNames
{0: 'NOTSET', 10: 'DEBUG', 'WARN': 30, 20: 'INFO', 'ERROR': 40, 'DEBUG': 10, 30: 'WARNING', 'INFO': 20, 'WARNING': 30, 40: 'ERROR', 45: 'custom', 'custom': 45, 50: 'CRITICAL', 'CRITICAL': 50, 'NOTSET': 0}

Based on this I'd say facilitating custom levels is far-fetched. As levels are merely numbers I'll add a test for a custom numeric level.

Leaves the actual implementation. On a first glance it indeed doesn't look like very good practice to list these levels, on the other hand, it is very explicit and the levels aren't really subject to change.

@abusalimov Let me know if you still want the implementation changed. My opinion is that changing it doesn't improve, but it's not my project. ;)

Reference:

• https://docs.python.org/2/library/logging.html#logging.addLevelName
• https://docs.python.org/2/howto/logging.html#custom-levels

[abusalimov]

@TBeijen Sure, I see. But still, what do you think about the proposed solution?

    def __getattr__(self, name):
        if name == name.upper():
            return getattr(logging, name)
        return getattr(super(...), name)

It seems to solve the issue in question in a generic way, without the need to know any of existing levels.

[TBeijen]

Generic of course is also a good thing...
See update, slightly different check but otherwise the same as your proposal.

[TBeijen]

I notice it's still marked as 'changes requested'. I think 385c440 fixes that. Anything I can do to move this PR forward?

[abusalimov]

@TBeijen Please notice my comments above/ Sorry, they have been left pending for all these months. =\

[abusalimov]

IIUC, there should be super(...) in place on self, otherwise we end up with infinite recursion, don't we? Please correct me if I'm wrong.

[abusalimov]

My concern is still there. caplog.unknown_attr -> infinite recursion.

[abusalimov]

What is the isalpha() check for?

[abusalimov]

Please, also add a check for lower case attributes.
Plus: 'LEVEL_WITH_UNDERSCORES', LEVEL42
Thanks

[TBeijen]

N/p that it takes some time, life can be busy.

Recursion was indeed not handled well. Fixed implementation and added a attribute lookup that will not be retrieved from logging module. (Sorry for polluting the history, should have run tox locally. Python 2.6 coding has been ages ago)

The combination of .isalpha() and .isupper() basically allows access to all log levels, but not to other attributes that don't fall into that pattern, like ._STYLES or .BASIC_FORMAT.

Custom loglevels, added for example via logging.setLevelName(13, 'custom'), are stored in logging._levelNames (python2) or logging._nameToLevel and logging._levelToName (python3).

The logging module itself uses .getLevelName() as described here to get a textual representation for a level. Illustrated by doing logging.getLevelName(123456) which returns Level 123456.

I would not go down the rabbit hole of looking up custom log levels. It's discouraged by python and adds complexity. If people insist on custom log levels they can always import logging itself in the tests.

Looking back at previous commits I actually think the explicit list of levels was better (because: explicit) than the isalpha(), isupper() combo (or lvl == lvl.upper() for that matter). Those levels haven't changed ever and are based on good practices.