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

ignition80
#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)
0 Likes

#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.

0 Likes

#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)

0 Likes

#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?

0 Likes

#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.

0 Likes

#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.

0 Likes

#7

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

0 Likes

#8

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

0 Likes

#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 ?

0 Likes

#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