Search code examples
pythonpython-3.xtwistedtwisted.internet

Twisted: catching DNSLookupError upon internet connection drop


I have a simple twisted script which sends GET requests to some API endpoint. It works fine, except that when my internet connection drops it pollutes the log with a bunch of Unhandled error in Deferred: messages.

The minimal example looks like this:

import sys
from twisted.web.client import Agent
from twisted.internet import reactor, task
from twisted.internet.defer import Deferred
from twisted.internet.protocol import Protocol
from twisted.logger import Logger, textFileLogObserver

# the DNSLookupError gets thrown before an instance of this class
# is created
class DataReceiver(Protocol):    
    def __init__(self, finished):
        self.finished = finished

    def dataReceived(self, data):
        log.info('Got data!')

    def connectionLost(self, reason):
        log.info(reason.getErrorMessage())
        self.finished.callback(None)

def receive_data(response):
    try:
        response.deliverBody(DataReceiver(Deferred()))
    except Exception as e:
        log.failure(e)

def schedule_request(agent):
    try:
        req = agent.request(b'GET', b'https://www.example.org')
        req.addCallbacks(receive_data, errback=log.failure)
    except Exception as e:
        log.failure(e)

if __name__ == '__main__':
    log = Logger(observer=textFileLogObserver(sys.stdout))
    try:
        # schedule requests every two seconds
        agent = Agent(reactor)
        loop = task.LoopingCall(lambda: schedule_request(agent))
        loop.start(2)

        # run event loop
        reactor.run()
    except Exception as e:
        log.failure(e)

When the internet connection is up, the log looks as expected:

2018-02-06T16:50:32+0100 [__main__#info] Got data!
2018-02-06T16:50:32+0100 [__main__#info] Response body fully received

But when the connection drops I see:

Unhandled error in Deferred:

If I use the log from twisted.python, the full traceback is:

2018-02-06 16:42:54+0100 [-] Unhandled Error
    Traceback (most recent call last):
      File "/usr/local/lib/python3.5/dist-packages/twisted/internet/_resolver.py", line 137, in deliverResults
        resolutionReceiver.resolutionComplete()
      File "/usr/local/lib/python3.5/dist-packages/twisted/internet/endpoints.py", line 900, in resolutionComplete
        d.callback(addresses)
      File "/usr/local/lib/python3.5/dist-packages/twisted/internet/defer.py", line 459, in callback
        self._startRunCallbacks(result)
      File "/usr/local/lib/python3.5/dist-packages/twisted/internet/defer.py", line 567, in _startRunCallbacks
        self._runCallbacks()
    --- <exception caught here> ---
      File "/usr/local/lib/python3.5/dist-packages/twisted/internet/defer.py", line 653, in _runCallbacks
        current.result = callback(current.result, *args, **kw)
      File "/usr/local/lib/python3.5/dist-packages/twisted/internet/endpoints.py", line 954, in startConnectionAttempts
        "no results for hostname lookup: {}".format(self._hostStr)
    twisted.internet.error.DNSLookupError: DNS lookup failed: no results for hostname lookup: www.example.org.

How do I catch and handle this exception in twisted?


Solution

  • Your application code is logging this failure:

    req.addCallbacks(receive_data, errback=log.failure)
    

    When the req Deferred fails with this DNS error, the errback is called. If you don't want this case to be logged, change your errback. For example:

    def do_not_log_dns_errors(failure):
        if not failure.check(DNSLookupError):
            log.failure("request failed", failure)
    

    (note also that the first argument to log.failure is not a Failure).