Debugging HSL
(→How to Use It) |
(→Real-Time Monitoring of Field Values) |
||
| Line 384: | Line 384: | ||
DebugTrackerRGB(customName as String, r as Integer, g as Integer, b as Integer) | DebugTrackerRGB(customName as String, r as Integer, g as Integer, b as Integer) | ||
</hsl> | </hsl> | ||
| − | |||
| − | |||
| − | |||
| − | |||
== IDE Debug Switches == | == IDE Debug Switches == | ||
Revision as of 17:44, 14 September 2012
|
- Plain messaging
- The ASSERT command
- The Debug System
- Remote Call Failscript Debugging Utility
- Performance Profiling
- Real-Time Monitoring of Field Values
- IDE Debug Switches
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
- The $DEBUG system node
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
- Cross-instance messaging
- Message history
- Client and Server debugging
- Dynamic subscription of listeners
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?
- The Debug System is not a debugger
- Production(live) world debug messaging
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?
- Provides a common failure routine to handle remote call failures that do not require special handling
- Displays the contents of the failed remote call in a script error
What problem does this not solve?
- Failures that require the calling code perform some kind of recovery should not use this functionality
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
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
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.
