[Home] [Downloads] [Search] [Help/forum]


Register forum user name Search FAQ

Gammon Forum

[Folder]  Entire forum
-> [Folder]  MUSHclient
. -> [Folder]  General
. . -> [Subject]  Possible problem with timers in MUSHclient?

Possible problem with timers in MUSHclient?

It is now over 60 days since the last post. This thread is closed.     [Refresh] Refresh page


Pages: 1 2  3  4  

Posted by Nick Gammon   Australia  (22,973 posts)  [Biography] bio   Forum Administrator
Date Tue 30 Nov 2010 06:27 AM (UTC)
Message
Fiendish raises an interesting point in this thread:

http://www.gammon.com.au/forum/?id=10792

Basically timers in MUSHclient won't fire at the advertised time if there is a lot of activity. In particular, ones which have a low interval (eg. 0.5 seconds) might be delayed for a second or two while the client processes incoming text.

This includes the OnPluginTick callback, which is supposed to be called 25 times a second.

This is because the timers are implemented by handling a WM_TIMER event from Windows, and this happens to fire only if there is nothing better to do (except redraw windows, heh).

It seems slightly odd to me that no-one has complained before.

It is probably a simple enough change to make, that (say) before processing text from the MUD that the client manually checks if it is time to check timers.

Advantage


  • Timers would fire closer to the time they should


Disadvantages


  • Different behaviour to before, may make things work differently to what you are used to.

  • Checking timers every 1/10 of a second in preference to processing incoming messages may make processing of MUD output (which is input to the client) slower.

  • Calling OnPluginTick 25 times a second, when there is other stuff to do, like update the output window, process incoming text, handle keystrokes, handle mouse-clicks, might significantly slow down the client (if a plugin is calling that). Conceivably, if the processing in OnPluginTick takes most of the 40 milliseconds that elapse (since there are 40 * 25 milliseconds in a second) the client might become very unresponsive.


I am tempted to leave well-enough alone. No-one has complained before (over about 15 years), even Fiendish said at best he would like the documentation updated. Does anyone have any different ideas?

- Nick Gammon

www.gammon.com.au, www.mushclient.com
[Go to top] top

Posted by Worstje   Netherlands  (899 posts)  [Biography] bio
Date Reply #1 on Tue 30 Nov 2010 07:18 AM (UTC)

Amended on Tue 30 Nov 2010 07:20 AM (UTC) by Worstje

Message
There is an obvious difference between timers and the OnPluginTick callback. OnPluginTick is very high maintenance, prone to getting delayed by itself or even a simple repaint.

Timers on the other hand (I believe so anyhow, but too lazy to check) are implemented with a 0.1 being the smallest possible, thus giving them a 40ms to 100ms gap.

So I feel that OnPluginTick might need a different implementation if at all possible since it is designed to be so high-frequency, but Timers seem fine as it usually does not come down to <100ms accuracy with those.

The biggest reason I found for stuff to slow down has indeed become the GUI stuff. I tried a countdown-bar miniwindow once, but it just hogged so much CPU constantly by just having the timer which caused the redraw. It became a really unpleasant playing experience.

So either stuff was not optimized properly in painting back then, or it is just the fact that GDI isn't meant for live graphics.

[offtopic]MUSHclient v5.0: switching to DirectX for rendering the user interface?[/offtopic]
[Go to top] top

Posted by Fiendish   USA  (2,514 posts)  [Biography] bio   Global Moderator
Date Reply #2 on Tue 30 Nov 2010 04:21 PM (UTC)

Amended on Tue 30 Nov 2010 04:24 PM (UTC) by Fiendish

Message
Quote:
# Checking timers every 1/10 of a second in preference to processing incoming messages may make processing of MUD output (which is input to the client) slower.

# Calling OnPluginTick 25 times a second, when there is other stuff to do, like update the output window, process incoming text, handle keystrokes, handle mouse-clicks, might significantly slow down the client (if a plugin is calling that). Conceivably, if the processing in OnPluginTick takes most of the 40 milliseconds that elapse (since there are 40 * 25 milliseconds in a second) the client might become very unresponsive.

This I absolutely want to avoid. MUSHclient is already getting extremely slow for me with heavy plugin processing such that I'm having to try to come up with performance hacks to make the experience not terrible. I've resorted to pooling calls to repaint, because if a plugin doesn't call repaint then it doesn't guarantee a paint, so that multiple plugins don't trigger rapid repaints but still don't get starved out because redraw is too low priority, which was the impetus for that particular thread. And now I'm at the point where I have to either go in and try to heavily optimize for performance very complex plugins that I didn't write myself or consider spinning them off into other processes. Or be satisfied with orders of magnitude slowdown, which I'm not, or with not using those plugins at all, whch I'm not. So please, nothing that makes the program slower for no reason. :)

Related to the aforementioned thread, IMO there's a design flaw in how Redraw and Repaint are handled. Since Redraw never gets serviced if a lot of work is going on, the screen does not reliably update from calls to Redraw under load. But if every plugin uses Repaint, as they need to in order to guarantee display, then performance suffers because you only need one actual Repaint per batch of calls.


https://github.com/fiendish/aardwolfclientpackage
[Go to top] top

Posted by Nick Gammon   Australia  (22,973 posts)  [Biography] bio   Forum Administrator
Date Reply #3 on Tue 30 Nov 2010 08:25 PM (UTC)
Message
I would be looking at what you are trying to do to get this "extremely slow" response.

Just as an example, using the client setup I got from you SVN repository, I turned on GMCP debugging, and turned off triggers, and then "runto weather" to see what was being pushed through. For each room, I saw something like this:


East Windy Mountains (272)

<MAPSTART>
East Windy Mountains
 
 
                            
     ^ ~ ^ ~ . , . , ^ ~  
                             
 ^ ~ ^ ~ ^ ~ ^ ~ ^ ~ ^ ~ ^ ~ 
                             
 / \ ^ ~ / \ ^ ~ / \ ^ ~ ^ ~ 
                             
 / \ / \ / \ /#\ / \ / > ^ ~ 
                             
 / \ / \ / \ / \ / \ ^ ~ ^ ~ 
                             
 ^ ~ / \ / \ / \ ^ ~ ^ ~ / \ 
                             
     ~ ~ ^ ~ ^ ~ ~ ~ ~ ~  
                             
 
[ Exits: N E S W ]
<MAPEND>
room.info { "num": 18443, "name": "East Windy Mountains", "zone": "gelidus", 
"terrain": "icemount", "details": "", 
"exits": { "n": 18383, "e": 18444, "s": 18503, "w": 18442 }, 
"coord": { "id": 2, "x": 52, "y": 21, "cont": 1 } }

char.vitals { "hp": 1015, "mana": 1147, "moves": 272 }


Now for a start, you are sending 22 lines of map data (<MAPSTART> through to <MAPEND>) per room. That's 22 lots of:


  • Processing incoming TCP/IP data
  • Decoding ANSI colours
  • Trigger matching
  • Inserting line into output buffer
  • Calling a script to save that line in a table
  • Omitting that line from the output buffer


Done per room.

Then on top of that you get the GMCP data which effectively gives you a lot of the same information again (room number, exits, terrain type, whether there are shops).

So that is duplication basically. Duplication that takes time to process. Surely you can amend the GMCP information enough to not need the old <MAPSTART> stuff?

Then there is the room info (room.info). Now every time you visit room 18443 you send the name, zone, terrain, exits, coordinates. More duplication. More processing time.

I argued at some great length on the Mud Standards forum in favour of some sort of caching scheme. Didn't get much support, got a lot of lengthy posts explaining why I was wrong.

The point was, before even making those posts I had noticed this duplication of data, and was trying to alleviate it.

Let's say, instead of:


room.info { "num": 18443, "name": "East Windy Mountains", "zone": "gelidus", 
"terrain": "icemount", "details": "", 
"exits": { "n": 18383, "e": 18444, "s": 18503, "w": 18442 }, 
"coord": { "id": 2, "x": 52, "y": 21, "cont": 1 } }


you just sent:


room.info { "num": 18443 }


And then if you knew all about room 18443, then fine - you can instantly display it. If not you request the details about room 18443. Might be slower the first time. Would be faster every other time.


My other comment is that your idea of "extremely slow" and mine don't necessarily coincide. Last time I showed that I could move about 60 rooms in something like 19 seconds, which I thought was quite fast. You said it was far too slow and your players wouldn't accept it. Well, perhaps some player re-education is called for. You can have fast response time and a text-based interface, or slightly slower response with maps, spellups, status bars, chats windows etc. Or there was even the hybrid we discussed where you turn some features off when running around doing a speedwalk.


- Nick Gammon

www.gammon.com.au, www.mushclient.com
[Go to top] top

Posted by Nick Gammon   Australia  (22,973 posts)  [Biography] bio   Forum Administrator
Date Reply #4 on Tue 30 Nov 2010 08:54 PM (UTC)
Message
Nick Gammon said:

That's 22 lots of ... done per room.


Of course, from the server's point of view too, that's a lot of data it is pumping out if dozens of players are running around.

- Nick Gammon

www.gammon.com.au, www.mushclient.com
[Go to top] top

Posted by Fiendish   USA  (2,514 posts)  [Biography] bio   Global Moderator
Date Reply #5 on Tue 30 Nov 2010 09:29 PM (UTC)

Amended on Tue 30 Nov 2010 09:38 PM (UTC) by Fiendish

Message
I think you're barking up the wrong tree here. The amount of data streaming through is pretty negligible. You're talking about the order of hundreds of bytes per second, not a whole lot. You can even disable the automap and the speed will still be just as slow, despite now sending less than half the lines.

Compare speedwalks using the version I gave you last time with what is in the repo now:
http://code.google.com/p/aardwolfclientpackage/downloads/list

The data from the mud is the same. The plugins are basically the same. But the new one should be very noticably faster. The difference is mostly the amount of work that gets done inside the GMCP mapper during runs, because I trim down the search space as you suggested. There's also my new repaint buffering which cuts down on the number of repaints.

THESE are the things that make noticeable differences in performance, not lines from the MUD.

Quote:
Of course, from the server's point of view too, that's a lot of data it is pumping out if dozens of players are running around.
Eh, I'll start worrying about that when Lasher does.

Quote:
You said it was far too slow and your players wouldn't accept it. Well, perhaps some player re-education is called for.

I'm not satisfied with being satisfied. :) Not being satisfied with features is what causes me to add new ones. Not being satisfied with performance is what causes me to come up with new ways to make things faster. If something is CPU-limited on a brand new machine like mine, I can only imagine how bad it is on an older slower one.

https://github.com/fiendish/aardwolfclientpackage
[Go to top] top

Posted by Larkin   (278 posts)  [Biography] bio
Date Reply #6 on Wed 01 Dec 2010 01:02 PM (UTC)
Message
I've noticed some oddities with at least one of my timers lately, but I haven't decided if it's me doing something stupid or my timer being mishandled by MUSHclient. I have a timer that fires ever 2.5 seconds to keep a game clock synchronized on my Info bar. However, sometimes it seems to run ten times slower and the time is very far behind. I double-checked the timer options in the dialog, and it was indeed still set to fire every 2.5 seconds, so I'm confused.
[Go to top] top

Posted by Fiendish   USA  (2,514 posts)  [Biography] bio   Global Moderator
Date Reply #7 on Wed 01 Dec 2010 04:48 PM (UTC)
Message
Larkin, does Nick's first post in this thread help you at all?

https://github.com/fiendish/aardwolfclientpackage
[Go to top] top

Posted by Larkin   (278 posts)  [Biography] bio
Date Reply #8 on Wed 01 Dec 2010 05:10 PM (UTC)
Message
I have no idea if the proposed solution would help what I'm seeing (and I'm seeing some of it right now as I play today), but it probably wouldn't hurt.
[Go to top] top

Posted by Fiendish   USA  (2,514 posts)  [Biography] bio   Global Moderator
Date Reply #9 on Wed 01 Dec 2010 05:33 PM (UTC)
Message
Larkin said:

I have no idea if the proposed solution would help what I'm seeing (and I'm seeing some of it right now as I play today), but it probably wouldn't hurt.

I meant the explanation of the problem, not the proposed solution. Does it only seem to happen when you have a lot of script activity?

https://github.com/fiendish/aardwolfclientpackage
[Go to top] top

Posted by Nick Gammon   Australia  (22,973 posts)  [Biography] bio   Forum Administrator
Date Reply #10 on Wed 01 Dec 2010 10:29 PM (UTC)
Message
Larkin said:

I have a timer that fires ever 2.5 seconds to keep a game clock synchronized on my Info bar. However, sometimes it seems to run ten times slower and the time is very far behind.


Under the circumstances I described (where a lot of incoming text might delay timers firing) I would do a calculation in the timer itself. For example, rather than assuming that 2.5 seconds have elapsed, find out how much actually elapsed and use that in your calculations.

If you use Lua then these days utils.timer () returns the current hi-resolution timer value. So, once initialized at connect time (since it is not a time of day, but just an elapsed time) you could use the new value minus the previous value to find exactly how much time has elapsed. For example, it might be 3 seconds and not 2.5 seconds.

If you assume 2.5 seconds and you often get 3 seconds, then cumulatively you would gradually get further and further out.

- Nick Gammon

www.gammon.com.au, www.mushclient.com
[Go to top] top

Posted by Larkin   (278 posts)  [Biography] bio
Date Reply #11 on Thu 02 Dec 2010 10:27 AM (UTC)
Message
Yes, the description of the problem may very well apply to me.

And, thanks for the suggestion, Nick! I'll do just that.
[Go to top] top

Posted by David Haley   USA  (3,881 posts)  [Biography] bio
Date Reply #12 on Thu 02 Dec 2010 05:55 PM (UTC)
Message
I find it somewhat hard to believe that MUSHclient becomes "extremely slow" if you're doing something reasonable in a plugin. That said, it is easy for GUIs to appear slow if the redrawing thread is blocked during some other processing, but again that strikes me as unlikely unless people are doing something weird.

Typically the solution is to separate heavy processing from the GUI thread, but I think everybody would be inclined to agree that that shouldn't happen unless absolutely necessary due to the complications it involves.

But working through a search space is exactly the kind of activity that shouldn't be done in the main GUI thread. I would not say that "MUSHclient is slow" here, I would say that the stuff you're doing in plugins is slow... and because you're doing it in the thread that should be updating the GUI, the whole application seems to be slow.

Regarding the issue at hand, would it be hard to have an event system? It sounds wasteful to do something 25 times per second if you know you don't have to. If a plugin wants high-frequency logic, would it be unreasonable to force it to go through a special API that registers the intent? You could then not only avoid the cost if you could, but furthermore you could know how much time there is until the next requested tick (or how late you are).

And yes, I agree with Nick that such time-sensitive frame logic handlers should be checking elapsed time and not just assuming that they were invoked at exactly the right time. (This is very standard in many games' main loops, for instance.)

David Haley aka Ksilyan
Head Programmer,
Legends of the Darkstone

http://david.the-haleys.org
[Go to top] top

Posted by Fiendish   USA  (2,514 posts)  [Biography] bio   Global Moderator
Date Reply #13 on Thu 02 Dec 2010 06:32 PM (UTC)

Amended on Thu 02 Dec 2010 06:36 PM (UTC) by Fiendish

Message
David Haley said:

I find it somewhat hard to believe that MUSHclient becomes "extremely slow" if you're doing something reasonable in a plugin.

I disagree with your definition of reasonableness.

Quote:
That said, it is easy for GUIs to appear slow if the redrawing thread is blocked during some other processing, but again that strikes me as unlikely unless people are doing something weird.

I disagree with your definitions of weird and unlikely.

Quote:
But working through a search space is exactly the kind of activity that shouldn't be done in the main GUI thread.

Does spawning new threads inside plugins work?

Quote:
I would not say that "MUSHclient is slow" here, I would say that the stuff you're doing in plugins is slow... and because you're doing it in the thread that should be updating the GUI, the whole application seems to be slow.
I think you're splitting hairs. If a plugin is slow, not only can the entire program become unresponsive for the duration (if you don't force repaints, which are not free, you may not get screen updates at all until many pages of events have gone by, which could be tens of seconds later), but activities like walking around actually take much longer because the user is locked out of both input and output until the program is finished processing. I'm not sure how else to classify "having plugins loaded makes interaction with the game take significantly longer" except for "slow".

Quote:
Regarding the issue at hand, would it be hard to have an event system? It sounds wasteful to do something 25 times per second if you know you don't have to.
I like this idea, but offhand I think the answer is "Yes, it would be hard."

https://github.com/fiendish/aardwolfclientpackage
[Go to top] top

Posted by David Haley   USA  (3,881 posts)  [Biography] bio
Date Reply #14 on Thu 02 Dec 2010 07:10 PM (UTC)
Message
Fiendish, you may disagree all you like, but running search algorithms is simply not a good idea in the main (or only) GUI thread. Anybody who has written GUI code can tell you this. In fact, GUI frameworks are often designed around this fact of life. It is perhaps not your fault in this instance because you have little choice, but, well, your disagreement doesn't change the fact that it's what you're doing that's messing things up, not some inherent slowness in MUSHclient. I get the impression that you are blaming your problems on MUSHclient, and fretting about having to optimize code. Well, yes -- if the code isn't behaving the way it should according to well-known GUI programming rules, and it is impossible/unacceptable to change its paradigm, then it has to be optimized.

Would it be reasonable for somebody to complain to Nick about MUSHclient being slow because they're doing a full mini-max search routine to optimize some AI agent's playing strength in a plugin? No, that would be silly.

As a framework developer, Nick can provide two things here:
- a way for plugins to (temporarily) relinquish control to the GUI thread to restore responsiveness
- multi-threaded plugins to avoid computation in the GUI thread in the first place

This is all a separate issue from the timer issue, of course. It's related in the sense that plugins can consume time and that can mess with the main loop.

I don't believe that the scripting languages currently allow preemptive multi-threading.

You could perhaps restore the impression of responsiveness by using coroutines or something instead of whatever main loop you're doing now.

David Haley aka Ksilyan
Head Programmer,
Legends of the Darkstone

http://david.the-haleys.org
[Go to top] top

The dates and times for posts above are shown in Universal Co-ordinated Time (UTC).

To show them in your local time you can join the forum, and then set the 'time correction' field in your profile to the number of hours difference between your location and UTC time.


103,800 views.

This is page 1, subject is 4 pages long: 1 2  3  4  [Next page]

It is now over 60 days since the last post. This thread is closed.     [Refresh] Refresh page

Go to topic:           Search the forum


[Go to top] top

Quick links: MUSHclient. MUSHclient help. Forum shortcuts. Posting templates. Lua modules. Lua documentation.

Information and images on this site are licensed under the Creative Commons Attribution 3.0 Australia License unless stated otherwise.

[Home]


Written by Nick Gammon - 5K   profile for Nick Gammon on Stack Exchange, a network of free, community-driven Q&A sites   Marriage equality

Comments to: Gammon Software support
[RH click to get RSS URL] Forum RSS feed ( https://gammon.com.au/rss/forum.xml )

[Best viewed with any browser - 2K]    [Hosted at HostDash]