Log In
Register
Forum
Topic RSS
17:58, EEST
March 16, 2017
Offline
Hi,
I observed, that when I do some time consuming action in the onDataChange of a monitored item in a subscription, it prevents all other onDataChanges even from monitored items from other subscriptions from getting triggered.
Here’s the overview of the scenario:
I have 2 subscription.
Each subscription has one monitored item.
Each monitored item has it’s own MonitoredDataItemListener.
To test it I’m using the Prosys Simulation Server (Subscription 1 has a monitored item on ‘Counter1’, Subscription 2 has a monitored item on ‘Expression1’)
In a normal case, I get onDataChanges each second for Counter1 and Expression 1.
But when I do some time consuming stuff in e.g. the onDataChange for Counter1, I do not get the onDataChanges for ‘Expression1’ from the Subscription 2 until the time consuming tuff done in onDataChange of ‘Counter1’ has completed.
I always thought, that onDataChanges of MonitoredItems of different subscriptions are not blocked by each other.
Is there any possibility to set or to configure something to get the notification of the Subscription 2 ?
I’ve made some example to reproduce the behaviour.
The example makes two subscriptions whith each subscription has it’s own monitored item using it’s own MonitoredDataItemListener.
On the 3rd data change of monitored item 1 (The Counter1) I do some time consuming stuff (a 5sec sleep) in the onDataChange.
In the logs I can see, that the onDataChanges for monitored item of subscription 2 are not reported to the client until the time consuming stuff was completed.
Here’s my test code:
{code}
@Test
public void testSubscription()
throws Exception
{
/* 1st subscription */
LOGGER.info(“testSubscription() Create 1st Subscription”);
Subscription subscription1 = new Subscription();
LOGGER.info(“testSubscription() subscription1=” + subscription1);
MonitoredDataItem monitoredDataItem1 = new MonitoredDataItem(NodeId.get(IdType.String, _client.getNamespaceTable().getIndex(“http://www.prosysopc.com/OPCUA/SimulationNodes”), “Counter1”));
monitoredDataItem1.setDataChangeListener(new MonitoredDataItemListener() {
int i = 0;
@Override
public void onDataChange(MonitoredDataItem sender, DataValue prevValue, DataValue value) {
i++;
LOGGER.info(“MonitoredDataItemListener 1″ + ” testSubscription().onDataChange sender ” + sender);
LOGGER.info(“MonitoredDataItemListener 1″ + ” testSubscription().onDataChange value ” + value);
try {
if(i==3) {
// do some time consuming stuff
LOGGER.info(“MonitoredDataItemListener 1″ + ” testSubscription().onDataChange sleeping for 5secs”);
Thread.sleep(5000);
LOGGER.info(“MonitoredDataItemListener 1″ + ” testSubscription().onDataChange sleeping finished”);
}
}
catch (InterruptedException e) {}
}
});
subscription1.addItem(monitoredDataItem1);
LOGGER.info(“testSubscription() monitoredDataItem1=” + monitoredDataItem1.toString());
/* 2nd subscription */
LOGGER.info(“testSubscription() Create 2nd Subscription”);
Subscription subscription2 = new Subscription();
LOGGER.info(“testSubscription() subscription2=” + subscription2);
MonitoredDataItem monitoredDataItem2 = new MonitoredDataItem(NodeId.get(IdType.String, _client.getNamespaceTable().getIndex(“http://www.prosysopc.com/OPCUA/SimulationNodes”), “Expression1”));
monitoredDataItem2.setDataChangeListener(new MonitoredDataItemListener() {
@Override
public void onDataChange(MonitoredDataItem sender, DataValue prevValue, DataValue value) {
LOGGER.info(“MonitoredDataItemListener 2″ + ” testSubscription().onDataChange sender ” + sender);
LOGGER.info(“MonitoredDataItemListener 2″ + ” testSubscription().onDataChange value ” + value);
}
});
subscription2.addItem(monitoredDataItem2);
LOGGER.info(“testSubscription() monitoredDataItem2=” + monitoredDataItem2);
/* Adding the subscriptions to the client object */
LOGGER.info(“testSubscription() Adding 1st Subscription”);
_client.addSubscription(subscription1);
LOGGER.info(“testSubscription() subscription1=” + subscription1);
LOGGER.info(“testSubscription() Adding 2nd Subscription”);
_client.addSubscription(subscription2);
LOGGER.info(“testSubscription() subscription2=” + subscription2);
// wait for user input to stop
BufferedReader stdin = new BufferedReader(new InputStreamReader(System.in));
String s = stdin.readLine();
LOGGER.info(“testSubscription() exit”);
}
{code}
And here’s the corresponding log:
2020-06-19 15:09:45,042|INFO |org.opcfoundation.ua.transport.tcp.io.TcpConnection|/127.0.0.1:53530 Connecting
2020-06-19 15:09:45,049|INFO |org.opcfoundation.ua.transport.tcp.io.TcpConnection|/127.0.0.1:53530 Connected
/* I create the two subscriptions */
2020-06-19 15:09:46,212|INFO |testSubscription() Create 1st Subscription
2020-06-19 15:09:46,218|INFO |testSubscription() subscription1=Subscription id=null PublishingInterval=1000.0 isPublishingEnabled=true priority=0 lifetimeCount=60 maxKeepAliveCount=20 maxNotificationsPerPublish=0
2020-06-19 15:09:46,222|INFO |testSubscription() monitoredDataItem1=ClientHandle=1, MonitoredItemId=null, NodeId=ns=5;s=Counter1, AttributeId=Value
2020-06-19 15:09:46,222|INFO |testSubscription() Create 2nd Subscription
2020-06-19 15:09:46,223|INFO |testSubscription() subscription2=Subscription id=null PublishingInterval=1000.0 isPublishingEnabled=true priority=0 lifetimeCount=60 maxKeepAliveCount=20 maxNotificationsPerPublish=0
2020-06-19 15:09:46,223|INFO |testSubscription() monitoredDataItem2=ClientHandle=2, MonitoredItemId=null, NodeId=ns=5;s=Expression1, AttributeId=Value
/* Adding the subscription to the UaClient */
2020-06-19 15:09:46,224|INFO |testSubscription() Adding 1st Subscription
2020-06-19 15:09:46,250|INFO |testSubscription() subscription1=Subscription id=30 PublishingInterval=1000.0 isPublishingEnabled=true priority=0 lifetimeCount=60 maxKeepAliveCount=20 maxNotificationsPerPublish=0
2020-06-19 15:09:46,250|INFO |testSubscription() Adding 2nd Subscription
2020-06-19 15:09:46,270|INFO |testSubscription() subscription2=Subscription id=31 PublishingInterval=1000.0 isPublishingEnabled=true priority=0 lifetimeCount=60 maxKeepAliveCount=20 maxNotificationsPerPublish=0
/* When doing nothing in the onDataChange, everthing is fine
* I get onDataChange for the monitored items of each subscription */
2020-06-19 15:09:47,233|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange sender ClientHandle=1, MonitoredItemId=1, NodeId=ns=5;s=Counter1, AttributeId=Value
2020-06-19 15:09:47,234|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange value DataValue(value=92, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:47.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:09:47,258|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange sender ClientHandle=2, MonitoredItemId=1, NodeId=ns=5;s=Expression1, AttributeId=Value
2020-06-19 15:09:47,259|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange value DataValue(value=-0.01347331561243914, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:47.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:09:48,230|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange sender ClientHandle=1, MonitoredItemId=1, NodeId=ns=5;s=Counter1, AttributeId=Value
2020-06-19 15:09:48,231|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange value DataValue(value=94, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:48.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:09:48,257|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange sender ClientHandle=2, MonitoredItemId=1, NodeId=ns=5;s=Expression1, AttributeId=Value
2020-06-19 15:09:48,257|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange value DataValue(value=0.02442954980637113, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:48.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
/* No I start to to some time consuming stuff -> a sleep by 5sec
*/
2020-06-19 15:09:49,239|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange sender ClientHandle=1, MonitoredItemId=1, NodeId=ns=5;s=Counter1, AttributeId=Value
2020-06-19 15:09:49,241|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange value DataValue(value=96, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:49.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:09:49,241|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange sleeping for 5secs
2020-06-19 15:09:54,242|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange sleeping finished
/* I expected to get the onDataChanges of ‘Subscription 2’ during this 5 seconds, but for the 5
seconds, I do not get any onDataChange from Subscription 2 */
/* After the time consuming stuff in the onDataChange of MonitoredItem from Subscription 1
is completed, I get 5x onDataChanges of Monitored Item of Subscription 1 and afterwards the
5x 5x onDataChanges of Monitored Item of Subscription 2
*/
2020-06-19 15:09:54,242|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange sender ClientHandle=1, MonitoredItemId=1, NodeId=ns=5;s=Counter1, AttributeId=Value
2020-06-19 15:09:54,242|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange value DataValue(value=98, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:50.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:09:54,242|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange sender ClientHandle=1, MonitoredItemId=1, NodeId=ns=5;s=Counter1, AttributeId=Value
2020-06-19 15:09:54,242|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange value DataValue(value=100, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:51.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:09:54,243|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange sender ClientHandle=1, MonitoredItemId=1, NodeId=ns=5;s=Counter1, AttributeId=Value
2020-06-19 15:09:54,243|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange value DataValue(value=1, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:52.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:09:54,243|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange sender ClientHandle=1, MonitoredItemId=1, NodeId=ns=5;s=Counter1, AttributeId=Value
2020-06-19 15:09:54,243|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange value DataValue(value=3, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:53.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:09:54,243|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange sender ClientHandle=1, MonitoredItemId=1, NodeId=ns=5;s=Counter1, AttributeId=Value
2020-06-19 15:09:54,244|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange value DataValue(value=5, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:54.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:09:54,244|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange sender ClientHandle=2, MonitoredItemId=1, NodeId=ns=5;s=Expression1, AttributeId=Value
2020-06-19 15:09:54,244|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange value DataValue(value=0.11371037063523137, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:49.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:09:54,244|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange sender ClientHandle=2, MonitoredItemId=1, NodeId=ns=5;s=Expression1, AttributeId=Value
2020-06-19 15:09:54,245|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange value DataValue(value=0.26794924452492497, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:50.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:09:54,245|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange sender ClientHandle=2, MonitoredItemId=1, NodeId=ns=5;s=Expression1, AttributeId=Value
2020-06-19 15:09:54,245|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange value DataValue(value=0.4978869721615593, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:51.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:09:54,245|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange sender ClientHandle=2, MonitoredItemId=1, NodeId=ns=5;s=Expression1, AttributeId=Value
2020-06-19 15:09:54,245|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange value DataValue(value=0.8109561700334638, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:52.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:09:54,246|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange sender ClientHandle=2, MonitoredItemId=1, NodeId=ns=5;s=Expression1, AttributeId=Value
2020-06-19 15:09:54,246|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange value DataValue(value=1.2109562497118682, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:53.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:09:54,258|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange sender ClientHandle=2, MonitoredItemId=1, NodeId=ns=5;s=Expression1, AttributeId=Value
2020-06-19 15:09:54,259|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange value DataValue(value=1.697886973463879, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:54.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:09:55,229|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange sender ClientHandle=1, MonitoredItemId=1, NodeId=ns=5;s=Counter1, AttributeId=Value
2020-06-19 15:09:55,230|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange value DataValue(value=7, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:55.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:09:55,259|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange sender ClientHandle=2, MonitoredItemId=1, NodeId=ns=5;s=Expression1, AttributeId=Value
2020-06-19 15:09:55,259|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange value DataValue(value=-1.7320508305217501, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:55.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:09:56,234|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange sender ClientHandle=1, MonitoredItemId=1, NodeId=ns=5;s=Counter1, AttributeId=Value
2020-06-19 15:09:56,235|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange value DataValue(value=9, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:56.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:09:56,258|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange sender ClientHandle=2, MonitoredItemId=1, NodeId=ns=5;s=Expression1, AttributeId=Value
2020-06-19 15:09:56,258|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange value DataValue(value=-1.0862896977139518, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:56.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:09:57,236|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange sender ClientHandle=1, MonitoredItemId=1, NodeId=ns=5;s=Counter1, AttributeId=Value
2020-06-19 15:09:57,237|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange value DataValue(value=11, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:57.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:09:57,257|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange sender ClientHandle=2, MonitoredItemId=1, NodeId=ns=5;s=Expression1, AttributeId=Value
2020-06-19 15:09:57,258|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange value DataValue(value=-0.37557057054678733, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:57.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:09:58,230|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange sender ClientHandle=1, MonitoredItemId=1, NodeId=ns=5;s=Counter1, AttributeId=Value
2020-06-19 15:09:58,230|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange value DataValue(value=13, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:58.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:09:58,258|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange sender ClientHandle=2, MonitoredItemId=1, NodeId=ns=5;s=Expression1, AttributeId=Value
2020-06-19 15:09:58,259|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange value DataValue(value=0.3865267515410027, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:58.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:09:59,229|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange sender ClientHandle=1, MonitoredItemId=1, NodeId=ns=5;s=Counter1, AttributeId=Value
2020-06-19 15:09:59,230|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange value DataValue(value=15, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:59.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:09:59,265|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange sender ClientHandle=2, MonitoredItemId=1, NodeId=ns=5;s=Expression1, AttributeId=Value
2020-06-19 15:09:59,265|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange value DataValue(value=1.1841766429103475, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:09:59.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:10:00,230|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange sender ClientHandle=1, MonitoredItemId=1, NodeId=ns=5;s=Counter1, AttributeId=Value
2020-06-19 15:10:00,230|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange value DataValue(value=17, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:10:00.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:10:00,258|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange sender ClientHandle=2, MonitoredItemId=1, NodeId=ns=5;s=Expression1, AttributeId=Value
2020-06-19 15:10:00,258|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange value DataValue(value=1.9999998931668175, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:10:00.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:10:01,238|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange sender ClientHandle=1, MonitoredItemId=1, NodeId=ns=5;s=Counter1, AttributeId=Value
2020-06-19 15:10:01,239|INFO |MonitoredDataItemListener 1 testSubscription().onDataChange value DataValue(value=19, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:10:01.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
2020-06-19 15:10:01,262|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange sender ClientHandle=2, MonitoredItemId=1, NodeId=ns=5;s=Expression1, AttributeId=Value
2020-06-19 15:10:01,262|INFO |MonitoredDataItemListener 2 testSubscription().onDataChange value DataValue(value=2.8158232646966903, statusCode=GOOD (0x00000000) “”, sourceTimestamp=06/19/20 13:10:01.0000000 GMT, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)
x
2020-06-19 15:10:01,430|INFO |testSubscription() exit
2020-06-19 15:10:01,443|INFO |com.prosysopc.ua.client.UaClient$a |Got Bad_NoSubscription as a PublishResponse, although we have connected Subscriptions
2020-06-19 15:10:01,461|INFO |org.opcfoundation.ua.transport.tcp.io.SecureChannelTcp|84 Closed
2020-06-19 15:10:01,462|INFO |org.opcfoundation.ua.transport.tcp.io.TcpConnection |/127.0.0.1:53530 Closed
2020-06-19 15:10:01,462|INFO |org.opcfoundation.ua.transport.tcp.io.TcpConnection |/127.0.0.1:53530 Closed (expected)
14:13, EEST
Moderators
February 11, 2020
Offline
Hello,
UaClient periodically checks each Subscription for queued PublishResponses. Each PublishResponse is then checked for DataChange Notifications. Each DataChange Notification is then processed to set the Value of the corresponding Monitored Data Item. If the Value changes, onDataChange methods of associated MonitoredDataItemListeners are called.
This Subscription handling process is done in a predetermined order, which could be described as nested for-each loops. The outer loop is for Subscriptions, the middle loop is for PublishResponses and the inner loop is for DataChange Notifications. While this approach works well enough, it’s not perfectly safe as Subscriptions can face resource starvation if processing a PublishResponse takes longer than receiving a new PublishResponse as the loop won’t move on to the next Subscription as long as there are queued PublishResponses.
In your scenario, when the 3rd PublishResponse arrives for Subscription 1 and forces the onDataChange method to sleep for 5 seconds, five more PublishResponses are queued to both of your Subscriptions. After the sleep, Subscription 1 is still being processed and thus the five additional queued PublishResponses are processed one by one. After there are no more queued PublishResponses to Subscription 1, the six queued PublishResponses of Subscription 2 are processed one by one. After catching up, UaClient now has sufficient time to process PublishResponses to both Subscriptions in the order they’re received as shown by the last part of your log.
In short, calling onDataChange methods block the processing of DataChange Notifications, PublishResponses and Subscriptions until the called method has finished its execution. If you need to perform a time consuming operation in onDataChange method, you should have this method create a Thread or pass the necessary data to an already running Thread to perform this operation on the background and avoid blocking the Subscription handling process.
16:25, EEST
March 16, 2017
Offline
Hi,
thank you for the detailed explanation.
I’ll think I will pass the onDataChange handling for each subscription to an own thread executor, so that my onDataChanges of the monitored items of subscription 1 or no more blocking the onDataChanges of my the monitored items of subscription 2.
Thank you!
Most Users Ever Online: 1919
Currently Online:
81 Guest(s)
Currently Browsing this Page:
1 Guest(s)
Top Posters:
Heikki Tahvanainen: 402
hbrackel: 144
rocket science: 88
pramanj: 86
Francesco Zambon: 83
Ibrahim: 78
Sabari: 62
kapsl: 57
gjevremovic: 49
Xavier: 43
Member Stats:
Guest Posters: 0
Members: 739
Moderators: 7
Admins: 1
Forum Stats:
Groups: 3
Forums: 15
Topics: 1524
Posts: 6453
Newest Members:
shaylamaggard4, rickyjuarez140, jonathonmcintyre, fannielima, kristiewinkle8, rust, christamcdowall, redaahern07571, nigelbdhmp, travistimmonsModerators: Jouni Aro: 1026, Pyry: 1, Petri: 0, Bjarne Boström: 1027, Jimmy Ni: 26, Matti Siponen: 346, Lusetti: 0
Administrators: admin: 1
