Profiling

Important

This is considered an advanced topic. It’s mainly of interest to server developers.

Sometimes it can be useful to try to determine just how efficient a particular piece of code is, or to figure out if one could speed up things more than they are. There are many ways to test the performance of Python and the running server.

Before digging into this section, remember Donald Knuth’s words of wisdom:

[…]about 97% of the time: Premature optimization is the root of all evil.

That is, don’t start to try to optimize your code until you have actually identified a need to do so. This means your code must actually be working before you start to consider optimization. Optimization will also often make your code more complex and harder to read. Consider readability and maintainability and you may find that a small gain in speed is just not worth it.

Simple timer tests

Python’s timeit module is very good for testing small things. For example, in order to test if it is faster to use a for loop or a list comprehension you could use the following code:

    import timeit
    # Time to do 1000000 for loops
    timeit.timeit("for i in range(100):\n    a.append(i)", setup="a = []")
   <<< 10.70982813835144
    # Time to do 1000000 list comprehensions
    timeit.timeit("a = [i for i in range(100)]")
   <<<  5.358283996582031

The setup keyword is used to set up things that should not be included in the time measurement, like a = [] in the first call.

By default the timeit function will re-run the given test 1000000 times and returns the total time to do so (so not the average per test). A hint is to not use this default for testing something that includes database writes - for that you may want to use a lower number of repeats (say 100 or 1000) using the number=100 keyword.

In the example above, we see that this number of calls, using a list comprehension is about twice as fast as building a list using .append().

Using cProfile

Python comes with its own profiler, named cProfile (this is for cPython, no tests have been done with pypy at this point). Due to the way Evennia’s processes are handled, there is no point in using the normal way to start the profiler (python -m cProfile evennia.py). Instead you start the profiler through the launcher:

evennia --profiler start

This will start Evennia with the Server component running (in daemon mode) under cProfile. You could instead try --profile with the portal argument to profile the Portal (you would then need to start the Server separately).

Please note that while the profiler is running, your process will use a lot more memory than usual. Memory usage is even likely to climb over time. So don’t leave it running perpetually but monitor it carefully (for example using the top command on Linux or the Task Manager’s memory display on Windows).

Once you have run the server for a while, you need to stop it so the profiler can give its report. Do not kill the program from your task manager or by sending it a kill signal - this will most likely also mess with the profiler. Instead either use evennia.py stop or (which may be even better), use @shutdown from inside the game.

Once the server has fully shut down (this may be a lot slower than usual) you will find that profiler has created a new file mygame/server/logs/server.prof.

Analyzing the profile

The server.prof file is a binary file. There are many ways to analyze and display its contents, all of which has only been tested in Linux (If you are a Windows/Mac user, let us know what works).

You can look at the contents of the profile file with Python’s in-built pstats module in the evennia shell (it’s recommended you install ipython with pip install ipython in your virtualenv first, for prettier output):

evennia shell

Then in the shell

import pstats
from pstats import SortKey

p = pstats.Stats('server/log/server.prof')
p.strip_dirs().sort_stats(-1).print_stats()

See the Python profiling documentation for more information.

You can also visualize the data in various ways.

  • Runsnake visualizes the profile to give a good overview. Install with pip install runsnakerun. Note that this may require a C compiler and be quite slow to install.

  • For more detailed listing of usage time, you can use KCachegrind. To make KCachegrind work with Python profiles you also need the wrapper script pyprof2calltree. You can get pyprof2calltree via pip whereas KCacheGrind is something you need to get via your package manager or their homepage.

How to analyze and interpret profiling data is not a trivial issue and depends on what you are profiling for. Evennia being an asynchronous server can also confuse profiling. Ask on the mailing list if you need help and be ready to be able to supply your server.prof file for comparison, along with the exact conditions under which it was obtained.

The Dummyrunner

It is difficult to test “actual” game performance without having players in your game. For this reason Evennia comes with the Dummyrunner system. The Dummyrunner is a stress-testing system: a separate program that logs into your game with simulated players (aka “bots” or “dummies”). Once connected, these dummies will semi-randomly perform various tasks from a list of possible actions. Use Ctrl-C to stop the Dummyrunner.

Warning

You should not run the Dummyrunner on a production database. It
will spawn many objects and also needs to run with general permissions.

This is the recommended process for using the dummy runner:

  1. Stop your server completely with evennia stop.

  2. At the end of your mygame/server/conf.settings.py file, add the line

     from evennia.server.profiling.settings_mixin import *
    

    This will override your settings and disable Evennia’s rate limiters and DoS-protections, which would otherwise block mass-connecting clients from one IP. Notably, it will also change to a different (faster) password hasher.

  3. (recommended): Build a new database. If you use default Sqlite3 and want to keep your existing database, just rename mygame/server/evennia.db3 to mygame/server/evennia.db3_backup and run evennia migrate and evennia start to create a new superuser as usual.

  4. (recommended) Log into the game as your superuser. This is just so you can manually check response. If you kept an old database, you will not be able to connect with an existing user since the password hasher changed!

  5. Start the dummyrunner with 10 dummy users from the terminal with

     evennia --dummyrunner 10
    

    Use Ctrl-C (or Cmd-C) to stop it.

If you want to see what the dummies are actually doing you can run with a single dummy:

evennia --dummyrunner 1

The inputs/outputs from the dummy will then be printed. By default the runner uses the ‘looker’ profile, which just logs in and sends the ‘look’ command over and over. To change the settings, copy the file evennia/server/profiling/dummyrunner_settings.py to your mygame/server/conf/ directory, then add this line to your settings file to use it in the new location:

DUMMYRUNNER_SETTINGS_MODULE = "server/conf/dummyrunner_settings.py"

The dummyrunner settings file is a python code module in its own right - it defines the actions available to the dummies. These are just tuples of command strings (like “look here”) for the dummy to send to the server along with a probability of them happening. The dummyrunner looks for a global variable ACTIONS, a list of tuples, where the first two elements define the commands for logging in/out of the server.

Below is a simplified minimal setup (the default settings file adds a lot more functionality and info):

# minimal dummyrunner setup file

# Time between each dummyrunner "tick", in seconds. Each dummy will be called
# with this frequency.
TIMESTEP = 1

# Chance of a dummy actually performing an action on a given tick. This
# spreads out usage randomly, like it would be in reality.
CHANCE_OF_ACTION = 0.5

# Chance of a currently unlogged-in dummy performing its login action every
# tick. This emulates not all accounts logging in at exactly the same time.
CHANCE_OF_LOGIN = 0.01

# Which telnet port to connect to. If set to None, uses the first default
# telnet port of the running server.
TELNET_PORT = None

# actions

def c_login(client):
    name = f"Character-{client.gid}"
    pwd = f"23fwsf23sdfw23wef23"
    return (
        f"create {name} {pwd}"
        f"connect {name} {pwd}"
    )

def c_logout(client):
    return ("quit", )

def c_look(client):
    return ("look here", "look me")

# this is read by dummyrunner.
ACTIONS = (
    c_login,
    c_logout,
    (1.0, c_look)   # (probability, command-generator)
)

At the bottom of the default file are a few default profiles you can test out by just setting the PROFILE variable to one of the options.

Dummyrunner hints

  • Don’t start with too many dummies. The Dummyrunner taxes the server much more than ‘real’ users tend to do. Start with 10-100 to begin with.

  • Stress-testing can be fun, but also consider what a ‘realistic’ number of users would be for your game.

  • Note in the dummyrunner output how many commands/s are being sent to the server by all dummies. This is usually a lot higher than what you’d realistically expect to see from the same number of users.

  • The default settings sets up a ‘lag’ measure to measaure the round-about message time. It updates with an average every 30 seconds. It can be worth to have this running for a small number of dummies in one terminal before adding more by starting another dummyrunner in another terminal - the first one will act as a measure of how lag changes with different loads. Also verify the lag-times by entering commands manually in-game.

  • Check the CPU usage of your server using top/htop (linux). In-game, use the server command.

  • You can run the server with --profiler start to test it with dummies. Note that the profiler will itself affect server performance, especially memory consumption.

  • Generally, the dummyrunner system makes for a decent test of general performance; but it is of course hard to actually mimic human user behavior. For this, actual real-game testing is required.