Monday, June 11, 2012

Coding from the inside

Some time ago, a message on the Evennia mailing list asked about "softcode" support in Evennia. Softcode, a defacto standard in the MUX/MUCK/MUSH/MOO world, is conceptually a "safe" in-game scripting language that allows Players to extend the functionality of things without having access to the server source.

Now, Evennia is meant to be extended by normal Python modules. For coding game systems and advanced stuff, there is really no reason (in my opinion) for a small development team to not use a modern version control system and proper text editors rather than entering things on a command line without formatting.

But there is a potential fun aspect of having an online scripting language - and that is player content creation. Crafters wanting to add some pizazz to their objects, builders getting an extra venue of creativity with their rooms - that kind of thing. I didn't plan to add softcode support to Evennia, but it "sounded like an interesting problem" and one thing led to another.

Python is of course an excellent scripting language from the start. Problem is that it's notoriously tricky to make it run safely with untrusted code - like that inserted by careless or even potentially malignant Players. Scanning the Internet on this topic is a pretty intimidating experience - everywhere you hear that it shouldn't be done, and that the various suggested solutions of a "sandbox" are all inherently unsafe. Python's awesome introspection utilities is its own enemy in this particular case.

For Evennia we are however not looking for a full sandbox. We want a Python-like way for Players to influence a few determined systems. Moreover, we expect short, simple scripts that can do without most of Python's functionality (since our policy is that if it's too complex or large, it belongs in an external Python module). We could supply black-box "safe" functions to hide away complex functionality while still letting people change things we expect them to want to script. This willingness to accept heavy restrictions to the language should work to our advantage, I hope.

Evennia actually already has a safe "mini-language" in the form its "lock system", and thus it was a natural way for me to start looking. A "lock string" has a very restricted syntax - it's basically function calls optionally separated by boolean operators, like this:
lockfunc1(*args) and lockfunc(*args, **kwargs) and not lockfunc2()
The result of this evaluation will always be a boolean True/False (if the lock is passed or not). Only certain functions are available to use (controlled by the coder). The interesting thing is that this string can be supplied by the Player, but it is not evaluated - rather it's manually parsed, from left to right. The function names and arguments are identified (as for the rest, only and/or/not are allowed). The functions are then called explicitly (in Python code, not evaluated as a string) and combined to get a result. This should be perfectly safe as long as your functions are well-defined.


For the potential softcode language, I first took this hands-on approach - manually parsing the string into its components. I got a pretty decent demo going, but the possibilities are much larger than in the simple lockstring case. Just parsing would be one thing, but then to also make sure that each part is okay to use too is another matter ... It would probably be doable, but then I got to supplying some sort of flow-control. The code starts to become littered with special cases which is never a good sign.

So eventually I drifted off from the "lock-like" approach and looked into Python's ast module. This allows you to view Python code as an "abstract syntax tree" (AST).  This solves the parsing issues but once you start dealing with the AST tree you are sort of looking at the problem from the other end - rather than parsing and building the script from scratch it more becomes a matter of removing what is already there (an AST tree can be compiled directly back into Python code after all). It nevertheless seemed like the best way forward.

Testing a few different recipes from the web, I eventually settled on an approach which (with some modifications compared to the original) uses a whitelist (and a blacklist for some other things) to only allow a given set of ast nodes and items in the execution environment. It walks the AST tree before execution and kills dangerous Python structures in one large swath. I expanded on this a fair bit, cutting away a lot of Python functionality for our particular use case. Stuff like attribute acces and assignments, while loops and many other Pythonesque things went out the window.

Around this highly stunted execution system I then built the Evennia in-game scripting system. This includes in-game commands as well as scriptable objects with suitable slots defining certain functionality the Player might want to change. Each Evennia developer can also supply any set of "safe" blackbox functions to offer more functionality to their Player-coders.

A drawback is the lack of a functional timeout watchdog in case of a script running too long. I'm using Twisted's deferToThread to make sure the code blocks as little as possible, but alas, whereas I can check timeouts just fine,  the problem lies in reliably killing the errant sub-thread. Internet experts suggest this to be tricky to do safely at the best of times (with threads running arbitrary code at least), and not wanting to kill the Twisted server is not helping things. I pondered using Twisted's subprocess support, but haven't gotten further into that at this point. Fact is that most of the obvious DOS attack vectors (such as the while loop and huge powers etc) are completely disabled, so it should hopefully not be trivial to DOS the system (famous last words).

I've tentatively dubbed the softcode system "Evlang" to differentiate it from our normal database-related "Scripts".
So is Evlang "safe" to use by untrusted evil Players? Well, suffice to say I'm putting it up with a huge EXPERIMENTAL flag, with plenty of warnings and mentions of "on your own risk". Running Evennia in a chroot jail and with minimum permissions is probably to recommend for the security paranoid. Hopefully Evennia coders will try all sorts of nasty stuff with it in the future and report their finding in our Issue tracker!

But implementation details aside, I must admit it's cool to be able to add custom code like this - the creative possibilities really do open up. And Python - even a stunted version of it - is really very nice to work with, also from inside the game.

Wednesday, May 30, 2012

Dummies doing (even more) dummy things

This is a follow-up to the Dummies doing dummy things post. I originally posted info about this update on the mailing list some time back, but it has been pointed out to me that it might be a nice thing to put on the dev blog too since it's well, related to development!

I have been at it with further profiling in Evennia. Notably even more aggressive on-demand caching of objects as well as on-object attributes. I found from profiling that there was an issue with how object access checks were done - they caused the lock handler to hit the database every lock check as it retrieved the needed attributes.

Whereas this was not much of a hit per call, access checks are done all the time, for commands, objects, scripts, well everything that might need restricted access.
After caching also attributes, there is no need to hit the database as often. Some commands, such as listing all command help entries do see this effect (although you still probably wouldn't notice it unless you checked before and after like I did). More importantly, under the hood I'm happy to see that the profile for normal Evennia usage is no longer dominated by Django db calls but by the functional python code in each command - that is, in code that the end user have full control over anyway. I'd say this is a good state of affairs for a mud creation system.

 
In the previous "Dummies ..." post I ran tests with rather extreme conditions - I had dummy clients logging to basically act like heavy builders.  They dug rooms, created and defined objects randomly every five seconds (as well as walking around, reading help files, examining objects and other spurious things). In that post I found that my puny laptop could handle about 75 to 100 such builders at a time without me seeing a slowdown when playing. My old but more powerful desktop could handle some 200 or so.

Now, I didn't re-run these build-heavy tests with the new caches in place. I imagine the numbers will improve a bit, but it's just a guess. By all means, if you expect regularly having more than 100 builders on your game continuously creating 250 new rooms/objects per minute, do get back to me ...

... Instead I ran similar tests with more "normal" client usage. That is, I connected dummy clients that do what most players would do - they walk around, look at stuff, read help files and so on. I connected clients in batches of 100 at a time, letting them create accounts and logging in fully before connecting the next set of 100.

All in all I added 1000 dummy clients this way before I saw a noticeable lag on my small laptop. I didn't find it necessary to try the desktop at this point. Whereas this of course was with a vanilla Evennia install, I'd say it should be reasonable room for most realistic mud concepts to grow in.

With the rather extensive caching going on, it is interesting to know what the memory consumption is.
 
This graph shows memory info I noted down after adding each block of 100 players. The numbers fluctuated up and down a bit between readings (especially what the OS reported as total usage), which is why the lines are not perfectly straight.

In the end the database holds 1000 players (which also means there are 1000 Character objects), about as many rooms and about twice as many attributes.  The "idmapper cache" is the mapper that makes sure all Django model instances retain their references between accesses (as opposed to normal Django were you can never be sure of this). "Attribute cache" is a cache storing the attribute objects themselves on the Objects, to avoid an extra database lookup. All in all we see that keeping the entire database in memory takes about 450MB.

Evennia's caching is on-demand (so e.g. a room would not be loaded/cached until someone actually accessed it somehow). One could in principle run a script to clean all cached regularly if one was short on RAM - time will tell if this is something any user needs to worry about on modern hardware.

Monday, March 26, 2012

Shortcuts to goodness

Evennia, being a MUD-design system, needs to take some special considerations with its source code - its sole purpose is after all to be read, understood and extended.
Python is of course very readable by default and we have worked hard to give extensive comments and documentation. But for a new user looking into the code for the first time, it's still a lot of stuff to take in. Evennia consists of a set of Django-style "applications" interacting and in some cases inheriting from each other so as to avoid code duplication. For a new user to get an overview could therefore mean diving into more layers of code than one would like.

I have now gone through the process of making Evennia's API (Application Programming Interface) "flatter". This has meant exposing some of the most commonly used methods and classes at a higher level and fully documenting exactly what they inherit av every layer one looks at. But I have also added a new module ev.py to the root directory. It  implements "shortcuts" to all the most commonly used parts of the system, forming a very flat API. This means that what used to be

      from src.objects.objects import Object

can now be done as 

      from ev import Object

Not only should it be easier to find things (and less boilerplate code to write) but I like that one can also easier explore Evennia interactively this way.  Using a Python interpreter (I recommend ipython) you can just import ev and easily inspect all the important object classes, tab to their properties, helper functions and read their extensive doc strings.

Creating this API, i.e. going through and identifying all the useful entry points a developer will need, was also interesting in that it shows how small the API really is. Most of the ev interface is really various search functions and convenient options to inspect the database in various ways. The MUD-specific parts of the API is really lean, as befits a barebones MUD server/creation system.

Wednesday, February 22, 2012

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 ...

Friday, February 17, 2012

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.

Wednesday, February 15, 2012

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.

Sunday, February 5, 2012

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.