Title: Intermittent Gateway Tag Event delays / PLC heartbeat timeout on script-heavy InTouch 2012 migration

Ignition
,
1

Hi all,

I'm troubleshooting an intermittent performance/communications issue on an Ignition 8.1 Vision gateway and I'm looking for some advice around Gateway Tag Change scripts, the Tag Event thread pool and blocking tag writes.

APPLICATION BACKGROUND

This is a fairly large SCADA application that was migrated from Wonderware InTouch 2012 to Ignition Vision 8.1.

A lot of the original InTouch process and database functionality has been replicated in Ignition. The application communicates with several Rockwell PLCs and makes extensive use of UDTs and Gateway Tag Change scripts.

We probably have a few hundred Tag Value Changed scripts across the application, many inherited through UDTs.

One of the main uses of these Tag Change events is process state/data logging to SQL.

Rather than continuously polling all of the process information, particular UDT members act as triggers. When a relevant process state, cycle, step, interlock or error changes, a Gateway Tag Change script runs.

The general flow is something like:

PLC process state changes
↓
Ignition UDT member changes
↓
Gateway Tag Change event fires
↓
Script obtains the associated process context
↓
Determines the relevant state/process information
↓
Required information is assembled
↓
Database query/update is executed
↓
Process event/state is recorded in SQL

So this isn't simply standard tag history. We're recording the progression of the process through its states and associating that with the relevant process information in SQL.

There is similar event-driven functionality around interlocks and errors.

Other Tag Change scripts perform things such as:

  • Process state logging to SQL
  • Interlock/error logging
  • Recipe/setpoint downloads to PLCs
  • Batch/process handling
  • PLC/HMI heartbeat handling
  • Database connectivity monitoring
  • Dataset generation/processing
  • Various PLC reads and writes

Some of these scripts use system.tag.readBlocking(), system.tag.writeBlocking() and database queries.

This means that during a process transition several PLC values can change close together, potentially resulting in multiple Gateway Tag Change events firing around the same time.

For example:

PLC process transition
↓
Several process values change
↓
State logging events
Interlock/error events
Process sequence events
Recipe events
Other UDT events
↓
Multiple Gateway Tag Event scripts execute

This is why I'm wondering whether bursts of Tag Change activity, combined with blocking operations in some scripts, could be relevant to the issues we're seeing.

ISSUE 1 - PLC/HMI HEARTBEAT TIMEOUT

We have a heartbeat/watchdog value changing approximately once per second.

A Gateway Tag Value Changed event writes the changing heartbeat value to an OPC value in the PLC. The PLC monitors this and generates a communications alarm if it doesn't see the value change within its timeout period.

The heartbeat script is essentially:

def valueChanged(tag, tagPath, previousValue, currentValue, initialChange, missedEvents):

if not initialChange:
    system.tag.writeBlocking(
        [destination],
        [currentValue.value]
    )

Under normal conditions this works without any problem.

However, intermittently the PLC doesn't receive a heartbeat change within its timeout period and generates a communications alarm.

As a test, we moved the actual heartbeat write into system.util.invokeAsynchronous() so that the writeBlocking() wouldn't occupy one of the Gateway Tag Event threads.

The heartbeat/comms alarm has still occurred since making that change, so the Tag Event thread pool may not be the sole cause.

ISSUE 2 - INTERMITTENTLY SLOW RECIPE/SETPOINT DOWNLOADS

We also have Gateway Tag Change events responsible for downloading recipe/setpoint data to the PLC.

When the relevant process sequence changes, the script essentially:

  1. Executes a Named Query to retrieve the required recipe setpoints.
  2. Processes the returned dataset.
  3. Builds the destination paths.
  4. Writes the required setpoints to the PLC.
  5. Checks the QualityCode returned from each write.

We are currently writing the setpoints using system.tag.writeBlocking() in chunks of four.

Under normal conditions the actual setpoint download is very quick. We generally see the complete write taking approximately 100-200 ms.

However, intermittently we have seen the operation take several seconds, occasionally around 8-10 seconds.

We have now added additional logging to the recipe download. For every setpoint we log the value being written and the QualityCode returned by writeBlocking(), as well as the overall execution time.

For example:

Wrote value: 15 - Quality: Good
Wrote value: 20 - Quality: Good
Wrote value: 120.0 - Quality: Good
Wrote value: 1 - Quality: Good

Recipe successfully written in chunks of 4. Total time: 120 ms.

The idea is to catch one of the 8-10 second occurrences and determine whether the PLC writes themselves are taking several seconds and/or returning anything other than Good quality.

GATEWAY TAG EVENT THREAD POOL

This led us to start looking at the Gateway Tag Event execution threads.

The Tag Event script thread pool was originally configured with the default 3 threads.

We increased this from 3 to 10.

So far, increasing it hasn't made an obvious difference to the intermittent heartbeat or recipe issue.

Looking at the Gateway thread page, we can see the Gateway Tag Event execution threads moving between states such as:

RUNNABLE
WAITING
TIMED_WAITING

During normal operation we might see, for example:

3 RUNNABLE
7 WAITING

When deliberately generating a lot of SCADA activity ("button bashing") or during periods with a lot of process activity, we have seen more of these threads active and have also seen TIMED_WAITING.

I realise the Java thread state itself doesn't necessarily prove that Tag Events are backed up, so I'm trying to understand the correct way to determine whether Tag Change events are actually sitting in a queue waiting for an available event thread.

WHAT WE'RE TRYING TO DETERMINE

One theory is that because we're quite heavily dependent on Tag Change scripts, some of which contain blocking operations, we could occasionally get something like:

Several process changes occur
↓
Multiple Tag Change scripts start
↓
Available Tag Event threads are occupied
↓
Additional Tag Change events queue
↓
Time-sensitive heartbeat/recipe event waits
↓
Script eventually executes

If this is happening, it could potentially explain why something that normally executes very quickly occasionally appears to be delayed by several seconds.

However, the alternative is that the Tag Event pool isn't actually the problem and the script starts immediately, but the delay is occurring further downstream:

Tag Change event occurs
↓
Script starts immediately
↓
Script reaches writeBlocking()
↓
Ignition/OPC/device communication stalls
↓
writeBlocking() eventually returns
↓
Script takes several seconds to complete

The fact that increasing the Tag Event pool from 3 to 10 hasn't made an obvious difference, and that we've still seen the heartbeat alarm after moving its write into invokeAsynchronous(), makes me particularly interested in distinguishing between these two scenarios.

We're therefore trying to determine whether our occasional 8-10 second delay is:

EVENT OCCURS
↓
[Several seconds waiting in Tag Event queue]
↓
SCRIPT STARTS
↓
PLC writes complete quickly

OR:

EVENT OCCURS
↓
SCRIPT STARTS immediately
↓
[writeBlocking()/OPC operation takes several seconds]
↓
SCRIPT FINISHES

QUESTIONS

I'm hoping someone with more experience of the Gateway internals can give some guidance on the following:

  1. With a few hundred Tag Change scripts, is increasing the Gateway Tag Event thread pool from 3 to 10 reasonable, or are we potentially just masking an architectural issue?

  2. Is there any benefit in going higher than 10, or could that potentially make things worse by allowing more simultaneous OPC/database operations?

  3. Is there a good way to see the actual Tag Event queue depth/wait time rather than trying to infer it from the Java thread states?

  4. Are RUNNABLE, WAITING and TIMED_WAITING on the Gateway Tag Event execution threads actually useful for diagnosing this, or would capturing thread dumps/stack traces during the issue be more useful?

  5. Is using system.tag.writeBlocking() inside Gateway Tag Change events generally discouraged, particularly when writing to OPC-backed PLC values?

  6. Would system.tag.writeAsync() be preferable for operations where we don't need to wait for the write result?

  7. For something like a recipe download where ordering, completion and returned QualityCodes matter, what would be the recommended architecture? Would you still use writeBlocking(), but move the overall operation away from the Tag Event execution pool?

  8. Is there a recommended way of determining the time between the actual value change occurring and the Python valueChanged script beginning execution? This would allow us to distinguish an event that has been queued from a script that starts immediately but subsequently runs slowly.

  9. Are there particular Gateway loggers/metrics that would be useful to enable temporarily to determine whether the delay is happening in:

  • Tag Event execution
  • Ignition's tag system
  • OPC writes
  • Device driver/PLC communications
  • Database operations
  1. More generally, for an application migrated from InTouch 2012 that has ended up with several hundred Tag Change scripts, should we be looking at reducing the amount of logic performed directly inside Tag Events and moving heavier/event-driven operations elsewhere?

At this point I'm mainly trying to get enough diagnostics in place so that when the issue happens again we can establish exactly where those missing seconds are occurring.

Any suggestions on what diagnostics/loggers/thread information would be useful to capture when the issue occurs would be appreciated.

Thanks.

2
  1. Reformat your post so it isn't a code block or quote. (Edit in place with the pencil icon.) Just use plain markdown. Then we can read it. :check_mark:
3

Before diving in, you have a terminology problem.

  • A "Gateway Tag Change Event" is a project-level event defined in the gateway scripting section of a project. Relevant tags are listed for the event. Each defined tag change event gets one dedicated thread to handle all events from the listed tags. These events can use any library script in the same project.

  • A "Tag ValueChange Event" is a tag-level event defined directly on a tag, whether atomic or inherited from a UDT definition. The entire gateway shares a single thread pool, default quantity 3, that run all tag-level events. Blocking operations in tag-level event scripts can block the entire gateway's event processing. The tag-level event scripts can only call library scripts that are defined in the Gateway Scripting Project.

4

Can you clarify if you mean Gateway Tag Change Events which are defined in the project, or Tag Value Change Events which are defined on the tag. There reason is you seem to mix you language between these two things.

e.g.

Emphasis added.

These are two very different things with very different constraints.

Later in the post you provide a script which includes a def statement, but Gateway Event Scripts do not include this.

If you are in fact using Tag Value Change Events, and you are reaching out to databases and/or performing blocking writes, I wouldn't be suprised if you are having issues.

Here are some posts with pertinent information:

5

Yes. This is an architectural issue.

Yes. If you have hundreds of blocking scripts, you would need hundreds of threads, and your DB would be crushed.

Not really. You should use System.nanoTime() to collect precision timestamps at event start and log any events that exceed ~5ms.

  1. None of the above. First, get the blocking calls out of your tag-level events and then revisit.

If you mean Tag ValueChange Events, yes, don't do that. (Except memory tags.) If you mean project-level Gateway Tag Change Events, that's fine, as long as you allocate tags to event lists intelligently.

Yes. Though you should always supply a callable that checks the return value.

Yes. Either to a project-level event or directly in the UI if triggered by a user.

No, but you might find my Integration Toolkit's Bulk Script Tag Action helpful, as it provides the queuing timestamp in the .entryTS property of the action item.

No need. It pretty much has to be the tag event scripts calling any blocking operations. Those blocking operations are fine in other contexts.

  1. YES
6

One further piece of advice:

If you want to perform PLC-ish logic that participates in PLC sequencing, consider using a Gateway Timer Event to mimic a PLC periodic task, at whatever pace is appropriate and achievable.

Or more than one, if necessary for pacing.

Such scripts should follow this basic flow:

  • Use a single system.tag.readBlocking() call to gather all input signals and state values, then use one or more python unpacking operations to assign to python local variables (or most of them).

  • Establish a pair of empty python lists to contain tag paths and values to be written.

  • Compute new states and append any associated writes.

  • Compute new output signals and append as needed to the tag writes. (I would omit bulk items if unchanged. Always compute and write critical outputs--anything that would get an OTE in real PLC code.)

  • Perform DB operations or network API operations as needed, appending acknowledgements to the tag writes.

  • Use a single system.tag.writeBlocking() to send all tag writes in bulk.

Using event-driven techniques can be highly efficient, but is often hard to troubleshoot and maintain, and if not carefully designed, can leave some signals broken when scripts choke. In the above flow, no tags are written if any part of the script throws an error.