 |
ReedN Wizard
Joined: 04 Jan 2006 Posts: 1279 Location: Portland, Oregon
|
Posted: Wed Jan 02, 2008 11:13 pm
Takes a long time to change rooms |
Admittedly I have a lot of stuff going on when I change rooms, but this all worked great in Zmud. In Cmud it is unbearable. I'm looking at the debugger at what was run and how long it took, but I'm not sure where to concentrate. Can anyone give me some pointers?
I'm a little confused by some of the information given, like what do the letters stand for right after the time stamp and how do I use the timestamps to zone in on the problematic areas? For example I see a blank line with:
0.4441 | a Achaea.m |
Nothing is on there, but it takes 0.4441 seconds to complete. Is that the Mud or is that me?
And on this line:
0.3372 | a Achaea.m #Telnet 200: Room.Brief In the trees above A corridor of flowering plum trees
Does the 0.3372 apply to the whole trigger or just to the detection part. I guess I'm just looking for general feedback to help form a thought process as to how to go about this.
Code: |
0.0003 | c Achaea.m | exec : Macro "KEY4" : w
0.0028 | f Achaea.m | Command Input: ^(@moveDirs)$ : (%1="w")
0.0007 | c Achaea.m | exec : Command Input "^(@moveDirs)$" : i_move_executed %1 walk #...
0.0004 | k Achaea.m | Var "flags" changed from "" to "moving=w"
0.0003 | k Achaea.m | Var "flags" changed from "moving=w" to "movement=walk|moving=w"
0.0008 | k Achaea.m | Var "fst_prompt" changed from "" to "fst_moving=1"
0.0030 | f Achaea.m | Command Input: ^.
0.0006 | c Achaea.m | exec : Command Input "CommandRec" : #T+ SendLine trigger #T+ Wak...
0.0029 | k Achaea.m | Trigger "A corridor of flowering plum trees" changed from "" to "#OK"
0.0006 | a Achaea.m |8360h, 8470m, 36900e, 33888w exdb-w
0.0024 | j Achaea.m >w
0.0013 | m Achaea.m | Event "onRoomWalk" raised
0.3372 | a Achaea.m #Telnet 200: Room.Brief In the trees above A corridor of flowering plum trees
0.0037 | f Achaea.m | Telnet: ^Room\.Brief\s+(.*)$ : (%1="In the trees above A corridor of flowering plum trees")
0.0008 | c Achaea.m | exec : Telnet "RoomBriefTrigger" : #var RoomName %subregex( %1, ...
0.0003 | k Achaea.m | Var "RoomName" changed from "Staircase into the sunken gardens" to "A corridor of flowering plum trees"
0.0003 | m Achaea.m | Event "RoomName" raised
0.0002 | c Achaea.m | exec : Event "RoomName" : #class exitsActive 1 #class descActive...
0.0072 | k Achaea.m | Var "flags" changed from "movement=walk|moving=w" to "movement=walk"
0.0003 | k Achaea.m | Var "flags" changed from "movement=walk" to ""
0.0012 | a Achaea.m #Telnet 200: Room.Exits e,w
0.0017 | f Achaea.m | Telnet: ^Room\.Exits\s+(.*)$ : (%1="e,w")
0.0007 | c Achaea.m | exec : Telnet "RoomExitsTrigger" : #var RoomExits %subchar( %1, ...
0.0003 | m Achaea.m | Event "RoomExits" raised
0.0002 | c Achaea.m | exec : Event "RoomExits" : #T+ exitsPrompt
0.0006 | a Achaea.m #Telnet 200: Char.Vitals<LF>H:8360/8360 M:8470/8470 E:36898/36900 W:33900/33900 NL:0/100
0.0017 | f Achaea.m | Telnet: ^Char\.Vitals\12H:(\d+)/(\d+) M:(\d+)/(\d+) E:(\d+)/(\d+)... : (%1=8360, %2=8360, %3=8470, %4=8470, %5=36898, %6=36900, %7=33900, %8=33900)
0.0003 | c Achaea.m | exec : Telnet "^Char\.Vitals\12H:(\d+)/(\d+) M:(\d+)/(\d+) E:(\d...
0.0004 | k Achaea.m | Var "endurance" changed from "36900" to "36898"
0.0039 | k Achaea.m | Var "willpower" changed from "33888" to "33900"
0.0036 | a Achaea.m #Telnet 200: Room.Brief In the trees above A corridor of flowering plum trees
0.0017 | a Achaea.m #Telnet 200: Room.Exits e,w
0.4441 | a Achaea.m |
0.0069 | a Achaea.m |In the trees above A corridor of flowering plum trees.
0.0003 | f Achaea.m | Pattern: A corridor of flowering plum trees
0.0008 | c Achaea.m | exec : Pattern "A corridor of flowering plum trees" : #OK
0.0036 | f Achaea.m | Pattern: ^(?:\033\[37m(?:Flying above|In the trees above))?\033\[1... : (%1="A corridor of flowering plum trees")
0.0002 | c Achaea.m | exec : Pattern "^(?:\033\[37m(?:Flying above|In the trees above)...
0.0003 | k Achaea.m | Var "RoomNameSeen" changed from "Staircase into the sunken gardens" to "A corridor of flowering plum trees"
0.0013 | m Achaea.m | Event "RoomNameSeen" raised
0.3047 | a Achaea.m |You see exits leading east and west.
0.0113 | a Achaea.m ]8360h, 8470m, 36898e, 33900w exdb-
0.0023 | f Achaea.m | Pattern: ^\d+h, \d+m, \d+e, \d+w ([cexkdb@]*)\- : (%1="exdb")
0.0008 | c Achaea.m | exec : Pattern "prompt" : #var pflags %1 #RAISEEVENT Prompt #if ...
0.0003 | m Achaea.m | Event "Prompt" raised
0.0002 | c Achaea.m | exec : Event "Prompt" : #if (%iskey( @flags, runes)) { #class ...
0.0004 | k Achaea.m | Var "flags" changed from "" to "runes=1"
0.0005 | c Achaea.m | exec : Event "Prompt" : #var prompt_lock 1 #var fst_prompt %null...
0.0003 | k Achaea.m | Var "prompt_lock" changed from "0" to "1"
0.0002 | k Achaea.m | Var "fst_prompt" changed from "fst_moving=1" to ""
0.0031 | k Achaea.m | Var "prompt_lock" changed from "1" to "0"
0.0002 | c Achaea.m | exec : Event "Prompt" : #class descActive 0
0.0027 | c Achaea.m | exec : Event "Prompt" : #if (%db( @flags, find_room)) { i_del ...
0.0007 | m Achaea.m | Event "PromptBalanced" raised
0.4542 | m Achaea.m | Event "onRoomEnter" raised
0.0003 | c Achaea.m | exec : Event "onRoomEnter" : #if (!%iskey( @flags, ignore_room))...
0.0012 | k Achaea.m | Var "roomPrevious" changed from "17569" to "17570"
0.3718 | f Achaea.m | Alarm: *2
0.0008 | c Achaea.m | exec : Alarm "fst_moving" : #if (!%iskey( @fst_prompt, fst_movin...
|
|
|
|
 |
ReedN Wizard
Joined: 04 Jan 2006 Posts: 1279 Location: Portland, Oregon
|
Posted: Thu Jan 03, 2008 7:11 pm |
If at a minimum I could get someone to explain what the letters after the timestamp are referring to and what the timestamp measurement boundaries are, I think I could debug this on my own.
There are a couple of ways I could interpret the timestamps:
Method 1
=======
Delta = Time from the end of the last entry including idle time waiting for something to occur. In this case it's difficult to use the timestamps for anything unless you know for certain they are back to back without any idle time included.
Method 2
=======
Delta = Time from the start of execution of this chunk until this code is complete.
If it is using method 2 then this line:
0.4441 | a Achaea.m |
would mean that 0.4441 seconds after the last line completed it received a blank line and finished processing it. Is that accurate? I'm a bit uncertain I'm headed off on the wrong path here. |
|
|
 |
Dharkael Enchanter

Joined: 05 Mar 2003 Posts: 593 Location: Canada
|
Posted: Thu Jan 03, 2008 8:24 pm |
I don't use the debugger but after opening it and having a quick look around I would say the time stamps as you're showing them are delta time stamps, simple showing us the length of time since the beginning of the last message was received by the debugger.
If in the Options menu of the debugger you: check Show timestamps and uncheck Show delta time you'll see the actual time that these events were receieved.
If in addition you check Automatically add seperators whenever nothing happens for a duration of time, ie text received no triggers fire, input received whatever it will put a line showing the timestamp or duration of time that nothing happened.
Also as for what the letters in the 2nd column mean. You can work that out if you try.
notice for example whenever the 3rd column begins with "exec :" the 2nd column begins with a "c",3rd column "Event" 2nd column "m".
With a little effort you could work out a glossary.
Anyways,
Good luck! |
|
_________________ -Dharkael-
"No matter how subtle the wizard, a knife between the shoulder blades will seriously cramp his style." |
|
|
 |
ReedN Wizard
Joined: 04 Jan 2006 Posts: 1279 Location: Portland, Oregon
|
Posted: Thu Jan 03, 2008 9:34 pm |
"Automatically add seperators" was enabled, but for some reason it is not adding separators. That would actually really help if it did work.
|
|
|
 |
Arde Enchanter
Joined: 09 Sep 2007 Posts: 605
|
Posted: Thu Jan 03, 2008 10:24 pm |
ReedN wrote: |
If at a minimum I could get someone to explain what the letters after the timestamp are referring to and what the timestamp measurement boundaries are, I think I could debug this on my own.
|
It is easy. Just look in the Messages menu in the Debugger window - all possible letters and their meanings are listed there. |
|
|
 |
ReedN Wizard
Joined: 04 Jan 2006 Posts: 1279 Location: Portland, Oregon
|
Posted: Thu Jan 03, 2008 10:34 pm |
Doh, I didn't even see that there... It was right in front of me.
Now I just need to get the "Automatically Add Separators" working and I should be all set to debug this. I tried selecting it and unselecting it, then selecting it again, but it doesn't seem to want to add the separators for me. |
|
|
 |
Dharkael Enchanter

Joined: 05 Mar 2003 Posts: 593 Location: Canada
|
Posted: Fri Jan 04, 2008 12:03 am |
It wont add it for messages that have already been displayed.
Toggling show delta time stamps option will work on previously Logged debug messages.
However you'll have to debug some more after enabling the auto-sep option. |
|
_________________ -Dharkael-
"No matter how subtle the wizard, a knife between the shoulder blades will seriously cramp his style." |
|
|
 |
ReedN Wizard
Joined: 04 Jan 2006 Posts: 1279 Location: Portland, Oregon
|
Posted: Fri Jan 04, 2008 1:34 am |
Yeah, I had it enabled the whole time, so it should be working. Does it work for everyone else?
|
|
|
 |
ReedN Wizard
Joined: 04 Jan 2006 Posts: 1279 Location: Portland, Oregon
|
Posted: Mon Jan 07, 2008 8:59 pm |
Okay, I finally root caused this to two things which I noted in other topics. One thing I never figured out was an issue with "Automatically Add Separators". I use Cmud on two different computers and with the setting identical on both, it automatically adds separators on one computer but not the other. I can't find any reason why it doesn't work on one computer but works on the other. Quite strange.
|
|
|
 |
Zugg MASTER

Joined: 25 Sep 2000 Posts: 23379 Location: Colorado, USA
|
Posted: Mon Jan 07, 2008 10:53 pm |
The "Automatically add separators" only adds a separator when you enter a new command on the command line. It doesn't add anything when there is just a long delay or anything. Also, it won't add a new separator if one already exists on the last line of the debugger.
You can also send your own separator using the command:
#DEBUG "-" |
|
|
 |
ReedN Wizard
Joined: 04 Jan 2006 Posts: 1279 Location: Portland, Oregon
|
Posted: Mon Jan 07, 2008 11:04 pm |
Thanks, sending my own separator with that command will work perfectly.
|
|
|
 |
|
|