Scutils log callbacks

[joequery]

This PR provides a starting point for registering callbacks using the LogFactory. This PR addresses Issue #91

Usage

Given a logging object logger, you can register a callback via

logger.register_callback(log_level, callback_function, optional_criteria_dict)

Some examples:

logger.register_callback('ERROR', report)

Explanation: The callback function report will fire when the .error() logging method is called

logger.register_callback('<=INFO', add_1, {'key': 'val1'})

Explanation: The callback function add_1 will fire when .debug() or .info() are called AND the {'key': 'val1'} is a subdict of the extras` passed to the logging functions

logger.register_callback('>INFO', negate, {'key': 'val2'})

Explanation: The callback function negate will fire when .warning(), .error(), or .critical() are called AND {'key': 'val2'} is a subdict of extras passed to the logging functions.

logger.register_callback('*', always_fire)

Explanation: The callback function always_fire will fire for all log levels with no concern of the extras dict passed to the logging functions.

Testing

$ python -m unittest tests.test_log_factory

Notes

The callbacks respect the log level. If the log level for a logger is CRITICAL then a .debug() invocation will not trigger the callbacks registered for CRITICAL.

[madisonb]

First off, this idea is great and I would like to incorporate this in. There are a handful of minor things we need to address before we can merge this in.

Comments as follows:

1) With new features to the log factory we need to add the corresponding documentation to this file. An explanation similar to the PR above, with a bit more detail on how someone can use it is essential here.

2) The log factory is a singleton, and we shouldn't instantiate LogObjects directly (like is done in the unit test via self.logger = LogObject()). This is a minor change in code, but keeps with the design paradigm for multithreaded solutions

3) I find it interesting that these changes cause the SettingsWrapper tests to fail - more investigation into this is needed. The latest build (at time of writing on the dev branch here passed.

4) The tests should be ran with Nose, not python -m unittest tests.test_log_factory. There are instructions here for how to run the unit tests for this project

5) Given that this is designed for Scrapy Cluster, I would like to know how registering callbacks works within the Scrapy environment. Can I register a callback within the item pipeline that a spider can use? Can the spider use a callback that a scheduler registered? That creates some interesting ideas but reducing the amount of copy/paste for callbacks is important here. More testing with multiple log factory objects in a multithreaded environment is useful here, either in practice or in the unit tests themselves.

Going to look into point 3 a bit more, as I can replicate it on only 1 of my local machines, but not the other.

EDIT: Later commits to this branch have addressed all issues raised here.

[madisonb]

In continuing to investigate, point 2 I think is irrelevant, as I instantiate LogObjects() in the test as well.

[coveralls]

Coverage increased (+0.6%) to 67.216% when pulling bbdce44 on scutils_callbacks into 1506001 on dev.

[coveralls]

Coverage increased (+0.6%) to 67.216% when pulling bbdce44 on scutils_callbacks into 1506001 on dev.

[madisonb]

Latest commit fixes points 3 and 4, just need to add documentation and test how this works within Scrapy.

[madisonb]

For point 5, the behavior is as follows:

We will not have access to class instance variables, but the callback is available across the multithreaded/twisted process. What this means is that you can register your callback in one location, and it allows the scrapy item pipeline, scheduler, spider, etc to use/trigger the callback. In this case, you must decorate your method with @staticmethod or declare it outside (but within the same .py file) of the class where you register the callback. Regardless, this is a cool feature that should be explored in the future.

The callback functionality works as expected using the get_instance() method and using multiple logfactory calls, but I would like to remove the log_object from the function parameters and instead only use the message and extras which are standard.

# note the log object missing
def always_fire(log_message=None, log_extra=None):
    print("Here", log_message, log_extra)

I will try to see if I can refactor some of the tests to remove that log_object dependency in the callback method, but on track to be merged in.

[coveralls]

Coverage increased (+0.6%) to 67.216% when pulling fcfef5f on scutils_callbacks into 1506001 on dev.

[coveralls]

Coverage increased (+0.6%) to 67.216% when pulling 4b478e6 on scutils_callbacks into 1506001 on dev.

[coveralls]

Coverage increased (+0.6%) to 67.216% when pulling 4b478e6 on scutils_callbacks into 1506001 on dev.

[coveralls]

Coverage increased (+0.6%) to 67.216% when pulling 33e3767 on scutils_callbacks into 1506001 on dev.

[coveralls]

Coverage increased (+0.6%) to 67.216% when pulling 33e3767 on scutils_callbacks into 1506001 on dev.

[madisonb]

Latest commit address Point 1. Looks good on all fronts.