[BUG-14889] Error during blocking read of tags through scripting

Ignition Early Access
1

Ignition 8.0.4-NIGHTLY - 21/08/2019

I’ve some expression tag with runscript.

runScript("shared.tag.alarm.syntheseAlarme",0,"[default]{PathToParentFolder}")

This script read some tags with readBlocking.
If I delete a tag which is read by the script with readBlocking, I have the following error in the gateway log and the designer freeze for 30 seconds or more…

@mgross is this exception normal in the gateway logs ?
the same expression and script (with readAll) in 7.9 was not disturbed by non existing tags.

 E [Scripting[system_util_tag]    ] [11:47:48]: Error during blocking read of tags through scripting. tag=[default]SYN_ALARME/SYS/TVG_SYS/status
jvm 1    | java.util.concurrent.TimeoutException: null
jvm 1    |      at java.base/java.util.concurrent.CompletableFuture.timedGet(Unknown Source)
jvm 1    |      at java.base/java.util.concurrent.CompletableFuture.get(Unknown Source)
jvm 1    |      at com.inductiveautomation.ignition.gateway.script.GatewayTagUtilities.readBlockingImpl(GatewayTagUtilities.java:148)
jvm 1    |      at com.inductiveautomation.ignition.common.script.builtin.AbstractTagUtilities.readBlocking(AbstractTagUtilities.java:358)
jvm 1    |      at jdk.internal.reflect.GeneratedMethodAccessor34.invoke(Unknown Source)
jvm 1    |      at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
jvm 1    |      at java.base/java.lang.reflect.Method.invoke(Unknown Source)
jvm 1    |      at org.python.core.PyReflectedFunction.__call__(PyReflectedFunction.java:188)
jvm 1    |      at com.inductiveautomation.ignition.common.script.ScriptManager$ReflectedInstanceFunction.__call__(ScriptManager.java:518)
jvm 1    |      at org.python.core.PyObject.__call__(PyObject.java:497)
jvm 1    |      at org.python.core.PyObject.__call__(PyObject.java:501)
jvm 1    |      at org.python.pycode._pyx7016.syntheseAlarme$6(<module:shared.tag.alarm>:343)
jvm 1    |      at org.python.pycode._pyx7016.call_function(<module:shared.tag.alarm>)
jvm 1    |      at org.python.core.PyTableCode.call(PyTableCode.java:171)
jvm 1    |      at org.python.core.PyBaseCode.call(PyBaseCode.java:308)
jvm 1    |      at org.python.core.PyFunction.function___call__(PyFunction.java:471)
jvm 1    |      at org.python.core.PyFunction.__call__(PyFunction.java:466)
jvm 1    |      at org.python.core.PyFunction.__call__(PyFunction.java:456)
jvm 1    |      at org.python.core.PyFunction.__call__(PyFunction.java:451)
jvm 1    |      at com.inductiveautomation.ignition.common.script.ScriptManager.runFunction(ScriptManager.java:788)
jvm 1    |      at com.inductiveautomation.ignition.common.expressions.functions.ScriptFunction.execute(ScriptFunction.java:87)
jvm 1    |      at com.inductiveautomation.ignition.common.expressions.FunctionExpression.execute(FunctionExpression.java:66)
jvm 1    |      at com.inductiveautomation.ignition.gateway.tags.actors.factories.value.expression.ExpressionTagActorFactory$ExpressionTagActor.runInternal(ExpressionTagActorFactory.java:154)
jvm 1    |      at com.inductiveautomation.ignition.gateway.tags.actors.factories.value.AbstractExpressionActor.run(AbstractExpressionActor.java:119)
jvm 1    |      at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
jvm 1    |      at java.base/java.util.concurrent.FutureTask.runAndReset(Unknown Source)
jvm 1    |      at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
jvm 1    |      at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
jvm 1    |      at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
jvm 1    |      at java.base/java.lang.Thread.run(Unknown Source)
1 Like
2

I don’t see anything obvious with my mockup. When my shared script runs system.tag.readBlocking(), it reports the deleted tags as Bad_NotFound, and there is no lag. It might help to grab a thread dump during the time that the designer is freezing up to see where the gateway is getting stuck.

3

@mgross, when the designer freeze, I have Thread [tag-expressions-2] BLOCKED in the gateway Diagnostics Threads.

Thread [tag-expressions-2] id=111, (WAITING for java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@46c30d2a)
  java.base@11.0.3/jdk.internal.misc.Unsafe.park(Native Method)
  java.base@11.0.3/java.util.concurrent.locks.LockSupport.park(Unknown Source)
  java.base@11.0.3/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Unknown Source)
  java.base@11.0.3/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(Unknown Source)
  java.base@11.0.3/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(Unknown Source)
  java.base@11.0.3/java.util.concurrent.ThreadPoolExecutor.getTask(Unknown Source)
  java.base@11.0.3/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
  java.base@11.0.3/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
  java.base@11.0.3/java.lang.Thread.run(Unknown Source)

V8-Ignition-STVG-T9_thread_dump20190827-090425.txt (266.8 KB)

4

OK now we are getting somewhere. As per the thread dump, the tag deletions are backing up the expression threads somehow. Exactly what was being deleted when the thread dump was taken? Was the delete happening in the same script that is being called by the expression tag?

5

I manually delete folders with tags from the designer.
(folder tree with udt instance)

expression tags outside the deleted tag tree, execute runscript expression. In the script I read some tag value which are in the deleted folders

I generate the tag with json file. I need to ofen delete and recreate tags.

6

Yeah I still cannot replicate anything. I think we will need a tag export, the runscript, and a list of tags that are being deleted when this happens.

7

I’ve send with PM you a link to download data

8

OK thanks. Let me see what I can find with these.

9

OK I put in a ticket to figure this out.

1 Like
10

Hi @mgross,
Have you ever a fix for the 8.0.4 final or Another 8.0.5 nightly ?

11

Hi @mazeyrat,

We don’t have a fix ready for this yet, but I will certainly let you know when we do.

Thanks!

1 Like
12

Hi @mgross, @awalker,
Have you make any progress in the investigation of this issue ?
We are waiting to test a fix of it to update our application from 7.9 to 8.0 :slight_smile:

13

Hi @mazeyrat,

Investigation is still in progress for this issue. We hope to have a fix for you soon!

1 Like
14

Thanks, I stay tuned

15

Hi @awalker,
Any news about a fix…in 8.0.5 final ?

16

Hi @mazeyrat - Colby has been looking in to this issue, it will get fixed in 8.0.6 at the earliest

1 Like
17

Hi @awalker, @Colby.Clegg,

I have done other test with the final 8.0.5, and I think this issue is related to some tag expression with runscript where import doesn't work as in 7.9:

18

@awalker
Any news about this issue ?

19

Still not fixed yet, we are hoping to get it fixed for 8.0.7.

20

A change was implemented in the 8.0.7 nightly released this morning that should address the issue in this thread.