Write time out error caused by write id mismatch

Ignition
1

This is my first post here and I am a beginner in the PLC world as well as with Ignition (not with programming in general). Tried to educate myself before posting this question so hopefully it makes sense.

The problem:
I have a simple Vision client that works fine, but time to time I get an error message “Error writing to tag xxx Write timed out [C]”. First I tried increased the timeout value (I was up to 30 seconds at a stage) but the error happened with the same frequency. Then I started checking the console log and found that the source of the problem may be somewhere else. Every time I have a timeout error it is preceded by the following warning in the console log:
“WARN [DatasourceTagManager-TagManager-thread-3] Received finished write notification for unknown write id: WriteOpDone[id=333, result=[GOOD]]”

It seems that the write does happen, the “finished write notification” is indeed returned but the write id is unknown so the notification is ignored by the client.

I wonder if this is a bug or if there is a setting or other measure I could take to prevent this issue.

It seems that the problem only occurs when a system.tag.write method is used in the event script of a control.

I have Ignition Panel Edition 7.5.4 (b1206) 32 bit on CentOS 6.3 (32 bit), using the IcedTea Java Runtime that comes with the OS. The PLC’s are Allen-Bradley CompactLogix and ControlLogix.

I know that I can suppress this error but instead of hiding the problem I am looking for a real solution.

Thanks,
Robert

2

Have you started looking through the console on the gateway or the wrapper.log files for any error messages that occur around the same time this happens in the client?

It sounds like once in a while you may have a write to the PLC that is taking quite a while, but finishing eventually.

3

I have the same problem occurring on a system which is only writing to internal Tags not the PLC. This occurs from a client side timer script at random intervals (10mins - 5 hours).

The client and gateway are very lightly loaded and have no new or different actions happening at time of error.

4

Hi,

Could you post the script that's running, and the details of exactly what event it's firing on? I have a slight suspicion that perhaps you're firing off more write requests than you realize, causing the buffer to cycle through and some ids to get removed. I doubt the writes are taking long, but if the id is lost, the finish message can't be sent and the client will get the timeout message reported.

Regards,

5

this is the event handler of a button.
Event is action/actionPerformed.
The script is very basic:

window = system.gui.getWindow("Main")
dataframe = window.rootContainer.getComponent("frmDataExchange")
tagname = dataframe.getComponent("txtTagName").text
system.tag.write(tagname + "/TXID_To_PC", 0)
system.tag.write(tagname + "/Check", 0)
system.tag.write(tagname + "/Passed", 0)
system.tag.write(tagname + "/Failed", 0)
system.tag.write(tagname + "/Ready", 0)

I know that I could use writeAll, I may just try it… One of these writes gives the warning and then the error message. It has never actually failed.
The extract from the console log:

WARN  [DatasourceTagManager-TagManager-thread-3] Received finished write notification for unknown write id: WriteOpDone[id=274, result=[GOOD]]
ERROR [ClientTagUtilities-AWT-EventQueue-1] Error writing to tag MEM_MES_DE00/TXID_From_PC
Write timed out [C]

It is not always the first write (TXID_To_PC), sometimes the second or the third. I have never seen the 4th or the 5th having this issue.

6

Last time I had this problem was today at 14:19. Here is the extract from the log on the server:

INFO   | jvm 1    | 2013/02/13 14:16:25 | INFO  [Projects$ProjectChangeMonitor ] [14:16:25,851]: Starting up client project monitor. project=DummyClient, uuid=134fd4d3-604a-caa5-88b6-5e6d857cbbd6, editCount=51, scope=4, version=Published
INFO   | jvm 1    | 2013/02/13 14:16:41 | WARN  [ABControlLogixTransportPool   ] [14:16:41,933]: [TESTPLC] Transport for transaction 26308 not found.
INFO   | jvm 1    | 2013/02/13 14:17:21 | WARN  [ABControlLogixTransportPool   ] [14:17:21,014]: [TESTPLC] Transport for transaction 26958 not found.
INFO   | jvm 1    | 2013/02/13 14:19:28 | WARN  [ABControlLogixTransportPool   ] [14:19:28,044]: [TESTPLC] Transport for transaction 29000 not found.
INFO   | jvm 1    | 2013/02/13 14:19:43 | WARN  [ABControlLogixTransportPool   ] [14:19:43,014]: [TESTPLC] Transport for transaction 29237 not found.
INFO   | jvm 1    | 2013/02/13 14:22:33 | WARN  [ABControlLogixTransportPool   ] [14:22:33,209]: [TESTPLC] Transport for transaction 31965 not found.
INFO   | jvm 1    | 2013/02/13 14:37:40 | WARN  [ABControlLogixTransportPool   ] [14:37:40,566]: [TESTPLC] Transport for transaction 13736 not found.

I am not sure what the "Transport for transaction x not found" warning means but I have dozens of it in the log and clearly not all of them denotes the problem in question. The client worked just fine for this half an hour with the one hiccup at 14:19:49.

7

sorry, in the previous post I copied the code from the other side. (In case you spotted the different tag names TXID_To_PC and TXID_From_PC)

However, it is the same scenario, resetting 5 tags in a row and one of them has this issue. This is a function that is called from a tag change event script.

if (not initialChange) :
	app.local.manageReady(str(event.tagPath), newValue.value)

def manageReady(tagname, value) :
	print "manageReady call, tagname: %s, value: %i" % (tagname, value)
	import system
	import app
	tagfolder = tagname[:-5]
	system.tag.write(tagfolder + 'Acknowledged',0)
	system.tag.write(tagfolder + 'Accepted',0)
	system.tag.write(tagfolder + 'Rejected',0)
	system.tag.write(tagfolder + 'Reject_Code',-1)
	system.tag.write(tagfolder + 'TXID_From_PC',0)
        ...
8

Like Kevin said once in a while the communication to your device is slow causing the write timeouts. You can check the diagnostics of your device by clicking on the link to the right of the device in the configuration section. It might give you some insight into the performance. Periodically it could be overloaded causing the timeout. The write eventually goes down to the PLC but it just causes the error.

If you want you can suppress the error so it doesn’t show up ever by doing the following:system.tag.write(tagfolder + 'Acknowledged',0,1)The problem could also be that the script is firing more often than you think. Does that tag change script run a lot?

9

Quite a few things has been change since I had this error. It is now gone, I have no more “false” write time-outs. Unfortunately I cannot point out what solved the issue. The changes that happened (again, it is a pity that I had no chance to test after each change):

  • went from Linux 32 bit to Windows 32 bit
  • upgraded from 7.5.4 to 7.5.6
  • changed the code to use writeAll instead of a series of write whenever there were more than one tag writes necessary.

After all, I do not have this problem any more.