The Cost of Note()

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.

Well I got 305 microseconds on my computer:



Output:



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.

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?

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

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.

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

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.

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

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

Google: "threads are evil"

Also see:

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

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

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:



Results:



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.

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.

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.

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.

But the Note thread is not concurrent with all processing. A prompt arrives, which triggers a function. The Note thread is created within this function, and dies before the function ends. Inside this space, no further MUD data can be read/rendered, otherwise just a regular Note() in the function could cause the same problem. Unless I'm completely missing something here.

Then what's the point of splitting it into a new thread if it's just going to be executed inline anyways? You'd probably have more overhead just in the form of thread switching.

Also, MUSHclient's internals are a bit odd :) so I wouldn't even trust that to work. In theory it might, but in practice I'm not so sure.

In reality, there really isn't much point, but the idea was to have what was supposedly an expensive command, Note() at 2 ms, run in one thread, while my calculations, at 1.5 ms ran in the main thread. When calculations finish, the threads are joined, so it'll wait for the Note() thread. Assuming the Note() thread got assigned to a different cpu core, I'd go from 3.5 ms to 2 ms. Though, like you mentioned, this makes a lot of assumptions about Mush's internals.

Hmm. So is there any reason you can't keep the Note() in the main thread and do your calculations in the other thread? You'll be waiting on both to move on, regardless of which one does what.

You could do it either way. It's just much easier to make a set and forget Note() thread than a thread you then have to pass a bunch of data into and extract a bunch of data from. I can see why it may be more worthwhile though.

Well, in any set of tasks to be processed in parallel, the best speed you can possibly get is the best speed of the slowest task. According to your tests, Note() is 2ms and your calculations are 0.15ms. That means, in the best case, no matter how you arrange your threads, you will never do better than 2ms. It would be worthwhile if they were both 2ms, since you'd effectively halve the runtime, but 0.15ms is paltry savings.

Oh woops. I meant 1.5 ms not 0.15 ms.

A bunch of numbers were wrong. I edited my post above.

It's better, but when you look at the total time, I don't think it's worth it. Are you optimizing because it looks and feels slow, or just to iron out the wrinkles? Because I'd wait until you really need to before pulling out threads.

I'm optimizing because I was getting to the point where short freezes would occur in very spammy situations, and long freezes would occur in artificially spammy situations like sending 1000 commands at once, which I actually have reason to do on a regular though infrequent basis.

2 ms doesn't sound like much, and I'm pretty sure it's considered to be imperceptible to the eye. However, if you get 1000 prompts at once, that's 2 seconds of blocking just from prompt script alone. Now, of course the prompts don't come exactly all at once, so it's a bit more forgiving than that, but that's the gist of it.

People who have run my code on an i7 have been able to send any number of commands at once and not have it freeze, so I'm just trying to clean it up to the point where it will behave like that on my core duo too.

Would you mind posting your code here? There might be easier and more effective optimizations to make first. Sorry, I just don't like to use threads except where absolutely necessary. They tend to cause more problems than they solve.

I have tried to use MUSHclient functions from threads in the past. Suffice to say, it is an excellent way to make MUSHclient crash as those functions have proven not to be thread-safe. This makes sense since most GUI frameworks are not thread-safe either.

The best solution is to use a queue for those calls only: if you really need threads for whatever, make sure to post your stuff to a queue that gets emptied by code running on the main thread. I have used this method before and while it is annoying, it works flawlessly. :) For example, you can use a timer to periodically test your queue for items and act on it. That way, the expensive calculations can be off-loaded in their own thread while the display is done in the proper one.

(I freely assume MUSHclient hasn't had tons of prodding happen to make it thread-safe in the last few years. If it has, someone please correct me.)

It is not intended to be used under multiple threads.

Thanks for the offer, but reading through that much vague and uncommented code is not something I'd wish on anyone. All's well in the end though, since by replacing all my GetVariable's with lua variables I managed to get the non-visible processing down to 250 microseconds, which is about equal to the overhead for lua lanes to start a new thread.

Ah, that makes sense. I'm sure it's more costly to hop out of Lua and interoperate with MFC's string class than it is to nab a reference to an already-existing Lua value.