TS2015 - Scenario Scripting in LUA Part 6 - Speed Checking

In addition to providing various visual interactions such as pop-ups and cinematics, you can also use the LUA scripting logic to provide for additional gameplay features as well.

One such feature you can quickly use to great effect is to use the scripting to monitor the players speed and then react to it in some way.

There are a couple of uses for this, one is to see whether the player has got the train moving - and if so perhaps congratulate them and give them some next instructions.

Another is to see if the player has stopped, in which case you might want to remind them how to get moving again.  This is particularly useful if you're aiming your scenario at newcomers to the game!

The final one and perhaps the most useful generally is to check for going too fast according to some additional rules (beyond speed limits and so forth).  For example, while the speed limit on a particular stretch of line might be 70mph, if the train you're hauling has wagons with a maximum 40mph speed limit (perhaps they're sensitive or dangerous cargo, or simply old and not suitable for higher speeds for example) then it would be good to be able to factor this additional rule in to the scenario, rather than simply advising the user at the start and then just assuming they adhere to a guideline they probably forgot 10 minutes in to the scenario.

How do you get the speed?

This is the easy bit, getting the speed can be done with a simple single command:

speed = math.abs(SysCall("PlayerEngine:GetSpeed"))

Here, we call a command PlayerEngine:GetSpeed in the game core and then run it by a math function called "abs" - what this will do is ensure that the result is always positive.  That way no matter if you're going forwards or backwards, the speed returned is always a positive number.  The result is then stored in a variable called "speed".

Note that the units returned by GetSpeed are in meters per second, NOT, miles or kilometers per hour.

What I like to do is add some more constants to the section of definitions at the top of the script to help with these calculations:

MPH = 2.23693629
KMH = 3.6

gSpeedUnits = MPH

I can now adjust the above GetSpeed example as follows:

speed = math.abs(SysCall("PlayerEngine:GetSpeed")) * gSpeedUnits

Now "speed" will contain the current speed of the loco in miles per hour.  It might at first seem odd to have "gSpeedUnits" - why not just use the constant "MPH" ?  You could do that - but if you wanted to re-use components of your script in a future script and that needed to be in KMH then you would need to do a careful search and replace to swap "MPH" to "KMH" - by using "gSpeedUnits" everywhere you can simply change the assignment to gSpeedUnits at the top of the script and the rest will simply fall in to place.

Where does it go in the script?

You will generally want to check speed as part of a condition so that you can do it regularly.  You could check to see if you're at a particular speed as part of a one-off check in an event if you wish but there aren't many cases where you really want to do that.

Let's set up a small example to check if the player has started moving yet, triggered as part of the first trigger instruction in a scenario:

function OnEvent(event)
  _G["OnEvent" .. event]();
end

function TestCondition(condition)
  _G["TestCondition" .. condition]();
end

function OnEventStartMovingCheck()
  SysCall ( "ScenarioManager:BeginConditionCheck", "AreWeMovingYet" );
end

function TestConditionAreWeMovingYet()
  speed = math.abs(SysCall("PlayerEngine:GetSpeed")) * gSpeedUnits;
  if (speed > 1) then
    SysCall ( "ScenarioManager:ShowInfoMessageExt", "You're moving!", "moving.html", 10, MSG_TOP + MSG_TOP, MSG_SMALL, TRUE );
    return CONDITION_SUCCEEDED;
  end
  return CONDITION_NOT_YET_MET;
end

Ok, lots to see there, but most of it you've already seen in previous articles, i've just included it to provide context.

So in our scenario set-up in the timetable view of the game, we've added a trigger instruction that fires an event "StartMovingCheck".  This results in a call on OnEvent with event set to "StartMovingCheck". That in turn calls OnEventStartMovingCheck.

OnEventStartMovingCheck will begin a condition test called "AreWeMovingYet".  As of that moment, the game will begin firing calls to TestCondition with "condition" set to "AreWeMovingYet" and it in turn will call TestConditionAreWeMovingYet.

Ok, so we made it to the actual important bit of this example finally!

TestConditionAreWeMovingYet, which is being called very regularly now over and over, will obtain the speed of the player.  If the speed is more than 1mph then it will open an HTML message box that loads "moving.html" and might give the player some feedback now they're moving and perhaps more instructions.  The return of "condition succeeded" means it will now no longer perform this check, so if the player stops and starts moving again it will NOT do this again.

You can see that it would be easy to modify this example to check if the player is stopped, however in that case I would strongly recommend checking for speed<0.1 rather than speed == 0 simply because of rounding and physics behaviours in the game.

This has been a simple over view on how to check the speed, you should be able now to see how you can apply it to various different cases and provide some additional gameplay behaviours.

To give you some examples, there are some scenarios on Western Lines of Scotland where you are hauling tanker wagons and these have reduced speed limits.  The storyline of the scenario is that you're riding with a fireman and guard who are very cautious of accidents.  Even though the line speed is high, the train is in some cases only rated for 30mph maximum speed.  As you drive along, the speed is constantly being checked and if you ever exceed 30mph you get a warning to slow down, after two or three warnings then the brakes will be applied to bring the train to a stop.  If you then continue to cause this to happen more times then eventually the scenario is actually terminated early, resulting in a fail.  Of course you need to tune how flexible the scripts are - if they bang you out with a scenario failure for one error then that really does qualify as a super hard (possibly super frustrating!) scenario and you should set things up to match the level you're trying to achieve.

TS2015 - Scenario Scripting in LUA Part 5 - Cinematic Cameras

In todays article, I'm going to cover one of the most exciting features you can access through LUA scripting in your scenarios, the use of Cinematic Cameras.  These cameras allow you to create specific sequences that might commonly be used to set a scene at the start of a scenario, or perhaps even during a scenario they can be used to indicate some thing that's going on in the world around the player.

In addition to the Cinematic Cameras, I'll also then cover how you can access the other fixed cameras such as forcing cab view or track side view for example.

If you have not yet watched the YouTube video from the TSL show segment that covered this then I would recommend you do this first because it's always easier to see things visually.

Click here to watch the episode

There are a couple of steps to using the cinematic cameras:

1. Place and set up the cameras to create the sequence itself
2. Start the camera sequence from LUA script

Setting up the Camera

Most of how you place the camera is far better explained visually in the video but here's a route outline of what you need to do.


First, you need to place a Cinematic Camera asset, which you can find on the middle-left flyout under the "miscellaneous" group, which is the bag in the bottom right of the little group of icons.

First, you need to place a Cinematic Camera asset, which you can find on the middle-left flyout under the "miscellaneous" group, which is the bag in the bottom right of the little group of icons.

Double click on the camera asset to get access to its properties on the top right fly-out.

You can use one of the arrow icons (third one along) to move the camera so that it is pointing to exactly what you are currently looking at, this is by far the easiest way to position the camera.

You can change the field of view by changing the value in the fifth field down (it defaults to 65) to get a narrower angle by lowering it, or a more wide angle by raising it.

Click the "+" icon (second icon) to add a new key frame and then use the left/right yellow and white arrows on the top right to move between the key frames.  It tells you below the arrows which frame you're on, e.g. 3/4 means third out of four.  You can use the "bin" icon (first one) to delete the current key frame.

Once you've positioned all the cameras, go back and set times using the sixth field down - so for key frame 1, the time means how long to spend on that key frame before advancing to the next.

Once you've finished setting up all the key frames for your cinematic sequence, you can test it out right away by clicking on the "play" icon at the bottom.  This will run through the sequence and you can use the clock on the bottom right of the fly-out to watch as the sequence runs through it's timings to make sure everything works out as you planned it.

Once you start reviewing the sequence with "play" it is important to make sure that you click "stop" to end it as many of the fields are not accessible while it is playing.  You can use the rest of the controls along the bottom such as rewind and pause the same way you would expect to.

Once you're happy with the sequence, put a name in to the bigger text field (with the cube next to it) - this is the name that we'll use to start the sequence off.

Starting the Sequence

At this point, we're finished with the cinematic camera editor and can now return to the scenario editor and write a little LUA code to activate it.

In this example, let's assume it's an opening camera sequence.  I named the sequence "coolopening" in the cinematic camera name box described above, and in the scenario i've added a trigger box which triggers an event "Start".

Let's see the code that now makes the magic happen.

function OnEvent(event)
   _G["OnEvent" .. event]();
end

function OnEventStart()
  SysCall ( "CameraManager:ActivateCamera", "coolopening", 0 );
end

So we start out with our standard "OnEvent" function which passes it on to a separate function to handle the specific event - in this case, OnEventStart, because the first event we triggered was called "Start".

Inside that event, we then call the ActivateCamera function in the game and ask it to run "coolopening"; the name of our cinematic camera sequence.

That's really all there is to getting it working, but there are some extra bits that are worth knowing.

Delaying the next instruction

If you want to run a camera sequence and then do something else (which you most likely will!) then make sure that the trigger instruction has a timed offset.  This is because the command to run a camera sequence actually finishes immediately and returns control back to the game to run the next instruction in the scenario, while at the same time it runs the camera in parallel.  If you don't put a delay on the next instruction it can result in the camera sequence being interrupted.

The example above shows that in the first field of the trigger instruction, i've set up a 15 second delay - which means that from the moment this instruction would normally execute, it will hold off for 15 seconds.  If our first instruction was to fire a camera sequence that lasted 15 seconds, this would mean that the instruction above waits for 15 seconds and then fires another trigger to continue the script on to the next step.  You will simply need to add up the total time of your cinematic sequence (including the time on the last key frame) and then put that in to the delay box.

Chaining multiple camera sequences together

If you want to chain two camera sequences together, e.g. to do a pass through of a platform and then another pass over the player train then you simply set them up as normal and make sure that the trigger instruction which causes the second has a suitable delay so that it will not trigger before the first one has finished running.

Accessing Internal Cameras

There are a number of internal cameras defined that you can refer using the ActivateCamera call. Note that these names must be entered precisely, including the correct capitalisation.

CabCamera	Switches to the cab camera (like pressing 1 normally)
ExternalCamera	Switch to view "2"
TrackSideCamera	Switch to view "4"
CarriageCamera	Switch to view "5"
CouplingCamera	Switch to view "6"
YardCamera	Switch to view "7"
HeadOutCamera	Switch to view "Shift-2"
FreeCamera	Switch to view "8"

Helper Functions

All good coders know the importance of keeping your code clean, and one of the important ways of doing this is to spread your code in to different functions that look after different aspects.  One key area you can do this, and also greatly simplify reading of your code later, is to create some short helper functions that wrap the SysCall's, something like this:

function ShowCamera(camera)
  SysCall ( "CameraManager:ActivateCamera", "coolopening", 0 )
end

function ShowCabCamera()
  ShowCamera("CabCamera")
end

function ShowTracksideCamera()
  ShowCamera("TrackSideCamera")
end

It might seem redundant to have "ShowCabCamera" simply call ShowCamera when it could simply call the SysCall itself, this is a style choice you can make.  Personally I like to keep duplication to a minimum and the cost of a function call in these situations is minimal, so the code remains nicely readable and there's only one place that actually calls the game.

Having built yourself a nice library of helper functions (and this is a process you can apply to everything we talk about in these posts) your actual main code becomes quite a bit more readable:

function OnEventStart()
  ShowCamera("coolopening")
end

Recorded Messages and Cinematic Cameras

It is perfectly possible, and some times quite desirable, to link playing a cinematic camera with a recorded message.  It's important to remember to reset the camera back to the cab when you do this, as shown in the following example where I want to have a cinematic highlight a road traffic accident that the player is driving past.  I would have set up the scene using scenario-specific assets, then put the camera on it to fly around it a bit.  I could then call it like this:

function StartDisplayRTA()
  ShowCamera("RTACamera")
end

function StopDisplayRTA()
  ShowCabCamera()
end

function OnEventShowRTA()
  DisplayRecordedmessage("RTA")
end

Here you can see i'm continuing to use the new library of functions i've built up previously and the code is immediately far more readable than a bunch of SysCall's all over the place.  In this case the cinematic will play as normal and when it finishes it will return to the cab.  If the player then clicks on the "previous message" button on the HUD then it will simply re-play the cinematic and when finished go back to the cab.

As mentioned in an earlier article, you really can use the Recorded Message function for all kinds of things, not just messages.

TS2015 - Scenario Scripting in LUA Part 3 - HTML Pop-Up Messages

Continuing this series of articles about how to make use of LUA scripting in scenarios, this time we're going to take a look at how you can pop up a message box that contains HTML, including images and formatting.

If you haven't read the previous two articles or seen the YouTube video recording from the live Twitch session then I would strongly recommend doing so first.  The aim of these articles is really to dig a bit deeper and be a bit more detailed, so it might miss out some steps (all of which should be covered in the video).

You can find the video here: https://www.youtube.com/watch?v=1RcO_og8q7M

Where are HTML files placed?

You cannot place the HTML files directly in the Scenario folder, it is important to note that they are localised (meaning you can display different files for different languages, such as having a German HTML file shown to a German user, or an English one to an English user).

If your scenario is located in:

c:\program files (x86)\steam\SteamApps\common\RailWorks\Content\Routes\6700a000-afeb-4129-8b36-3a88d83ed073\Scenarios\502f3106-14cc-4626-8421-700ee44610a7

Then your English HTML files must be in an "En" folder beneath that, i.e.

c:\program files (x86)\steam\SteamApps\common\RailWorks\Content\Routes\6700a000-afeb-4129-8b36-3a88d83ed073\Scenarios\502f3106-14cc-4626-8421-700ee44610a7\En

Your German scenario files will be in a "De" folder beneath that, i.e.:

c:\program files (x86)\steam\SteamApps\common\RailWorks\Content\Routes\6700a000-afeb-4129-8b36-3a88d83ed073\Scenarios\502f3106-14cc-4626-8421-700ee44610a7\De

and so forth.

If you want to include any images then they should be in the base scenario folder (i.e. one folder above where the HTML files are).

For most cases, images should be 128x128 in size, if you want something bigger then note that they need to be multiples of 128, e.g. 256x256 or 128x256.  If you go above 128x128 then you must always pop up LARGE message boxes (more on that in a moment).

It's important to note that the HTML files shown in in-game message boxes cannot be very complex and only a minimal amount of HTML is supported.

Here's an example, simple, HTML file to get us started:

<html>
   <body bgcolor="#ff0000">
      <font color="#ffff00" face="Arial" size="3">
         <table>
            <tr>
               <td><img src="../professor.png" width="128" height="128"></td>
               <td>
                  <p><b>Welcome to this scenario</b></p>
                  <p>Can you <i>finish</i>  it in one piece??</p>
               </td>
            </tr>
         </table>
      </font>
   </body>
</html>

In this file, we've used a table to create two columns, in the left hand column is an image (which must be placed in the main scenario folder) and the right hand column has some example text with basic formatting options.

Save that file as "introtext.html" in the En folder.

Scripting

The next step is to update the script so that it will call up our HTML message box.

function OnEvent(event)
  _G["OnEvent" .. event]();
end

function OnEventIntroduction()
  SysCall ( "ScenarioManager:ShowInfoMessageExt", "Title of the box", "introtext.html", 0, MSG_VCENTRE + MSG_CENTRE, MSG_REG, TRUE );
end

I've included a copy of the "OnEvent" function just to remind you how we get to the "OnEventIntroduction" function.

So you can see that to open a message box, we use ScenarioManager:ShowInfoMessageExt and pass in a bunch of parameters.

Let's just dig in to each one of those, starting from after the name of the function.

The title of the message box
The HTML file that you want to display (the En or De etc bit will be added automatically)
MSG_VCENTER means center it vertically, this could also be MSG_TOP or MSG_BOTTOM.
MSG_CENTER means center it horizontally, this could also be MSG_LEFT or MSG_RIGHT.
MSG_REG means make a middle-sized regular box, this could also be MSG_SMALL or MSG_LRG.
Finally, the "TRUE" at the end means that while this message box is displayed, the game should be paused.  If this is FALSE then the game will continue even though the message box is still displayed.

If you want to use an image of greater size then 128x128 then you will need to use a MSG_LRG if you want to avoid an unsightly scrollbar appearing.

That's really all there is to it, in the next article, i'll talk about how to make it so that these pop-up messages can be recalled by the player any time they want to re-read through the instructions you're giving them as they go.

Don't forget to follow the blog so that you are kept immediately up to date with new posts and if you have any feedback I'd love to hear it in the comments section!

TS2015 - Scenario Scripting in LUA Part 4 - Recorded Messages

Following on from the series begun earlier, this post talks about how you can allow your users to recall pop-up messages easily.

If you're providing any kind of instruction to the player then you should definitely use the Recorded Message capability of the scripting system to handle that pop-up message box so that the player can bring it back on-screen to remind themselves what they need to do.

Let's write a quick function to simplify showing these messages, this will allow us to use a more simple command later when we want to actually show them, as well as enforce a degree of consistency on our code later on.

function DisplayRecordedMessage( messageName )
   SysCall("RegisterRecordedMessage", "StartDisplay" .. messageName, "StopDisplay" .. messageName, 1);
end

The way that the Recorded Message capability works is that you tell it a function name to execute when it shows message and another function to execute when it hides the message.  In the case of simply showing a simple or HTML message you generally won't have anything in the "stop" function.  Where things get potentially complex and powerful is when you realise you can put any code in those functions, so you can trigger cameras, audio playback and so forth.  As an example, if you use the "Start" function to trigger a cinematic camera then the "Stop" function probably should put it back to the cab view.

Let's define those two functions now for a simple HTML pop-up:

function StartDisplayIntroText()
   SysCall ( "ScenarioManager:ShowInfoMessageExt", "Title of the box", "introtext.html", 0, MSG_VCENTRE + MSG_CENTRE, MSG_REG, TRUE );
end

function StopDisplayIntroText()
end

So, why did we call the functions "StartDisplayIntroText" and "StopDisplayIntroText" ?  Let's actually write some code to call "DisplayRecordedMessage" and that will complete the picture.

function OnEventStart()
  DisplayRecordedMessage("IntroText")
end

Again, this is done using our previously described mechanism of having each event in its own function.

You can see that when we call DisplayRecordedMessage we are passing in the parameter "IntroText", the DisplayRecordedMessage function will then find the two functions that begin "StartDisplay" and "StopDisplay" that have this in them - so StartDisplayIntroText and StopDisplayIntroText, and register them with the game to show a recorded message.

When you call DisplayRecordedMessage the game will immediately call the StartDisplay function and when the player closes the message box, the game will call the StopDisplay function.

That's it for todays post - tomorrow I will talk about Cinematic Cameras as well as how you can call up the standard cameras from script such as the Cab Camera.

TS2015 - Scenario Scripting in LUA Part 2 - Debugging with LogMate

Continuing our series on using LUA scripts to enhance your Scenarios, I thought that it was prudent to cover how to debug your scripts as early as possible. That way, when things start going wrong (they will, trust me!) then you have the knowledge to figure out what's going on and then how to fix it.

Getting LogMate Running

Logging in Train Simulator is done via a tool called LogMate, we'll need to add some command line parameters to Train Simulator in order to enable this and set it up.

First, go to the in-game settings for Train Simulator and change it so that it's running in a window, this will make life much simpler. Once you've done that, close the game. Now go to the Steam Launcher, go to the Library and find Train Simulator. Right Click on it and select Properties.  Click "Set Launch options".

In the box that comes up, you need to type the following:

-LogMate -SetLuaFilters="All" -lua-debug-messages

It is important that you get all the capitalisation correct, if you make any mistakes it will not work.

Click OK and then the next time you launch the game, the LogMate window will open. It's important to note that while the LogMate window is open, the game is logging a lot and this will definitely slow the game down.  At any point, you can simply close the LogMate window to return the game to full performance (without logging of course) however to get it back again you must restart the game.

Once LogMate is running you will see a screen that looks like this:

The main part of the window is where logging will appear.

In the File menu there are a couple of options - Save Log and Clear Logs.  You can click "Save Log" to save everything out to disk, which will enable you to search it in another application such as Notepad++ much more easily.

Clear Logs is an option you will need to get used to using regularly.  As the game logs to LogMate, it will fill up - if you leave it too long, you'll find the game begins to slow to a crawl, once this happens it is quite hard to get it back again without simply closing it however if you keep pressing "clear log" this keeps everything moving relatively smoothly.  Find out how long it takes to fill up and then just keep an eye on it and clear it out before that happens.

Once you've started the game, LogMate will start receiving logging text, here's an example of what it might look like:

You can see that there's lots of complicated text in the logging, for the most part you can really just ignore a lot of the detail.  The aim here is going to be to look at your own logging rather than the in-game logging, and generally find anywhere it says "error" and see if it's something caused by your script.

Along the top you can see a number of new tabs have appeared, these help separate the logging in to various subsystems within the game, though for the most part I generally simply stick with the "All" tab.

Sending Log Text to LogMate

When you're testing debugging your script you are going to want to put in some simple logging to try and work out "did it get here?", "well, what's that value then?" and so forth.  With the help of this logging you can then work out what path the game took through your code and where the code went wrong.

Writing to LogMate is very easy:

print ("This is a line of logging")

You can also add variables, so let's take our OnEvent function and add some interesting logging:

function OnEvent(event)
  print ("OnEvent called - event is [" .. event .. "]")
  _G["OnEvent" .. event]();
end

You can see that the  two dots, "..", are used to allow us to append other things to the string in the "print" statement, including continuing on with the string.

Tip: Whenever printing a value, I like to always wrap it in brackets, that way I know for sure if the value has any extra characters like newlines in it, or if there's anything else generally of note.

You can also print numbers the same way:

function TestConditionOverspeed()
  speed = SysCall("PlayerEngine:GetSpeed")
  print ( "Player speed [" .. speed .. "] m/s")
end

As a general point of style, I would recommend including common information that helps gather your log entries together, so in an event handler perhaps always include the name of the event being handled, such as this:

function OnEventIntroText()
  print("OnEventIntroText() - Started")
  -- do some stuff
  print("OnEventIntroText() - Finished")
end

In this way you can simply do a search for "OnEventIntroText" in the log file later and you'll see all the lines of log that came out of that function.

Debugging Process

As a general process, when you're debugging you need to work methodically and not assume anything.  Prove all facts to ensure that you don't end up spending hours looking at a problem and not seeing it because you assumed "well it can't possibly be wrong here" - in most cases, that's exactly where the problem ultimately sits!

I would recommend having a debug line at the start of OnEvent to log each event as it is fired.  Don't log at the top of TestCondition unless necessary as this will badly spam the log file, use it to prove you're getting the right conditions to check and then remove the log entry again.

I would also recommend logging each event that you handle, so if you're using the function-based method I recommend in the first part of this tutorial, then a line of log at the top of each of those functions will prove it got in to the right function that you were expecting it to.

If you are reading any values from controllers or as the returns from other function calls perhaps to get the player engine speed or signal states etc then it's worth logging those values out.

At various decision points in your code where you have "if/then/else" type statements, you could log the variables that you're checking before the IF statement and then log inside each of the "then" or "else" sections so that you can trace through where it actually ended up going.

Debugging is an investigative process and one that will take time to really get to grips with. 

Imagine that there's an invisible person running through your code and you're trying to figure out what he's doing.  Any time that invisible person steps on a "print" statement you can get a line of log - and therefore by being clever about where you put these print statements you can build up a picture of where he went and why he went there.  Using this information you are then well armed to correct any errors and make him go where you want!

Here's a quick example:

function TestCondition(condition)
  if (condition == "OverspedCondition") then
    speed = SysCall("PlayerEngine:GetSpeed");
    if (speed < 4.47) then
      DisplayRecordedMessage("Overspeed1");
      SysCall ( "ScenarioManager:TriggerDeferredEvent", "starttoofastcheck2", 5 );
      return CONDITION_SUCCEEDED;
    end
  return CONDITION_NOT_YET_MET;
end

This function has problems, it's there to detect when we exceed 10mph but nothing is happening, so let's put some debug in and try to find out why.

First step - let's check  TestCondition and if we're detecting the condition correctly.  Since this is a spammy log entry we'll just do that first, the new function looks like this:

function TestCondition(condition)
  print ( "TestCondition() - Condition[" .. condition .. "]")
  if (condition == "OverspedCondition") then
    speed = SysCall("PlayerEngine:GetSpeed");
    if (speed < 4.47) then
      DisplayRecordedMessage("Overspeed1");
      SysCall ( "ScenarioManager:TriggerDeferredEvent", "starttoofastcheck2", 5 );
      return CONDITION_SUCCEEDED;
    end
  return CONDITION_NOT_YET_MET;
end

When we run it in LogMate, save the log file after our test and then open it in Notepad, if we search for "TestCondition" we see:

TestCondition() - Condition[OverspeedCondition]
TestCondition() - Condition[StoppedCondition]
TestCondition() - Condition[OverspeedCondition]
TestCondition() - Condition[StoppedCondition]
TestCondition() - Condition[OverspeedCondition]
TestCondition() - Condition[StoppedCondition]
TestCondition() - Condition[OverspeedCondition]
TestCondition() - Condition[StoppedCondition]
TestCondition() - Condition[OverspeedCondition]

(etc)

So we can see two conditions are being fired, which is what i'd expect in my scenario script, but I still can't see a problem so let's check the IF statement.  We'll leave the existing "print" statement in place.

function TestCondition(condition)
  print ( "TestCondition() - Condition[" .. condition .. "]")
  if (condition == "OverspedCondition") then
    print ( "TestCondition() - Checking for the overspeed condition")
    speed = SysCall("PlayerEngine:GetSpeed");
    if (speed < 4.47) then
      DisplayRecordedMessage("Overspeed1");
      SysCall ( "ScenarioManager:TriggerDeferredEvent", "starttoofastcheck2", 5 );
      return CONDITION_SUCCEEDED;
    end
  return CONDITION_NOT_YET_MET;
end

So, now we've got two log entries - one happens each time TestCondition is called and the other confirms we're in our specific check for overspeed.

When we run it, this is what we end up with in the log:

TestCondition() - Condition[OverspeedCondition]
TestCondition() - Condition[StoppedCondition]
TestCondition() - Condition[OverspeedCondition]
TestCondition() - Condition[StoppedCondition]
TestCondition() - Condition[OverspeedCondition]
TestCondition() - Condition[StoppedCondition]
TestCondition() - Condition[OverspeedCondition]
TestCondition() - Condition[StoppedCondition]
TestCondition() - Condition[OverspeedCondition]

Hmm, that looks remarkably familiar and it proves we're not getting in to our overspeed check code.  This means that the "if" statement is what's wrong and we can now pull out our microscope and find out why.  Having done that, I realise that I've mis-spelled the condition name in the "if" statement!  Let's correct that and re-run.

TestCondition() - Condition[OverspeedCondition]
TestCondition() - Checking for the overspeed condition
TestCondition() - Condition[StoppedCondition]
TestCondition() - Condition[OverspeedCondition]
TestCondition() - Checking for the overspeed condition
TestCondition() - Condition[StoppedCondition]
TestCondition() - Condition[OverspeedCondition]
TestCondition() - Checking for the overspeed condition
TestCondition() - Condition[StoppedCondition]
TestCondition() - Condition[OverspeedCondition]
TestCondition() - Checking for the overspeed condition
TestCondition() - Condition[StoppedCondition]
TestCondition() - Condition[OverspeedCondition]
TestCondition() - Checking for the overspeed condition

Better, we're now getting in to the "if" statement, but what happened when I ran it was that I immediately got told I was overspeeding even though I hadn't moved yet.  So let's find out what's happening there.  Now that we're know we're in the "if" statement, i'm going to comment that logging out, that way we can easily put it back if we want but for the time being it's out of our way.

function TestCondition(condition)
  -- print ( "TestCondition() - Condition[" .. condition .. "]")
  if (condition == "OverspeedCondition") then
    -- print ( "TestCondition() - Checking for the overspeed condition")
    speed = SysCall("PlayerEngine:GetSpeed");
    print ( "TestCondition() - Overspeed - Speed[" .. speed .. "]")
    if (speed < 4.47) then
      print ( "TestCondition() - Overspeed - We are going too fast!")
      DisplayRecordedMessage("Overspeed1");
      SysCall ( "ScenarioManager:TriggerDeferredEvent", "starttoofastcheck2", 5 );
      return CONDITION_SUCCEEDED;
    end
  return CONDITION_NOT_YET_MET;
end

In our updated function, we are now reporting the speed of the loco that was returned to the script from the game, and then reporting if we got in to the "if" statement once we reached overspeed.  Let's run it and see what we get.

TestCondition() - Overspeed - Speed[0.01235532]
TestCondition() - Overspeed - We are going too fast!

Wait, hang on, even though the speed was definitely very low, we still succeeded that IF statement and got in to the overspeed code!  We need to scrutinise that IF statement, and upon doing so we realise that what it currently reads is "if the current speed is LESS than 4.47 meters per second", oops.  Once that is fixed, the script is now running correctly.
Closing Notes
Debugging is something that is going to take time to learn how to do so stick with it, once you get the hang of it you will be able to quickly work out what is happening and identify the many causes of problems that might be haunting you in your script.

Another tool I recommend for analysing log files that you've saved is Log Expert, which you can get for free here: http://www.log-expert.de/

To use LogExpert, run LogMate as normal to get the log file and save it out.  Then run LogExpert.

Drag Drop the log file you saved on to it and it will log in to a tab which you can browse and search as normal.  Where LogExpert really comes in to its own however is Filtering and Highlighting.

On the View/Navigate menu, select Filter and a new section will appear in the bottom half.

In the "Text Filter " field you can type parts of your log entries - this is where having good common logging will really help.  E.g. it's here you could type "TestCondition" from the example above, and see precisely every thing in the log file that contains that phrase.  If you want to get more complex, learn Regular Expressions (not for the faint of heart, but very powerful) and you can even type Regular Expressions in this field to search based on a complex search string by ticking the "regex" field.

To do highlighting, which can make navigating complex logs much easier than trying to search specific things out, click on the Options menu and then select Highlighting and Triggers.

In the "Search string" field, type in the phrase you want to pick out (this can be a regular expression too if you want).  Choose a foreground and background colour in the bottom left and then click the Add button in the middle section.  When you click OK, anything in the log that contains this text will now be highlighted.

Highlighting is great for many reasons - it may be that you want to look for a variety of things but for various reasons can't search, perhaps you want to see around the entry more and get more context for the entry.  Perhaps the lines you're finding are good at marking the start of something and you just want to then read the log - once it's highlighted you can simply scroll through and you'll find it very easy to quickly pick out the highlights and navigate the log file.

Finally, when your scenario is working well make sure you go back and either remove or at least comment out all of your debug.  Leaving debug in can cause a performance slow-down even if the player isn't running LogMate.

Hope that was useful, it was long and detailed but I wanted to cover everything needed to debug your scripts - you'll be coming back to this article as you get more proficient at scripting scenarios and run in to more challenges where things don't quite work, so don't worry if it doesn't all make sense just yet.

I'd love to hear your feedback in comments and don't forget to follow the blog to make sure you find out about future articles - there are quite a few planned in this series!