Debugging HSL

From HEWIKI
Jump to: navigation, search


Contents

Debugging HSL is primarily done via inserting messages or asserts at major branches in the code, though there are many other mechanisms available. This page covers the pro's and con's of each method, which basically boil down to:

Background

Debugging HSL scripts uses techniques familiar to programmers, and some that are not. In programming languages like C++, for example, one might debug code with asserts, printf()s, log messages, and ultimately a sophisticated debugging tool like that built into Visual Studio. It is important to realize that HeroEngine servers are servicing many connected users simultaneously (both in the live game and in development) and therefore the HSL virtual machines cannot afford to be suspended for the typical "single stepping" that is common to debuggers. As you can imagine, this would break the highly collaborative nature of HeroEngine.

Instead, HeroEngine supports an extremely rapid iterative development style where a developer can make changes to code and compile in literally seconds to create rapid, incremental tests. Consequently, debugging HSL primarily consists of inserting messages or asserts at major branches in the code and then adding additional messaging as needed to narrow down the problem.

This may seem odd, or a bit primitive at first, but it does work remarkably well. This is made possible by the extremely rapid code-compile-test cycle time (and no startup time, as in rerunning a C++ program).

Because of this approach, HeroEngine (and its Required Systems) also include advanced functionality that allows for real-time monitoring of field changes (on the client), debug message histories and multiple implementations of the observer pattern for selectively monitoring of these messages (so as to filter high-frequency message streams).

General Considerations for Debugging

Performance

It is important to think about how your debug messaging will be used and the volume you expect it will produce in a production server. For almost all systems, debug messaging should be #defined out of compilation for live servers and frequently should be #defined out in development servers when you are not actively debugging.

Using #define in your code to elimitate debugging when unnecessary.

// Top of script
#define debug
 
function Foo()
  #if debug  
    // If you are using the Debug System for example
    Debug("This is a debug message that will be sent as long as the #define debug is not commented out.")
  #endif
.

To tell the compiler to ignore your debug messages you simply comment the #define debugEnabled line.

// Top of script
// #define debug


Plain Messaging

Overview

Rapid and iterative development environment of HeroEngine is often well suited to the simplest of debugging methodologies, text output to a window. In fact, most of the more complex debugging techniques described on this page are incremental improvements on the idea of a simple println.

What problem does this solve?

The humble println serves quite well in an rapid iterative development environment allowing a developer to quickly narrow the scope of a problem to a particular routine by simply throwing more printlns at the problem.

What problem does this not solve?

Simple messaging is not particularly suited to expression of complex data objects.

Usage

Client

There are two potential outputs for messaging: the chat panel, and the console window.

Output to the Chat Panel

// The second parameter is an empty string for the "default" channel, depending on your game's implementation of chat
//   some other channel may be preferred.
//
$CHAT._GotChatMessage( message, "" )
Output to the Console

Output to HeroBlade's console window uses the println external function.

println("This is a message.")

Server

Output from the server to the client's Chat panel use the various messaging methods supported by the $CHAT system node.

// The second parameter is an empty string for the "default" channel, depending on your game's implementation of chat
//   some other channel may be preferred.
//
$CHAT.ChatPlayer( accountID, "", "This is a debug message." )

Assert

See also: ASSERT

Overview

There is a programming philosophy called Design By Contract, in which certain preconditions must be satisfied before a call to a routine is valid. For HSL's purposes, the way of enforcing a contract is the insertion of Asserts verifying that the conditions have been met.

Sometimes, the addition of one or more asserts is a quick way to debug a routine that is misbehaving. Likewise the external function ScriptError can be used in this manner. The primary benefit of using an assert in debugging is that it produces the entire call stack in the output.

A useful intermediate option is ScriptErrorAndContinue() which produces a call stack at the point that it is executed by does not halt the execution.

Usage

Using Assert:

assert( theNode <> None, "The node passed to this function was None.")

Using Script Error:

b as boolean = true
if b
  ScriptError("This is a script error" )
.

Using ScriptErrorAndContinue():

b as boolean = true
if b
  ScriptErrorAndContinue()
.
// This line of code will be reached

Debug System

The Debug System is an implementation of the Observer Pattern for messaging that is included as a part of the HeroEngine MMO Foundation Framework. The implementation supports system-specific messaging, cross-instance reporting, a history, and multiple interested listeners.

Overview

The Debug System is comprised of two major components:

The system area serves as a repository for the persistence of data for the current server session. It is to this area that all messaging is sent and subsequently farmed out to those parties that have registered themselves as interested listeners. Debug messages are then cached in the area to provide for message histories for a given system.

What problem(s) does this solve?

Granularity

The Debug System allows interested listeners to subscribe based on a particular system for a category of messages, a script or a message for system X for a specific node. Even restricted to the development environment, messaging in major systems(combat for example) often produce messaging that is low frequency for a particular instance but high frequency when taking into consideration all of the instances involved in combat. This type of messaging requires a more granular methodology to avoid overwhelming the listener with information which is not relevant to their current needs.

The Debug System supports subscription to messages on a general "system" level down to messages relating to a specific node.

Cross-Instance Messaging

The chat functions for messaging (MsgPlayer, MsgArea) only send a message to the client if the character is currently loaded into that same local GOM. This limitation can be extremely inconvenient for systems that span multiple area instances, and especially problematic when working on a system area.

The Debug System handles getting the message to the listener regardless to whether or not the listener is currently loaded into the same local GOM.

Message History

Without some kind of message history, debugging is lost when the message passes beyond the end of the chat buffer. The implementation of message history permits a developer to later review messages they may have missed and/or see the messages in sequence without interruption by other messages.

The Debug System has a hard limit of a maximum of five-hundred messages stored for a given subject (system name or script name), this ensures the memory footprint of the system area that stores the history is not capable of unlimited growth.

Dynamic Subscription of Listeners

As an implementation of the observer pattern, the Debug System supports the concept of subscribe/unsubscribe for listeners to dynamically add or remove themselves from the list of people interested in debug messaging.

What problem(s) does this not solve?

Usage

Adding Debugging to your Scripts

Low Frequency Messages

For systems that will not generate high frequency messaging, the following code is very appropriate. Caution, there is no granularity for these types of messages so it is best used for higher level debugging and not for debugging what is going on for a specific node.

If your system needs to do frequent messages that are particular to a specific node look at the next section High Frequency Messages that Require Granularity.

function Debug(Message as String)
  $Debug.SendNotifyDebugMessage("YourSystemNameHere", message)
.

Anywhere in that script, when you need to do debug messaging:

debug("My silly debug messaging here")
High Frequency Messages that Require Granularity

For extremely high traffic systems, such as the STATE ENGINE for creature AI, we found the need to allow for monitoring of debug messages for a specific node for better granularity of messaging. This does require a minor alteration of the function I originally sent out, you do not have to make this change since the other way works and will continue to work. If your system needs the capability for someone to monitor debugging for a specific ID, then the following the function you need:

NOTE: Sending a specific debug message DOES send the message to listeners subscribe to the system as a whole. So if I send a message pertaining to a specific node for the MissionSystem, anyone listening to the MissionSystem as a whole will receive the message as well as anyone listening to the specific node under the MissionSystem. If you are listening to both the sytsem as a whole and the node, you will get two messages.

function Debug(message as string)
 
  nodeToWhichMessageAppliesID as id = FindTheNodeIDICareAbout()
  // in other words, what ever code you need to specify the ID you care about
 
  $DEBUG.SendNotifyDebugMessageSpecificNode(YourSystemName, message, nodeToWhichMessageAppliesID)
.

function Debug(nodeToWhichMessageAppliesID as id, message)
  $DEBUG.SendNotifyDebugMessageSpecificNode(YourSystemName, message, nodeToWhichMessageAppliesID)
.

/Commands for debugging

All of these commands should be entered in the chat window's textinputbox.

Subscribe

To listen to debug messages from your system

/debug subscribe YourSystemNameHere

To subscribe to messages for a specific node of a system:

/debug subscribe YourSystemNameHere nodeOfInterestID

To subscribe to messages that contain or lack one or more words:

/debug subscribe YourSystemNameHere filteron="word1,word2,!word3...N"

Unsubscribe

To stop listening to debug messages from your sytem:

/debug unsubscribe YourSystemNameHere

To unsubscribe to a message for a specific node of a system:

/debug unsubscribe YourSystemNameHere nodeOfInterest

Additional Options

View the last (up to 500 debug messages):

/debug history YourSystemNameHere

View the last (up to 500 debug messages) that contain or lack specific words:

/debug history YourSystemNameHere filteron="word1,word2,!word3...N"

View the current systems that are listening to debug messages:

/debug view

Remote Call Failscript Debugging Utility

Overview

Remote calls perform a callback to a specified script in case of a failure(script error) on the receiving side. This is a useful capability if the calling code needs to perform some sort of special handling to recover from the error. However, often there is no special handling required merely the developer needs to know that an error occured.

The DebugUtils script has several utility functions that save the time for writing a remote call fail function, and may be used as a generic alternative.

What problem does this solve?

What problem does this not solve?

Usage

Using the common remote call failure functions located in debugUtils requires only changing the fields .failScript and .failFunction for the remote call prior to making the call.

Using the Common Fail Function in Remote Calls to the Client

For remote calls to the client, destined for a remote function, the failure function(untrusted) is found in the debugUtils script with the name ClientRMCFail.

// Failed remote call to the client returns to the debugUtils script on the server
untrusted function ClientRMCFail(rmcin as Class RemoteCallClientIn)
Example

rmc as Class RemoteCallClientOut
rmc.toPlayer = thePlayer
rmc.toScript = "theScript"
rmc.toFunction = "IMustFail"
rmc.failScript = debugUtils
rmc.failFunction = "ClientRMCFail"
rmc.args["this"]= "is"
rmc.args["a"] = "test"
RemoteCallClient(rmc)

Using the Common Fail Function in Remote Calls To the Server

For remote calls to the server, destined for an untrusted function, the failure function is found in the debugUtils script with the name ServerRMCFail.

// Failed remote call to the server returns to the debugUtils script on the client
remote function ServerRMCFail(rmcin as Class RemoteCallServerIn)
Example

rmc as Class RemoteCallServerOut
rmc.toScript = "theScript"
rmc.toFunction = "IMustFail"
rmc.failScript = debugUtils
rmc.failFunction = "ServerRMCFail"
rmc.args["this"]= "is"
rmc.args["a"] = "test
RemoteCallServer(rmc)

Performance Profiling

Profiling, refers to the analysis of a routines behavior generally for the purpose of optimizing the speed or memory usage of a program. HeroEngine supports profiling HSL for the purpose of speed optimizations through the implementation of several external functions for per call or per line tracing of processing.

See also: Profiling


Real-Time Monitoring of Field Values

What It does

This feature works only on the client (HeroBlade).

The purpose of this variable tracker is to provide a means to view the current value of a variable at a specific line of code. For example,

a as Integer = 5;
DebugTrackerInt("MyVariable",a)

At the line of code where that function is called, the string "MyVariable: 5" will be displayed on the Variable HUD. If you were to call the same function again after "a" has changed its value to say, 10, then the string "MyVariable: 10" will be displayed in place of the previous string. It won't create a new entry, as long as the exact same string is used to identify the variable. The string is CaSeSeNsItIvE and does not remove trailing / beginning spaces.

Where It Is

Variable Heads Up Display

The button which spawns the Variable HUD window can be found on the Renderer Panel, just under the programmer switches. It's the only current button which is colored on the render panel. The button is labelled "View Debug Tracker Values". When you click on it, the Variable HUD window will pop up and all current values will be displayed.

Why It Is Useful

This can be used to examine the current state of things at a glance. In the case of C++, you don't need a debugger to view the values, and for both C++ and HSL you don't need to print the values to the logging window to see them.

In the case of a realtime application such as ours, if DebugTracker("VarName",blah) is called every frame, and blah is a changing variable, you'll be able to see how blah changes over time.

Things to Avoid

The function calls to DebugTracker obviously take up a certain amount of CPU time in HeroBlade. If you don't use it, don't keep the function call around. Keep a close eye on where you call the functions from, I'd assume it'd be very easy to lose track of which script called which DebugTracker.

How to Use It

In C++, the DebugTracker function is fully templated. All you need to do is DebugTracker("VariableName",variable) and it will work.

In HSL, overloading and templating is not supported, so things are a little more tricky. But it currently supports the following functions:

DebugTrackerBool(customName as String, b as Boolean)
DebugTrackerInt(customName as String, i as Integer)
DebugTrackerFloat(customName as String, f as Float)
DebugTrackerString(customName as String, s as String)
DebugTrackerVector3(customName as String, v as Vector3)
DebugTrackerRGB(customName as String, r as Integer, g as Integer, b as Integer)

IDE Debug Switches

What It Does

The purpose of the debug switches are to provide a means to retrieve a boolean value which is set by clicking a checkbox. For example:

if(DebugSwitch("MySwitch"))
  // This code will be executed only if the checkbox
  //"MySwitch" on the programmer switches listbox
  // is checked.
  println("Switch is on.")
.

When you call a DebugSwitch("MySwitch") for the first time, internally HeroBlade checks the list of switches to see if "MySwitch" already exists. If it does not, it creates it with the value "false". It then returns the value "false". If it already exists, it returns the current value, determined by the state of the checkbox in the programmer switches listbox.

Note: If you want to set a default value for a switch, use DebugSwitchDefaultFalse or DebugSwitchDefaultTrue, and when it creates the switch it will be assigned to that default value.

Where It Is

Programmer Switches

The programmer switches listbox can be found on the Renderer Panel, just above the Variable Tracker button.

Why It Is Useful

All that spam that you need to print out to the console can now just be on a switch. Any other arbitrary code that you want to control whether or not it gets executed can now be on a switch.

Things to Avoid

The only performance implications with this is in the case of a per frame callback. If a DebugSwitch is called every frame, or even multiple times per frame, it will slow down heroblade slightly. You need to remove these switches as soon as debugging is done. If it's not called per frame then the performance hit is minimal. However, please keep the debugswitch clutter to a minimum. If you're not using it, don't keep it around.

If you're going to call a debug switch multiple times inside of a loop, such as

// Pseudocode
for(i = 0; i < 20; i ++)
 if(DebugSwitch("MySwitch"))
   Code
 .
.

You should pull it out, so that it looks like this:

*Pseudocode*
TheResult as Boolean = DebugSwitch("MySwitch")
for(i = 0; i < 20; i ++)
 if(TheResult)
   Code
 .
.

This is a simple optimization that will speed things up.

How to Use It

You have three functions at your disposal for this feature.

DebugSwitch(switchName as String)
DebugSwitchDefaultTrue(switchName as String)
 
//This is the same result as "DebugSwitch", just a different name.
DebugSwitchDefaultFalse(switchName as String)

To use it, just call if(DebugSwitch("MySwitchName")) and it will create a switch for you to modify on the programmer switches listbox. You can then alter the switch value by clicking the checkbox. The next time that DebugSwitch("MySwitchName") is called, the return value will be the "true" if the checkbox is checked, and "false" if the checkbox is not checked. Use this however you wish.

Personal tools
Namespaces
Variants
Actions
Navigation
Toolbox