Zugg Software :: View topic - [2.18] Enabling classes during walking causing a 5x slowdown in walking speed

Posted: Mon Jan 07, 2008 8:47 pm

This is a problem I've been grappling with for over a month now and I finally root caused it.

In Zmud I had walking setup so that items that could only happen while walking were enabled solely during a walk movement. Items such as "There is a wall in the way" were safely disabled until I actually entered a direction for movement. At that time various classes are enabled and everything worked just fine.

In Cmud I was experiencing this atrocious delay time between when I entered a direction to move and when it actually moved. The delay was somewhere around 0.8 seconds to execute a movement, which really was unacceptable.

When I started debugging I found these two things:

1) As noted in my previous post on the subject, setting "Automatic step confirmation" to "Disable automatic confirmation" and doing the confirmation myself shaved off over 0.4 seconds right off the bat without any other changes.

2) Enabling and disabling classes during a movement caused another 0.3 seconds of delay while moving. When I avoid any time of enabling or disabling of classes and triggers during movement I got my movement time down to around 63ms which certainly is acceptable.

Focusing on Item#2 I ran a couple of tests. In the tests I looped thousands of times to check the speed of enabling or disabling items.

Enable/Disable a single trigger: 2,192 enable/disables per second
Enable/Disable a well stocked class: 207 enable/disables per second

I don't see anything wrong with the speed of my tests as even at 207 enable/disables per second it should only take about 5ms of execution time. Notwithstanding, if I do these enables or disables while moving it makes moving 5 times as long to complete. So I'm not sure why this would be. Standalone this wouldn't seem to be the cause, but I've very thoroughly debugged this and it's definitely the cause. I'm at about the limits of visibility in what I can test from my point of view unless someone has an idea I hadn't though of.

Posted: Mon Jan 07, 2008 11:56 pm

Not sure why this would happen, but I'll see if I can reproduce it. The only time enabling/disabling a class would be slow is if the class contains a button or status bar/window item that needs to be refreshed, or if it contains a variable that is used in an expression trigger or button expression.

It might help if you can isolate this problem down to something simpler that I can try to reproduce. For example, does it still happen if the class you are enabling/disabling only contains a single trigger (like your Can't go that direction trigger)?

Posted: Tue Jan 08, 2008 12:03 am

I'll try to narrow it down a little further. It was a difficult thing to quantify because part of the movement component comes from the internet latency and can vary. It took many hours to narrow it down to the enabling/disabling of classes. Hopefully getting more details should be faster now.

Posted: Tue Jan 08, 2008 7:06 am

Using what I learned from one computer I tried to replicate the enabling/disabling results on my other computer and found that it didn't behave the same as the first computer. So I started from scratch and disabled parts one by one until I was left with the prompt trigger. Disabling all the lines of the prompt trigger one by one yielded that the line:

#tag prompt

Was what was causing the slowdown.

I went into the zfg file and started playing around with the settings and found that disabling "Wait for prompt in Slow speedwalking" eliminated the wait. However, although this speed things up so that the input to movement time was around 60ms the map no longer follows because it sees no prompt after the #ok I provide.

So now both issues have been traced back to some wait that is happening in the slow speedwalking mode. The first was the automatic step confirmation for slow speedwalking. The second has something to do with the detection of the prompt. I have a feeling this may somehow have to do with the fact that I do all the tagging (#tag roomname/exit/prompt), but there is something with slow speedwalking that is inserting a delay in the process when it doesn't get the information like it thinks it should.

I'm not sure why my other computer pointed towards the enabling/disabling, but the slow speedwalking items seem pretty repeatable as I have it right now. Perhaps when the slow speedwalking cause is found the other symptoms may explain themselves.

Is there some slow speedwalking code which inserts a delay under certain conditions?

Posted: Tue Jan 08, 2008 7:16 am

So disabling both automatic step confirmation for slow speedwalking and disabling wait for prompt in slow speedwalking combined with doing all my own tagging gets me down to the 60ms I've been looking for. This also has the strange effect of fixing the zone crossing error/crash that I was having before.

Perhaps the two issues are related? All I know is that the slow walking has some serious quirks and I'm ecstatic that I've solved a problem that has been plaguing me for over a month and as a bonus, I fixed another problem that I had set aside for later.

Additional information: I use ATCP and I use the ATCP information to do the #TAG statements. I had reconfigured the mapper after I had put the tags in.

Posted: Tue Jan 08, 2008 5:54 pm

OK, thanks for the additional information. This is the kind of detailed stuff that I want to fix/improve in the Mapper rewrite later this year. This kind of bug requires some very detailed and careful work in the low-level configuration part of the Mapper. I plan to improve using the #TAG command. Right now, using #TAG doesn't always disable the rest of the automatic mapper configuration stuff. But it gets very complicated (as you have already seen).

Anyway, this isn't going to get fixed right away. When I start working on the Mapper rewrite, that will be the time to re-visit this issue to help improve it. I'll be posting the "roadmap" for 2008 later this week to give you more info on the timescale for this.

Posted: Tue Jan 08, 2008 6:48 pm

Thanks for the information. I think I'm set for the time being. With the changes I made to the mapper configuration it works and it is fast, so I'm happy. With this resolved Cmud is getting very close to usable for me. There are just a few more bugs such as %dbkeys (already on your list) and such and then I think I can use it full-time.

I'll be eagerly awaiting the mapper rewrite when it occurs, thanks for all your work! If I might venture to put a bug in your ear, or if I can just outright beg, when you are rewriting the mapper, please include a way to deselect currently selected rooms by script (as opposed to having to click on the map).

Posted: Tue Jan 08, 2008 6:58 pm