selectreactor's addReader unexpectedly assumes a logPrefix attr

[marienz]

After adding an object implementing IReadDescriptor with reactor.addReader and
making the fd readable I get the following traceback:
  File "/usr/lib/python2.4/site-packages/twisted/internet/posixbase.py", line
206, in run
    self.mainLoop()
  File "/usr/lib/python2.4/site-packages/twisted/internet/posixbase.py", line
217, in mainLoop
    self.doIteration(t)
  File "/usr/lib/python2.4/site-packages/twisted/internet/selectreactor.py",
line 133, in doSelect
    _logrun(selectable, _drdw, selectable, method, dict)
--- <exception caught here> ---
  File "/usr/lib/python2.4/site-packages/twisted/python/log.py", line 51, in
callWithLogger
    lp = logger.logPrefix()
exceptions.AttributeError: 'INotify' object has no attribute 'logPrefix'
t.i.interfaces claims something added with addReader only has to implement
IReadDescriptor, logPrefix is not mentioned in that interface. I guess either
interfaces should be updated to mention this requirement or the requirement
should go away.

[therve]

I've attached a patch adding the logPrefix documentation on IFileDescriptor. It seems the better to put it. Note though that it should not cause as it's been caught for a long time in log.py.

[glyph]

I don't like this solution, because logPrefix is part of a different interface, really. IFileDescriptor should subclass that interface, perhaps.

The whole IReactorFDSet universe is somewhat neglected, and the interaction here was not intentionally designed.

Here's the original idea behind the design: all event sources in the reactor (callFromThread, callLater, file descriptor events) should have a logger associated with them which has a logPrefix method, so that when messages are logged it is clear what event generated them. This was supposed to be easily pluggable, so that, for example, a timed call which was scheduled at a particular connection's request would indicate both the connection that was active when it was scheduled and the fact that it was occurring in a timed event in any log messages. Through a series of implementation accidents and optimizations, instead, many different kinds of events generate "-" for their log prefix and anything not synchronously logged in the middle of a connection is logged without any context as to what caused it.

I'd like to gather up some of the logging issues into a more usefully scoped chunk of work, so that we end up with a set of actual fixes rather than a slow drift of unobtrusive changes that simply formalize the current brokenness.

Also, I appreciate the docstring cleanups, but could you make a separate ticket for it? It makes the patch very hard to read / review when there are such a large volume of related cleanups along with one change.

[therve]

Thanks for the comment. I think I'm aware of the logging issue, but this ticket is just about a documentation problem.

I made a new patch creating a ILoggingContext interface, and making it parent of IFileDescriptor. I also revert all my whitespace changes :).

[glyph]

OK. This fix is better. I'm still not completely happy with it, but it is better to accurately document the state of things than to pretend they are better than they are :). Please merge.

I hope that I can get to this before the next release though and do something more intelligent with the ILoggingContext interface.

[therve]

(In [19854]) Apply patch from tracker.

Author: therve Reviewer: glyph Fixes #1272

Add ILoggingContext interface and make IFileDescriptor inherit of it: that documents the logPrefix method needed on IReadDescriptor/IWriteDescriptor.