MUSHclient : General : The Cost of Note()

Gammon Software Solutions forum

See www.mushclient.com/spam for dealing with forum spam. Please read the MUSHclient FAQ!

Entire forum
MUSHclient
General
The Cost of Note()

Home \| Users \| Search \| FAQ
Username:	Register forum user name
Password:	Forgotten password?

The Cost of Note()

Reply to this subject Start a new subject Refresh page

Pages: 1 2

Posted by

Candido USA (78 posts)

Date

Thu 16 Jun 2011 09:16 AM (UTC) [ quote ]

Message

So, I was working on optimizing my prompt. I do one of things where I gag the prompt from the MUD and then output it custom with ColourNote. What I found in my analysis is that that one line of the prompt function (ColourNote) is far and away the most expensive thing in the function. It's more expensive than the rest of the function combined, and it's a fairly hefty chunk of code.

In more detail, the Note takes 2 ms to execute most of the time, which is already more than the rest of the function (about 0.15 ms), and often enough to be worrying, it will be higher, anywhere from 3 to 6 ms. I know it's not something I'm doing within the ColourNote, because a vanilla call of simply Note() exhibits the exact same behavior.

Is this an unavoidable cost? If I didn't gag/reoutput the line, would Mushclient still incur the same cost to redraw the output with the raw line? One thing I noticed is that if I change the ColourNote to a ColourTell and just let new output make the line break, it cuts the measured cost down to the microseconds. However, my instinct is that this is a false gain because Mushclient will still do that work when the line breaks. It just happens outside my measurements.

Posted by Nick Gammon Australia (18,770 posts) bio Forum Administrator

Date Reply #1 on Thu 16 Jun 2011 11:34 AM (UTC) [ quote ]

Message

Well I got 305 microseconds on my computer:


s = utils.timer ()
ColourNote ("green", "blue", "hello, world")
e = utils.timer ()

print ("time taken = ", e - s)

Output:


time taken =  0.00030506658367813

Of course, mine might be faster than yours.

The bigger question is, how long does writing a line to the output buffer take, in general?

If it normally takes 3 mS then you would expect it to take 3 mS if you omit it and write a new one.

- Nick Gammon

www.gammon.com.au, www.mushclient.com

Posted by

Candido USA (78 posts)

Date

Reply #2 on Thu 16 Jun 2011 05:56 PM (UTC) [ quote ]

Message

What's the best way to test that other than Note? Simulate? Timestamp a packet receipt and then trigger the output line with all other triggers disabled?

Judging by your response, the delay is normal and expected, and I'm not incurring any consequential extra overhead by doing a gag/replace.

Now, what if there was a way to override Mushclient's default behavior and have it only redraw on the prompt (with a manual call to Repaint), letting any lines in between process without being visible until a prompt appears. Would this result in a performance gain, or does Mushclient already redraw in blocks based on the size of incoming packets?

Posted by

Fiendish USA (848 posts)

bio Global Moderator

Date

Reply #3 on Thu 16 Jun 2011 06:14 PM (UTC) [ quote ]

Message

MUSHclient already redraws in blocks unless you enable the smooth/smoother scrolling options in global prefs.

http://aardwolfclientpackage.googlecode.com/

Posted by

Candido USA (78 posts)

Date

Reply #4 on Thu 16 Jun 2011 06:43 PM (UTC) [ quote ]

Message

Aha, so that might explain why my Note() takes twice as long sometimes. But maybe not since I can get it to spike with nothing but an empty line between it and the last prompt.

What if I managed to call Note() from a separate lua thread, and let that run parallel to the rest of my prompt? My guess is it wouldn't actually be any help since the actual redrawing is done in Mushclient's thread. I guess what I could do is leave Note() in the main thread, and make a separate thread for the rest of the processing. Scary to think about how tedious that would be to set up, hah.

Posted by

Twisol USA (2,229 posts)

Date

Reply #5 on Thu 16 Jun 2011 08:08 PM (UTC) [ quote ]

Message

Candido said:
What if I managed to call Note() from a separate lua thread, and let that run parallel to the rest of my prompt?

I can guarantee that, if you managed to pull that off, it would break horribly. Only one thread should ever touch the GUI.

('sides, Lua doesn't have real threads. It has coroutines, which are cooperative, not preemptive like OS threads.)

'Soludra' on Achaea

Blog: http://jonathan.com/
GitHub: http://github.com/Twisol

Posted by

Candido USA (78 posts)

Date

Reply #6 on Thu 16 Jun 2011 08:59 PM (UTC) [ quote ]

Message

You only get coroutines with the stuff that comes with Mush, but I've been playing around with Lua Lanes.

http://kotisivu.dnainternet.net/askok/bin/lanes/

To my understanding, they work at the C level to make true, separate OS threads of your Lua code. So far I've converted my coroutine based http stuff to just work in separate lua lanes, and it's worked really well.

The reason I used such hypothetical language when talking about putting the Note in a separate thread is I haven't figured out how to pass the world object into a lane yet, and like you said it's probably not a good idea. Plus, my instinct is that the separate thread will just send the command to Mush, which will then execute it in the main thread anyways.

Posted by

Twisol USA (2,229 posts)

Date

Reply #7 on Fri 17 Jun 2011 12:01 AM (UTC) [ quote ]

Message

More like, it'll execute Note() in MUSHclient in the other thread while it's doing other stuff in the main thread. If it were message passing nothing would break, but in this case everything would break, and in very strange ways. (We've seen people try it from Python threads.)

'Soludra' on Achaea

Blog: http://jonathan.com/
GitHub: http://github.com/Twisol

Posted by

Candido USA (78 posts)

Date

Reply #8 on Fri 17 Jun 2011 12:51 AM (UTC) [ quote ]

Message

That actually sounds promising. So long as I join the threads at the end of the function, what's the worst that could happen? There is one way to find out...

Posted by

Nick Gammon Australia (18,770 posts)

bio Forum Administrator

Date

Reply #9 on Fri 17 Jun 2011 01:10 AM (UTC) [ quote ]

Message

Google: "threads are evil"

Also see:

http://www.sqlite.org/faq.html

Quote:

(6) Is SQLite threadsafe?

Threads are evil. Avoid them.

SQLite is threadsafe. ... (but) ...

- Nick Gammon

www.gammon.com.au, www.mushclient.com

Posted by

Twisol USA (2,229 posts)

Date

Reply #10 on Fri 17 Jun 2011 01:28 AM (UTC) [ quote ]

Message

Candido said:

That actually sounds promising. So long as I join the threads at the end of the function, what's the worst that could happen? There is one way to find out...

What would happen if the main thread tries to Note() something at the same time as the auxiliary thread?

'Soludra' on Achaea

Blog: http://jonathan.com/
GitHub: http://github.com/Twisol

Posted by Nick Gammon Australia (18,770 posts) bio Forum Administrator

Date Reply #11 on Fri 17 Jun 2011 03:05 AM (UTC) [ quote ]

Message

Candido said:

Now, what if there was a way to override Mushclient's default behavior and have it only redraw on the prompt (with a manual call to Repaint), letting any lines in between process without being visible until a prompt appears. Would this result in a performance gain, or does Mushclient already redraw in blocks based on the size of incoming packets?

MUSHclient invalidates the text rectangle upon changing the output buffer. This causes Windows to schedule a redraw which is a low-priority message. That is, it happens after all incoming packets have been received. So it doesn't redraw in blocks, nor based on any particular size. It's when there is nothing much else to do.

Doing a Note (ColourNote etc.) per se does not do anything except add more data to the in-memory buffer (and invalidate the rectangle). So noting should be fast, in that it is just memory manipulation.

What is the real problem here? The client can process notes much faster than you can read the results. For example:


s = utils.timer ()
for i = 1, 10000 do
  ColourNote ("green", "blue", "hello, world")
end -- for 
e = utils.timer ()

print ("time taken = ", e - s)

Results:


time taken =  1.7540601517539

Now you can't read 10000 lines in under two seconds.

In fact I ran that test a second time, with Fiendish's Tetris game underneath (so the text had to scroll under a miniwindow) and it took 0.74 seconds.

- Nick Gammon

www.gammon.com.au, www.mushclient.com

Posted by

Candido USA (78 posts)

Date

Reply #12 on Fri 17 Jun 2011 03:42 AM (UTC) [ quote ]

Message

Twisol said:

What would happen if the main thread tries to Note() something at the same time as the auxiliary thread?

Understandably, that would be a problem. My plan though was, well, to not let that happen. I'd have only the Note() in the auxiliary thread, and then all the invisible processing takes place in the main thread as normal. When the processing finishes, it joins to the Note thread.

Posted by

Candido USA (78 posts)

Date

Reply #13 on Fri 17 Jun 2011 03:53 AM (UTC) [ quote ]

Message

Thanks Nick. With that new info, it seems this entire thread was the result of trusting numbers without understanding what they mean. Of course the cost of single Note()'s is going to be high, because Mushclient is doing nothing else and will go ahead and redraw straight away.

I ran another test where I did 10000 Send()'s to get a bunch of prompts coming in close succession. The most common cost for the Note() under these conditions was 800 microseconds. Still slightly heavy for just memory manipulation, but nothing I am worried about any longer.

Posted by

Twisol USA (2,229 posts)

Date

Reply #14 on Fri 17 Jun 2011 04:05 AM (UTC) [ quote ]

Message

Candido said:

Twisol said:

What would happen if the main thread tries to Note() something at the same time as the auxiliary thread?

Understandably, that would be a problem. My plan though was, well, to not let that happen. I'd have only the Note() in the auxiliary thread, and then all the invisible processing takes place in the main thread as normal. When the processing finishes, it joins to the Note thread.

I'm not sure you understand. While your Note thread is running, MUSHclient is also running. It's doing things to the same memory your Note thread is trying to access, including reading in more data from the MUD and rendering it. There is no way to make this work effectively. What you can do is put your processing in an auxiliary thread (so long as it doesn't touch non thread-safe data), and have your Note() in the main thread.

'Soludra' on Achaea

Blog: http://jonathan.com/
GitHub: http://github.com/Twisol

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.

4,776 views.

This is page 1, subject is 2 pages long: 1 2

Reply to this subject Start a new subject Refresh page

Go to topic: Search the forum

Comments to: Gammon Software support
Forum RSS feed ( http://www.gammon.com.au/rss/forum.xml )