Gateway timer event fixed delay not correct

Hello,

I used to use Ignition 7.9 and had gateway TIMER events defined as FIXED DELAY on DEDICATED threading to execute every 60 seconds.

The script within the timer event would take anywhere from 10-15 seconds to execute.
THEN, 60 seconds after that the timer would execute again. Just like in the documentation.

However since I have upgraded to Ignition 8.0.13 this is not behaving the same.
I have a “master” inheritable project defined.
I have the gateway timer events defined in it.
I have a “child” project defined that has my windows in it.

NOW when my gateway timer events fire, the execute as follows.

  1. gateway starts.
  2. 60 seconds later the timer fires.
  3. My script within the timer executes for 10-15 seconds.
    (I verify this with logging.)
  4. 50-45 seconds later the timer fires again!

What happened to the FIXED delay that used to be between the END of your script firing INSIDE the timer and the NEXT interval?

thanks

How many projects do you have inheriting this? Because that’s how many copies of the script will be running. I suspect you are seeing logging from two different projects, not mistiming from one project. Gateway events should never be defined in an inheritable project, only in leaf projects.

1 Like

Those are the only 2 PROJECTS in my gateway.
“master” is inheritable.
“child” is inherited from “master” and is not inheritable.

My gateway TIMER event is defined as follows:

60,000 ms
Delay Type = FIXED DELAY
Threading = DEDICATED

script:
from time import sleep
lSeconds = 10
MES_global.DB.logMessageDirectlyToDB(‘zTestFIXEDdelay’, 'Starting…sleeping for ’ + str(lSeconds))
sleep(lSeconds)
MES_global.DB.logMessageDirectlyToDB(‘zTestFIXEDdelay’, ‘Finished’)

Since my script above takes 10 seconds to “run”.
I would expect there to be 70 seconds between log entries that start with:
'Starting…sleeping for 10

Here is the actual log entries:
|2020-09-11 14:03:56.540|zTestFIXEDdelay|Starting…sleeping for 10|
|2020-09-11 14:04:06.547|zTestFIXEDdelay|Finished|
there should be a 60 second gap AFTER 14:04:06.547 above!!!
|2020-09-11 14:04:56.537|zTestFIXEDdelay|Starting…sleeping for 10|
|2020-09-11 14:05:06.543|zTestFIXEDdelay|Finished|
|2020-09-11 14:05:56.550|zTestFIXEDdelay|Starting…sleeping for 10|

I changed the threading = SHARED.

same logging as above.
from the END of one execution of the script, there is NOT 60 seconds before
the next one begins.

I’m able to replicate using this script:

from time import sleep

logger = system.util.getLogger('timer_test')

logger.info('starting')

sleep(10)

logger.info('finished')

with these settings:

output:

I [timer_test                    ] [18:21:13]: starting 
I [timer_test                    ] [18:21:23]: finished 
I [timer_test                    ] [18:22:13]: starting 
I [timer_test                    ] [18:22:23]: finished 
I [timer_test                    ] [18:23:13]: starting 
I [timer_test                    ] [18:23:23]: finished 

Thanks Kevin.

Would you happen to have EASY access to an Ignition 7.9 you could check against?

It doesn’t work as you’d expect in 7.9 either. It’s likely never work as expected.

The crazy thing is that this isn’t even some bug in Ignition (I mean technically it is because it’s not behaving like it should), but this is really either a bug in java.util.Timer or its documentation, because this is reproducible on its own in Java.

Can you suggest a workaround?

So that I get a 60,000ms delay AFTER my script executes…before it executes again?

Kevin Herron,

Will this be addressed in any upcoming versions?
thank you

Hmm, it probably will be, there’s a ticket but it’s been marked low priority.

Hello everyone,
i faced this same problem and i’d like to say that from my personal point of view,
this shouldn’t be a low priority ticket.

Is there any news on this issue? The documentation is clear about fixed and delay interval.
Is two months i’m struggling wit this, being thinking was something in my code.

Thanks for your time

I’ll note your objection and see if it can be re-reviewed.

Because these timers, while technically behaving incorrectly, have been behaving this way for over a decade and “fixing” them will alter the behavior of many existing projects, the fix may have serious repercussions.

I thought Java’s util.Timer fixed delay schedule implemented a fixed delay from the execution time (i.e. the time the task actually started), rather than from the time the task finished. Variance in how long the task took to execute shouldn’t change when the task is scheduled to run next.

To achieve what is described in the Ignition docs, I think the gateway script would need to manually call schedule() again after every execution for a single schedule rather than trying to set it up to run for an extended period with one call. I don’t know whether this would be fragile or not.

A workaround might be to bind a tag’s value to the system time and write an on change script that does something when the seconds == 0.

Edit: Hey I was reading that! :laughing:

Yes, that appears to be the case, but that is hardly distinguishable from fixed rate execution.

I ninja-deleted my original response because I misread yours. It was just a code sample showing that fixed delay execution with java.util.Timer is broken entirely independent of Ignition.

Yeah it’s basically the same thing to an Ignition user. I think it still achieves one of the benefits from the Ignition docs:

This is the safest option since it prevents a script from mistakenly running continuously because it takes longer to execute the script than the delay.

But this bit isn’t accurate

This means that the script’s rate will actually be the delay plus the amount of time it takes to execute the script.

The difference probably isn’t relevant to an Ignition user, but technically you did implement a fixed delay script - just defined it differently. Safest thing might be to add a third option and clarify what a fixed delay script is. Fixed Sleep or something similar.

Fixed delay is defined and works as expected with ScheduledExecutorService::scheduledWithFixedDelay, which is what we’d probably use instead.

https://docs.oracle.com/en/java/javase/11/docs/api/java.base/java/util/concurrent/ScheduledExecutorService.html#scheduleWithFixedDelay(java.lang.Runnable,long,long,java.util.concurrent.TimeUnit)

edit: I’m having a rough morning apparently.

Ah, the old “define fixed-delay two different ways in your documentation” trick. Java you rascal.

Even the docs for java.util.Timer indicate it should behave how we want though:

In fixed-delay execution, each execution is scheduled relative to the actual execution time of the previous execution.

https://docs.oracle.com/en/java/javase/11/docs/api/java.base/java/util/Timer.html#schedule(java.util.TimerTask,long,long)

How can you interpret that in a way that resembles fixed rate instead?

In fixed-delay execution, each execution is scheduled relative to the actual execution time of the previous execution.

Here they’re using ‘execution time’ to mean the time that the function begins executing, not the time that it takes to execute. Bit ambiguous.

1 Like