Register to post in forums, or Log in to your existing account
 

Play RetroMUD
Post new topic  Reply to topic     Home » Forums » CMUD Beta Forum Goto page 1, 2  Next
Zugg
MASTER


Joined: 25 Sep 2000
Posts: 23379
Location: Colorado, USA

PostPosted: Mon Nov 05, 2007 8:17 pm   

New Script debugger window and timestamps for v2.11
 
It looks like there are many situations occurring with various problems in v2.10 that are hard to track down because of complex scripts. Whether it's crashing, or just causing speed problems. I've seen many posts on the forum where it is very hard to determine the problem because it only occurs online when using your entire set of scripts.

So, I've decided to try and add something to v2.11 that everyone (including me) has wanted for a long time: a script debugging window.

Now, this has *nothing* to do with the Debugger that was in zMUD. That was more of a traditional debugger which only worked with the specific parser that zMUD used. And honestly, it wasn't very useful for real-time script debugging.

The existing "debug trigger" option helps a little, but because it displays the matching trigger within the main MUD output window, it usually causes a mess, and can easily cause side effects (like gagging the wrong line, etc).

What CMUD really needs is a separate debugging "logging" window. This window would display the text from the MUD that causes a trigger to fire, tell you what trigger fired, tell you the values of the %1..%99 subpatterns. It would also tell you when a particular script thread starts, whether it's a trigger, alias, macro, command line, whatever, and optionally also tells you when that thread finishes. It would tell you when a thread suspends itself for a #WAIT, #WAITFOR, etc.

In addition, each line in the debug log window would be timestamped, so that you could easily determine the time between steps, etc.

To handle displaying the ANSI and MXP color of the lines from the MUD in the debugger window, the debugger window needs to use the same scrolling ANSI display component as the main MUD output. Adding timestamps to this has the side-effect of providing optional time-stamps on all existing MUD windows (main session, capture windows, etc). I will allow you to define the time format that you want displayed on a window-by-window basis. You'll also be able to display "ticks" instead of absolute time values, where the "ticks" come from the GetPerformanceCount API for accurate timing. You'll also be able to toggle whether to display the time value, or to display the difference between the previous line and the current line (in milliseconds).

For the debugger, there will be options for what kind of debug lines you want to be displayed. I'll probably also allow you to set a flag for individual settings so that you can just debug a certain set of triggers or scripts without getting spammed from all of your other scripts.

I'll post more on this once I have something implemented, but feel free to post your own suggestions. Let's not get *too* carried away...I want this to be immediately useful in v2.11 without trying to make it do *everything* and having it take a month to implement. But I think having something like this will make it a *lot* easier for people to see exactly what is running and how long it is taking and to be able to post this to the forums when asking for help on a specific problem.
Reply with quote
Fang Xianfu
GURU


Joined: 26 Jan 2004
Posts: 5155
Location: United Kingdom

PostPosted: Mon Nov 05, 2007 9:20 pm   
 
I have only one thing to say on this topic: Timestamps are something that's surprisingly annoying to add via triggers. This is excellent news

I'll reserve judgement on the debugger itself until I've tried it out.
_________________
Rorso's syntax colouriser.

- Happy bunny is happy! (1/25)
Reply with quote
Seb
Wizard


Joined: 14 Aug 2004
Posts: 1269

PostPosted: Tue Nov 06, 2007 2:25 am   
 
Every aspect of this sound excellent! I added a bunch of stuff myself for timestamping lines and calculating the time differences in zMUD, but your implementation of this and the debugging sound great! The debugger in zMUD was pretty horrible to use as when you had a lot of scripts running, which I often do (prompt triggers and such), there is just so much spam to wade through when more triggers keep firing on more text coming in from the mud. I can't find the smilie that Fang used, but that's the one I want to use too! Very Happy
Reply with quote
Zugg
MASTER


Joined: 25 Sep 2000
Posts: 23379
Location: Colorado, USA

PostPosted: Tue Nov 06, 2007 3:19 am   
 
Here is some sample output from the new debugger window. This is subject to change based upon suggestions:

  [1] untitled Comline : start : #trigger {hello (*)} {#show fired}   
  [1] untitled Comline : stopped                                      
  [1] untitled Comline : start : #show hello this is a test            

hello this is a test                                                   
  Trigger: hello (*) : (%1="this is a test")                          
    [2] untitled Trigger : start : Trigger: hello (*) : #show fired    

fired                                                                  
    [2] untitled Trigger : stopped                                    
  [1] untitled Comline : stopped                                       


The forum code can't really color this the way it really is on the screen. Those "highlighted" lines have a background color that actually extends across the entire line, and of course there isn't any white space between the lines. The lines from the MUD like "hello this is a test" and "fired" are in the same color as they are in the MUD output window (the green on black default session color).

The "Trigger: hello (*)" is underlined and is a hyperlink. If you double-click on it in the debugger window, it will open the settings editor to show the actual trigger. Also notice that the captured values of %1 are displayed for debugging purposes.

The indentation indicates the depth of currently executing threads. Notice that the command line is thread [1], and when I typed "#SHOW hello this is a test", the output caused the trigger to fire, which spawned another thread [2]. It is indented to show that thread [1] is still active at this point.
Reply with quote
Zugg
MASTER


Joined: 25 Sep 2000
Posts: 23379
Location: Colorado, USA

PostPosted: Tue Nov 06, 2007 3:20 am   
 
Oh, and obviously there isn't any timestamping yet in that sample output. When I get timestamps done tomorrow, then I'll show a real screenshot.
Reply with quote
Tech
GURU


Joined: 18 Oct 2000
Posts: 2733
Location: Atlanta, USA

PostPosted: Tue Nov 06, 2007 2:18 pm   
 
This all sounds great Zugg. Keep up the good work. I haven't done anything so complex where I'd need this but clearly some of IRE guys are going to fall in love with it. It will help me when ( real life slows down a bit and) I get back to the business of making packages.

One of these days I've got to check out an IRE mud.
_________________
Asati di tempari!
Reply with quote
JQuilici
Adept


Joined: 21 Sep 2005
Posts: 250
Location: Austin, TX

PostPosted: Tue Nov 06, 2007 3:48 pm   
 
I love this idea. One of the most annoying things about debugging BIG collections of scripts is simply not knowing what script is causing an effect. Big, BIG thumbs-up to this addition!

I have a couple of suggestions, too. Certainly not needed for the initial, quick implementation, but please put them on the to-do list somewhere:
  • A #DEBUG command, or something similar. Works like #say or #show, but only puts info into the debugger window. Can probably made to act like a noop (fast) when the debugger is not active.
  • Some command to dump the current script call stack (with arguments) into the debugger window. So, if I find that my Foo alias is being called unexpectedly somehow, I can put the command in there and quickly find the call chain. (Note that this info all appears to be available in the current implementation, but it can take some work to tease it all out if the call stack is deep.)
_________________
Come visit Mozart Mud...and tell an imm that Aerith sent you!
Reply with quote
Caled
Sorcerer


Joined: 21 Oct 2000
Posts: 821
Location: Australia

PostPosted: Tue Nov 06, 2007 9:42 pm   
 
I think this will be a very popular feature. I know it'll make debugging other people's scripts in the tech section of our mud forums pretty easy, which will make me as happy as it makes them, heh.

A simple way to time-stamp is something I've wanted for a long time.

What are the chances of being able to display other bits of information (variable values) of our choice, in the main window in the same way that this will allow a timestamp? Being able to do away with #subs and #psub in prompt triggers would be great. In the past I've used all sorts of displays (status windows, buttons, echoes, child windows and probably more) to help out in combat, but as the years go by I find more and more that if it can fit in the prompt, or better yet on every line, then it is both easier to fight AND (importantly) easier to find bugs later when going over the logs.
_________________
Athlon 64 3200+
Win XP Pro x64
Reply with quote
Zugg
MASTER


Joined: 25 Sep 2000
Posts: 23379
Location: Colorado, USA

PostPosted: Tue Nov 06, 2007 10:24 pm   
 
Quote:
A #DEBUG command, or something similar. Works like #say or #show, but only puts info into the debugger window. Can probably made to act like a noop (fast) when the debugger is not active.

*Excellent* idea. Of course, it conflicts with the current #DEBUG command that I use for testing, but maybe I can change that to something more obscure. But I think you will see this in the next version.
Quote:
Some command to dump the current script call stack (with arguments) into the debugger window. So, if I find that my Foo alias is being called unexpectedly somehow, I can put the command in there and quickly find the call chain. (Note that this info all appears to be available in the current implementation, but it can take some work to tease it all out if the call stack is deep.)

That is actually quite difficult. The current implementation doesn't keep track of a "call" stack in terms of who called whom. But in the existing debugger window you can already see that using the indentation levels shown in the example above. So I think it's still visually available. It's just that the script execution module doesn't have that information available to be dumped from a command.
Quote:
What are the chances of being able to display other bits of information (variable values) of our choice, in the main window in the same way that this will allow a timestamp?

Probably no chance, sorry. The timestamp is relatively easy because I already have a record for each line that stores a value, and I can easily just display this value to the left of the line for each and every line. But this record isn't available to the scripting module...it's hidden deep within the scrolling text display. So this line record can easily store the time the record was created/updated, but there would be no way to add information to this record from your scripts themselves, and this record has no access to the database or cache where your variables and stuff are stored. Also, this "column" is going to be a fixed width, and the stuff you are talking about is usually variable-width information. And really, there is no reason not to just use #PSUB or #SUB...that's what they are there for and they work well for that.
Reply with quote
Seb
Wizard


Joined: 14 Aug 2004
Posts: 1269

PostPosted: Wed Nov 07, 2007 3:03 am   
 
jquilici wrote:
A #DEBUG command, or something similar. Works like #say or #show, but only puts info into the debugger window. Can probably made to act like a noop (fast) when the debugger is not active.

Can't we just use #NOOP for that? I already have lots of #NOOPs that used to be #ECHOs before when I was debugging... Wink
Reply with quote
Zugg
MASTER


Joined: 25 Sep 2000
Posts: 23379
Location: Colorado, USA

PostPosted: Wed Nov 07, 2007 5:57 am   
 
No, I'd rather keep #NOOP performing "no operation" like it should. If you want to convert your #NOOP into #DEBUG then it's easy to just copy/paste the XML in an external editor (someday I'll add a find/replace to the settings editor since the XML view definitely needs it).
Reply with quote
Seb
Wizard


Joined: 14 Aug 2004
Posts: 1269

PostPosted: Thu Nov 08, 2007 2:38 am   
 
OK, no biggie - I'd probably just change the ones I wanted anyway. Just thought it might be less work for you. Smile
Reply with quote
Seb
Wizard


Joined: 14 Aug 2004
Posts: 1269

PostPosted: Thu Nov 08, 2007 11:01 am   Re: New Script debugger window and timestamps for v2.11
 
Zugg wrote:
For the debugger, there will be options for what kind of debug lines you want to be displayed. I'll probably also allow you to set a flag for individual settings so that you can just debug a certain set of triggers or scripts without getting spammed from all of your other scripts.

It would be great to be able to toggle viewing of various things on and off: contents of settings that are fired, show variables changing, triggers showing or not, alarms or not, other settings being changed, added or deleted, etc. So for example, you could set-up the debug window to only show you which variables are changing and when, with or without mud output getting in the way, with or without triggers getting in the way.
Reply with quote
Zugg
MASTER


Joined: 25 Sep 2000
Posts: 23379
Location: Colorado, USA

PostPosted: Thu Nov 08, 2007 5:08 pm   
 
Yes, there are a *lot* of options in the debugger window for controlling all sorts of different message displays. Most of them are turned off by default because of the spam that they can generate.
Reply with quote
Zugg
MASTER


Joined: 25 Sep 2000
Posts: 23379
Location: Colorado, USA

PostPosted: Fri Nov 09, 2007 12:17 am   
 
One problem I am running into is using copy/paste and getting the timestamp values. By design, the timestamps are *displayed* on the MUD screen, but they are not part of the stored text for each line. The timestamp acts as a separate column to the left of the displayed text (sort of like the line numbers in the script editor).

When you copy text from the screen, the timestamp values are ignored. Just like when you copy/paste text in the script editor, you don't get the line numbers.

So, while this is exactly what you want in the MUD window, it's not what you want in the Debugger window. I want people to be able to copy/paste everything to post it to the forum where we want to be able to see the timestamps.

I can easily make the "Save to file" routine write the timestamps to the file. But it's going to be tricky handling this copy/paste. I really don't want to mess up how normal copy/paste works in the MUD window, and right now the timestamp implementation is very clean. Anyway, the first version of the debug window/timestamps that I'm planning to release tomorrow might still have this problem unless I can think of an easy and clever solution.

Other than that, the rest of the debug window stuff is going smoothly and should be ready for tomorrow's release.
Reply with quote
Seb
Wizard


Joined: 14 Aug 2004
Posts: 1269

PostPosted: Fri Nov 09, 2007 1:13 am   
 
Will #LOGs contain the timestamps? I think it would be nice if they did (but some people probably think the opposite) (probably with the Timestamp column as a fixed width so the logs remain easy to read and they can still be stripped off with Excel or a regular expression find/replace). Personally, I wouldn't have a problem with all windows copy/pasting the timestamp (if it is displayed). Although perhaps a preference option controlling this, or not actually copying to the clipboard when you select text, but instead waiting until you either use Edit, Copy, or Copy with Timestamps, or right-click, Copy, or Copy with Timestamps. In other words, having both options available from the Edit menu and right-click menu. Maybe double-clicking a word would still copy it to the clipboard like it does now.
Reply with quote
Vijilante
SubAdmin


Joined: 18 Nov 2001
Posts: 5182

PostPosted: Fri Nov 09, 2007 5:35 am   
 
I would say probably a right-click option is going to be the easiest way. The choices then for selection of the text is to either kludge it so the user can't select the time stamps, or put a small hideable panel on the window. The hideable panel will make selection easier, but then you have to synch is display to the main window scrolling. If I had a choice I would go for the hideable panel.
_________________
The only good questions are the ones we have never answered before.
Search the Forums
Reply with quote
Seb
Wizard


Joined: 14 Aug 2004
Posts: 1269

PostPosted: Sat Nov 10, 2007 5:22 am   
 
Yep, definitely loving the debugger window and timestamps! Very Happy I like the way you can switch timestamps on and off and it affects the existing scrollback. What would also be really cute, but maybe impractical, is if you could retrospectively turn on and off various Messages in the debug window. So they would all have to be sent to it, but some would be initially hidden. I suppose one of the snags though is that would screw with the timestamp deltas, unless they were recalculated when you showed or hid other lines...
Reply with quote
Seb
Wizard


Joined: 14 Aug 2004
Posts: 1269

PostPosted: Sat Nov 10, 2007 5:28 am   
 
Oh, and it would be nice to be able to display both timestamp and timestamp delta sometimes.
Reply with quote
Iceclaw
Apprentice


Joined: 11 Sep 2005
Posts: 124

PostPosted: Sat Nov 10, 2007 5:49 am   
 
It would be really nice if we could hide the timestamps but still get them logged. I find myself toggling them occassionaly on when I need to keep track of when things were said, but you really cant go and do that well retrospectively.
Reply with quote
slicertool
Magician


Joined: 09 Oct 2003
Posts: 459
Location: USA

PostPosted: Sat Nov 10, 2007 8:34 am   
 
Wow, having the script debugger active takes Ctrl+Q from 3.3s on my machine to about 14s. However, that's to be expected.

Thanks for adding the debugger window, Zugg.
_________________
Ichthus on SWmud: http://www.swmud.org/
Reply with quote
Seb
Wizard


Joined: 14 Aug 2004
Posts: 1269

PostPosted: Sat Nov 10, 2007 4:49 pm   
 
Iceclaw wrote:
It would be really nice if we could hide the timestamps but still get them logged. I find myself toggling them occassionaly on when I need to keep track of when things were said, but you really cant go and do that well retrospectively.

Er, that's exactly what happens already. I can switch them on and off with no problems and it affects all the scrollback - you don't even have to close the Preferences window.
Reply with quote
Iceclaw
Apprentice


Joined: 11 Sep 2005
Posts: 124

PostPosted: Sat Nov 10, 2007 4:56 pm   
 
It affects the scrollback, but it doesnt log them if the display is switched off.
Reply with quote
Seb
Wizard


Joined: 14 Aug 2004
Posts: 1269

PostPosted: Sat Nov 10, 2007 5:13 pm   
 
Do you mean with #LOG? Saving scrollback works fine. Is what you want separate options for displaying them to the screen and logging them with #LOG? I have to agree that this would be useful for some people.
Reply with quote
Zugg
MASTER


Joined: 25 Sep 2000
Posts: 23379
Location: Colorado, USA

PostPosted: Sat Nov 10, 2007 6:48 pm   
 
Quote:
What would also be really cute, but maybe impractical, is if you could retrospectively turn on and off various Messages in the debug window

No way to do that unfortunately. Once the text is written to the debugger, it's "gone" and can't be easily filtered since the window itself doesn't have any knowledge of the message structure...the window itself just sees them as lines, like lines from the MUD. Timestamps are implemented at a low level within the scrolling text component, so that's why it can easily show or hide them. The timestamps are stored for each line regardless of whether they are actually displayed.
Quote:
Oh, and it would be nice to be able to display both timestamp and timestamp delta sometimes.

I'll have to think about how I'd implement this. When delta time is disabled, it just uses the timestamp Format with the Delphi FormatDateTime routine (same as %time) and there is no easy way for me to hook into this to add support for delta times.
Quote:
It would be really nice if we could hide the timestamps but still get them logged.

I'll definitely add an option to that in the Log preferences.
Quote:
Wow, having the script debugger active takes Ctrl+Q from 3.3s on my machine to about 14s

Well yeah, obviously the debugger is going to have a big impact on the speed because of all the processing that it is doing. I tried very hard to prevent the timestamps from slowing anything down, but with the debugger window open, it's always going to be slower.
Reply with quote
Display posts from previous:   
Post new topic   Reply to topic     Home » Forums » CMUD Beta Forum All times are GMT
Goto page 1, 2  Next
Page 1 of 2

 
Jump to:  
You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot vote in polls in this forum

© 2009 Zugg Software. Hosted by Wolfpaw.net