Debugging Your AGHTM Missions
Mission building is an iterative experience of trial and error, with lots of tweaking in between. It is nearly impossible to build a rich mission experience without being able to identify why something does not work as expected. Neither LUA Script nor DCS offer any methods of debugging your code natively. There are no built-in error handling code structures that we can use, like we would find in other programming languages. For those familiar with other programming languages, this would be the analog to a try/catch or an onerror goto type block.
The only real method we have of being able to identify and resolve these issues is our ability to capture or trap information about something before an error occurs to compare to information available after a failure occurs. This is called Object State. by comparing a before and after state of an object, we can often tell what went wrong. This section will walk you through how to use the agLogger script from the agScript for DCS library, to add debugging and logging to your mission files so you can get a clear idea of what is going on inside your code, especially when it fails unexpectedly.
The agLogger script (one of the scripts in the agScript for DCS Library) is included in the AGHTM download, and is used by AGHTM to log critical events while the missions are running. In your code, you can instantiate additional instances of the agLogger object to capture and log any additional information you want in separate files to make reviewing those logs for the necessary information much easier. Additionally, any messages added to custom log files, will also contain timestamps, in seconds after mission start, so you can trace exactly when events occur in mission time.
The logger will attempt to log messages to a file with the name specified when the logger is instantiated. This file will be created in your [Saved Games]\Logs
folder, the same folder containing your standard dcs.log
file. If for some reason, this write attempt fails, either due to permission settings, or to the default io
or lfs
Lua libraries not being enabled (see below), the logger will make the entries into the standard DCS log file with the prefix specified. When searching the logs, you simply search for the prefix and traverse all of the items with that prefix. That being said, make sure your prefix is something not likely to be encountered regularly in the log file already. Dont use prefixes like error, warning, dcs, log, etc. Try something like MYMISSION
or AGHTM_PG_DUBAI
, for example, as they are guaranteed to be unique.
Enabling the Native io and lfs Lua Libraries in DCS
By default, DCS blocks access to the local machine's file system to prevent possible malicious actions by third-party developers like us. Generally speaking, this is a good thing, as it keeps unsavory types from tricking you into executing code on your machine that "does bad things" which we totally support. Don't take our word for it outright, but you can safely run any of the code in our libraries without fear of any malicious action.
In order for agLogger to create a new file, and subsequently log to it, we need to tell DCS that we want to allow the code to be able to access the file system. If you do not feel safe enabling this, we understand. You can still use agLogger to log messages to the default DCS log file, we won't mind. Just beware your messages will be injected into the standard log file alongside all other messages being logged so finding what you are looking for may be difficult. See the section above for more information about how we accounted for this with prefixes, to help make your life a little easier when trying to review the standard log entries you generate using agLogger.
If you trust the code is not malicious (the script is clearly readable in any text editor, and you can see we only have one method to write to the file you specify), you will need to enable the default Lua Script io
and lfs
libraries in order to use the agLogger script to its full and intended potential. If you navigate to and open [Install Dir]\Scripts\Mission Scripting.lua
, you will see a line that reads sanitizeModule('io')
and another that reads sanitizeModule('lfs')
. What this is doing, is telling DCS to sanitize or remove access to calls being made into those libraries. This is what prevents scripts from reading or writing to the file system.
In order to enable the script to write to the file system, all you need to do is either remove these two lines entirely, or prefix them with two dash characters like
--sanitizeModule('io')
and --sanitizeModule('lfs')
respectively. This now turns these lines of code which blocked the access, into comments, which are now no longer executed when the code is run, essentially preventing the blocks from ever happening, and allowing the script to now write to the intended file. Save the file, and the next time DCS is launched, the agLogger script will be able to create and write to the specified log files.
An added benefit of this approach goes to the mission builders using AGHTM (to create transport missions in this case). As the mission builder, you can enable the io
and lfs
libraries, and log whatever you want, however and wherever you want. Then when you release your mission to the public, you do not have to worry about whether the end users have them enabled or not, as agLogger will safely rollover to the standard DCS log if they do not. This gives the mission builder a lot of granularity about how they want to log information while developing their missions with no impact or relevance to the end user who can just simply run them.
Note: Since we cannot account for the nature of other developers who might try to exploit this "vulnerability" we recommend you only leave this feature enabled as long as you are running trusted code, like that contained in AGHTM, the AGHTM Mission Bundles, agScript for DCS or your own code. This will help prevent malicious people from doing unsavory things.
Adding agLogger to Your Mission
If you are only trying to add additional logging to an AGHTM mission built either from scratch, or by using one of the premade mission templates, then agLogger is already loaded by default, and ready for you to use. There is nothing further you need to do. You can choose to jump down to the next appropriate section. If you want to create your own instance of the agLogger, to isolate all of your logging to a file you specify, go to Creating an agLogger Instance
below. If you just want to use the existing agLogger component that comes with AGHTM, jump to Using agLogger
to see how to use the default logger already built into AGHTM.
You can add agLogger to your existing, non-AGHTM missions, to gain the benefits mentioned in this section and to debug them. To add agLogger to your own mission, you can load the script using a trigger. Create a new Once
trigger, with a condition of Time More
and choose a value in seconds, greater than 0, at which point you would like to load the script. If there are no other scripts in your mission that you need to load, you can use 1 second. If you have other scripts in your mission that are being loaded by this same standard mechanism, you can likely figure out what you would need to set this value to, in order to load them at the appropriate time in your mission. The only thing left to do is add a Do Script File
action, where you select the agLogger script using the file browser. Typically, you want to load one script per second after mission start until all of your scripts are loaded. Each script should be loaded using a separate trigger. Tip: create one and clone it as many times as you need, and you just have to change the time and script file file being loaded for each copy which saves you quite a few clicks per script you need to load.
The agLogger script does not have any additional dependencies and can be added by itself to your mission. However, we highly recommend you also add the agCore script, also from the agScript for DCS Library, and also included in the AGHTM download. as it will offer some additional tools with some significant value, that you can use while debugging, namely the ability to serialize or convert objects in your mission into text values you can easily read. You must load agCore before any other agScript script files, including agHTM.lua. If agCore is loaded, agLogger will automatically register itself with agCore on load. That topic is covered in the agScript for DCS documentation section and has no impact here. If you opt to load agCore, be sure to load it before you load any other agScript script files. For example, you could load agCore at 1 second after mission start, and agLogger at 2 seconds after start.
Creating an agLogger Instance
If you want to create your own log files, you can easily do so by creating additional instances of the logger component, and specifying file names and prefixes, as mentioned above for each. Each instance of agLogger you create represents a different physical log file in your logs folder, therefore the log file names must be unique or unpredictable results may occur.
In the example below, we first create an empty object called myCode
which represents a container which all of your code properties should fall under. For more information on how to structure your code, and to better understand how Lua scripts are executed inside of DCS, see the section on Mission.lua and Structuring Your Code. We add some properties that represent our desired filename and prefix. Finally we instantiate the agLogger component, passing the filename and prefix, as well as the 'w' flag, indicating we should create a new empty file each time the mission runs, versus one file that is updated constantly as iterative missions are flown, potentially making them very large and unwieldy.
Each run through a mission is captured solely in a new log file, which is cleared each time you run the mission so the only thing you see is the complete record of just the mission that was most recently flown. Notice the path being passed is relative to the DCS Saved Games folder, and contains Logs\\
in order to correctly create the file in the Logs subfolder. In this example, a file named My Log File.log
and using prefix myCode
will be created in the Logs
subfolder.
Example:
myCode = {}
myCode.logFilename = "My Log File"
myCode.logPrefix = "myCode"
myCode.logger = agLogger:new("Logs\\" .. myCode.logFilename .. ".log", myCode.logPrefix, "w")
Using agLogger
In order to use the logger, you need a reference to an agLogger instance. This can either be an object like the myCode.logger
object created above in your own agLogger instance, or the built-in one, agHTM.logger
that is part of AGHTM, and is instantiated automatically when the AGHTM script is instantiated. Examples of both methods are provided below.
The agLogger object has only one method used for logging messages to the specified log. In order to add an entry to the specified log, you can call yourLogger:log(text, ...)
. This method uses the ... syntax for the second argument. This simply allows you to pass additional values to be inserted into tokens found in the text parameter value being passed. This is a shortcut for standard string formatting offered by Lua Script, and all of those rules apply. If your string has no tokens to replace, you must still pass a second argument. We recommend passing an empty string "", but any value will work as it will be ignored anyway.
Example:
agHTM.logger:log("This is a string with a replacement token displaying 25: %s and 50: %s", 25, 50)
--Outputs 'This is a string with a replacement token displaying 25: 25 and 50: 50' to the AGHTM log
myCode.logger:log("This is a string with a replacement token displaying 25: %s and 50: %s", 25, 50)
--Outputs 'This is a string with a replacement token displaying 25: 25 and 50: 50' to the custom log file
myCode.logger:log("This is a string with no tokens", "")
--Outputs 'This is a string with no tokens' to the custom log file
Debugging Your Code with agLogger
There are several approaches you can take to debug your missions with agLogger. You should use a combination of these techniques when debugging your mission code. Over time, you will learn the best way to approach different tasks, and debugging will become second nature.
One method is called Tracing, where you log key timeline events in the execution of your code. With this method, you add messages along the way, and when your code fails, you can trace it back to the last key event that was logged prior to the failure. This tells you your code failed between that message and the next expected message. With some refinement of where you place these messages, you can narrow down a code failure rather quickly.
Example:
function someFunction()
agHTM.logger:log("Starting Step 1", "")
-- Step 1 code goes here
agHTM.logger:log("Starting Step 2", "")
-- Step 2 code goes here
agHTM.logger:log("Starting Step 3", "")
-- Step 3 code goes here
end
A second approach you can take is a method called Trapping, in which you trap execution of certain code to determine exactly what code is being run. An example of when you might want to do this might be when you have complex if/else statements and want to determine which branch of the conditional statement is executed when the mission is run.
Example:
function someFunction(someNumber)
if someNumber == 1 then
agHTM.logger:log("Executing branch 1", "")
-- Branch 1 code goes here
elseif someNumber == 2 then
agHTM.logger:log("Executing branch 2", "")
-- Branch 2 code goes here
elseif someNumber == 3 then
agHTM.logger:log("Executing branch 3", "")
-- Branch 3 code goes here
else
agHTM.logger:log("Executing failover branch, someNumber: %s", someNumber)
-- Failover Branch code goes here
end
end
Once you determine where your code is failing, you can start to dig into why it was failing. Often objects have values we do not expect, and we think our code is failing because of our logic, where it may be failing for invalid or missing values, or perhaps we may be trying to access the wrong property of an object or maybe have the property name wrong. Sometimes, the values of certain properties give us insight into some of the data structures being used that we do not know or are not documented. For example, we all know what an airplane is conceptually, but in order to know how to use a specific unit as an object in our code, we would need to know what properties it has available. It has positional information, heading and speed information, perhaps waypoint or weapon information, tasking, etc.
One way we can look at these objects and their values, is to use agLogger to log a serialized version of the object. Serialization is the conversion of an object into a readable, structured text string. You can find a serialization function, agSerialization.serialize(name, value, level)
, in the agCore library. The name
parameter is a name you will use to find the item in the log file, and should be meaningful. The value
parameter is the object you want to serialize. The level
parameter indicates the level of depth we should drill into our object when serializing, but in most cases should be omitted to serialize the entire object. This is the main reason we recommend adding it to your missions, alongside agLogger. You can use the logged serialized values to check for expected values, or to discover what properties an object may have that you are not aware of so you can drill into those objects further.
In the example below, we capture a unit named Easy Rider-1-1
into a variable called myUnit
. We then log that object using the built-in AGHTM agLogger instance, as a serialized value named easyRider
so we can look at it in the log file. Note, in this example, we are using the Unit:getDesc()
function of the unit to get the actual descriptor information for the unit, which is then serialized. Serializing the unit directly, would result in an object being serialized that only contains an id property.Many of t he objects in DCS use this pattern. This example assumes we are using AGHTM, but could easily be modified to use any agLogger instance.
Example:
local myUnit = Unit.getByName("Easy Rider-1-1")
local msg = agSerialization.serialize("easyRider", myUnit)
agHTM.logger:log(msg, "")
Log File Output:
easyRider =
{
["massEmpty"] = 8866.2001953125,
["range"] = 580,
["box"] =
{
["min"] =
{
["y"] = -3.048718214035,
["x"] = -14.517512321472,
["z"] = -11.079641342163,
}, -- end of ["min"]
["max"] =
{
["y"] = 4.4567427635193,
["x"] = 10.739423751831,
["z"] = 11.079620361328,
}, -- end of ["max"]
}, -- end of ["box"]
["Hmax"] = 6000,
["Kmax"] = 0.60000002384186,
["_origin"] = "",
["NyMin"] = 0.5,
["fuelMassMax"] = 1929,
["speedMax"] = 250,
["NyMax"] = 1.5,
["massMax"] = 13000,
["RCS"] = 12,
["displayName"] = "mi-8mt",
["life"] = 18,
["HmaxStat"] = 1850,
["VyMax"] = 14.60000038147,
["attributes"] =
{
["Air"] = true,
["NonAndLightArmoredUnits"] = true,
["NonArmoredUnits"] = true,
["All"] = true,
["Helicopters"] = true,
["Attack helicopters"] = true,
}, -- end of ["attributes"]
["typeName"] = "Mi-8MT",
["category"] = 1,
} -- end of easyRider