Introduction Doc Examples are Incomplete / Possibly Non-functional

[Julian]

(Carried over from IRC to an actual bug tracker :/)

The API doc links from e.g. https://tubes.readthedocs.org/en/latest/tube.html#an-introduction-to-tubes point at twistedmatrix.com when they seem to want to point at twisted.github.io now.

Also, the second example (with a Reverser) seems incomplete, or at least, reading through it, I cannot yet tell how to make it work.

If I put

from tubes.protocol import factoryFromFlow

from twisted.internet.endpoints import serverFromString
from twisted.internet.defer import Deferred

def reverseFlow(fount, drain):
    from tubes.framing import bytesToLines, linesToBytes
    lineReverser = series(bytesToLines(), Reverser(), linesToBytes())
    fount.flowTo(lineReverser).flowTo(drain)

class Reverser(object):
    def received(self, item):
        yield b"".join(reversed(item))

def main(reactor, listenOn="stdio:"):
    endpoint = serverFromString(reactor, listenOn)
    endpoint.listen(factoryFromFlow(reverseFlow))
    return Deferred()

if __name__ == '__main__':
    from twisted.internet.task import react
    from sys import argv
    react(main, argv[1:])

in a file and run it, I get a thing that silently does nothing, seemingly.

There's possibly a mix of an upstream issue here, but after some quick debugging:

if I stop listening on stdio, now I get tracebacks on stdout when I make a connection:

/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/twisted/internet/endpoints.py:29: DeprecationWarning: twisted.internet.interfaces.IStreamClientEndpointStringParser was deprecated in Twisted 14.0.0: This interface has been superseded by IStreamClientEndpointStringParserWithReactor.
  from twisted.internet.interfaces import (
2015-11-19T14:51:22-0500 [-] Factory starting on 1234
2015-11-19T14:51:22-0500 [twisted.internet.protocol.Factory#info] Starting factory <twisted.internet.protocol.Factory instance at 0x0000000108c6c720>
asdf
Unhandled Error
Traceback (most recent call last):
  File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/twisted/python/log.py", line 84, in callWithContext
    return context.call({ILogContext: newCtx}, func, *args, **kw)
  File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/twisted/python/context.py", line 118, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/twisted/python/context.py", line 81, in callWithContext
    return func(*args,**kw)
  File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/twisted/internet/selectreactor.py", line 149, in _doReadOrWrite
    why = getattr(selectable, method)()
--- <exception caught here> ---
  File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/twisted/internet/tcp.py", line 1074, in doRead
    protocol.makeConnection(transport)
  File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/twisted/internet/protocol.py", line 494, in makeConnection
    self.connectionMade()
  File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/tubes/protocol.py", line 231, in connectionMade
    self._flow(self._fount, self._drain)
  File "send.py", line 23, in reverseFlow
    lineReverser = series(bytesToLines(), Reverser(), linesToBytes())
  File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/tubes/tube.py", line 220, in series
    drains = map(IDrain, tubes)
  File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/zope/interface/interface.py", line 142, in __call__
    raise TypeError("Could not adapt", obj, self)
exceptions.TypeError: ('Could not adapt', <__main__.Reverser object at 0x0000000108c59fa0>, <InterfaceClass tubes.itube.IDrain>)

2015-11-19T14:51:27-0500 [twisted.internet.protocol.Factory] Unhandled Error
        Traceback (most recent call last):
          File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/twisted/python/log.py", line 84, in callWithContext
            return context.call({ILogContext: newCtx}, func, *args, **kw)
          File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/twisted/python/context.py", line 118, in callWithContext
            return self.currentContext().callWithContext(ctx, func, *args, **kw)
          File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/twisted/python/context.py", line 81, in callWithContext
            return func(*args,**kw)
          File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/twisted/internet/selectreactor.py", line 149, in _doReadOrWrite
            why = getattr(selectable, method)()
        --- <exception caught here> ---
          File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/twisted/internet/tcp.py", line 1074, in doRead
            protocol.makeConnection(transport)
          File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/twisted/internet/protocol.py", line 494, in makeConnection
            self.connectionMade()
          File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/tubes/protocol.py", line 231, in connectionMade
            self._flow(self._fount, self._drain)
          File "send.py", line 23, in reverseFlow
            lineReverser = series(bytesToLines(), Reverser(), linesToBytes())
          File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/tubes/tube.py", line 220, in series
            drains = map(IDrain, tubes)
          File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/zope/interface/interface.py", line 142, in __call__
            raise TypeError("Could not adapt", obj, self)
        exceptions.TypeError: ('Could not adapt', <__main__.Reverser object at 0x0000000108c59fa0>, <InterfaceClass tubes.itube.IDrain>)

which seems to indicate that that isn't in fact enough to get a working IDrain?

It's also really off-putting I think to new users if tracebacks are completely silenced there. That was my first 5 minutes with Tubes unfortunately and I had literally no idea what was going wrong, and also there were 2 logging frameworks to disect to figure out where my tracebacks went (along the way I discovered that if I added both:

globalLogPublisher.addObserver(textFileLogObserver(sys.stderr))

and

log.startLogging(sys.stderr)

to try and get both frameworks to not swallow anything, I get instead an infinite stream of recursion on stderr which I think is the two of them fighting with each other:

# ... truncated
2015-11-19 14:58:12-0500 [-]   File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/twisted/internet/defer.py", line 121, in execute
2015-11-19 14:58:12-0500 [-] 2015-11-19T14:58:12-0500 [stderr#error]   File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/twisted/internet/defer.py", line 121, in execute
2015-11-19 14:58:12-0500 [-] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error]   File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/twisted/internet/defer.py", line 121, in execute
2015-11-19 14:58:12-0500 [-] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error]   File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/twisted/internet/defer.py", line 121, in execute
2015-11-19 14:58:12-0500 [-] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error]   File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/twisted/internet/defer.py", line 121, in execute
2015-11-19 14:58:12-0500 [-] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error]   File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/twisted/internet/defer.py", line 121, in execute
2015-11-19 14:58:12-0500 [-] UNFORMATTABLE OBJECT WRITTEN TO LOG with fmt '%(log_legacy)s', MESSAGE LOST
2015-11-19 14:58:12-0500 [-]     result = callable(*args, **kw)
2015-11-19 14:58:12-0500 [-] 2015-11-19T14:58:12-0500 [stderr#error]     result = callable(*args, **kw)
2015-11-19 14:58:12-0500 [-] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error]     result = callable(*args, **kw)
2015-11-19 14:58:12-0500 [-] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error]     result = callable(*args, **kw)
2015-11-19 14:58:12-0500 [-] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error]     result = callable(*args, **kw)
2015-11-19 14:58:12-0500 [-] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error]     result = callable(*args, **kw)
2015-11-19 14:58:12-0500 [-] UNFORMATTABLE OBJECT WRITTEN TO LOG with fmt '%(log_legacy)s', MESSAGE LOST
2015-11-19 14:58:12-0500 [-]   File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/twisted/internet/posixbase.py", line 478, in listenTCP
2015-11-19 14:58:12-0500 [-] 2015-11-19T14:58:12-0500 [stderr#error]   File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/twisted/internet/posixbase.py", line 478, in listenTCP
2015-11-19 14:58:12-0500 [-] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error]   File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/twisted/internet/posixbase.py", line 478, in listenTCP
2015-11-19 14:58:12-0500 [-] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error]   File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/twisted/internet/posixbase.py", line 478, in listenTCP
2015-11-19 14:58:12-0500 [-] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error]   File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/twisted/internet/posixbase.py", line 478, in listenTCP
2015-11-19 14:58:12-0500 [-] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error]   File "/Users/Julian/.local/share/virtualenvs/kafka_faf/site-packages/twisted/internet/posixbase.py", line 478, in listenTCP
2015-11-19 14:58:12-0500 [-] UNFORMATTABLE OBJECT WRITTEN TO LOG with fmt '%(log_legacy)s', MESSAGE LOST
2015-11-19 14:58:12-0500 [-]     p.startListening()
2015-11-19 14:58:12-0500 [-] 2015-11-19T14:58:12-0500 [stderr#error]     p.startListening()
2015-11-19 14:58:12-0500 [-] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error]     p.startListening()
2015-11-19 14:58:12-0500 [-] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error]     p.startListening()
2015-11-19 14:58:12-0500 [-] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error]     p.startListening()
2015-11-19 14:58:12-0500 [-] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error] 2015-11-19T14:58:12-0500 [stderr#error]     p.startListening()
# ... truncated

-- it might be that not having tracebacks shown is really an upstream issue which is "maybe tracebacks should be going to stderr when listening on a stdio endpoint? or something?"

Sorry to file such a tangled issue report, as I learn a bit more about tubes over the next hour I'll hopefully be able to untangle, but that was a brain dump of the first 10 minutes or so.