Script Timing Issues
Context: HL Kit … Kit Reference … Debugging Mechanisms
Overview
We'll start this section off by answering the obvious question. What's a timing issue?
The evaluation cycle controls the order in which everything is processed for each character, and it's up to the author to make sure that every task is assigned an appropriate phase and priority. A timing issue is the result of scheduling a task in the wrong sequence, which causes the evaluation cycle to yield the wrong final results.
It doesn't matter how experienced you are as an author, script timing issues will crop up if the game system has even a modicum of complexity. The trick is in being able to recognize when you are dealing with a timing issue. In general, timing issues are identified via a process of elimination, wherein the possibility of all other types of errors is systematically ruled out.
This section provides assorted tips on how to recognize and resolve timing issues.
Using the Task List
The most fundamental tool for solving timing issues is the task list, which is accessible via the "Debug" menu and the "Floating Info Windows" sub-menu. The task list, as its name suggests, presents a single list of all of the different tasks that are scheduled during the evaluation cycle. This list is often rather lengthy, since every pick and every field has its own distinct set of tasks.
The list is sorted in the order that the tasks will be evaluation by the HL engine. For each task, you'll see its phase, priority, and a brief description. This description should help in identifying exactly what the task is doing and what it is operating upon.
If you think you have a timing issue, the thing to do is check the task list. Make sure that each of the tasks you're working with is occurring in the proper sequence. If you're integrating new functionality that relies upon other tasks to setup state appropriately, be sure to check that your new tasks are occurring after the existing tasks have been invoked. Similarly, if your new tasks apply modifications that other tasks will rely upon, make sure to verify that sequencing as well.
Remember that there are two separate task lists. In general, you will want to utilize the task list for the active hero. This task list is perfect for verifying timing relationships between tasks within a single actor, which is normally what you'll be trying to do. The full list contains all the tasks for all actors, interspersed amongst each other. The only time you'll want to use this task list is when you have masters and minions that have inter-dependencies between each other, such as familiars in the d20 System, which have traits derived from their master and also confer bonuses back onto their master.
NOTE! The task list is the only way to diagnose timing issues that involve tag expressions, such as live states and condition tests. Using the task list is critical to verifying that important tag expressions are being evaluated appropriately relative to scripts and/or other tag expressions.
Debug Output Tracing
If a review of the task list doesn't reveal the source of the problem, another useful trick is to insert assorted trace information into your scripts. For quick checks, the "notify" statement is convenient. However, in most cases, you're going to find the "debug" statement is preferable.
By sprinkling "debug" statements in various places within scripts, you can achieve two goals. First, you can report important state information during the course of the evaluation cycle. For example, you can output field values and tag lists at various points to ascertain that everything matches the state you expect at each of these junctures.
Second, you can report the overall execution flow of scripts, allowing you to verify that ActionA is actually being triggered and that it's occurring before ActionB. For example, when a field value is set or a tag assigned, you can output a message that relays that fact, with the option of also including details about the new state.
The debug output window displays message in the exact sequence that they are called from within scripts. Consequently, what you see within the debug output window is an accurate reflection of what is actually going on within your data files.
Based on the debug output, you should be able to spot the problem. Sometimes, you'll start with only a handful of debug statements and then add more based on the output you see. This technique will systematically narrow down where the timing problem is occurring until you can finally pinpoint it and determine a proper fix.
Script Timing Output
There are times when you have numerous different tasks all working together for some purpose and a timing issue arises. In situations like this, it can be very tedious and time-consuming to pour through the task list and cross-reference everything to make sure all the timing relationships are correct. So the Kit provides a convenient way to check timing information without having to wade through the task list.
From within any script, you can use the target identifier "state.timing" to retrieve the timing information for that script. The string returned has the format "phase/priority", consisting of the name of the phase followed by the numeric priority at which the script is running. By using this within a "debug" statement, you can report the timing of the current script. For example, you could use a statement like the one below to report the timing when a field is modified and its new value.
debug "Script 'blah' at " & state.timing & " - Field 'foo': " & field[foo].value
When you have numerous scripts all working together, or when you have the same field being setup by multiple different scripts under different conditions, this technique can be extremely handy. Along with the timing, you can include information about the script that is being invoked, and the net result is debug output that tells a very clear and specific story about what changes are occurring from which sources and at which times. Armed with detailed output like this, you should have a relative easy time nailing down the problem.
Diagnosing a Timing Issue
Whenever you think you have a timing issue, the first diagnostic step is always to review each of the tasks involved in the behavior you're implementing. For each task, you need to double-check the associated tag expressions and/or script code to make sure everything should be working correctly.
Once you've verified that everything looks right, the next step is check the appropriate info windows to see whether all of your assumptions are being satisfied. Do fields contain the values they should? Are all the proper tags assigned where they should?
If everything appears correct, then you may very well have a timing issue. Why? Because the info windows only show what everything looks like at the end of the evaluation cycle. If TaskA is evaluated before TaskB, and TaskB sets a field value that TaskA depends upon, the field value will show the correct value within the info window. The problem in this case is that TaskA assumes the field will be set before it is invoked. The two tasks are being evaluated out of order, which can be corrected.
If everything is not correct within the info windows, then you may also have a timing issue. The key difference is that you also have some additional clues to help you isolate the problem this time. In a situation like this, the erroneous field values and/or tags will point you at the specific areas where the problem resides. If a field has the wrong value, then whatever scripts are setting that value are basing their logic on information that hasn't been setup properly yet or that has been further modified. If the tags are incorrect, then whatever scripts are assigning/deleting the tags are basing their logic on similarly wrong information. Keying on the extra clues should make the process of isolating the problem significantly quicker and easier.