How to execute code asynchronously in Twisted Klein?

Question

I have two functions in my python Twisted Klein web service:

@inlineCallbacks
def logging(data):
    ofile = open("file", "w")
    ofile.write(data)
    yield os.system("command to upload the written file")

@APP.route('/dostuff')
@inlineCallbacks
def dostuff():
    yield logging(data)
    print "check!" 
    returnValue("42")

When os.system("command to upload the written file") runs, it will show message saying "start uploading" then "upload complete". I want to make the logging function asynchronous so that processing in logging handler happens after dostuff handler prints out "check!". (I actually want processing to happen after returnValue("42"), but both of those are making the logging function async I think?)

I thought the yield statement will make it non-blocking but it seems not the case, the "check!" always got printed after "start uploading" and "upload complete". I'll appreciate if anyone can give me some feedback on it since I'm new to async coding and got blocked on this for a while...

Answer 1

To make your code async you need to use Twisted Deferreds as described here. Deferreds give you an API for asynchronous code execution, they allow you to attach callbacks to your functions and they execute code in Twisted event loop managed by reactor object.

I see two potential ways to use Deferreds in your case.

1) Execute task in background with reactor.callLater()

This is ok if dostuff handler doesn't care about result. You can use reactor.callLater(). This way your async function will execute after you return value from doStuff.

So something like this:

from klein import run, route, Klein
from twisted.internet import defer, task, reactor
import os

app = Klein()


def logging(data):
    ofile = open("file", "w")
    ofile.write(data)
    result = os.system("ls")
    print(result)


@route('/')
def dostuff(request):
    reactor.callLater(0, logging, "some data")
    print("check!")
    return b'Hello, world!'

run("localhost", 8080)

The order of events with this code is following, first "check" is printed, then "hello world" response is returned and in the end async call suceeds and prints results of running os.system().

2016-08-11 08:52:33+0200 [-] check!
2016-08-11 08:52:33+0200 [-] "127.0.0.1" - - [11/Aug/2016:06:52:32 +0000] "GET / HTTP/1.1" 200 13 "-" "curl/7.35.0"
a.py  file

2) Execute task in background and get result with task.deferLater()

If you care about results of your 'logging' function you can also attach callback to this object and use twisted.internet.task API. If you want to go this way you need to refactor your handler to work like this

@route('/')
def dostuff(request):
    def the_end(result):
        print("executed at the end with result: {}".format(result))
    dfd = task.deferLater(reactor, 0, logging, "some data")
    dfd.addCallback(the_end)
    print("check!")
    return b'Hello, world!'

This way order of events will be same as above, but the_end function will be executed at the end after your logging function finishes.

2016-08-11 08:59:24+0200 [-] check!
2016-08-11 08:59:24+0200 [-] "127.0.0.1" - - [11/Aug/2016:06:59:23 +0000] "GET / HTTP/1.1" 200 13 "-" "curl/7.35.0"
a.py  file
2016-08-11 08:59:24+0200 [-] executed at the end with result: some result

Answer 2

The 'yield' statement doesn't make things happen asynchronously. It just defers execution of the function containing it and returns a generator object that can later be used to iterate a sequence.

So dostuff() is going to return a generator object. Nothing will happen until that generator object is iterated sometime later. But there's nothing in your code to make this happen. I expect your dostuff routine will produce a syntax error because it contains both a yield and a non-empty return. The logging routine won't do anything because it contains a yield and the generator it returns is never used.

Finally, the logging routine is going to truncate its output file every time it's called because it opens the log file with mode 'w' on every invocation.

For asynchronous execution, you need some form of multiprocessing. But I don't think that's needed in this context. Your logging function is fairly light weight and should run quickly and not interfere with dostuff's work.

I would suggest trying something like this:

@inlineCallbacks
def logging(data):
    try:
        logging._ofile.write(data + '\n')
    except AttributeError:
        logging._ofile = open("file", 'w')
        logging._ofile.write(data + '\n')

@APP.route('/dostuff')
@inlineCallbacks
def dostuff():
    logging("before!")
    os.system("command to upload the written file")
    logging("after!")
    return("42")

Here we open the logging file only once, the first time logging is called when _ofile is not defined as an attribute of logging. On subsequent calls, logging._ofile will already be open and the write statement in the try block will be successful.

Routine dostuff() calls logging to indicate we're about to do the work, actually does the work, then calls logging to indicate the work has been done, and finally returns the desired value.