Micro benchmark with curl

People who want to benchmark an HTTP server usualy use tools such as Apache Benchmark or HTTPerf. The day I had do to it, it was against object storages: AWS S3 or DropBox, so I didn't have hands on servers. My goal was to measure object storages' performances as a real customer user (Cloudscreener's philosophy), no need to know how backend is designed only to know how many time it take for every step of an HTTP connection.

I worked under many constraint:

• No stress test: As the server is a cloud provider's endpoint, it would be very expensive to stress until reaching the limit
• I must be able detect cache
• Deal with HTTP and HTTPS

I choose maybe the simpliest solution curl. Instead of burst the server, I make several requests with a small interval like an heartbeat. I gather many connection data like:

• Time until TCP connection is started
• Time until first byte is sent (TTFB)
• Time until end of SSL handshake
• Total time (Load time)

It is not step's times but enough for compute the following things:

• Time of TCP hanshake (SYN, SYN+ACK, ACK)
• Time of SSL handshake (if HTTPS used)
• Transfer time
• Total time

Until I learn how to install PyCurl (yep I failed), let's make an example with curl command and Python:

import subprocess
import tempfile
import json
import time

URL = os.environ.get("url", "https://anthony-monthe.me/weblog/")
COUNT = int(os.environ.get('count', 10))
CMD_TEMPLATE = 'curl -w @{format_file} -o /dev/null -s {url}'
FORMAT_TEMPLATE = '''{"time_appconnect": %{time_appconnect},
"time_connect": %{time_connect},
"time_namelookup": %{time_namelookup},
"time_pretransfer": %{time_pretransfer},
"time_redirect": %{time_redirect},
"time_starttransfer": %{time_starttransfer},
"time_total": %{time_total}}\\n'''


def main():
    """Launch n request to server x and print HTTP stats"""
    # Create a template file for curl formart
    format_file = tempfile.mktemp()
    with open(format_file, 'w') as ffd:
        ffd.write(FORMAT_TEMPLATE)
    # Launch curls
    cmd = CMD_TEMPLATE.format(format_file=format_file, url=URL)
    result_file = tempfile.mktemp()
    with open(format_file) as ffd:
        with open(result_file, 'a') as rfd:
            # Launch several requests
            for i in range(COUNT):
                try:
                    subprocess.call(cmd.split(), stdin=ffd, stdout=rfd)
                    time.sleep(1)  # Temporize a little
                    print 'Request #%s ' % (i+1)
                except KeyboardInterrupt:
                    break
    # Read results where each line is a dict
    with open(result_file) as rfd:
        results = [json.loads(line.strip()) for line in rfd]
    # Print results
    os.system('clear')
    for result in results:
        print result
    # Clean temp files
    os.remove(format_file)
    os.remove(result_file)


if __name__ == '__main__':
    main()

This script make 10 HTTPS requests to my blog and use curl debug to get informations about requests. I choose to get data in JSON format and it helps me to gather data as following:

{u'time_redirect': 0.0, u'time_pretransfer': 0.07, u'time_appconnect': 0.0, u'time_starttransfer': 0.494, u'time_namelookup': 0.013, u'time_connect': 0.07, u'time_total': 0.912}
{u'time_redirect': 0.0, u'time_pretransfer': 0.074, u'time_appconnect': 0.0, u'time_starttransfer': 0.607, u'time_namelookup': 0.016, u'time_connect': 0.073, u'time_total': 1.541}
{u'time_redirect': 0.0, u'time_pretransfer': 0.075, u'time_appconnect': 0.0, u'time_starttransfer': 0.505, u'time_namelookup': 0.031, u'time_connect': 0.075, u'time_total': 1.387}
{u'time_redirect': 0.0, u'time_pretransfer': 0.086, u'time_appconnect': 0.0, u'time_starttransfer': 0.326, u'time_namelookup': 0.013, u'time_connect': 0.085, u'time_total': 0.848}
{u'time_redirect': 0.0, u'time_pretransfer': 0.071, u'time_appconnect': 0.0, u'time_starttransfer': 0.537, u'time_namelookup': 0.014, u'time_connect': 0.071, u'time_total': 1.208}
{u'time_redirect': 0.0, u'time_pretransfer': 0.073, u'time_appconnect': 0.0, u'time_starttransfer': 0.308, u'time_namelookup': 0.014, u'time_connect': 0.072, u'time_total': 2.015}
{u'time_redirect': 0.0, u'time_pretransfer': 0.07, u'time_appconnect': 0.0, u'time_starttransfer': 0.465, u'time_namelookup': 0.013, u'time_connect': 0.07, u'time_total': 2.005}
{u'time_redirect': 0.0, u'time_pretransfer': 0.058, u'time_appconnect': 0.0, u'time_starttransfer': 0.279, u'time_namelookup': 0.013, u'time_connect': 0.057, u'time_total': 1.06}
{u'time_redirect': 0.0, u'time_pretransfer': 0.086, u'time_appconnect': 0.0, u'time_starttransfer': 0.35, u'time_namelookup': 0.013, u'time_connect': 0.086, u'time_total': 0.812}
{u'time_redirect': 0.0, u'time_pretransfer': 0.072, u'time_appconnect': 0.0, u'time_starttransfer': 0.311, u'time_namelookup': 0.013, u'time_connect': 0.07, u'time_total': 1.309}

 With a JSON, there's nothing more simple than draw a graph, let's make it:

This graph could be better with operations' time instead of steps' time but sufficient for expose what I have in head.

References

• curl man page