Profiling your web application with wsgid request filters

It’s always important to know how your web app is performing and there are many ways to do this. One such way is measuring memory consumption, for example. This blog post will explore how you can measure response time on your live application.

We will see how to make this using a new feature available in wsgid 0.7.0:  RequestFilters.

Request Filters

This feature works in a very simple way. Wsgid gives you the opportunity to run external code inside the regular request/response flow. Wsgid defines two distinct interfaces: IPreRequestFilter and IPostRequestFilter. By implementing any of these interfaces you will have your code called on every request.

Since we are injecting external code into the execution flow of our application, wsgid must ensure that a failing filter does not crash a successful request. So unless you call sys.exit(0) or crash the python interpreter (believe me, it happens!) all requests should complete as usual.

IPreRequestFilter Interface

This interface has just one method (code here):

def IPreRequestFilter(plugnplay.Interface):

    def process(self, m2message, environ):
        pass

The m2message parameter is an instance of wsgid.core.Message. This is the parsed mongrel2 message. The environ is the WSGI Environ, as described by the PEP-333 specification.

Your code can modify the environ freely. This modified environ will be passed to the running WSGI app.

IPostRequestFilter Interface

This interface has two methods (code here):

def IPostRequestFilter(plugnplay.Interface):

    def process(self, m2message, status, headers, body):
        pass

    def exception(self, m2message, e):
        pass

Since this filter is called after the WSGI app has ran, the filter receives all values returned by it. These values are are the raw values as defined by PEP-333. The exception method is called when the WSGI app call fails for any reason (usually an unhandled exception). From the wsgid perspective, even if the application returns an HTTP 500 it will be considered a successful run. If you want to detect error HTTP responses you should inspect the status parameter, received by the process method.

Important note: If the WSGI app call fails, just the exception method will be called. Does not make sense to call the process method since the WSGI app did not return any value.

Simple examples

The wsgid source-code includes two simple examples of request filters. The first is the WorkerPidFilter. This just adds an header to the response containing the PID of the Wsgid worker that ran the WSGI app. The code is very simple:

class WorkerPidFilter(Plugin):
 '''
 Simple fillter that adds one more response header containing the
 pid of the Wsgid workers that was running the WSGI application
 '''
    implements = [IPostRequestFilter, ]

    def process(self, message, status, headers, body):
        return (status, headers + [('X-Worker', os.getpid())], body)

    def exception(self, message, e):
        pass

Another example is a filter that calculates the total elapsed time of your request. You can take a look at the code here.

A more real world example

These example filters works very well for simple cases. When it comes to real world production application we may have to do it a little different. First of all, when writing a request filter we must consider the time the filter will take to run. The less it takes, the less it interferes in the request response time.

We could, for example, save the response times in a database. But we know that this wouldn’t be a great idea in the end! So the idea here is to save the information to later processing. We could save it into the logs. You can do this by just importing wsgid.core.log. This is a stantard Python Logger and it writes the information into your app main log file (the file is located inside your wsgidapp folder at logs/wsgid.log). But by doing this we would have to keep parsing the application log, not a very good idea either.

Another idea is to use a queue server, such as RabbitMQ. This way we can keep the filter execution time very low and we will have all messages saved to be processes later, without the need to parse any log file.

Attached to the RabbitMQ server we would have a separated process, reading all the messages and storing them anywhere, in a database, in a Graphite server or any other place.

The idea behind this implementation

The idea is very simples. Since your filter receives the parsed mongrel2 message, you have access to the connection ID of the client making the current request. This could be your primary key when measuring the values. In your PreRequestFilter you can send to the queue server, along with the connection ID, all the HTTP headers, the current time and any other information you want.

When the PostRequestFilter runs, you send the connection ID, the status returned by the WSGI app, the response headers and the current time again. With this information you can not only calculate the response time (per request URI, if you like) but you can calculate all sorts of information about your requests. User-Agent percentage, Content-Length average size, the most/less visited URI, HTTP status distribution (how many 200’s, 400’s, 500’s is your WSGI app returning) just to cite a few.

I will leave this implementation for a future post as I pretend to calculate all this information for the wsgid (http://wsgid.com) website and for my personal website (http://daltonmatos.com). This will be perfectly possible since they both run with wsgid.

Thanks for the reading and I hope you enjoyed!

, ,

  1. Deixe um comentário

Deixe uma resposta

Preencha os seus dados abaixo ou clique em um ícone para log in:

Logotipo do WordPress.com

Você está comentando utilizando sua conta WordPress.com. Sair / Alterar )

Imagem do Twitter

Você está comentando utilizando sua conta Twitter. Sair / Alterar )

Foto do Facebook

Você está comentando utilizando sua conta Facebook. Sair / Alterar )

Foto do Google+

Você está comentando utilizando sua conta Google+. Sair / Alterar )

Conectando a %s

%d blogueiros gostam disto: