Locust.io experiments — enriching results

One of the good things about Locust is its event-based nature. This time I’ll try to exploit this to extend the system capabilities with features like custom (non-HTTP) client and results enrichment.

The rationale

Before going into technicalities, let me explain why it could be even of any interest to you.

When doing performance tests it’s often important to be able to introduce some additional metadata to the “standard” results.

You may want to analyze the data by grouping some requests together, filtering others. In this case, it would be good if you were able to “tag” specific request types, for example, by service/component name, criticality (these requests should never fail, these are less important) or any other criteria. Going further, having these kind of “tagging”, you’d be able to investigate things like: “which component fail most frequently under the stress“.

Having custom (non-HTTP) system under testing is also a good use case for result data shaping. For example, request URL makes perfect sense for a web service, but if you are stress-testing a service exposed via Kafka topics, you’d probably want to collect some other information instead.

Even in simple HTTP case, there is a room for this. For example, Locust keeps track of the following metadata for the requests it produces: request type, name, response time, response length. When you are testing a file upload (via POST), it’s more important how big the request is and this is the value you want to collect.

The status quo

Let’s see what what is under our disposal in Locust.

Events and handlers

Internally, Locust uses events and event listeners to communicate the state the system all over the cluster.

Every time something interesting is happening, an event is triggered (or “fired”).

Locust 0.8.1 events

When some action needs to be performed in response to given event, it’s put into a handler and the handler gets hooked to that event.

For example, when you want to do something special when tests start to fail, you’d use request_failure event. The following pseudo-code would work:

The logic is defined on the module level (line 3) here and then it is added to request_failure handlers (line 6). Now, if send_message_to_slack would really exist, you’d be notified every time some request fails.

On the other hand, if — for some reason — you wanted to produce an event, you’d use something like this: events.request_failure.fire(request_type, name, response_time, exception)

And that’s it. Quite easy and smart.

Default request success/failure handlers

Now, that we know Locust communication is based on events, there is no surprise that the mechanics are also used to handle information about requests.

Locust encapsulates HTTP communication in HttpSession class (clients.py). Take a look at this fragment of request method for notification on successful request:

events.request_success.fire(
    request_type=request_meta["method"],
    name=request_meta["name"],
    response_time=request_meta["response_time"],
    response_length=request_meta["content_size"],
)

And the corresponding handler is defined in stats.py:

def on_request_success(request_type, name, response_time, response_length):
    global_stats.log_request(request_type, name, response_time, response_length)

Similarly, failure handler looks like this:

def on_request_failure(request_type, name, response_time, exception):
    global_stats.log_error(request_type, name, exception)

The Execution

Initially, I wanted to change the way “standard” requests data is collected. But then I thought I could kill two birds with one stone and illustrate data result enrichment while introducing an example of custom client at the same time.

The principles of operation would be very similar, so instead of experimenting with one thing I’ll have a chance to verify more stuff at once.

Capturing atomic results

By default Locust periodically dumps test results and computes aggregated values like median, average response time, number of requests per second, etc.

Now, I’ll introduce individual (not aggregated) results logging. In my case, I just want to make sure additional metadata I am adding to the results are really there, but this feature could be particularly useful if you plan to send the results to some external store and/or calculate the aggregates yourself.

I’ll hook to request_success and request_failure events, so in response to them I can output a particular result.

Short document on extending locust gives the following information and advice:

from locust import events

def my_success_handler(request_type, name, response_time, response_length, **kw):
    print "Successfully fetched: %s" % (name)

events.request_success += my_success_handler

It’s highly recommended that you add a wildcard keyword argument in your listeners (the **kw in the code above), to prevent your code from breaking if new arguments are added in a future version.

Let’s do this:

The first piece of code defines handlers that print results in json format to the console. In addition to the default parameters, the handlers accept arbitrary number of keyword arguments. For this implementation, all the additional data will go into “other” field.

Custom client

I will start with a client (for an imaginary queuing system) with the following contract:

class CustomClient:
    def __init__(self, host, port):
       """ Initialize the connection """ 
       pass

    def push(self, topic):
        """ push message using custom protocol """
        pass

    def pull(self, topic):
        """ pull message using custom protocol """
        pass

On object creation it will “connect” to the system under testing and provide two operations: push and pull.

Corresponding methods, should contain the actual logic (communication with the system) — now it’s only a simulation. For the results produced by this client to be more “realistic” I am introducing random “execution” time and force sporadic failures (see _sleep and _decide_the_fate).

Custom client is responsible for informing Locust about the outcome of the requests it produces, so push and pull need to handle:

• measuring the time,
• collecting other metadata (request type, success/failure, response time),
• firing proper event (request_success or request_failure).

In my artificial case, the logic for this is going to be exactly the same for both methods. I decided to put it into custom_timer function wrapper and use it for push and pull.

As the example assumes blocking API, time measurement will be simple: the wrapper will call actual (wrapped) method while checking time before and after the invocation. (Let me attack the problem of asynchronous client in the near future.)

Custom client source code

If you take a look at triggering the events (lines 23 and 27) you’ll notice that besides default parameters (see earlier section: “Default request success/failure handlers”) new one is being used: tag.

Using the custom client

There is a little snack smuggled into the code. The wrapper (lines 14-15) extracts the name of the function where push/pull was invoked. This way we are able to automatically tag the result with test method name. So, for the user defined in the code above, test1 and test2 will be used as values for tag.

Please, don’t run the code yet.

Multiple users

Back then, when I started with Locust I didn’t even know if having multiple (different) user behaviour defined is possible. I promised myself to check. Now, of course, I know it is easily doable (at least in the most basic form — without the control on the order of test invocation, for example), but let me show it anyways. Maybe somebody who starts his adventure with Locust will find the example useful.

Here’s the extract from locustifle.py:

It defines “normal” HTTP user and our new custom user and their tests.

The results

It’s time to run some code…

All the sources for this experiments are stored in /enriching-results folder of an accompanying GitHub repo.

Let’s clone the repo and start Locust in standalone mode using docker (and of course my favourite OS). Start powershell and use the following commands:

Locust has started. Everything should be fine, so open the browser and start the tests.

Small problem

Well, everything is not fine. If you run the code against the current version (Locust 0.8.1), you get error like this:

What happened?

In this experiments we created a custom client that produces some additional arguments for request_success (and failure) events. We also introduced dedicated handlers that are capable of consuming extra data — thanks to the advice given in Locust docs (see: Capturing atomic results section) — by using **kwargs.

When you take a second look at the default handlers implementation, you’ll notice that the Locust creators hadn’t took their advice seriously ;-).

Small fix

Because on_request_success and on_request_failure don’t declare **kwargs, Locust fails when invoking them. There is an easy fix for this. I proposed the following change to the Locust sources:

diff --git a/locust/stats.py b/locust/stats.py
index dab8bc7..1fdcb5d 100644
--- a/locust/stats.py
+++ b/locust/stats.py
@@ -554,10 +554,10 @@ global_stats = RequestStats()
 A global instance for holding the statistics. Should be removed eventually.
 """

-def on_request_success(request_type, name, response_time, response_length):
+def on_request_success(request_type, name, response_time, response_length, **kwargs):
     global_stats.log_request(request_type, name, response_time, response_length)

-def on_request_failure(request_type, name, response_time, exception):
+def on_request_failure(request_type, name, response_time, exception, **kwargs):
     global_stats.log_error(request_type, name, exception)

 def on_report_to_master(client_id, data):

To continue the experiment, please go to /docker-handler-fix folder and build patched version of Locust:

docker build -t grubykarol/locust:0.8.1-py3.6-patch -t grubykarol/locust:latest .

Big success

After re-running the docker image (please, note the label used here, it forces patched version of Locust):

docker run --rm -it --name standalone --hostname standalone -e ATTACKED_HOST=http://standalone:8089 -p 8089:8089 -v c:\experiments\enriching-results\locust-scripts:/locust grubykarol/locust:0.8.1-py3.6-patch

and starting the tests you will notice custom requests being logged:

Take a look at example Making a virtual data push entry (line 4) and the following line containing JSON object:

{
  "request_type":"CUSTOM",
  "name":"push /metrics/",
  "result":"OK",
  "response_time":"64",
  "response_length":"0",
  "other":{
    "tag":"task1"
  }
}

As expected, the object contains “other” field that holds our tag. In this case tag’s value is task1, which — as we wanted — happens to be the test method name.

Thanks to fixed default handlers, our custom requests can be treated by Locust as any other request, so they are included in the statistics and the UI:

Custom client results

Conclusions

In this experiment we managed to:

• create a custom client — here it’s just a mock, but it shows it’s possible to implement something sophisticated (create RPC-client, deal with other protocols, like TCP, create Kafka client, etc.)
• log individual results (not aggregated, for further “consumption”)
• define multiple users (one for web tests, one for custom client)
• make custom requests visible in Locust as any other requests

Thanks to even-based nature of Locust it was quite an easy exercise.

That’s wraps it up.

Thank You!

Few last formalities:

As usual, the sources mentioned in this article are stored in https://github.com/karol-brejna-i/locust-experiments. enriching-results folder holds locustfiles, docker-handler-fix has docker image definition that includes Locust fix (it’s going to be obsolete if/when https://github.com/locustio/locust/pull/746 is merged).

Locust 0.8.1 was used.