I'm posting this report for someone else because they don't have an account, don't want one, and don't really care to figure out what's going on because they'll just use zMud instead. I on the other hand would like to get to the bottom of this, especially because at least four other people have experienced the same delay. I have never experienced this delay, myself, and I know at least one other person who is also delay-free.
It seems that MUSHclient has a delay on the order of ~250ms after submitting a command, before the response is shown on-screen. The aforementioned user claims that there is no delay if he uses TinTin++ or raw telnet, and less of a delay with zMud. The MUSHclient version in question is 4.44, though I imagine it's not the only affected version.
The only delay I personally have ever noticed was when chatting on a pseudo-MUD that uses IMC (InterMud Chat) to communicate between separate MUDs; due to the nature of the protocol, it takes some time to pass the message through. All other delays I've ever seen were easily explained by a simple 'ping' to the MUD server, which always matched up to the delay period.
Anyways, this isn't really a full bug report, it's more of a noticing of a bug. I don't know what is going on, and the other person doesn't care to join the forums, so I'd appreciate it if you could give me a few diagnostic questions to pass along. It worries me that some people have it and some people don't.
Is this a vanilla installation? That is, no plugins, triggers, aliases etc.?
If not, could they make a new world file with no plugins or anything else, and see if the problem persists?
I know this might sound strange, but perhaps they have an alias that picks up every command, and sends it after the speedwalk delay, or something.
Or, they have a trigger that is very slow to execute.
Or maybe if some sort of "screen reader" plugin or similar is installed, it may delay output.
Does this always happen (ie. from the moment you connect), or does it gradually get worse?
If so, possibly they have a very large output buffer, and it fills up, and due to a shortage of memory, every attempt to write to it causes a page fault, and disk access.
Does this apply to every line, or ones with a prompt?
Does it seem to be a delayed input, rather than delayed output? Eg. if they type "help" then does the whole help arrive very quickly, once the initial delay is over?
Can they try turning on "Debug Packets" (on the Edit menu).
Then type a command to make the debug window appear, then move and resize it so they can see it easily.
Then type another command. Does it appear immediately in the packet debug window - for example:
Sent packet: 9 (6 bytes) at Tuesday, December 15, 2009, 1:28:50 PM
sigh.. 73 69 67 68 0d 0a
... or is there a delay before the command appears in the packet debug?
Are other things open? (eg. other worlds)
Are they logging the session? Maybe the log file is slow to write to (eg. on a network drive).
If this delay occurs, and they *immediately* switch to another client, such as zMUD, then does the delay go away? Perhaps the MUD just happens to have lag at this time.
I have MUSHclient running on all sorts of PCs, Windows XP, Vista, Windows 7, natively and under VMware on a Mac. Also on Ubuntu. I never notice this delayed input problem.
Packet debugging would be most interesting to me, as it would confirm if MC is for some reason receiving the packets but choosing to not print them straight away; this could be due to several reasons, such as perhaps not getting a telnet GA for the prompt?
A delay of 250 ms isn't that long (one quarter of a second - a bit short to time with a stopwatch). It could originate from a number of sources:
A delay between hitting <enter> and the command being transmitted via the Internet.
A delay between the PC you are on, and the MUD server (so the server hasn't got the command yet) (outgoing network lag)
A delay at the MUD end (server lag) - where it takes a few milliseconds to process the command, perhaps because of lots of players being on, or because they are doing backups or something.
A delay from where the MUD responds, and the response being received by the PC (incoming network lag)
A delay before MUSHclient receives the message from the operating system (perhaps other applications are running)
A delay inside MUSHclient from when the message is received to when it is processed (eg. triggers, plugins)
A delay from when MUSHclient decides to display the message and when it becomes visible (eg. screen refresh a bit slow)
The packet debug, closely observed, might help work some of this out. Also running a tracert might help show if there is network lag.
I would also have another client running at the same time, and confirm that, within a second of each other, commands in one client are noticeably slower than in another one - this would tend to rule out network lag.
It's [MUSHclient] always been a speedy and extremely stable application, which I personally appreciate immensely!
and:
Cage_fire_2000 said:
I agree MUSHclient is very speedy, I tried simpleMU once, and while I really liked the spawn feature it's very awesome, on my 933 Mhz computer, the GUI was peculiarly slow in comparison to MUSHclient for some reason, just clicking the different buttons seemed to lag strangely, I can't imagine why, but it did.
Now we have a 3rd-hand complaint, from someone who doesn't bother to log onto the forum themselves, saying that MUSHclient is slow but TinTin++ and zMUD are faster. It's almost like an ad for a competing client.
Sorry, Twisol, but I think we can ask your friend to complain in person, or say "screen shot or it didn't happen".
Right, I'm pretty sceptical myself - I absolutely think it's something external to the client. The problems is that there are multiple "3rd parties" who have experienced this, so it's somewhat less likely to be a shill sort of thing. (Also, he and the others only brought it up during a separate conversation, and I wanted to look into it. It was entirely my idea to report it)
I don't mind dropping the matter, but I just wanted to bring it up and hopefully reach some kind of conclusive proof that it's not MUSHclient that's the issue. Something else that might help is that he says even the command echo is delayed, which seems to me to rule out latency issues. It occured to me that maybe there is a send() operation on a socket that, for some low-level reason specific to certain factors that most MUSHclient users don't have, is blocking longer than appropriate. However, I haven't looked into the source code to check, so this is just theoretical. It did remind me of the issue with timers and a processor issue from a while back, though.
EDIT: Speaking of which, he said he had an Intel Core Duo. Just throwing that out there.
While I'm not the original person who brought this up, I can confirm that I've had this happen. Most recently while I was using MUSHClient to test that output from recent changes were showing properly across all the clients I knew of.
The lag I experience with MUSHClient is from the time enter is pressed to the time MUSHClient displayed the local echo on the screen. (I don't know why, but I always turn on local echo.)
I've never experienced this on any other client, and the MUD that I connect to has never mattered. Realms of Despair, my own mud, any of them. I've always experienced this delay. I've never brought it up before, because MUSHClient isn't my preferred client. I personally use zMUD, not because of some loyalty, but because I paid for it, and I believe in getting my money's worth. ;)
Thanks for the clarification. If there is a delay between hitting <enter> and the command being echoed locally, that certainly seems to be a client problem.
Having said that, it isn't one I experience myself. I wonder if spell-checking is turned on? Conceivably, spell-checking might delay the interval between when you press <enter> and the line is accepted as having no spelling mistakes.
Just to clarify, can you confirm whether or not automatic spell checking is enabled?
I note that, fairly recently, the spell checker migrated from Lua tables to an SQLite database. If, for some reason, SQLite accesses are slow, this might account for the delay. Maybe with a 10 word line, for example, looking up 10 words in the database might take 25 ms each.
For my part, I tried enabling the spellchecker (in global preferences -> general and world properties -> commands), and there was no noticable delay at all.
However I can't offhand see anything there that might account for why a small number of people (out of thousands) are experiencing a delay.
Problems like this are easier solved if they can be reproduced. If I could reproduce it I could add timing code between each step and work out which step has the 250 ms delay in it.
I don't mind if people use other clients, after all I don't get paid for MUSHclient, but I like to think it is fast and reliable.
I just tested on two other computers in the house, one of which is relatively new, the other is relatively old. Both experienced that same bit of lag.
Kayle, can you please copy and paste your entire world file here? Sometimes some obscure option that I didn't think to look at is responsible for these things. Just open the world file in Notepad or similar, as it is stored as straight text.
You can delete or "x" out any lines with identifying information in them, like the world name, character name, password, and connection details.
For example, a while ago someone complained that what they typed wasn't being echoed, and that was because the "echo your input" box wasn't checked.
There's two different ones. The first one is the one I was using to test the lag. The second was the one I used a couple weeks ago while testing the output of changes to my MUD. Both displayed the lag issues, but I figured something might be different between them.
Still seems fast to me on my PC. Let's try to time it. Internally the processing is similar for a scripted send, compared to typing something in.
Please press Ctrl+I to open the Immediate window, and then paste in this:
tstart = os.time ()
for i = 1, 20 do
Send ("look")
Send ("score")
end -- for
tend = os.time ()
print ("Time taken =", os.difftime (tend , tstart))
You could change "look" and "score" to something else that works on your MUD, but these probably will. I am sending two different commands to avoid the MUD disconnecting us because of spamming the same command.
Then hit the "Run" button, and then close the window and check the output window.
What the client does here is process the command, echo it on the screen, and send it to the MUD. Because of the asynchronous nature of MUD processing you see all commands echoed before any are replied to. However the claimed problem here is not the MUD response time, but the time taken to echo the command locally.
When I run that (on my local MUD server) I see this:
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
Time taken = 0
Inside the Northern Gate
You stand inside the northern gate of Darkhaven. To the south lies the
intersection of Vertic Avenue and Justice Road.
Exits: north south.
A gate guard tends the north gate.
<24hp 145m 110mv> <#21100>
Score for Admin the Attendant.
... and so on
The important thing here is that the time taken to execute 40 commands (20 x 2) is under 1 second. Now maybe the delay is in between when you hit <enter> and when command processing even starts, but we may as well rule out the obvious.
A minor change gives higher granularity results:
tstart = GetInfo (232) -- high performance timer
for i = 1, 20 do
Send ("look")
Send ("score")
end -- for
tend = GetInfo (232)
print ("Time taken =", tend - tstart)
In this case I got:
Time taken = 0.067820332478732
So you can see I processed 40 commands in 68 milliseconds, that is about 1.4 milliseconds per command, far faster than the reported 250 milliseconds per command.
This is on Windows XP SP3
Intel Core 2 Duo CPU at 3.06 GHz
512 Mb of RAM
(running under VMware - the host processor has 4 Gb RAM)
Another test can show how long it takes for everything to be processed, including receiving responses. We need an alias and trigger for this:
<aliases>
<alias
match="start"
enabled="y"
send_to="12"
sequence="100"
>
<send>
tstart = GetInfo (232) -- high performance timer
for i = 1, 20 do
Send ("look")
Send ("score")
end -- for
Send ("say End timing test.")
tend = GetInfo (232)
print ("Time taken to send =", tend - tstart)
</send>
</alias>
</aliases>
<triggers>
<trigger
enabled="y"
match="*You say 'End timing test.'"
send_to="12"
sequence="100"
>
<send>
outputend = GetInfo (232)
print ("Time to receive all output =", outputend - tstart)
</send>
</trigger>
</triggers>
For advice on how to copy the above, and paste it into MUSHclient, please see Pasting XML.
The alias (type "start") starts the high-performance timer, and the trigger notices when the final "say" arrives, indicating all commands have been processed.
In my case I got this:
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
look
score
say End timing test.
Time taken to send = 0.0024757329374552
Inside the Northern Gate
You stand inside the northern gate of Darkhaven. To the south lies the
intersection of Vertic Avenue and Justice Road.
Exits: south.
A gate guard tends the north gate.
... (about 650 lines here) ...
<24hp 145m 110mv> <#21100> You say 'End timing test.'
Time to receive all output = 10.213389072102
In this case it sent all 40 commands in 2 milliseconds. Now it took over 10 seconds to get everything back (over 600 lines) but I think here, the MUD has "throttled" command processing (which is perfectly reasonable for it to do) because I saw slight pauses between each lot of output arriving back.
tstart = GetInfo (232) -- high performance timer
for i = 1, 20 do
Send ("look")
Send ("score")
end -- for
tend = GetInfo (232)
print ("Time taken =", tend - tstart)
I am still interested in hearing from Kayle about what happens with packet debug turned on. It is possible the command is processed quickly, but simply not drawn quickly (the packet debug should therefore show the command being sent before the screen redraw).
Or, is the delay such that it is sent (in packet debug) and drawn in the output window at about the same moment?
So I tried the 2nd test just for giggles. I'm not one of the ones that notice a delay, it's always been acceptable for me but then I have not used anything else to compare it to.
Windows XP Home SP3
Intel Core 2 Duo 3.166GHz
2GB RAM
MUSHclient 4.40
Time taken = 0.083629991226189
I was very surprised and did notice how choppy looking the output became. I guess I'm now in this category with the delay folks.
tstart = GetInfo (232) -- high performance timer
for i = 1, 20 do
Execute ("look")
Execute ("score")
end -- for
tend = GetInfo (232)
print ("Time taken =", tend - tstart)
This changes Send to Execute, thus making the commands go through more of what usually happens when you type something in manually (eg. checking for script prefix, checking for aliases, checking for speedwalks).
In fact, the results should be very similar to manually typing if the following is true:
You don't have spellchecking enabled - obviously that might slow things down, particularly for longer lines
You don't have any plugins installed (which would check for the OnPluginCommandEntered plugin callback).
You don't have Auto-Say activated (which does extra processing)
I was very surprised and did notice how choppy looking the output became. I guess I'm now in this category with the delay folks.
However as I said, the choppy output may well be an artifact of the way the server is written. For example, it may pull incoming commands out of the queue every 0.5 seconds. Thus there is nothing you can do to make output faster.
Your results showed 83 ms for processing 40 commands, which is about 2 ms per command (nothing like 250 ms the original poster mentioned).
A better test again might get rid of some of the decimal places, I think the last ones are a bit irrelevant. Try this:
tstart = GetInfo (232)
for i = 1, 20 do
Execute ("look")
Execute ("score")
end -- for
tend = GetInfo (232)
print (string.format ("Time taken = %1.3f seconds", tend - tstart))
Running that I got:
Time taken = 0.003 seconds
Effectively this truncates the results down to milliseconds, after that I think things become a bit problematic, because things like another program becoming active for a few microseconds are going to affect the results.
I'm running Smaug so it's exactly the same match as yours. Even removing the preceeding * it doesn't print. Might be a colour code in there, I'll check.
Also, modified execute test: Time taken = 0.074 seconds.
I'm in Canada and my server is in Belgium so I do expect some delay and that's probably what I'm seeing in these results. As I said it doesn't particularly bother me anyway. :)
For what it's worth, you can fairly easily subtract network delay from your test by running 'ping <server>' in the console window, and subtracting that amount from the test results. It only makes sense to do that with the trigger version of the test, though.
Operating system - is there a common thread here? For example, is the "slow" version always running on Vista? (Or are you still using Windows 95 maybe?)
Operating system configuration. Occasionally I get complaints that MUSHclient shows text "right to left" in the command window. This turns out to be that they have activated right-to-left keyboard entry in Windows. The command window is just a Windows "Edit" control, and thus is subject to operating-system parameters like that.
Other operating system optional things, like "sticky keys".
Other known external software, such as "automated macro" recording. This may be slowing down processing of input as the keystokes are first recorded by this software.
A virus or trojan horse (keylogger). Try scanning for viruses. Maybe when you press <enter> the keylogger busily adds what you typed to a lengthy file on disk (or sends it over the Internet to the site which installed the Trojan).
Some other unusual configuration you haven't mentioned, such as running under Ubuntu, or on a Mac on Parallels, or via a network using pcAnywhere.
They keyboard is some non-standard keyboard, like a gamers keyboard with an LCD screen, or a wireless keyboard, and it is a long way away from the computer.
I use Vista Home Premium myself and don't experience a delay... so I'm not sure it's specific to a single OS. I also have a G11 (pretty much a gamer's keyboard, just missing the LCD from the G14), though admittedly I don't really use its macro keys.
This thing still exists. I was helping someone switch to MUSHclient, but because MUSHclient gave 4 second delays and other clients didn't, she gave up on it. (Same computer, same MUSH and login data...)
I don't blame her, and after suffering through it with me for two hours I can't ask her to go through a bugtesting session. :/ Regardless, I felt it was necessary to point out it still lurks somewhere, somehow.
Newest version, I pointed her to it. OS, I don't know. Game is Firan (firan.legendary.org). Again, I can't say I experienced it, but the fact people are getting this problem means it does exist in some really weird combination of circumstances.
I just connected to Firan under XP and the latest MUSHclient. Interaction seems instantaneous to me.
No information was given as to what, if anything, she had loaded (eg. plugins). There was a vague idea before that Python might be to blame. Who knows?
I accept that under some circumstances some people are having problems. With such little detail though it's impossible to go further. Next time:
Please provide a summary of your world configuration:
Either use the scripting Immediate window (Ctrl+I) to execute: Debug ("summary")
or
Install the Summary plugin (see
"Summary" feature) and type "summary"
Then copy the resulting information from the output window, and paste into a Forum message.
You need version 4.55 onwards of MUSHclient to do this.
Yeah I know you can't do anything with it. It was a straight fresh first-time install, no plugins or anything involved. No Python either, obviously. :-) My posting was intended to hopefully point out it isn't plugin-specific and help point out it isn't an old issue that has no relevance anymore.
Maybe someone else will see it, realize they have it, and stuff can pick up from there. Who knows. :)
