Dummies doing dummy things

It can often be interesting to test hypothetical situations. So the other day I did a little stress test to see how Evennia handles many players. This is a follow-up to the open bottlenecks post.

Evennia, being based on Twisted, is an asynchronous mud server. This means that the program is not multi-threaded but instead it tries to divide up the code it runs into smaller parts. It then quickly switches between executing these parts in turn, giving the impression of doing many things at the same time. There is nothing magical about this - each little piece of code blocks the queue as it runs. So if a particular part takes too long, everyone else will have to wait for their turn. Likewise, if Twisted cannot flip through the queue as fast or faster than new things get added to it, it will start to fall behind.

The good thing is that all code in the queue will run, although if the event loop cannot keep up there will be a noticeable delay before it does. In a mud, this results in "lagging" (in addition to whatever lag is introduced by your network connection). Running Evennia with a handful of users shows no effect of this, but what happens when we start to add more and more players?

My "dummy runner" is a stand alone Twisted program that opens any number of Telnet connections to the Evennia server. Each such "dummy" client is meant to represent a player connecting. In order to mimic actual usage, a dummy client can perform a range of actions:

• They can create a new account and log in
• They can look around and read random help files
• They can create objects, name and describe them (for testing, the server is set to grant build privileges to all new players)
• They can examine objects, rooms and themselves 
• They can dig new rooms, naming all exits and giving aliases
• They can move between rooms

The clients tick every 5 seconds, at which time there is a 10% chance each will perform an action from the list above (login first, then one of the others at random).  This is meant to spread out the usage a bit, like it would be with real people. Some of these actions actually consist of multiple commands sent to the server (create + describe + set etc), possibly simulating people using shortcuts in their client to send several commands at the same time.

Results

Note that I didn't do a proper objective benchmark. Rather, I logged in and ran commands to see, very subjectively, how the game "felt" with a number of different players. The lag times are rough estimates by putting time() printouts in the server.

First I tried with my development laptop, a Thinkpad X61s. It's about 5 years old by now and certainly not the fastest thing out there, mainly it's small and thin and has great battery life. I used a MySQL database.

• 1-50 dummy players didn't show any real difference from playing alone. It's not so strange; 50 players meant on average 5 of them would do an action every 5 seconds. My laptop could handle that just fine.
• 50-75 dummy players introduced a brief lag (less than a second) when they logged in. 5-7 players logging in at exactly the same time will after all mean a lot of commands sent to the server (they not only log in, they create a new character at the same time). Throughout these tests, clients logging in showed the greatest effect on lag. I think this is mostly an artifact of how the clients operate by sending all relevant login commands at the same time. Once all were logged in, only brief lag occurred at random times as coincidence had all clients do something expensive at the same time.
• 75-100 dummy players introduced longer lags during login, as on average 7-10 clients were now logging in at exactly the same time. Most commands were unaffected, but occasionally there were some noticeable "hiccups" of about a second depending on what the clients were doing.
• 100-150 dummy players - here things started to go downhill rapidly. Dummy client login caused seriously lagging and at 150 logged in players, there were 15 exactly simultaneous actions coming in. This was clearly too much for my laptop; it lead to a very varying lag of 1-10 seconds also for simple commands.

Next I tried my desktop machine. This is also not bleeding edge; it's a 4-year old machine with 3GHz processor and 4GB RAM. Since I don't have MySQL on this machine, I used SQLite3, which is interesting in its own right since it's Evennia's default database.

• 1-75 dummy players didn't affect the feel of the game one bit.
• 75-100 showed some occasional effects starting to appear during dummy client logins. 
• 100-150 dummy players didn't introduce more than a few hiccups of less than a second when approximately 15 clients decided to do something expensive at the same time.
• 150-200 introduces 2-3 seconds lag during client mass-logins, but once all clients had connected, things worked nicely with only brief random hiccups.
• 200-250 showed the lag getting more uneven, varying from no lag at all to 2-3 seconds for normal times and up to 5 seconds when clients were logging in.
• 250-300 dummy players showed login lag getting worse. The general lag varied from 0-5 seconds depending on what the other clients were up to.
• 300-350 dummy players, about double of what the laptop could handle,  the CPU was not able to keep up anymore. The system remained stable and all commands got executed - eventually. But the lag times went up very rapidly.

Conclusions

So, based on this I would say 50-75 was a comfortable maximum number of (dummy) players to have on my laptop whereas the desktop could handle around 150 without much effort, maybe up to 250 on a good day.

So what does these numbers mean? Well, the dummy clients are rather extreme, and 100+ builders walking around building stuff every 5 seconds is not something one will see in a game. Also so many logging on at the same time is not very likely (although it could happen after a crash or similar). If anything the usage pattern of human players will be more random and spread out, which helps the server to catch up on its event queue.

On the other hand these tests were run with a vanilla Evennia install - a full game might introduce more expensive commands and subsystems. Human players may also introduce random spikes of usage. So take this for what it is - a most subjective, un-scientific and back-of-the-envelope measure.

All in all though, I would say that few MUDs these days see 30 concurrent online users, even less 100 ...

Commands and you

Commands define how a Player interacts with a given game. In a text-based game it's not amiss to say that the available commands are paramount to the user experience. In principle commands could represent mouse clicks and other modernistic GUI sugar - but for this blog I'll stick with the traditional entered text.

Like most things in Evennia, Commands are Python classes. If you read the documentation about them you'll find that the command classes are clumped together and tacked onto all objects in-game. Commands hanging onto a Character object will be available all the time, whereas commands tacked onto a grandfather's clock will only be available to you when you stand in front of said clock.

The interesting thing with Commands being classes is that each Character gets a separate instance of each command. So when you do look 100 times in a row, it's always the same Look command instance that has its methods called by the engine. Apart from being an efficient way to handle things, this has a major neat side-effect:

You can store things on the Command object and whatever you store can be retrieved next time you execute that command.

I find this very cool mainly because I didn't really plan with this in mind when designing the command system - it was a happy side effect. A use I have thought of is to implement cooldowns. Say you have a powerful bash command. It makes a lot of damage, but you need time to recover between bashes. So when you do the bash  command the Bash command object simply stores the current time on itself:

self.last_bash = time.time()

Next time the Player tries to use bash, all the command object needs to is to check if self.last_bash is set, and compare the time stored herein with the current time. No twisted tasks needed, no overhead. Very neat and tidy.

Another nice functionality (just added today in fact) is that Evennia can be set to store a copy of the last command object executed. What can one do with this? For starters, it allows for commands to check what a previous command was. This can be useful in itself, but since the next command actually have access to (a copy of) the previous command object itself, it will allow a lot more than that.

Consider a look command that remembers whatever object it is looking at. Since the Look command is a Python object, it simply stores the looked-at object on itself before returning the normal info to the Player. Next, let's assume we use a get command. If no argument is given to this get (no given object to pick up), the get normally returns an error. But it can now instead peek at the previous command (look) and see what that command operated on. This allows for nice potential constructs like

>> look [at] box 

>> get [it]

Evennia does not use this functionality in its default command set, but it offers some very powerful possibilities for MUD creators to design clever parsing schemes.

Such a small thing ...

Lately I went back to clean up and optimize the workings of Evennia's Attributes. I had a nice idea for making the code easier to read and also faster by caching more aggressively. The end result was of course that I managed to break things. In the end it took me two weeks to get my new scheme to a state where it did what it already did before (although faster).

Doing so, some of the trickier aspects of implementing easily accessible Attributes came back into view, and I thought I'd cover them here. Python intricacies and black magic to follow. You have been warned. 

Attributes are, in Evennia lingo, arbitrary things a user may want to permanently store on an object, script or player. It could be numbers or strings like health, mana or short descriptions, but also more advanced stuff like lists, dictionaries or custom Python objects.

Now, Evennia allows this syntax for defining an attribute on e.g. the object myobj:

myobj.db.test = [1,2,3,4]

This very Pythonic-looking thing allows a user to transparently save that list (or whatever) to an attribute named, in this example, test. This will save to the database.
 What happens is that db, which is a special object defined on all Evennia objects, takes all attributes on itself and saves them by overloading its __setattr__ default method (you can actually skip writing db most of the time, and just use this like you would any Python attribute, but that's another story).

Vice-versa,

value = myobj.db.test

This makes use of the db object's custom __get_attribute__ method behind the scenes. The test attribute is transparently retrieved from the database (or cache) for you.

Now, the (that is, my) headache comes when you try to do this:

myobj.db.test[3] = 5

Such a small, normal thing to do! Looks simple, right? It is actually trickier than it looks to allow for this basic functionality.
The problem is that Python do everything by reference. The list is a separate object and has no idea it is connected to db. db's __get_attribute__ is called, and happily hands over the list test. And then db is out of the picture!. My nifty save-to-database feature (which sits in db) knows nothing about how the 3rd index of the list test now has a 5 instead of a 4.

Now, of course, you could always do this:

temp = myobj.db.test

temp[3] = 5

myobj.db.test = temp

This will work fine. It is however also clumsy and hardly intuitive. The only solution I have been able to come up with is to have db return something which is almost a list but not quite. It's in fact returning an object I not-so-imaginatively named a PackedList. This object works just like a list, except all modifying methods on it makes sure to save the result to the database. So for example, what is called when you do mylist[3] = 4 is a method on the list named __setitem__. I overload this, lets it do its usual thing, then call the save.

myobj.db.test[3] = 5

now works fine, since test is in fact a PackedList and knows that changes to it should be saved to the database. I do the same for dictionaries and for nested combinations of lists and dictionaries. So all is nice and dandy, right?  Things work just like Python now?

No, unfortunately not. Consider this:

myobj.db.test = [1, 3, 4, [5, 6, 7]]

A list with a list inside it. This is perfectly legal, and you can access all parts of this just fine:

val = myobj.db.test[3][2] # returns 7!

But how about assigning data to that internal nested list?

myobj.db.test[3][2] = 8

We would now expect test to be [1, 3, 4, [5, 6, 8]]. It is not. It is infact only [5, 6, 8]. The inner list has replaced the entire attribute! 

What actually happens here? db returns a nested structure of two PackedLists. All nice and dandy.  But Python thinks they are two separate objects! The main list holds a reference to the internal list, but as far as I know there is no way for the nested list to get the back-reference to the list holding it! As far as the nested list knows, it is all alone in the world, and therefore there is no way to trigger a save in the "parent" list.
 The result is that we update the nested list just fine - and that triggers the save operation to neatly overwrite the main list in the cache and the database.
 
This latter problem is not something I've been able to solve. The only way around it seems to use a temporary variable, assign properly, then save it back, as suggested earlier. I'm thinking this is a fundamental limitation in the way cPython is implemented, but maybe I'm missing some clever hack here (so anyone reading who has a better solution)?

Either way, the db functionality makes for easy coding when saving things to the database, so despite it not working quite like normal Python, I think it's pretty useful.

Evennia's open bottlenecks

Since Evennia hit beta I have been mostly looking behind the scenes to see what can be cleaned up and not in the core server. One way to do that is to check where the bottlenecks are. Since a few commits, Evennia's runner has additions for launching the Python cProfiler at startup. This can be done for both the Portal and the Server separately.

I have created a test runner (soon to hit trunk) that launches dummy clients. They log on and then goes about their way executing commands, creating objects and so on. The result of looking at the profiling data (using e.g. runsnake) has been very interesting.

Firstly, a comparably small part of execution time is actually spent in Evennia modules - most is spent using Python built-ins and in the Twisted/Django libraries. This is promising in a way - at least there are no expensive loops in the Evennia code itself that sucks up cycles. Of course it also means we depend heavily on django/twisted (no surprise there) and especially when it comes to database access, I know there could be more caching going on so as to cut down on db calls. 

Of the Evennia modules, a lot of time is spent in getting properties off objects - this is hard to avoid, it a side effect of Evennia's typeclass system - and this is cached very aggressively already. What also stands out as taking a considerable time is the command system - the merging of command sets in particular does a lot of comparing operations. This happens every time a command is called, so there are things to be done there. The same goes for the help system; it needs to collect all the currently active command sets for the calling player. Maybe this could be cached somehow.

More work on this is needed, but as usual optimization is a double-edged sword. Evennia is written to have a very readable code. Optimization is usually the opposite of readable, so one needs to thread carefully. 

About this dev blog

This is to be my Evennia dev blog, but it will also cover various other musings concerning programming in general and mud designing in particular. Whereas the Evennia mailing list remains the main venue for discussion, I will probably use this blog for announcing features too.

Some background:
Evennia is a Python MUD/MUX/MU* server. More correct is probably to call it a "MUD-building system". The developer codes their entire game using normal Python modules. All development is done with the full power of Python - gritty stuff like database operations and network communication are hidden away behind custom classes that you can treat and modify mostly like any Python primitives.

Since the server is based on the Twisted and Django technologies we can offer many modern features out of the box. Evennia is for example its own web server and comes with both its own website and an "comet"-style browser mud client. But before this turns into even more of a sales pitch, I'll just just direct you to the evennia website if you want to know more. :)

I, Griatch, took over the development of Evennia from the original author, Greg Taylor, in 2010.