i have a strange problem with the modbus driver. Yesterday after 6:30pm one of the subscribed values stopped updating, but the quality is still ‘good’. All other values (which are in a different ScanClass) are working.
I checked the plc, and the value is changing (counting up every 15 minutes). If i set the drivers’s log to trace i can see that the actual value is received correctly by the driver (see the value ‘40 D2’ change to ‘40 D3’ in the log snippet). For any reason the subscription is not updated with this change.
Please let me know if i can check anything else to help. I will leave the system in this state until tomorrow. thread-dump.txt (132 KB) logs.bin.gz (578 KB)
On the logger level tab, if you search “NotificationReceiver”, or in earlier versions “MyNotificationReceiver”, you should find one that belongs to the OPC-UA connection.
If you turn this to TRACE the UA client will log every value it receives from the server - maybe with this on we can see if the value is making its way to the client or not.
Ok, lets try a different one. Turn the notification receiver logger back to INFO level, we’re done with it for now.
Search for “DriverVariableNode” and turn this TRACE. This is going to log every value that every driver sets on a UA node. You should only need to leave this on TRACE for a few seconds before switching back to INFO, since the driver should be setting the value every second. (Filtering for value changes happens elsewhere in the UA server.)
If there’s not too many log entries generated from this, it would be nice to verify that the driver is indeed setting the value on the UA node.
Are there other tags with changing values in this subscription? Are those values frozen as well? What happens if you add another tag that has a changing value to this subscription?
The screenshot in the first post shows the two Scanclasses that contain this value. There are no other changing values in this ScanClasses, so i can’t tell if they are frozen.
I will try adding another value to this ScanClass tomorrow.
If you go to Status > OPC-UA Server (on the left) > Server Statistics, you should see a list of subscriptions the server currently has. Can you verify this IRUI264 node is found in two of the subscriptions listed? Unfortunately the UA spec doesn’t provide any capability for clients to name subscriptions, so there’s no names on these.
In the Server Statistics there is no subscription with a rate of 1000ms. After realizing this, i checked all other Scan Classes with a similar rate, and that values are also not updated. This did not attract attention so far, because those values are only logged to trace production errors.
So, the project has three Scan Classes with an update rate of 1000ms, using three different devices (One Modbus, two Siemens). The last value update in any of this Scan Classes is from 2013-02-26 18:41:29.
I then added a new ScanClass with a 1000ms update rate and added one opc value. The subscription was immediately displayed in the Server Statistics, but it contains only the new value.
After that i changed one of the erroneous tags to the new Scan Class and the data quality changed to ‘Bad, unknown’. At the same time i got an error in the log (The german text here means ‘Call failed on server side’, maybe we should not translate log messages in the translation project…):
INFO | jvm 1 | 2013/02/28 14:47:59 | WARN [CreateMonitoredItemsService ] [14:47:58,965]: Returning ServiceFault for request: [CreateMonitoredItemsRequest requestHandle=3661102]. StatusCode=StatusCode[0x80280000, Severity=Bad, Subcode=Bad_SubscriptionIdInvalid]
INFO | jvm 1 | 2013/02/28 14:47:59 | ERROR [CreateMonitoredItemsCall ] [14:47:58,996]: Aufruf auf der Serverseite fehlgeschlagen. Statuscode: StatusCode[0x80280000, Severity=Bad, Subcode=Bad_SubscriptionIdInvalid]. Bad_SubscriptionIdInvalid
INFO | jvm 1 | 2013/02/28 14:47:59 | WARN [DeleteMonitoredItemsService ] [14:47:58,996]: Returning ServiceFault for request: [DeleteMonitoredItemsRequest requestHandle=3661103]. StatusCode=StatusCode[0x80280000, Severity=Bad, Subcode=Bad_SubscriptionIdInvalid]
INFO | jvm 1 | 2013/02/28 14:47:59 | ERROR [DeleteMonitoredItemsCall ] [14:47:58,996]: Aufruf auf der Serverseite fehlgeschlagen. Statuscode: StatusCode[0x80280000, Severity=Bad, Subcode=Bad_SubscriptionIdInvalid]. Bad_SubscriptionIdInvalid
Since then, this error repeats every 15 seconds in the log. The other erroneous tags still show good quality with the old timestamp.
Ah, I’m afraid we’re running into a problem that has been fixed for 7.5.6 (also fixed in the latest beta).
What happens, basically, is that due to some faulty subscription calculation logic on the UA client side, it’s possible in some cases that some subscriptions on the server will shut down due to inactivity. Then, thanks to two more flaws, the client 1) never receives notification that the subscription stopped and 2) doesn’t know how to handle a subscription that has disappeared from underneath it (all the Bad_SubscriptionIdInvalid warnings not causing a reconnect).
