# Modbus driver - One of many subscriptions stopped updating **URL:** \ **Category:** Ignition\ **Created:** [February 27, 2013, 10:10am UTC](https://forum.inductiveautomation.com/t/modbus-driver-one-of-many-subscriptions-stopped-updating/5929 "2013-02-27T10:10:35Z")\ **Posts on this page:** 15\ **Page:** 1
**Author:** ![chi](https://avatars.discourse-cdn.com/v4/letter/c/0ea827/32.png) [@chi](https://forum.inductiveautomation.com/u/chi)\ **Post date:** [February 27, 2013, 10:10am UTC](https://forum.inductiveautomation.com/t/modbus-driver-one-of-many-subscriptions-stopped-updating/5929/1 "2013-02-27T10:10:35Z")
Hi, 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. ![](https://us1.discourse-cdn.com/inductiveautomation/original/2X/7/7d639bc0c58fb78e7c1c46131e03f6c6a155b6ed.png) 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. [quote]INFO | jvm 1 | 2013/02/27 10:45:01 | TRACE [ReadInputRegistersRequest] [10:45:00,239]: Sending message: [1F 55 00 00 00 06 00 04 01 04 00 7C] INFO | jvm 1 | 2013/02/27 10:45:01 | TRACE [SocketIODelegate] [10:45:00,239]: [hostname=10.224.62.80,port=502] Sending ByteBuffer [1F 55 00 00 00 06 00 04 01 04 00 7C] INFO | jvm 1 | 2013/02/27 10:45:02 | TRACE [ModbusDriver2[Station2] ] [10:45:00,255]: Received 257 [1F 55 00 00 00 FB 00 04 F8 3B 70 00 9F 34 9A 00 4D [color=#BF0000]40 D2[/color] 00 00 AC 0B 00 03 04 04 00 00 02 25 00 00 03 E8 00 00 00 59 00 9E 07 BC 0A D6 1E 63 03 83 1E 53 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 0C 5E 00 50 43 7E 00 4D 6A 9A 00 00 00 00 00 00 89 F8 00 00 00 00 00 00 98 4C 00 07 14 EF 00 06 F5 1D 00 00 00 00 00 00 00 00 00 00 72 2B 00 00 49 39 00 00 00 00 00 00 8A D4 00 00 7E 03 00 00 19 29 00 01 0B 05 00 01 E7 FF 00 00 36 C7 00 00 33 5E 00 00 EB 5D 00 00 10 2C 00 01 00 00 00 00 00 00 00 00 0F 46 00 10 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 29 B8 00 00 4E C3 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 F5 28 00 00 3A 7A 00 00 1F 1E 00 00 15 C8 00 00 4C 96 00 00 3C 22 00 00 ] INFO | jvm 1 | 2013/02/27 10:45:02 | TRACE [BasicRequestCycle] [10:45:01,146]: Posting ScheduledRequest[com.inductiveautomation.xopc.drivers.modbus2.requests.ReadInputRegistersRequest@414433] request to queue with delay 93ms. INFO | jvm 1 | 2013/02/27 10:45:02 | TRACE [BasicRequestCycle] [10:45:01,240]: Sending PendingRequest[ScheduledRequest[com.inductiveautomation.xopc.drivers.modbus2.requests.ReadInputRegistersRequest@414433]] request INFO | jvm 1 | 2013/02/27 10:45:02 | TRACE [ReadInputRegistersRequest] [10:45:01,240]: Sending message: [1F 56 00 00 00 06 00 04 01 04 00 7C] INFO | jvm 1 | 2013/02/27 10:45:02 | TRACE [SocketIODelegate] [10:45:01,240]: [hostname=10.224.62.80,port=502] Sending ByteBuffer [1F 56 00 00 00 06 00 04 01 04 00 7C] INFO | jvm 1 | 2013/02/27 10:45:02 | TRACE [ModbusDriver2[Station2] ] [10:45:01,333]: Received 257 [1F 56 00 00 00 FB 00 04 F8 3B 72 00 9F 34 9B 00 4D [color=#BF0000]40 D3 [/color]00 00 AC 0C 00 03 03 DF 00 00 02 28 00 00 03 DF 00 00 00 5C 00 9F 00 02 00 03 1E 63 00 00 1E 68 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 0C 5F 00 50 43 7E 00 4D 6A 9A 00 00 00 00 00 00 89 F8 00 00 00 00 00 00 98 4C 00 07 14 EF 00 06 F5 1D 00 00 00 00 00 00 00 00 00 00 72 2B 00 00 49 39 00 00 00 00 00 00 8A D4 00 00 7E 03 00 00 19 29 00 01 0B 05 00 01 E7 FF 00 00 36 C7 00 00 33 5E 00 00 EB 5D 00 00 10 2C 00 01 00 00 00 00 00 00 00 00 0F 46 00 10 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 29 B8 00 00 4E C3 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 F5 28 00 00 3A 7A 00 00 1F 1E 00 00 15 C8 00 00 4C 96 00 00 3C 22 00 00 ] [/quote] 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](https://us1.discourse-cdn.com/inductiveautomation/original/2X/9/9b9b81231b3ddcffae0cf850bff214da4e6668e5.txt) (132 KB) [logs.bin.gz](https://us1.discourse-cdn.com/inductiveautomation/original/2X/1/1f23836503f065135129db811099c9b66736af71.gz) (578 KB) ---
**Author:** ![Kevin.Herron](https://sea1.discourse-cdn.com/inductiveautomation/user_avatar/forum.inductiveautomation.com/kevin.herron/32/7259_2.png) [@Kevin.Herron](https://forum.inductiveautomation.com/u/Kevin.Herron)\ **Post date:** [February 27, 2013, 3:08pm UTC](https://forum.inductiveautomation.com/t/modbus-driver-one-of-many-subscriptions-stopped-updating/5929/2 "2013-02-27T15:08:35Z")
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. ---
**Author:** ![chi](https://avatars.discourse-cdn.com/v4/letter/c/0ea827/32.png) [@chi](https://forum.inductiveautomation.com/u/chi)\ **Post date:** [February 27, 2013, 3:25pm UTC](https://forum.inductiveautomation.com/t/modbus-driver-one-of-many-subscriptions-stopped-updating/5929/3 "2013-02-27T15:25:38Z")
Thank you for your reply. I attached the log with the new trace. There is no entry for this subscription, the value changed some seconds around 4:15. [logs.bin.gz](https://us1.discourse-cdn.com/inductiveautomation/original/2X/c/c5ca438f2c0d55d57c768e44724f96cfdfed577a.gz) (587 KB) ---
**Author:** ![Kevin.Herron](https://sea1.discourse-cdn.com/inductiveautomation/user_avatar/forum.inductiveautomation.com/kevin.herron/32/7259_2.png) [@Kevin.Herron](https://forum.inductiveautomation.com/u/Kevin.Herron)\ **Post date:** [February 27, 2013, 3:31pm UTC](https://forum.inductiveautomation.com/t/modbus-driver-one-of-many-subscriptions-stopped-updating/5929/4 "2013-02-27T15:31:52Z")
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. ---
**Author:** ![chi](https://avatars.discourse-cdn.com/v4/letter/c/0ea827/32.png) [@chi](https://forum.inductiveautomation.com/u/chi)\ **Post date:** [February 27, 2013, 3:37pm UTC](https://forum.inductiveautomation.com/t/modbus-driver-one-of-many-subscriptions-stopped-updating/5929/5 "2013-02-27T15:37:48Z")
Ah, here i see the tag. The value 16618 is the current value in the plc. `INFO | jvm 1 | 2013/02/27 16:33:13 | TRACE [DriverVariableNode] [16:33:12,482]: Driver setting value value=16618, status=StatusCode[0x00000000, Severity=Good, Subcode=NotSpecified], source=Wed Feb 27 16:33:12 CET 2013, server=null on NodeId [Station2]IRUI264 INFO | jvm 1 | 2013/02/27 16:33:14 | TRACE [DriverVariableNode] [16:33:12,482]: Driver setting value value=16618, status=StatusCode[0x00000000, Severity=Good, Subcode=NotSpecified], source=Wed Feb 27 16:33:12 CET 2013, server=null on NodeId [Station2]IRUI264 INFO | jvm 1 | 2013/02/27 16:33:14 | TRACE [DriverVariableNode] [16:33:12,482]: Driver setting value value=16618, status=StatusCode[0x00000000, Severity=Good, Subcode=NotSpecified], source=Wed Feb 27 16:33:12 CET 2013, server=null on NodeId [Station2]IRUI264` ---
**Author:** ![Kevin.Herron](https://sea1.discourse-cdn.com/inductiveautomation/user_avatar/forum.inductiveautomation.com/kevin.herron/32/7259_2.png) [@Kevin.Herron](https://forum.inductiveautomation.com/u/Kevin.Herron)\ **Post date:** [February 27, 2013, 3:39pm UTC](https://forum.inductiveautomation.com/t/modbus-driver-one-of-many-subscriptions-stopped-updating/5929/6 "2013-02-27T15:39:57Z")
Related to the driver sent/received bytes: What is the value of your “Zero-Based Addressing” setting for this device? ---
**Author:** ![Kevin.Herron](https://sea1.discourse-cdn.com/inductiveautomation/user_avatar/forum.inductiveautomation.com/kevin.herron/32/7259_2.png) [@Kevin.Herron](https://forum.inductiveautomation.com/u/Kevin.Herron)\ **Post date:** [February 27, 2013, 3:41pm UTC](https://forum.inductiveautomation.com/t/modbus-driver-one-of-many-subscriptions-stopped-updating/5929/7 "2013-02-27T15:41:45Z")
[quote=“chi”]Ah, here i see the tag. The value 16618 is the current value in the plc. `INFO | jvm 1 | 2013/02/27 16:33:13 | TRACE [DriverVariableNode] [16:33:12,482]: Driver setting value value=16618, status=StatusCode[0x00000000, Severity=Good, Subcode=NotSpecified], source=Wed Feb 27 16:33:12 CET 2013, server=null on NodeId [Station2]IRUI264 INFO | jvm 1 | 2013/02/27 16:33:14 | TRACE [DriverVariableNode] [16:33:12,482]: Driver setting value value=16618, status=StatusCode[0x00000000, Severity=Good, Subcode=NotSpecified], source=Wed Feb 27 16:33:12 CET 2013, server=null on NodeId [Station2]IRUI264 INFO | jvm 1 | 2013/02/27 16:33:14 | TRACE [DriverVariableNode] [16:33:12,482]: Driver setting value value=16618, status=StatusCode[0x00000000, Severity=Good, Subcode=NotSpecified], source=Wed Feb 27 16:33:12 CET 2013, server=null on NodeId [Station2]IRUI264`[/quote] But 16618 isn’t making to the client, correct? It has some other value? ---
**Author:** ![chi](https://avatars.discourse-cdn.com/v4/letter/c/0ea827/32.png) [@chi](https://forum.inductiveautomation.com/u/chi)\ **Post date:** [February 27, 2013, 3:43pm UTC](https://forum.inductiveautomation.com/t/modbus-driver-one-of-many-subscriptions-stopped-updating/5929/8 "2013-02-27T15:43:41Z")
Yes, the client still shows 16.530. The value is used in a SQLTag and as a trigger in a transaction group. Zero based adressing is set to false. ---
**Author:** ![Kevin.Herron](https://sea1.discourse-cdn.com/inductiveautomation/user_avatar/forum.inductiveautomation.com/kevin.herron/32/7259_2.png) [@Kevin.Herron](https://forum.inductiveautomation.com/u/Kevin.Herron)\ **Post date:** [February 27, 2013, 3:45pm UTC](https://forum.inductiveautomation.com/t/modbus-driver-one-of-many-subscriptions-stopped-updating/5929/9 "2013-02-27T15:45:46Z")
Ok. 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? What version of Ignition is this, btw? ---
**Author:** ![chi](https://avatars.discourse-cdn.com/v4/letter/c/0ea827/32.png) [@chi](https://forum.inductiveautomation.com/u/chi)\ **Post date:** [February 27, 2013, 3:51pm UTC](https://forum.inductiveautomation.com/t/modbus-driver-one-of-many-subscriptions-stopped-updating/5929/10 "2013-02-27T15:51:53Z")
This is Ignition 7.5.5 (b1255). 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. ---
**Author:** ![Kevin.Herron](https://sea1.discourse-cdn.com/inductiveautomation/user_avatar/forum.inductiveautomation.com/kevin.herron/32/7259_2.png) [@Kevin.Herron](https://forum.inductiveautomation.com/u/Kevin.Herron)\ **Post date:** [February 27, 2013, 3:54pm UTC](https://forum.inductiveautomation.com/t/modbus-driver-one-of-many-subscriptions-stopped-updating/5929/11 "2013-02-27T15:54:30Z")
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. ---
**Author:** ![chi](https://avatars.discourse-cdn.com/v4/letter/c/0ea827/32.png) [@chi](https://forum.inductiveautomation.com/u/chi)\ **Post date:** [February 28, 2013, 2:05pm UTC](https://forum.inductiveautomation.com/t/modbus-driver-one-of-many-subscriptions-stopped-updating/5929/12 "2013-02-28T14:05:40Z")
Ok, we are getting closer. 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…): ```auto 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. ---
**Author:** ![Kevin.Herron](https://sea1.discourse-cdn.com/inductiveautomation/user_avatar/forum.inductiveautomation.com/kevin.herron/32/7259_2.png) [@Kevin.Herron](https://forum.inductiveautomation.com/u/Kevin.Herron)\ **Post date:** [February 28, 2013, 3:02pm UTC](https://forum.inductiveautomation.com/t/modbus-driver-one-of-many-subscriptions-stopped-updating/5929/13 "2013-02-28T15:02:55Z")
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). All of this has been addressed for 7.5.6. ---
**Author:** ![chi](https://avatars.discourse-cdn.com/v4/letter/c/0ea827/32.png) [@chi](https://forum.inductiveautomation.com/u/chi)\ **Post date:** [February 28, 2013, 5:29pm UTC](https://forum.inductiveautomation.com/t/modbus-driver-one-of-many-subscriptions-stopped-updating/5929/14 "2013-02-28T17:29:11Z")
Ok, thank you. Since i have to restart the gateway anyway, i’ll update to the latest beta tomorrow. ---
**Author:** ![Kevin.Herron](https://sea1.discourse-cdn.com/inductiveautomation/user_avatar/forum.inductiveautomation.com/kevin.herron/32/7259_2.png) [@Kevin.Herron](https://forum.inductiveautomation.com/u/Kevin.Herron)\ **Post date:** [February 28, 2013, 7:35pm UTC](https://forum.inductiveautomation.com/t/modbus-driver-one-of-many-subscriptions-stopped-updating/5929/15 "2013-02-28T19:35:37Z")
I’m told 7.5.6 will likely be released tomorrow, if you can wait for that.