Playing Battleship with the HSS

July 29, 2015 / 1 comments / in General  / by Walter Goodwater

Scripting in CygNet is great…when it works.

Debugging script issues in Studio (especially without a just-in-time debugger like Microsoft’s Visual Studio) is like a game of Battleship: “Is there a bug at B9? No? OK, let’s try a MsgBox at H2…” And don’t get me started once you have to deal with Nested Views.

But even worse is debugging script issues in the HSS. That’s like playing a game of Battleship while blindfolded, ten miles from your opponent, and you can only make your guesses via Morse code. And did I mention your opponent can move the ships around? It’s enough to make HSS and VBScript (and maybe CygNet for that matter) four-letter words in many a SCADA admin’s vocabulary.

Maybe we can help.

The HSS is very powerful, and with great power, comes great complexity (or something like that). With all these moving pieces, conflicts are unavoidable. But while I can’t give you “Five Easy Steps to Never Struggling with an HSS Script Again!” I can try to give you some tips on how to debug HSS script problems that have helped us in the past.

1. Check HSS Status Points, or “Is this thing on?”

You ever hear the joke about the IT guy who gets a call about why a word processing program isn’t working anymore, only to discover that the computer isn’t plugged-in? There’s a CygNet version: wondering why your SetPoint or Roll-up or CSV Export isn’t working right when it turns out the HSS Script Engine isn’t even running.

To be fair, determining if the Script Engine is running can be a bit harder than knowing if your computer has power. The simplest way to check is by referencing the two status points unique to the HSS: Script Engine State (UDC: SYHPEST) and Script Engine Errors (UDC: SYHPECT).

Playing Battleship with the HSS - HSS status points that help you know if the thing’s even running

HSS status points that help you know if the thing’s even running

The Script Engine State point will tell you if your HSS is processing scripts at the moment. If this point’s value is anything other than Running, something (likely a script error) is killing your HSS. Maybe it was something you wrote. More likely, it was something Bob who sits in the cubicle across from you wrote. C’mon, Bob.

The Script Engine Errors point will keep a count of every script error that your Script Engine has encountered. Keep in mind that errors that are triggered while the dreaded On Error Resume Next (the bane of every true scripter) is turned on, they will not increment this count.

Furthermore, not all errors are created equal. The HSS can survive some and keep on keepin’ on, and others will take the Script Engine down (but not the service itself — its lights will still be on, though no one will be home, kinda like Bob). Either way, this point’s value will get incremented. If this number is non-zero, you have a problem; some script in your HSS is not successfully running to completion. There is little point in understanding why your particular script isn’t working until you’ve fixed whatever is causing the error count to rise. More on that in the next tip.

These two points should be in your HSS by default, but too often I’ve seen misconfigured HSS services in live systems without these points, or with them misconfigured. Remember that these guys are special and therefore have their own rules. While normal CygNet points have to settle for a numeric Point ID, these two must have the following values for Point ID: ~SYHPECT and ~SYHPEST (that’s a tilde before each of those, in case that isn’t coming across with the blog’s font). Since you can’t change Point ID after point creation, if you have these in your system and they don’t have those Point IDs, delete and re-add. You’ll thank me later.

2. Understand the HSS Log Files, or “More files, more problems”

Logging with the HSS was created with the philosophy that More is More: why have one log file when you can have three?

Hss.log

This log file is the most similar to other service logs: it will contain info about when the service started, licensing info, other services it is talking to, etc. For our purposes, it is important to note that script errors will appear here, hopefully with some helpful information about what failed. Even if the error description isn’t helpful, it will tell you which line caused the error, which leads us to our next log file.

Script.txt

This file contains all scripts currently active in your HSS. If you have an error on line 2854, you can open this file, navigate to the problematic line, and see what script is causing you grief. Note that while you can change this file and even save it, changes here will not affect the HSS in any way. Tell Bob to write his scripts here.

Hss_Script.log

This log file will be your best friend when debugging your HSS. By making changes in your HSS.cfg file, you can enable verbose logging information which will be written to this file. For example, by setting the LOGMASK_SCRIPT keyword to MAX_TRACE, you will see when the HSS calls every event handler (OnInitialize, OnUpdate, Timer, PointChange) which can be incredibly helpful when trying to determine if your script is even being hit.

The other helpful way to use this file is so important it gets its own separate tip, so read on.

3. Use LogManager, or “What the heck is going on in there?”

The reason HSS debugging is so hard is that it can be very difficult to know what is going on inside. If the Script Engine is running, you know it is doing something, you just don’t know what. This is where LogManager comes in. It is a global object in the HSS that always exists, just waiting to be helpful. Strings that you write to LogManager will appear in your Hss_Script.log file, so you can use it to help you understand what is happening in the HSS and when.

For example, in desperation I’ve written many a line of script that looked like:

LogManager.LogAll "The script engine made it this far!"

More helpful might be something more along these lines:

LogManager.LogAll "Made it to Function XYZ and my facility is: " & strFac & " and my other variable is: " & strThing

With access to information about the state (what lines get hit, the value of your variables, etc.) of your script while it is running, you can start making some more educated guesses about why something isn’t working exactly as you expected.

In other words, LogManager is your friend.

4. Gather HSS Performance Metrics, or “Are we there yet?”

LogManager has a brother who can be equally helpful: the Profiler. This object allows you to time your script execution so you can find out how long it is taking to run.

You might ask why I’m including info on checking HSS performance in a list of tips on troubleshooting HSS script problems and I might answer that the topics are more closely related than you might realize. One of the most important things to remember about the HSS is that it is single-threaded, which means it can only be executing one line of script at a time. If it is processing a Group Roll-up, it can’t also be parsing a transaction record and exporting information to a file. So if you have script to execute on a timer using the OnTimer event handler, and it isn’t being executed when you think it should, that’s probably because the HSS was stuck in traffic somewhere.

The more scripts you pile onto an HSS, the slower it will become. You might have written your script correctly, but if it doesn’t trigger when you need it to, it isn’t useful. Profiling your script will help you identify bottlenecks or inefficient script for potential enhancement.

Before I dive into the details of using the Profiler object, let me offer some free advice on how to speed up that heavily-loaded HSS: use the Job Runner

To time your script, create a Profiler object where you want to start timing and then clear it when you want it to stop:

' start the timer
Set objProfiler = LogManager.GetProfiler("Timer started!")

' do some stuff worth timing here

' stop the timer and write the results to the log
Set objProfiler = Nothing

The string you provide plus the time it took to get from start to end will appear in your Hss_Script.log file.

You can see an example script using the Profiler to time calls to GetFacilityTagList() in the attached file at the bottom of this article.

And don’t forget that you can also use the Profiler and LogManager in CygNet Studio.

5. Respect variable scope, or “Who touched my stuff!?”

In the last tip, I called out the fact that other scripts in your HSS can affect the timing of your script, but it is possible for different HyperPoint’s scripts to interact is much more destructive ways. Since all HSS scripts execute in the same Script Engine, they all have access to each other’s stuff. It’s like the fridge in your office: you can write your name on your lunch, but that won’t stop Bob from eating your BLT if he gets hungry.

Consider this (greatly simplified) example inspired by an actual customer installation I had to help debug.

A warning: this is going to get a little nerdy and talk about things like variable scope, but here you are reading a blog post about scripting in CygNet, so I think you’re probably my kind of folks.

We have two separate points:

HyperPoint A:

Dim objMyObject

Sub A_OnInitialize()
  Set objMyObject = CreateObject("Some.Object")
End Sub

Sub A_OnPointChange()
  objMyObject.DoSomething()
End Sub

HyperPoint B:

Sub B_OnPointChange()
  Set objMyObject = CreateObject("Some.Object")

  objMyObject.DoSomething()

  ' this is the important line
  ' so pay attention here
  objMyObject = Null
End Sub

So, two HyperPoints (which are just like regular Points, except they need Ritalin) doing their own thing. They know nothing about each other and aren’t expecting to work together. They just happen to be using the same type of object to do something. More than that, they just so happened to have used the same variable name. Great minds think alike, right?

But here’s the problem: in order to use objMyObject in multiple functions (OnInitialize and OnPointChange) it is declared in Global scope by Point A. Any variable declared outside of a Function or Sub is in Global scope and therefore will exist as long as the script is running, which in our case, is as long as the HSS Script Engine is running.

In other words, it means the variable objMyObject exists in functions for both Point A and Point B, so changes made in one will affect the other.

Let’s say events fire in this order:

  1. A_OnInitialize()
  2. B_OnPointChange()
  3. A_OnPointChange()

So that would mean the following would happen for objMyObject:

  1. objMyObject declared as soon as HSS starts, since it is in Global scope
  2. objMyObject set to an object of type Some.Object (A_OnInitialize)
  3. Ignorant of the globally declared objMyObject variable, objMyObject is used without being declared because Option Explicit is not turned on (B_OnPointChange)
  4. Then it is set to a new object, some work done (B_OnPointChange)
  5. objMyObject is set to null (B_OnPointChange)
  6. Expecting objMyObject to still exist, it is called to do some work, but it is now null, so Script Engine crashes (A_OnPointChange)

If you were the programmer for Point A, you would see that you created the object you needed, but by the time you wanted to use it, it was gone. How could that be possible? Bob, that’s how. He wrote Point B, didn’t explicitly declare his own variable using the Dim keyword (because VBScript doesn’t require him to — it is the Bob of scripting languages), and then thought he was cleaning up after himself by setting it to null when he was done. Instead all he did was make a mess for you that is nearly impossible to anticipate.

It is easy enough (I hope) to see the problem here, but on the real customer site, there were 10000+ lines of script, the system was live and in production, and I was debugging through several layers of Remote Desktop. I still sometimes wake in the middle of the night in cold sweats reliving the horror.

Since we can never trust Bob, what can we do when writing scripts in the wild west free-for-all that is the HSS?

First, name your variables well. The more specific your variable is named, the less likely you are to step on someone else’s. If you have ever written an HSS script and you used variable names like “x” or “y” or “l” (which is the worst I’ve ever seen — is it a lowercase L or the number one?) then I hate to break it to you, but you are Bob. You can do better.

And be especially careful when creating variables in Global scope. That’s like leaving your front door unlocked: sure, sometimes it is convenient, but sometimes your neighbors will have an impromptu free yard sale in your living room.

Second, always, always, always use Option Explicit, which will force you to declare all variables before using them. In the humble opinion of this scripter, the fact that VBScript will let you use variables without declaring them is one of mankind’s greatest (script-related) failures. The only excuse to do this is laziness and the dangers are immense, especially in a crowded script pool like the HSS.

To enable Option Explicit for HSS scripts, there’s an easy way and a hard way. The hard way is to have every (and I mean every, or it won’t work) script declare Option Explicit as their first line in the Declarations section.

The easy way is to enable the SCRIPTING_OPTION_EXPLICIT keyword in the service configuration file.

6. Leverage a debugger, or “There has to be an easier way…”

We can get around a lot of the aforementioned complexity if we could just debug our script by itself, away from the hustle and bustle of the HSS Script Engine; you know, someplace nice and quiet with just you, your script, and a few friendly breakpoints.

If your script doesn’t rely on the context of the HSS (say, for example, it doesn’t requires use of the global Points object, or isn’t heavily reliant on events firing in a particular order), then it is easy to pull it out of your HyperPoint and drop it into your favorite VBScript debugger (we recommend VBSEdit). If it works here, it’ll likely work in the HSS. Even if your script does need some of the trappings of the HSS, you can often simulate those, or just break it down into small enough pieces that you can test each one by itself (often referred to as “unit testing” or “common sense”).

You can also debug scripts in a simulated HSS environment using the Point Editor’s Simulation Test feature:

Playing Battleship with the HSS - Using PNT editor to simulate HSS execution so we can debug

Using PNT editor to simulate HSS execution so we can debug

Be aware, however, that this is only a test: you can’t do things like issue SetPoints and you won’t be able to test script interaction issues like those covered in Tip #5: Bob’s Revenge.

And if you have a just-in-time debugger like Visual Studio installed on your machine, you can set breakpoints in your HyperPoint script editor and when you run the simulation, they will call into your debugger, where you can see variable values, step through the code, etc. Think of a just-in-time debugger like a MsgBox or LogManager on serious steroids (though I don’t recommend using that analogy when trying to convince your boss to pay for a license for Visual Studio — just tell him Walter says you need it).

I hope these tips help next time you are playing blindfolded Battleship with the HSS. As a reward for slogging through all those words, I’ve distilled my tips down to a bite-sized version that I’ve attached at the bottom of this post for future reference.

And please share your own helpful HSS debugging tips (or painful HSS stories) in the comments below!

HSS Troubleshooting Quick Reference Guide
Using Profiler

Share this entry
Share by Mail



Comments

Blog post currently doesn't have any comments.
{{com.name}}           {{com.blogCommentDateFormatted}}

Leave Comment

Please correct the following error(s):

  • {{ error }}

Subscribe to this blog post

Enter your email address to subscribe to this post and receive notifications of new comments by email.


Search the CygNet Blog

Subscribe to the CygNet Blog

Enter your email address to subscribe to this blog and receive notifications of new posts by email.

Tags