log observer bridging to python logging facility

[ctheune]

This one isn't too fancy because it is for embedding into Zope 3. This you might
want to change:
- use a different logger system for each message depending on the dict.
- use a different logging level depending on whether the message is a failure or
not
...

[exarkun]

I'm not sure why this should be added to Twisted?  Python's logging system is
potentially blocking.  Using this could block an entire Twisted application any
time a message is logged.

[ctheune]

Hmm. Interesting. itamar wanted me to post that bridge because he liked the idea.
Obviously I totally forgot about blocking ...

[therve]

Ready to review in logging-bridge-1351.

[dreid]

• _safeFormat doesn't have a docstring. Yes it's private, but it might be useful to implementors of other observers and the docstring should explain what it's for and how to use it.
• LoggingObserver? isn't a very descriptive class name, PythonLoggingObserver? would probably be better.
• There is an opportunity in emit to use the eventDict to support more logging levels than just INFO and ERROR. Perhaps a logLevel key in the eventDict could be used to set the log level, and use self.logger.log(level, msg) to send the message)

Good docstrings, and good test cases. I'm all for making twisted's logging more flexible and giving people the option of using the logging module is a great start.

[therve]

Thanks for your review. Indeed adding log level seems fine. I changed the name to PythonLoggingObserver? and add the docstring.

[dreid]

_safeFormat's second argument "crap" isn't very descriptive. perhaps fmtDict would be better?

It feels like textFromEventDict is a tool for authors of log observers, so maybe we should document the keys that it expects in eventDict.

Otherwise this looks good to merge.

[therve]

Thanks, I ended up writing too much English for pushing it further, so I put it back for review.

[dreid]

Try to format the string C{fmtString} using C{fmtDict} arguments,
swallowing every errors to always return a string.

Should be all errors, or every error.

- C{isError}: boolean indication the nature of the event. Required if
    message is empty.

I think you mean indicating. Also isError isn't actually required if message is empty because format will be used if present.

Perhaps this should be moved to the docs for message with something along these lines.

- C{message}: by default, it holds the final text. It's required, but can
    be empty if either C{isError} or C{format} is provided.

- C{format}: string format used in place of C{message} to customize
    the event. It uses every other present keys of C{eventDict} to format
    the text.

Perhaps "It uses all keys present in C{eventDict} to format the text."? And the incompatibility between isError and format could be cleared up elsewhere?

[therve]

Thanks a lot for the corrections!

[dreid]

+    There's a way we could make this if not safer at least more
+    informative: perhaps some sort of str/repr wrapper objects
+    could be wrapped around the things inside of C{fmtDict}. That way
+    if the event dict contains an object with a bad __repr__, we
+    can only cry about that individual object instead of the
+    entire event dict.

I'm not sure this is relevant to the docstring. It's discussing a possible implementation change instead of anything about it's usage. Other than that, this looks ready to merge. Keep up the good work.

[therve]

(In [19696]) Merge logging-bridge-1351

Author: therve, ctheune Reviewer: dreid Fixes #1351

Add a log observer bridging to python logging module. It allows better integration for people who already use logging but want to use twisted log methods. In the process some methods have been extracted from FileLogObserver? to be easier to use by other observers.

[therve]

(In [19697]) Revert [19696], test regression with web2. Refs #1351.

[therve]

There was a problem with textFromEventDict when it returns None. I think it should be an error as it fails silently. What about adding a deprecation warning here ?

[itamarst]

Documentation should be added somewhere to the log howto.

And, I hate to say this... do we want to consider twistd integration?

[exarkun]

We do want to consider twistd integration, but that shouldn't be done in a way which is specific to this code, so I think it's beyond the scope of this ticket.

Do we have a ticket for general logging configuration yet?

[therve]

I write the documentation if you review it.

For twistd integration, it seems in scope of #638.

[therve]

I've done a basic introduction in the howto. That's my first lore document so please be indulgent :).

Also, I had no answer regarding textFromEventDict returning None: I really think that's a broken behaviour.

[exarkun]

The howto docs should include a warning about blocking behavior. Also, startLoggingWithObserver isn't really the preferred interface to the logging system. PythonLoggingObserver has those nice start and stop methods. Perhaps we should suggest that people use them? :) Oh, which brings up this point: PythonLoggingObserver.start and PythonLoggingObserver.stop have no test coverage. :)

I also expect PythonLoggingObserver should be new-style. I'm uncertain what the testing implementations of this statement are, though (should there be tests which fail if it is classic? should they rely on new-style behavior or should they use isinstance? etc)

[therve]

I've update the docs and the tests.

I actually tested the new-style behavior using super(). I don't know if it's so great, but that seems like a primary need to me. Of course I could do a stupid issubclass call instead.

[glyph]

• PythonLoggingObserver's docstrings have some problems.
  • It should be more specific. "Python logging module" should be "the Python standard library L{logging} module", so that it's clear we are referring specifically to that one and not to an arbitrary logging module you might like to use. (I would suggest a name change too, except that would imply a ridiculous name, like PythonStandardLibraryLoggingModuleObserver or something like that, so never mind...)
  • "so be sure to not use this, or assume." - that seems to be ending in the middle of a sentence. It should also stress that code within Twisted, such as twisted.web, assumes that the logging module does not block, except perhaps on local disk access.
  • the epydoc formatting in 'emit' is messed up. The the line before the code sample should end with "::" and the prefixing the lines with "|" is no longer necessary; that recommendation should be deleted from the coding standard, sorry. It was based on an epydoc bug that does not exist in pydoctor; and probably not even in more recent epydoc versions. You should probably grab pydoctor from the website yourself, so you can preview the output.
• The docstring of textFromEventDict implies that eventDict may not have any other keys. It should be clarified that, in fact, it can have arbitrary keys other than the ones specified. This is what the 'format' string will be formatting, after all.

Optional - make a separate ticket or implement these:

• The comment that dreid called out earlier as not relevant to the docstring, "There's a way we could make this if not safer...", could fairly easily be implemented by using twisted.python.reflect.safe_str. Given that this comment was there before, I'll leave it up to your discretion whether to fix it or file a new ticket.
• It seems likely that users who want this functionality would also want it exposed via a twistd command-line option. I personally don't care about this functionality though, so it's hard to say for sure.

[therve]

I've done the docstrings cleanup. For the 2 other points:

• That doesn't seem too obvious to use safe_str. For example, today you could use format with something like %0.4f for example, which means we can't convert all the eventDict elements to strings.
• For twistd command line, this class is no less (or more :)) available to users than other log configuration, so that seems out of the scope of this. It seems something may be done in #638 (which is not still available for review but should be soon).

Thanks for pushing me to install pydoctor, I had been to lazy to do it previously :)

[drewp]

A message from the link police:

The howto with a new section about usage of PythonLoggingObserver? is here: http://twistedmatrix.com/trac/browser/branches/logging-bridge-1351/doc/core/howto/logging.xhtml

The new PythonLoggingObserver? class is here: http://twistedmatrix.com/trac/browser/branches/logging-bridge-1351/twisted/python/log.py#L398

The code LGTM. I'm looking forward to using this with the tac configuration proposed on http://twistedmatrix.com/trac/ticket/638

[exarkun]

For the docstring of test_strangeEventDict, I'd suggest something along these lines instead:

Verify that an event dictionary which is not an error and has an empty message isn't recorded.

Keeping the note about the historic behavior may also be useful, but it shouldn't be the primary test description.

Why does PythonLoggingIntegrationTestCase use bare asserts instead of trial assert methods?

[exarkun]

Oops, one other thing. Running the full Twisted test suite with this branch merged to trunk eventually fails like this:

twisted.trial.test.test_output
  TestImportErrors
    test_badimport ...                                                     [OK]
Traceback (most recent call last):
  File "/home/exarkun/Projects/Twisted/trunk/bin/trial", line 24, in ?
    run()
  File "/home/exarkun/Projects/Twisted/trunk/twisted/scripts/trial.py", line 345, in run
    test_result = trialRunner.run(suite)
  File "/home/exarkun/Projects/Twisted/trunk/twisted/trial/runner.py", line 795, in run
    suite.run(result)
  File "/home/exarkun/Projects/Twisted/trunk/twisted/trial/runner.py", line 285, in run
    TestSuite.run(self, result)
  File "/home/exarkun/Projects/Twisted/trunk/twisted/trial/runner.py", line 149, in run
    test(result)
  File "/home/exarkun/Projects/Twisted/trunk/twisted/trial/runner.py", line 138, in __call__
    return self.run(result)
  File "/home/exarkun/Projects/Twisted/trunk/twisted/trial/runner.py", line 176, in run
    super(LoggedSuite, self).run(result)
  File "/home/exarkun/Projects/Twisted/trunk/twisted/trial/runner.py", line 149, in run
    test(result)
  File "/home/exarkun/Projects/Twisted/trunk/twisted/trial/runner.py", line 138, in __call__
    return self.run(result)
  File "/home/exarkun/Projects/Twisted/trunk/twisted/trial/runner.py", line 149, in run
    test(result)
  File "/home/exarkun/Projects/Twisted/trunk/twisted/trial/runner.py", line 138, in __call__
    return self.run(result)
  File "/home/exarkun/Projects/Twisted/trunk/twisted/trial/runner.py", line 149, in run
    test(result)
  File "/home/exarkun/Projects/Twisted/trunk/twisted/trial/runner.py", line 138, in __call__
    return self.run(result)
  File "/home/exarkun/Projects/Twisted/trunk/twisted/trial/runner.py", line 149, in run
    test(result)
  File "/home/exarkun/Projects/Twisted/trunk/twisted/trial/runner.py", line 138, in __call__
    return self.run(result)
  File "/home/exarkun/Projects/Twisted/trunk/twisted/trial/runner.py", line 149, in run
    test(result)
  File "/home/exarkun/Projects/Twisted/trunk/twisted/trial/unittest.py", line 537, in __call__
    return self.run(*args, **kwargs)
  File "/home/exarkun/Projects/Twisted/trunk/twisted/trial/unittest.py", line 735, in run
    log.msg("--> %s <--" % (self.id()))
  File "/home/exarkun/Projects/Twisted/trunk/twisted/python/log.py", line 246, in msg
    o = self.observers.pop(i)
IndexError: pop index out of range

[therve]

There was a stupid typo, and I did other corrections, thanks.

[exarkun]

The logging.xhtml text is still a bit rough. We can probably clean it up later (suggesting text in a review comment seems lame, and if I just check in changes then we'll have to find another reviewer), and it's certainly clear enough to convey the information it is trying to convey.

All the code looks good, and the test suite passes now. Looks good to merge, I'd say.

[therve]

Closed in [20100].