reports of miniwindow slowness?

Posted by Fiendish on Mon 15 Nov 2010 09:53 PM — 33 posts, 122,976 views.

USA Global Moderator #0
Nick, I'm not sure what's going on here, but here's a compilation of a few comments that I've gathered about miniwindow performance. Can you give me feedback on this?

A player reports the following computer configuration:

Celeron 2.5 GHz dual-core, 4GB DDR2/1066, onboard Intel graphics. Ubuntu 10.04 Server with Ubuntu Studio desktop pkg, running Mush under Wine 1.0.1

And the following problem descriptoin:

"I don't have a high-end graphics card, and miniwindows are MUCH more graphics-card-intensive. I get a 30-second lag with runto sometimes. I removed the health bar and communications miniwindows and got back MOST of the speed, but that's not great. I'm using Mush 4.63ish, (one of the recent bastmush setups)."

I don't get the "graphics card intensive" claim. Is this anything people should be concerned about?
Australia Forum Administrator #1
I have been getting occasional slowdowns myself, but I am a bit of an atypical user. For one thing, I mainly develop rather than play. For another, I actually run XP under VMware on a Mac, something most people probably don't do.

Generally it seems fine to me, but I get the occasional pause that makes me a bit uneasy. On modern PCs however there is so much going on that it could be a background process kicking in (like a backup).

If something reproducible is happening, we need to get to the bottom of it. The speed of the graphics card shouldn't really matter, but perhaps with a large monitor, and with MUSHclient sized to take up most of it, and lots of miniwindows, it might push the boundaries of what can be shoved out to the card, bearing in mind I don't use hardware acceleration like DirectX.

I would be investigating whether any of the following might be responsible:

  • The recent changes to the blending drawing (which uses an API not previously used)
  • The operating system. Ubuntu? Windows 7?
  • How long the client has been running - is some memory leak occurring?
  • The size of the output buffer - have they gone from RAM to paging disk?
  • Lua garbage-collection. If that kicks in, there might be a big lag spike. Maybe someone's plugin creates lots of temporary items (eg. tables) which get collected every 30 seconds.
  • How big is their MUSHclient window sized?
  • Maybe some plugin is doing Repaint rather than Redraw, and forcing much more drawing than the system can cope with.
  • Can the slowdowns be pinned down to a particular version change? For instance, going back 10 versions, do the problems go away?
  • Can a particular plugin be identified as the problem?
  • If running under Wine, it is possible that a change has occurred that is not for the best, as far as MUSHclient is concerned. So reverting Wine versions might help. Or alternatively, upgrading to the latest Wine.
  • Is there some other factor? eg. adding a plugin that plays sounds.
  • Some things are known to hang the system, in particular if you use the LuaSocket to grab a web page - this is synchronous, so it might cause a few seconds delay. My new plugin that looks for new versions is an example, but that is designed to only run every 7 days, and only when it is loaded, not while you are playing.

Amended on Mon 15 Nov 2010 11:04 PM by Nick Gammon
Australia Forum Administrator #2
You might get a clue from the "summary" plugin. Typing "summary" shows, amongst other things:


Scripting for: 2.071758 seconds.
-- Triggers, aliases, timers, variables --
** Triggers: 34 in world file, triggers enabled: yes. [Triggers]
   27 enabled, 15 regexp, 15093 attempts, 0 matched, 0.034890 seconds.
** Aliases: 38 in world file, aliases enabled: yes. [Aliases]
   37 enabled, 0 regexp, 1554 attempts, 0 matched, 0.003419 seconds.
** Timers: 2 in world file, timers enabled: yes. [Timers]
   2 enabled, 12 fired.
   Timers checked every 0.1 seconds.
** Variables: 25. [Variables]


If one of those timings is very high (eg. scripting) that might point to where we could look further. I could add more metrics to measure the amount of time in scripting, per plugin.
Australia Forum Administrator #3
Version 4.70, now released, has an extra metric for timing the scripts in each plugin. You can access this from scripting, or by doing a Debug ("summary"). In part, you might see this:


ID: 5c13fd1ed4511dbe0ea00ff0, 'Mapper_Telnet2', (Lua, 0.587 s) Enabled [Al Va Cb]
ID: 565dae21eb816a2fdb8d50f9, 'Chat_Capture_Miniwindow', (Lua, 0.021 s) Enabled [Tr Al Va Cb]
ID: 2eb7301f3ac637b02a4467ef, 'Version_Check', (Lua, 0.008 s) Enabled [Al Ti Va]


Of course, you would need to have a general feel for what is a realistic time to spend in the plugin, and the figures will gradually go up. However if the mapper plugin showed a 20 second amount, just after a 19 second delay, only a few seconds after starting the client, then that would tend to point to the culprit.
USA Global Moderator #4
Cool. I like that new metric. Offhand, how complicated do you think it would be to go a step further and do per-function times?
Australia Forum Administrator #5
I seem to recall you asked me that before.

Template:post=10279
Please see the forum thread: http://gammon.com.au/forum/?id=10279.


Those remarks still apply, really. It is hard for the calling program to get down to function level, but the ideas there could narrow down the problem in a plugin (if one is suspected).
USA Global Moderator #6
Nick Gammon said:

I seem to recall you asked me that before.

Oops. Your memory is better than mine.
USA Global Moderator #7
Extreme slowdown can probably be pinned on the GMCP mapper.
I can tell you that with no other plugins loaded on a fresh launch of MUSHclient, doing a speedwalk causes so much processing inside the mapper that the screen doesn't refresh until the whole thing is over.

The only reason the screen gets refreshed at all during a speedwalk, it seems, is if you have another plugin running (like the ascii overhead map) that forces repaints. Then you get your updates, but they are very slow.
Australia Forum Administrator #8
There are some mapper configuration options you can set that will affect its speed:

  • Depth - this is how many rooms out from your starting point it "looks". Obviously the lower the faster, because it has less rooms to draw.
  • Size (x and y). Since it stops drawing at the edge, a small map will be faster than a large one.
  • Zoom. If you zoom in, the rooms are drawn larger, and thus there are less to draw in a given map size.


Also I would look at how you are getting the room information (the get_room function). In my version I cached the room information. If you are getting it from the database every time that would probably slow it down, a lot.

Can you give me a link to the current GMCP mapper? And any support files? Is it live on Aardwolf or just on the test port?
USA Global Moderator #9
Entire ready to use MUSHclient package available in my subversion repo with:
svn checkout http://aardwolfclientpackage.googlecode.com/svn/trunk/MUSHclient MUSHclient-fiendish

or I've made a .zip of the latest version (r92) available at:
http://www.megaupload.com/?d=BJKMXEP9

And it's live on main.
Amended on Tue 16 Nov 2010 07:59 PM by Fiendish
Australia Forum Administrator #10

Filename: MUSHclient.zip
File description: aardwolf mushclient package
File size: 14.92 MB


How does my 2.98 Mb download, with a couple of plugins added, become 14.92 Mb? Surely the mapper database isn't that big?
Australia Forum Administrator #11
Hey it looks really cool! Well done, you are a master.

And, it's fast too!


-- Plugins (Processing order) --
ID: 3e7dedbe37e44942dd46d264, 'GMCP_handler', (Lua, 6.361 s) Enabled [Al Cb]
ID: b555825a4a5700c35fa80780, 'Chat_Capture_Miniwindow', (Lua, 0.492 s) Enabled [Tr Al Va Cb]
ID: 3f498d929793c12cb70fb59e, 'Aardwolf_Ascii_Mapper', (Lua, 1.820 s) Enabled [Tr Va Cb]
ID: c293f9e7f04dde889f65cb90, 'Aardwolf_Main_Layout', (Lua, 0.014 s) Enabled [Al Va Cb]
ID: b11c1b7fe961558d6f6aba5e, 'Aardwolf_Helper_Aliases', (Lua, 0.000 s) Enabled [Al]
ID: ef4a86dbc9cd4dd6f4c69386, 'Aardwolf_Statmon', (Lua, 1.747 s) Enabled [Va Cb]
ID: ef4a86dbc9cd4dd6f4c69385, 'Aardwolf_Health_Bars', (Lua, 2.108 s) Enabled [Va Cb]
ID: b6eae87ccedd84f510b74714, 'Aardwolf_GMCP_Mapper', (Lua, 2.776 s) Enabled [Tr Al Va Cb]
ID: 71a90acddb14f784437b8b80, 'Summary', (Lua, 0.028 s) Enabled [Al]
** Plugins: 9 loaded, 9 enabled.


That was after running around a bit. Can't say I notice any annoying slowdown. Admittedly I have a fast PC. And I sized the mapper window to be quite large.

2.8 GHz Intel Core i7 (4 core). However this is running VMware on a Mac, so it is a "guest" operating system, if you like. The Mac part is humming along in the background.

And the PC you mention in the original post, being 2.5 GHz, isn't much slower.
Australia Forum Administrator #12
Just tested on Ubuntu (which I actually have running simultaneously with Windows XP). Still seems fast. So in my case I have running at the same time, on the same box:

  • Mac OS/X
  • Windows XP (VMware)
  • Ubuntu (VMware)


And I would say, you wouldn't complain about performance. Certainly nothing like what you describe with windows that don't refresh until you stop walking. I can take a video if you like.
Australia Forum Administrator #13
Just to be sure, I tested also on my Ubuntu 10.10. This has Wine 1.2.1 on it. Still works fine.

I think the other Ubuntu was 8 or something.
Australia Forum Administrator #14
Fiendish, you want to turn on the "wrap output" checkbox (output configuration). Otherwise long chat lines break in the middle of a word which looks crappy. The "wrap output" wraps at the nearest space.
Australia Forum Administrator #15
And personally I would throw in the Omit_Blank_Lines plugin - gets rid of the rather useless blank lines.
Australia Forum Administrator #16
You can see it here:




This was running under Ubuntu 10.10, MUSHclient 4.70, Wine 1.2.1.

2.8 Ghz CPU (Intel) - one processor allocated to the Ubuntu virtual machine.

1 Gb RAM allocated to virtual machine.


The video is "real time" - not sped up at all. I omitted a couple of boring bits while I worked out what to do next, or typed "recall" into the command window.

I initally speedwalk around Aylor by clicking on room names, then "recall" and "runto verume" to do a lengthy run from the city to another zone.

As you can see, the mapper window is quite large, it updates quickly, along with the smaller map, and everything seems quite smooth.
Amended on Mon 25 Nov 2013 08:35 PM by Nick Gammon
USA Global Moderator #17
Errr. A couple of things with the video...

1) That's about what I see too with all the plugins running, and for a speedwalk on Aardwolf that's incredibly slow. Disable the gmcp mapper and compare how long it takes to run from room to room doing something like "run 10w10e10w10e" on the continent.

2) Can you do another video with the gmcp mapper removed but other plugins still running?

3) And one with the other plugins removed but the gmcp mapper still running?

My experience is that for case 3 the screen will not update during a speedwalk, and only case 2 will be fast.
Amended on Wed 17 Nov 2010 01:05 AM by Fiendish
USA Global Moderator #18
Nick Gammon said:


Filename: MUSHclient.zip
File description: aardwolf mushclient package
File size: 14.92 MB


How does my 2.98 Mb download, with a couple of plugins added, become 14.92 Mb? Surely the mapper database isn't that big?

I think my archiver is broken. It's clearly not doing any compression.
Australia Forum Administrator #19
Fiendish said:

Extreme slowdown can probably be pinned on the GMCP mapper.
I can tell you that with no other plugins loaded on a fresh launch of MUSHclient, doing a speedwalk causes so much processing inside the mapper that the screen doesn't refresh until the whole thing is over.


But it was hardly that was it? It refreshed as you changed rooms.
USA Global Moderator #20
See my comment above. It only refreshes when the other plugins call Repaint() once per room. If you disable those other plugins (or change repaint to redraw probably), then it won't.
Amended on Wed 17 Nov 2010 01:31 AM by Fiendish
#21
I watched the video. I thought it was rather slow. Here is why I think that:

I used enter and rt weather in the same command line.

1. Main window and ascii map plugin with a 11 seconds speedwalk time.

2. Main Window, ascii map plugin, and stats, with a 13 seconds speedwalk time.

3. Main Window, ascii map plugin, stats, and health bar with a 17 seconds speedwalk time.

4. Main Window, ascii map plugin, stats, and chat window with a 13 seconds speedwalk time.


5. Main Window, Ascii Map Plugin, Stats, Health Bar, Chats Window with a 16 seconds speedwalk time.

6. All Stock Plugins 24 seconds.
Australia Forum Administrator #22
There is a bug in aard_ASCII_map.xml

Disabling and re-enabling it gives this:




Run-time error
Plugin: Aardwolf_Ascii_Mapper (called from world: Aardwolf)
Function/Sub: OnPluginEnable called by Plugin Aardwolf_Ascii_Mapper
Reason: Executing plugin Aardwolf_Ascii_Mapper sub OnPluginEnable
[string "Plugin"]:451: attempt to call global 'OnPluginConnect' (a nil value)
stack traceback:
        [string "Plugin"]:451: in function <[string "Plugin"]:447>
Error context in script:
 447 : function OnPluginEnable ()
 448 :     WindowShow (win, true)
 449 :     -- if we are connected when the plugin loads, it must have been reloaded whilst playing
 450 :     if IsConnected () then
 451*:         OnPluginConnect ()
 452 :     end -- if already connected
 453 : end -- OnPluginEnable
 454 : 
 455 : --=================================================================================



In fact there is no OnPluginConnect function. Perhaps comment out that line?
USA Global Moderator #23
Nick Gammon said:

There is a bug in aard_ASCII_map.xml

Disabling and re-enabling it gives this:

Thanks. I'll fix it in the next upload.
Australia Forum Administrator #24
My timing with XP (not Ubuntu, but it shouldn't matter a heap) is as follows for running from recall to Verume (64 rooms):

  • All plugins disabled: 9 secs
  • Mapper only: 14 secs
  • Mapper with Repaint () added: 16 secs
  • All plugins: 18 secs


Adding in Repaint () to the mapper after the call to:


mapper.draw(room_number)


... eliminates the problem of the map updating in a jerky fashion. After all, the idea of Redraw is to have something drawn when there is nothing else to do. Doing Repaint slows things down a bit, but gives you smoother updating.

I'm sorry, but you can't make an omelette without breaking some eggs. In the outdoor zones the screen is filled with rooms (18 x 18 = 324 rooms). Some slowdown to draw them in a scripting language is going to be inevitable.

According to my figures, the slowdown from using the mapper is only an increase from 9 seconds to 18 seconds, and that is traversing 64 rooms. So you are saying that to map 7 rooms a second (64 / 9) is "incredibly slow". Can't agree with that.

You have the search depth cranked up to 40. That's a long way out for the mapper to search. I changed it to 10, which still largely fills the map (albeit in a bit of a diamond shape). This reduces the time for my run to Verume to around 12 seconds, only 3 seconds more than without the mapper.

I suggest you put in the Repaint line, to get the immediate drawing, so the map doesn't seem to jump from one batch of rooms to another. I also suggest you do what I suggested earlier, either make the mapper size just smaller, or drop back the depth amount to around the 10 - 12 room mark.

If you are just walking around exploring, I think the ability to draw 7 rooms a second is more than adequate. If the slowdown during speedwalks bothers you, you could disable the mapper temporarily, or drop down the mapper depth temporarily.

Personally I find the idea that you can "walk" across about 3 continents in 9 seconds a tiny bit ridiculous, and makes the MUD feel a bit small. Having to wait 20 seconds while you traverse a large amount of ground actually "feels right" to me (in fact, longer could be better).
Australia Forum Administrator #25
Crowe said:

I watched the video. I thought it was rather slow. Here is why I think that:

I used enter and rt weather in the same command line.

1. Main window and ascii map plugin with a 11 seconds speedwalk time.

6. All Stock Plugins 24 seconds.



I found that with all plugins disabled it took 11 seconds to runto weather. With all plugins enabled, but the depth set to 10, it took 14 seconds. With the depth at 40 it took 18 seconds (and that was with Repaint () added).

I think dropping the depth back doesn't really hurt. It only really visibly affects the outside zones which are cluttered with a wall of "rooms" anyway. Once inside a zone the 10 room depth is probably plenty.
USA Global Moderator #26
Nick Gammon said:

Personally I find the idea that you can "walk" across about 3 continents in 9 seconds a tiny bit ridiculous, and makes the MUD feel a bit small. Having to wait 20 seconds while you traverse a large amount of ground actually "feels right" to me (in fact, longer could be better).


While I agree that speedwalks should be slower on the MUD side in certain situations to more closely simulate a real world (I'd like to see mountains take longer than roads, for example), the players who participate in Global Quests where every second counts would scoff at the suggestion that that makes a halving of client performance ok. Aardwolf is a very competitive MUD where the most competitive players use mappers extensively and the players do care when their clients slow them down by what could amount to essentially ten seconds of lag every time the player changes areas (which can happen a dozen times during a global quest). Which means that in order to stay competitive you have to use another client.

This isn't meant to be a diatribe against you or anything, just a description of why I care. I will try out your various suggestions for optimization, though, and a few more of my own. I think this is salvagable in a way that makes a lot of sense. As you say, the depth during speedwalks doesn't need to be high at all.

In any case, I do appreciate you taking a look. Though if anything you've convinced me that there IS a speed problem, not that there isn't one. :D
But I think it can be overcome without too much trouble.
Australia Forum Administrator #27
Glad I can help!

BTW, with the depth dropped down to 7 I found that I ran to Verume in about 10 seconds, only about 1 more second than without the mapper, and you still get a sense of where you are.

I think if you can detect when a speedwalk is active (maybe you know how, maybe talk to Lasher) and drop the depth down to around 7 during a speedwalk, and put it back up to 20 outside one, you should get the best of both worlds.

Quote:

Which means that in order to stay competitive you have to use another client.


Well I trust that this other client will be faster when the same features are enabled, otherwise you may as well just turn off the features in this one.
Australia Forum Administrator #28
To change the scan depth, do this:


 config.SCAN.depth = 7      -- or whatever
 mapper.draw (room_number)  -- draw from this room
 Repaint ()                 -- force screen repaint

Amended on Wed 17 Nov 2010 03:16 AM by Nick Gammon
USA Global Moderator #29
Nick Gammon said:

To change the scan depth, do this:


 config.SCAN.depth = 7      -- or whatever
 mapper.draw (room_number)  -- draw from this room
 Repaint ()                 -- force screen repaint




Cool, thanks. :)

Quote:
Well I trust that this other client will be faster when the same features are enabled, otherwise you may as well just turn off the features in this one.

I hope (and think) we can make that not be the case.
Amended on Wed 17 Nov 2010 03:45 AM by Fiendish
Australia Forum Administrator #30
Here is another cool (30 second) video from the MUSHclient studios ...




This shows how quickly the mapper can work with a reduced room scan depth (and has some groovy music).
Amended on Mon 25 Nov 2013 10:51 PM by Nick Gammon
USA Global Moderator #31
How did you time the music ending so perfectly? :D
Amended on Wed 17 Nov 2010 05:54 AM by Fiendish
USA Global Moderator #32
Nick Gammon said:

And personally I would throw in the Omit_Blank_Lines plugin - gets rid of the rather useless blank lines.


Aardwolf has a command for that if the players want. Personally, I like blank lines.