6 replies to this topic

[snowmanZOMG]

I've recently inherited a small 2D engine which uses Lua for implementing the core game logic. Over the course of implementing new features and doing some performance tuning, I've moved an increasingly large percentage of time into the Lua code (as opposed to the C++ code). I've come to the point now where in some situations, Lua code takes up significant portions of my running time and I'd like to track those hotspots down more finely.

As implied earlier, most of my performance tuning was done in the core engine which is C++ code. At this point, I have some gprof callstacks which look like this:

Flat profile:
Each sample counts as 0.01 seconds.
  %   cumulative   self			  self	 total
time   seconds   seconds	calls  ms/call  ms/call  name
16.45	  1.76	 1.76							 luaS_newlstr
  9.25	  2.75	 0.99							 luaH_getstr
  8.41	  3.65	 0.90							 luaV_execute
  6.17	  4.31	 0.66							 luaD_precall
  4.02	  4.74	 0.43							 luaV_gettable
  3.93	  5.16	 0.42							 luaC_separateudata
  3.64	  5.55	 0.39							 index2adr
  3.46	  5.92	 0.37							 sweeplist
  3.08	  6.25	 0.33							 GCTM
  2.43	  6.51	 0.26							 lua_getfield
  2.34	  6.76	 0.25							 propagatemark
  2.20	  7.00	 0.24							 luaD_poscall
  1.87	  7.20	 0.20							 f_call
  1.87	  7.40	 0.20							 luaS_newudata
  1.50	  7.56	 0.16 17920943	 0.00	 0.00  luaSet(lua_State*, LuaField const*, void*, int)
  1.40	  7.71	 0.15							 luaH_getnum

That's approximately 70% of my running time for this trace. I would really like to see where in the code all of this time is being spent, but I'm not sure what my best options are in this regard. Lua profilers I've looked at (but so far haven't been successful in actually running) don't seem nearly as polished as some of the C++ tools out there.

Currently, I'm using Lua 5.1 and just write my Lua code in emacs on a Linux system. I'm relatively new to Lua, so I could just be doing some strange things, but I'm just finding it very difficult to know where all of the time is being spent without having a profiler to tell me where to investigate. Also, any good morality guides on maintaining high performance in Lua would be appreciated.

[e‍dd]

Handy: http://lua-users.org/wiki/OptimisationTips

Also, have you tried LuaJIT? It's much, much faster than the reference interpreter (on supported architectures).

[snowmanZOMG]

I just tried using LuaJIT, but it doesn't look like it has made any observable difference in performance. It has definitely changed my profiler outputs, but the actual performance difference looks completely negligible over the reference interpreter. Perhaps this just means the performance bottlenecks remain in my C++ code? I find this quite puzzling since my previous profiles suggest otherwise.

[e‍dd]

It could simply be that you're doing a lot of communication between C++-land and Lua-land, and so shuffling/encoding/decoding data between these two worlds is taking its toll on performance. You'll have to look at what the functions in your profile actually do.

[snowmanZOMG]

I've also considered this, but it seems if this were true, then I would expect some of my binding functions to show up in my profiles. They simply don't seem to appear anywhere near the heavy hitters. Right now, it seems to me that my best bet is find a profiler that can maintain its state between embedded Lua calls or write my own profiler...

[Adam_42]

Are you doing lots of string manipulation? luaS_newlstr() is string related, and allocates memory.

Also you seem to be making an awful lot of function calls to luaSet() - they are tiny fractions of a millisecond each call, but it's being called a lot.

How many milliseconds per frame is being spent on lua execution?

[snowmanZOMG]

Yes, I ended up doing a thorough search through my Lua code last night and I ended up finding that the original author of the code put in some string concatenation code in a loop that gets called very often... quite literally screamed in horror. In the process of removing those string ops.

For that profile, I don't recall exactly how much the total time per frame it was, but I was running a very heavy test which was something like 50-100 ms per frame. So if it was 50 ms, then 35 ms per frame based on that profile.