Runnable demo of timer bugs in Twisted's asyncioreactor

asyncioreactor_timer_bugs.py

import gc
import time

from twisted.internet import asyncioreactor
asyncioreactor.install()

from twisted.internet import reactor


def bug_reset_later():
    """
    Move timer on later time doesn't work.
    This is because DelayedCall.resetter isn't called if the call is reset
    on later time. It is only called when DelayedCall.reset() is called with
    earlier time. But current implementation relayes on resetter is being called.

    Expected result:
    >>> fired 3

    Actual result:
    >>> fired 1
    """
    t0 = time.time()
    dc = reactor.callLater(1, lambda: print('fired', round(time.time() - t0)))
    dc.reset(3)

    reactor.callLater(5, reactor.stop)
    reactor.run()


def bug_reset_earlier():
    """
    Move timer on earlier time raising exception when original time is come.
    This is because current implementation doesn't cancel original asyncio timer.

    Expected result:
    >>> fired 1

    Actual result:
    >>> fired 1
    Exception in callback AsyncioSelectorReactor.callLater.<locals>.run() at .../twisted/internet/asyncioreactor.py:287
    Traceback (most recent call last):
        ...
    KeyError: <DelayedCall 0x7f033cf6bc50 [-2.004988376997062s] called=True cancelled=0 AsyncioSelectorReactor.callLater.<locals>.run()>
    """
    t0 = time.time()
    dc = reactor.callLater(3, lambda: print('fired', round(time.time() - t0)))
    dc.reset(1)

    reactor.callLater(5, reactor.stop)
    reactor.run()


def nonbug_circular_references():
    """
    Current timer implementation leaves many circular references between local
    functions in AsyncioSelectorReactor.callLater and theirs closures. In apps
    that heavily use timers this leads to significantly higher memory usage
    and/or significantly more frequent GC invocations.

    I've raised similar issue before for TLS code and it was considered worth fixing:
    https://github.com/twisted/twisted/pull/955

    This sample calculates number of cyclically linked objects leaved per single
    timer after scheduling and running many timers.

    Expected result:
        Much less than 1. For example, I get 0.0064 for EPollReactor, PollReactor
        and SelectReactor.

    Actual result:
        ≈ 20
    """
    nop = lambda: ...

    count = 10000

    gc.disable()

    try:
        objects_before = len(gc.get_objects())

        for _ in range(count):
            reactor.callLater(1, nop)

        def stop():
            objects_after = len(gc.get_objects())
            print('Garbage objects per timer:', (objects_after - objects_before) / count)
            reactor.stop()

        reactor.callLater(3, stop)
        reactor.run()
    finally:
        gc.enable()


bug_reset_later()
# bug_reset_earlier()
# nonbug_circular_references()