Regular traceback in system logs

[eythian]

I get a lot of this in my logs:

Mar 21 14:47:22 taniwha pac4cli[1386]: Unhandled Error
Mar 21 14:47:22 taniwha pac4cli[1386]: Traceback (most recent call last):
Mar 21 14:47:22 taniwha pac4cli[1386]:   File "/usr/lib/python3/dist-packages/pac4cli/__main__.py", line 126, in <module>
Mar 21 14:47:22 taniwha pac4cli[1386]:     reactor.run()
Mar 21 14:47:22 taniwha pac4cli[1386]:   File "/usr/lib/python3/dist-packages/twisted/internet/base.py", line 1243, in run
Mar 21 14:47:22 taniwha pac4cli[1386]:     self.mainLoop()
Mar 21 14:47:22 taniwha pac4cli[1386]:   File "/usr/lib/python3/dist-packages/twisted/internet/base.py", line 1255, in mainLoop
Mar 21 14:47:22 taniwha pac4cli[1386]:     self.doIteration(t)
Mar 21 14:47:22 taniwha pac4cli[1386]:   File "/usr/lib/python3/dist-packages/twisted/internet/epollreactor.py", line 235, in doPoll
Mar 21 14:47:22 taniwha pac4cli[1386]:     log.callWithLogger(selectable, _drdw, selectable, fd, event)
Mar 21 14:47:22 taniwha pac4cli[1386]: --- <exception caught here> ---
Mar 21 14:47:22 taniwha pac4cli[1386]:   File "/usr/lib/python3/dist-packages/twisted/python/log.py", line 103, in callWithLogger
Mar 21 14:47:22 taniwha pac4cli[1386]:     return callWithContext({"system": lp}, func, *args, **kw)
Mar 21 14:47:22 taniwha pac4cli[1386]:   File "/usr/lib/python3/dist-packages/twisted/python/log.py", line 86, in callWithContext
Mar 21 14:47:22 taniwha pac4cli[1386]:     return context.call({ILogContext: newCtx}, func, *args, **kw)
Mar 21 14:47:22 taniwha pac4cli[1386]:   File "/usr/lib/python3/dist-packages/twisted/python/context.py", line 122, in callWithContext
Mar 21 14:47:22 taniwha pac4cli[1386]:     return self.currentContext().callWithContext(ctx, func, *args, **kw)
Mar 21 14:47:22 taniwha pac4cli[1386]:   File "/usr/lib/python3/dist-packages/twisted/python/context.py", line 85, in callWithContext
Mar 21 14:47:22 taniwha pac4cli[1386]:     return func(*args,**kw)
Mar 21 14:47:22 taniwha pac4cli[1386]:   File "/usr/lib/python3/dist-packages/twisted/internet/posixbase.py", line 627, in _doReadOrWrite
Mar 21 14:47:22 taniwha pac4cli[1386]:     self._disconnectSelectable(selectable, why, inRead)
Mar 21 14:47:22 taniwha pac4cli[1386]:   File "/usr/lib/python3/dist-packages/twisted/internet/posixbase.py", line 258, in _disconnectSelectable
Mar 21 14:47:22 taniwha pac4cli[1386]:     selectable.connectionLost(failure.Failure(why))
Mar 21 14:47:22 taniwha pac4cli[1386]:   File "/usr/lib/python3/dist-packages/twisted/internet/tcp.py", line 475, in connectionLost
Mar 21 14:47:22 taniwha pac4cli[1386]:     self._commonConnection.connectionLost(self, reason)
Mar 21 14:47:22 taniwha pac4cli[1386]:   File "/usr/lib/python3/dist-packages/twisted/internet/tcp.py", line 289, in connectionLost
Mar 21 14:47:22 taniwha pac4cli[1386]:     protocol.connectionLost(reason)
Mar 21 14:47:22 taniwha pac4cli[1386]:   File "/usr/lib/python3/dist-packages/twisted/web/http.py", line 585, in connectionLost
Mar 21 14:47:22 taniwha pac4cli[1386]:     self.handleResponseEnd()
Mar 21 14:47:22 taniwha pac4cli[1386]:   File "/usr/lib/python3/dist-packages/twisted/web/proxy.py", line 87, in handleResponseEnd
Mar 21 14:47:22 taniwha pac4cli[1386]:     self.father.finish()
Mar 21 14:47:22 taniwha pac4cli[1386]:   File "/usr/lib/python3/dist-packages/twisted/web/http.py", line 992, in finish
Mar 21 14:47:22 taniwha pac4cli[1386]:     "Request.finish called on a request after its connection was lost; "
Mar 21 14:47:22 taniwha pac4cli[1386]: builtins.RuntimeError: Request.finish called on a request after its connection was lost; use Request.notifyFinish to keep track of this.

version:

robin@taniwha:~$ apt policy pac4cli
pac4cli:
  Geïnstalleerd: 0.1ubuntu2+git119~ubuntu18.04.1
  Kandidaat:     0.1ubuntu2+git119~ubuntu18.04.1
  Versietabel:
 *** 0.1ubuntu2+git119~ubuntu18.04.1 500
        500 http://ppa.launchpad.net/tkluck/pac4cli/ubuntu bionic/main amd64 Packages
        500 http://ppa.launchpad.net/tkluck/pac4cli/ubuntu bionic/main i386 Packages
        100 /var/lib/dpkg/status

[tkluck]

Thanks for the report @eythian !

Twisted is notoriously hard to debug and from the looks of it, this issue is with twisted's own http proxy stack. I think we should probably mitigate in some way (install error handlers (errBacks) where they are missing; adjust logging levels for tracebacks) before trying to dive into this.

I'm not sure I'll have time soon to look into this. Will keep this ticket open not to forget.