search

pjkundert / cpppo

Communications Protocol Python Parser and Originator -- EtherNet/IP CIP
https://hardconsulting.com/products/6-cpppo-enip-api
Other
332 stars 109 forks source link

Error"sub-machine terminated in a non-terminal state" #37

Closed nisargpandyadattus closed 6 years ago

nisargpandyadattus commented 7 years ago

I'm using CPPPO for reading string data from the PLC. Here is the Error I'm getting while trying to read string tag. raise NonTerminal( "%s sub-machine terminated in a non-terminal state" % ( self )) cpppo.automata.NonTerminal: ( data.( select.((noop)) ) ) sub-machine terminated in a non-terminal state Here is the detailed log of the request: debian@DattusBBB84BC:~/code_repository/branches/EthernetIP/python-codes/source$ python3 -m cpppo.server.enip.client --print -vvv 'CIP1_Data_Log_Text[0]' -a 10.10.135.120 07-25 09:33:28.784 MainThread enip.cli DETAIL init Connect: TCP/IP to ('10.10.135.120', 44818) 07-25 09:33:29.171 MainThread enip.cli DETAIL cip_send Client CIP Send: { "enip.status": 0, "enip.sender_context.input": "bytearray(b'\x00\x00\x00\x00\x00\x00\x00\x00')", "enip.session_handle": 0, "enip.CIP.register.protocol_version": 1, "enip.CIP.register.options": 0, "enip.options": 0 } 07-25 09:33:29.178 MainThread enip.cli INFO cip_send EtherNet/IP: 24 + CIP: 4 == 28 bytes total 07-25 09:33:29.180 MainThread enip.cli INFO send EtherNet/IP--> 10.10.135.120:44818 send 28: b'e\x00\x04\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00' 07-25 09:33:29.183 MainThread enip.cli INFO next EtherNet/IP--> 10.10.135.120:44818 rcvd 28: b'e\x00\x04\x00\x01\x00:\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00' 07-25 09:33:29.188 MainThread cpppo INFO terminate ( header.( command.((byte)) : => enip.command = 101 (format b'<H' over array('B', [101, 0])) 07-25 09:33:29.192 MainThread cpppo INFO terminate ( header.( command.((byte)) : => enip.length = 4 (format b'<H' over array('B', [4, 0])) 07-25 09:33:29.197 MainThread cpppo INFO terminate ( header.( command.((byte)) : => enip.session_handle = 3801089 (format b'<I' over array('B', [1, 0, 58, 0])) 07-25 09:33:29.202 MainThread cpppo INFO terminate ( header.( command.((byte)) : => enip.status = 0 (format b'<I' over array('B', [0, 0, 0, 0])) 07-25 09:33:29.210 MainThread cpppo INFO terminate ( header.( command.((byte)) : => enip.options = 0 (format b'<I' over array('B', [0, 0, 0, 0])) 07-25 09:33:29.216 MainThread enip.cli INFO next EtherNet/IP 10.10.135.120:44818 done: ((enip.((payload.((byte))) -> ((payload.; next byte 28: None : {'peer': ('10.10.135.120', 44818), 'enip': {'status': 0, 'sender_context': {'input': array('B', [0, 0, 0, 0, 0, 0, 0, 0])}, 'session_handle': 3801089, 'length': 4, 'command': 101, 'input': array('B', [1, 0, 0, 0]), 'options': 0}} 07-25 09:33:29.220 MainThread cpppo INFO run ( register.( protocol_version.((byte)) -- limit='enip.CIP.register...length' == 4; ending at symbol 4 vs. None 07-25 09:33:29.225 MainThread cpppo INFO terminate ( register.( protocol_version.((byte)) : => enip.CIP.register.protocol_version = 1 (format b'<H' over array('B', [1, 0])) 07-25 09:33:29.229 MainThread cpppo INFO terminate ( register.( protocol_version.((byte)) : => enip.CIP.register.options = 0 (format b'<H' over array('B', [0, 0])) 07-25 09:33:29.232 MainThread enip.cli INFO next Returning result: {'peer': ('10.10.135.120', 44818), 'enip': {'status': 0, 'sender_context': {'input': array('B', [0, 0, 0, 0, 0, 0, 0, 0])}, 'session_handle': 3801089, 'length': 4, 'CIP': {'register': {'protocol_version': 1, 'options': 0}}, 'command': 101, 'input': array('B', [1, 0, 0, 0]), 'options': 0}} 07-25 09:33:29.235 MainThread enip.cli NORMAL init Connect: Success in 0.451s/ 5.000s 07-25 09:33:29.237 MainThread enip.cli DETAIL main Client Register Rcvd 0.453/ 5.000s 07-25 09:33:29.240 MainThread enip.cli DETAIL parse_oper Tag: 'CIP1_Data_Log_Text[0]' yields Operation: {'path': [{'symbolic': 'CIP1_Data_Log_Text'}, {'element': 0}]}.update({'route_path': None, 'send_path': None}) 07-25 09:33:29.247 MainThread enip.cli DETAIL cip_send Client CIP Send: { "enip.status": 0, "enip.sender_context.input": "bytearray(b'0\x00\x00\x00\x00\x00\x00\x00')", "enip.session_handle": 3801089, "enip.CIP.send_data.interface": 0, "enip.CIP.send_data.CPF.item[0].type_id": 0, "enip.CIP.send_data.CPF.item[1].unconnected_send.status": 0, "enip.CIP.send_data.CPF.item[1].unconnected_send.route_path.segment[0].link": 0, "enip.CIP.send_data.CPF.item[1].unconnected_send.route_path.segment[0].port": 1, "enip.CIP.send_data.CPF.item[1].unconnected_send.service": 82, "enip.CIP.send_data.CPF.item[1].unconnected_send.timeout_ticks": 157, "enip.CIP.send_data.CPF.item[1].unconnected_send.request.path.segment[0].symbolic": "CIP1_Data_Log_Text", "enip.CIP.send_data.CPF.item[1].unconnected_send.request.path.segment[1].element": 0, "enip.CIP.send_data.CPF.item[1].unconnected_send.request.read_tag.elements": 1, "enip.CIP.send_data.CPF.item[1].unconnected_send.request.service": 76, "enip.CIP.send_data.CPF.item[1].unconnected_send.request.input": "bytearray(b'L\x0b\x91\x12CIP1_Data_Log_Text(\x00\x01\x00')", "enip.CIP.send_data.CPF.item[1].unconnected_send.priority": 5, "enip.CIP.send_data.CPF.item[1].unconnected_send.path.segment[0].class": 6, "enip.CIP.send_data.CPF.item[1].unconnected_send.path.segment[1].instance": 1, "enip.CIP.send_data.CPF.item[1].type_id": 178, "enip.CIP.send_data.timeout": 0, "enip.options": 0 } 07-25 09:33:29.257 MainThread enip.cli INFO cip_send EtherNet/IP: 24 + CIP: 56 == 80 bytes total 07-25 09:33:29.259 MainThread enip.cli INFO send EtherNet/IP--> 10.10.135.120:44818 send 80: b'o\x008\x00\x01\x00:\x00\x00\x00\x00\x000\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x02\x00\x00\x00\x00\x00\xb2\x00(\x00R\x02 \x06$\x01\x05\x9d\x1a\x00L\x0b\x91\x12CIP1_Data_Log_Text(\x00\x01\x00\x01\x00\x01\x00' 07-25 09:33:29.262 MainThread enip.cli DETAIL format_pat Formatted CIP1_Data_Log_Text[0] from: [{'symbolic': 'CIP1_Data_Log_Text'}, {'element': 0}] 07-25 09:33:29.264 MainThread enip.cli DETAIL issue Sent 0.019/ 5.000s: Single Read Tag CIP1_Data_Log_Text[0] { "path.segment[0].symbolic": "CIP1_Data_Log_Text", "path.segment[1].element": 0, "read_tag.elements": 1, "service": 76, "input": "bytearray(b'L\x0b\x91\x12CIP1_Data_Log_Text(\x00\x01\x00')" } 07-25 09:33:29.269 MainThread enip.cli DETAIL issue Sending 1 (Context b'0') 07-25 09:33:29.271 MainThread enip.cli DETAIL pipeline Issuing 0/ 1; curr: 0 - last: -1 == 1 depth 07-25 09:33:29.274 MainThread enip.cli INFO next EtherNet/IP--> 10.10.135.120:44818 rcvd 136: b'o\x00p\x00\x01\x00:\x00\x00\x00\x00\x000\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x02\x00\x00\x00\x00\x00\xb2\x00`\x00\xcc\x00\x00\x00\xa0\x02\xce\x0f\x1f\x00\x00\x00CIP PATH #2 WASH W/HOT SANITIZE\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00' 07-25 09:33:29.278 MainThread cpppo INFO terminate ( header.( command.((byte)) : => enip.command = 111 (format b'<H' over array('B', [111, 0])) 07-25 09:33:29.282 MainThread cpppo INFO terminate ( header.( command.((byte)) : => enip.length = 112 (format b'<H' over array('B', [112, 0])) 07-25 09:33:29.287 MainThread cpppo INFO terminate ( header.( command.((byte)) : => enip.session_handle = 3801089 (format b'<I' over array('B', [1, 0, 58, 0])) 07-25 09:33:29.291 MainThread cpppo INFO terminate ( header.( command.((byte)) : => enip.status = 0 (format b'<I' over array('B', [0, 0, 0, 0])) 07-25 09:33:29.300 MainThread cpppo INFO terminate ( header.( command.((byte)) : => enip.options = 0 (format b'<I' over array('B', [0, 0, 0, 0])) 07-25 09:33:29.340 MainThread enip.cli INFO next EtherNet/IP 10.10.135.120:44818 done: ((enip.((payload.((byte))) -> ((payload.; next byte 164: None : {'peer': ('10.10.135.120', 44818), 'enip': {'status': 0, 'sender_context': {'input': array('B', [48, 0, 0, 0, 0, 0, 0, 0])}, 'session_handle': 3801089, 'length': 112, 'command': 111, 'input': array('B', [0, 0, 0, 0, 0, 0, 2, 0, 0, 0, 0, 0, 178, 0, 96, 0, 204, 0, 0, 0, 160, 2, 206, 15, 31, 0, 0, 0, 67, 73, 80, 32, 80, 65, 84, 72, 32, 35, 50, 32, 87, 65, 83, 72, 32, 87, 47, 72, 79, 84, 32, 83, 65, 78, 73, 84, 73, 90, 69, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]), 'options': 0}} 07-25 09:33:29.345 MainThread cpppo INFO run ( send_data.( interface.((byte)) -- limit='enip.CIP.send_data...length' == 112; ending at symbol 112 vs. None 07-25 09:33:29.350 MainThread cpppo INFO terminate ( send_data.( interface.((byte)) : => enip.CIP.send_data.interface = 0 (format b'<I' over array('B', [0, 0, 0, 0])) 07-25 09:33:29.355 MainThread cpppo INFO terminate ( send_data.( interface.((byte)) : => enip.CIP.send_data.timeout = 0 (format b'<H' over array('B', [0, 0])) 07-25 09:33:29.361 MainThread cpppo INFO terminate ( CPF.( count.((byte)) : => enip.CIP.send_data.CPF.count = 2 (format b'<H' over array('B', [2, 0])) 07-25 09:33:29.367 MainThread cpppo INFO terminate ( each.( type_id.((byte)) : => enip.CIP.send_data.CPF.item.type_id = 0 (format b'<H' over array('B', [0, 0])) 07-25 09:33:29.372 MainThread cpppo INFO terminate ( each.( type_id.((byte)) : => enip.CIP.send_data.CPF.item.length = 0 (format b'<H' over array('B', [0, 0])) 07-25 09:33:29.378 MainThread cpppo INFO terminate ( each.( type_id.((byte)) : => enip.CIP.send_data.CPF.item.type_id = 178 (format b'<H' over array('B', [178, 0])) 07-25 09:33:29.383 MainThread cpppo INFO terminate ( each.( type_id.((byte)) : => enip.CIP.send_data.CPF.item.length = 96 (format b'<H' over array('B', [96, 0])) 07-25 09:33:29.387 MainThread cpppo INFO run ( unconnected_send.( select.((noop)) -- limit='enip.CIP.send_data.CPF.item__.unconnected_send..length' == 96; ending at symbol 112 vs. 112 07-25 09:33:29.498 MainThread cpppo INFO terminate ( read_tag.( service.((byte)) : => service = 204 (format b'B' over array('B', [204])) 07-25 09:33:29.503 MainThread cpppo INFO terminate ( status.( status.((byte)) : => status = 0 (format b'B' over array('B', [0])) 07-25 09:33:29.506 MainThread cpppo INFO terminate ( status.( status.((byte)) : => status_ext.size = 0 (format b'B' over array('B', [0])) 07-25 09:33:29.512 MainThread cpppo INFO terminate ( read_tag.( service.((byte)) : => read_tag.type = 672 (format b'<H' over array('B', [160, 2])) Traceback (most recent call last): File "/usr/lib/python3.2/runpy.py", line 161, in _run_module_as_main "main", fname, loader, pkg_name) File "/usr/lib/python3.2/runpy.py", line 74, in _run_code exec(code, run_globals) File "/usr/local/lib/python3.2/dist-packages/cpppo/server/enip/client.py", line 1649, in sys.exit( main() ) File "/usr/local/lib/python3.2/dist-packages/cpppo/server/enip/client.py", line 1630, in main fragment=fragment, printing=printing, timeout=timeout ) File "/usr/local/lib/python3.2/dist-packages/cpppo/server/enip/client.py", line 1406, in process transactions = list( self.results( operations=operations, kwds )) File "/usr/local/lib/python3.2/dist-packages/cpppo/server/enip/client.py", line 1398, in results for idx,dsc,req,rpy,sts,val in self.operate( operations, kwds ): File "/usr/local/lib/python3.2/dist-packages/cpppo/server/enip/client.py", line 1393, in operate for idx,dsc,req,rpy,sts,val in harvested: File "/usr/local/lib/python3.2/dist-packages/cpppo/server/enip/client.py", line 1283, in validate for index,descr,request,reply,status,val in harvested: File "/usr/local/lib/python3.2/dist-packages/cpppo/server/enip/client.py", line 1258, in pipeline col = next( harvester ) File "/usr/local/lib/python3.2/dist-packages/cpppo/server/enip/client.py", line 1190, in harvest issued, self.collect( timeout=timeout )): # must be "lazy" zip! File "/usr/local/lib/python3.2/dist-packages/cpppo/server/enip/client.py", line 1115, in collect response,elapsed = await( self, timeout=timeout ) File "/usr/local/lib/python3.2/dist-packages/cpppo/server/enip/client.py", line 872, in await for response in cli: # if StopIteration raised immediately, defaults to {} signalling completion File "/usr/local/lib/python3.2/dist-packages/cpppo/server/enip/client.py", line 546, in next for mch,sta in engine: File "/usr/local/lib/python3.2/dist-packages/cpppo/automata.py", line 645, in run source=source, machine=machine, path=path, data=data, ending=ending ): File "/usr/local/lib/python3.2/dist-packages/cpppo/automata.py", line 1226, in delegate for which,target in submach: # 75% of runtime is spent inside 'run' File "/usr/local/lib/python3.2/dist-packages/cpppo/automata.py", line 645, in run source=source, machine=machine, path=path, data=data, ending=ending ): File "/usr/local/lib/python3.2/dist-packages/cpppo/automata.py", line 1226, in delegate for which,target in submach: # 75% of runtime is spent inside 'run' File "/usr/local/lib/python3.2/dist-packages/cpppo/automata.py", line 645, in run source=source, machine=machine, path=path, data=data, ending=ending ): File "/usr/local/lib/python3.2/dist-packages/cpppo/automata.py", line 1291, in delegate raise NonTerminal( "%s sub-machine terminated in a non-terminal state" % ( self )) cpppo.automata.NonTerminal: ( data.( select.((noop)) ) ) sub-machine terminated in a non-terminal state

I tried reading it using EPATH as well, as you have mentioned in one of the past issue and here is the log for the same. Here lies one question to me as, for the PLC I am using the TAG is written like CIP1_Data_Log_Text[0].DATA/82, according to your answer to the similar question was if you query using path the symbolic will be DATA and there should be element as number. But here its given like DATA/82. debian@DattusBBB84BC:~/code_repository/branches/EthernetIP/python-codes/source$ python3 -m cpppo.server.enip.client --print -vvv '@{"symbolic":"CIP1_Data_Log_Text"}/{"element":0}/{"symbolic":"DATA"}/{"element":82}' -a 10.10.135.120 07-25 09:46:53.110 MainThread enip.cli DETAIL init Connect: TCP/IP to ('10.10.135.120', 44818) 07-25 09:46:53.499 MainThread enip.cli DETAIL cip_send Client CIP Send: { "enip.status": 0, "enip.sender_context.input": "bytearray(b'\x00\x00\x00\x00\x00\x00\x00\x00')", "enip.session_handle": 0, "enip.CIP.register.protocol_version": 1, "enip.CIP.register.options": 0, "enip.options": 0 } 07-25 09:46:53.506 MainThread enip.cli INFO cip_send EtherNet/IP: 24 + CIP: 4 == 28 bytes total 07-25 09:46:53.508 MainThread enip.cli INFO send EtherNet/IP--> 10.10.135.120:44818 send 28: b'e\x00\x04\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00' 07-25 09:46:53.511 MainThread enip.cli INFO next EtherNet/IP--> 10.10.135.120:44818 rcvd 28: b'e\x00\x04\x00\x01\x00?\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00' 07-25 09:46:53.515 MainThread cpppo INFO terminate ( header.( command.((byte)) : => enip.command = 101 (format b'<H' over array('B', [101, 0])) 07-25 09:46:53.519 MainThread cpppo INFO terminate ( header.( command.((byte)) : => enip.length = 4 (format b'<H' over array('B', [4, 0])) 07-25 09:46:53.524 MainThread cpppo INFO terminate ( header.( command.((byte)) : => enip.session_handle = 4128769 (format b'<I' over array('B', [1, 0, 63, 0])) 07-25 09:46:53.529 MainThread cpppo INFO terminate ( header.( command.((byte)) : => enip.status = 0 (format b'<I' over array('B', [0, 0, 0, 0])) 07-25 09:46:53.537 MainThread cpppo INFO terminate ( header.( command.((byte)) : => enip.options = 0 (format b'<I' over array('B', [0, 0, 0, 0])) 07-25 09:46:53.542 MainThread enip.cli INFO next EtherNet/IP 10.10.135.120:44818 done: ((enip.((payload.((byte))) -> ((payload.; next byte 28: None : {'peer': ('10.10.135.120', 44818), 'enip': {'status': 0, 'sender_context': {'input': array('B', [0, 0, 0, 0, 0, 0, 0, 0])}, 'session_handle': 4128769, 'length': 4, 'command': 101, 'input': array('B', [1, 0, 0, 0]), 'options': 0}} 07-25 09:46:53.546 MainThread cpppo INFO run ( register.( protocol_version.((byte)) -- limit='enip.CIP.register...length' == 4; ending at symbol 4 vs. None 07-25 09:46:53.551 MainThread cpppo INFO terminate ( register.( protocol_version.((byte)) : => enip.CIP.register.protocol_version = 1 (format b'<H' over array('B', [1, 0])) 07-25 09:46:53.555 MainThread cpppo INFO terminate ( register.( protocol_version.((byte)) : => enip.CIP.register.options = 0 (format b'<H' over array('B', [0, 0])) 07-25 09:46:53.558 MainThread enip.cli INFO next Returning result: {'peer': ('10.10.135.120', 44818), 'enip': {'status': 0, 'sender_context': {'input': array('B', [0, 0, 0, 0, 0, 0, 0, 0])}, 'session_handle': 4128769, 'length': 4, 'CIP': {'register': {'protocol_version': 1, 'options': 0}}, 'command': 101, 'input': array('B', [1, 0, 0, 0]), 'options': 0}} 07-25 09:46:53.561 MainThread enip.cli NORMAL init Connect: Success in 0.450s/ 5.000s 07-25 09:46:53.563 MainThread enip.cli DETAIL main Client Register Rcvd 0.452/ 5.000s 07-25 09:46:53.565 MainThread enip.cli DETAIL parse_oper Tag: '@{"symbolic":"CIP1_Data_Log_Text"}/{"element":0}/{"symbolic":"DATA"}/{"element":82}' yields Operation: {'path': [{'symbolic': 'CIP1_Data_Log_Text'}, {'element': 0}, {'symbolic': 'DATA'}, {'element': 82}]}.update({'route_path': None, 'send_path': None}) 07-25 09:46:53.575 MainThread enip.cli DETAIL cip_send Client CIP Send: { "enip.status": 0, "enip.sender_context.input": "bytearray(b'0\x00\x00\x00\x00\x00\x00\x00')", "enip.session_handle": 4128769, "enip.CIP.send_data.interface": 0, "enip.CIP.send_data.CPF.item[0].type_id": 0, "enip.CIP.send_data.CPF.item[1].unconnected_send.status": 0, "enip.CIP.send_data.CPF.item[1].unconnected_send.route_path.segment[0].link": 0, "enip.CIP.send_data.CPF.item[1].unconnected_send.route_path.segment[0].port": 1, "enip.CIP.send_data.CPF.item[1].unconnected_send.service": 82, "enip.CIP.send_data.CPF.item[1].unconnected_send.timeout_ticks": 157, "enip.CIP.send_data.CPF.item[1].unconnected_send.request.path.segment[0].symbolic": "CIP1_Data_Log_Text", "enip.CIP.send_data.CPF.item[1].unconnected_send.request.path.segment[1].element": 0, "enip.CIP.send_data.CPF.item[1].unconnected_send.request.path.segment[2].symbolic": "DATA", "enip.CIP.send_data.CPF.item[1].unconnected_send.request.path.segment[3].element": 82, "enip.CIP.send_data.CPF.item[1].unconnected_send.request.read_tag.elements": 1, "enip.CIP.send_data.CPF.item[1].unconnected_send.request.service": 76, "enip.CIP.send_data.CPF.item[1].unconnected_send.request.input": "bytearray(b'L\x0f\x91\x12CIP1_Data_Log_Text(\x00\x91\x04DATA(R\x01\x00')", "enip.CIP.send_data.CPF.item[1].unconnected_send.priority": 5, "enip.CIP.send_data.CPF.item[1].unconnected_send.path.segment[0].class": 6, "enip.CIP.send_data.CPF.item[1].unconnected_send.path.segment[1].instance": 1, "enip.CIP.send_data.CPF.item[1].type_id": 178, "enip.CIP.send_data.timeout": 0, "enip.options": 0 } 07-25 09:46:53.585 MainThread enip.cli INFO cip_send EtherNet/IP: 24 + CIP: 64 == 88 bytes total 07-25 09:46:53.588 MainThread enip.cli INFO send EtherNet/IP--> 10.10.135.120:44818 send 88: b'o\x00@\x00\x01\x00?\x00\x00\x00\x00\x000\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x02\x00\x00\x00\x00\x00\xb2\x000\x00R\x02 \x06$\x01\x05\x9d"\x00L\x0f\x91\x12CIP1_Data_Log_Text(\x00\x91\x04DATA(R\x01\x00\x01\x00\x01\x00' 07-25 09:46:53.590 MainThread enip.cli DETAIL format_pat Formatted CIP1_Data_Log_Text.DATA[82] from: [{'symbolic': 'CIP1_Data_Log_Text'}, {'element': 0}, {'symbolic': 'DATA'}, {'element': 82}] 07-25 09:46:53.593 MainThread enip.cli DETAIL issue Sent 0.021/ 5.000s: Single Read Tag CIP1_Data_Log_Text.DATA[82] { "path.segment[0].symbolic": "CIP1_Data_Log_Text", "path.segment[1].element": 0, "path.segment[2].symbolic": "DATA", "path.segment[3].element": 82, "read_tag.elements": 1, "service": 76, "input": "bytearray(b'L\x0f\x91\x12CIP1_Data_Log_Text(\x00\x91\x04DATA(R\x01\x00')" } 07-25 09:46:53.599 MainThread enip.cli DETAIL issue Sending 1 (Context b'0') 07-25 09:46:53.601 MainThread enip.cli DETAIL pipeline Issuing 0/ 1; curr: 0 - last: -1 == 1 depth 07-25 09:46:53.603 MainThread enip.cli INFO next EtherNet/IP--> 10.10.135.120:44818 rcvd 44: b'o\x00\x14\x00\x01\x00?\x00\x00\x00\x00\x000\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x02\x00\x00\x00\x00\x00\xb2\x00\x04\x00\xcc\x00\x05\x00' 07-25 09:46:53.608 MainThread cpppo INFO terminate ( header.( command.((byte)) : => enip.command = 111 (format b'<H' over array('B', [111, 0])) 07-25 09:46:53.612 MainThread cpppo INFO terminate ( header.( command.((byte)) : => enip.length = 20 (format b'<H' over array('B', [20, 0])) 07-25 09:46:53.616 MainThread cpppo INFO terminate ( header.( command.((byte)) : => enip.session_handle = 4128769 (format b'<I' over array('B', [1, 0, 63, 0])) 07-25 09:46:53.621 MainThread cpppo INFO terminate ( header.( command.((byte)) : => enip.status = 0 (format b'<I' over array('B', [0, 0, 0, 0])) 07-25 09:46:53.629 MainThread cpppo INFO terminate ( header.( command.((byte)) : => enip.options = 0 (format b'<I' over array('B', [0, 0, 0, 0])) 07-25 09:46:53.639 MainThread enip.cli INFO next EtherNet/IP 10.10.135.120:44818 done: ((enip.((payload.((byte))) -> ((payload.; next byte 72: None : {'peer': ('10.10.135.120', 44818), 'enip': {'status': 0, 'sender_context': {'input': array('B', [48, 0, 0, 0, 0, 0, 0, 0])}, 'session_handle': 4128769, 'length': 20, 'command': 111, 'input': array('B', [0, 0, 0, 0, 0, 0, 2, 0, 0, 0, 0, 0, 178, 0, 4, 0, 204, 0, 5, 0]), 'options': 0}} 07-25 09:46:53.644 MainThread cpppo INFO run ( send_data.( interface.((byte)) -- limit='enip.CIP.send_data...length' == 20; ending at symbol 20 vs. None 07-25 09:46:53.649 MainThread cpppo INFO terminate ( send_data.( interface.((byte)) : => enip.CIP.send_data.interface = 0 (format b'<I' over array('B', [0, 0, 0, 0])) 07-25 09:46:53.654 MainThread cpppo INFO terminate ( send_data.( interface.((byte)) : => enip.CIP.send_data.timeout = 0 (format b'<H' over array('B', [0, 0])) 07-25 09:46:53.660 MainThread cpppo INFO terminate ( CPF.( count.((byte)) : => enip.CIP.send_data.CPF.count = 2 (format b'<H' over array('B', [2, 0])) 07-25 09:46:53.666 MainThread cpppo INFO terminate ( each.( type_id.((byte)) : => enip.CIP.send_data.CPF.item.type_id = 0 (format b'<H' over array('B', [0, 0])) 07-25 09:46:53.670 MainThread cpppo INFO terminate ( each.( type_id.((byte)) : => enip.CIP.send_data.CPF.item.length = 0 (format b'<H' over array('B', [0, 0])) 07-25 09:46:53.677 MainThread cpppo INFO terminate ( each.( type_id.((byte)) : => enip.CIP.send_data.CPF.item.type_id = 178 (format b'<H' over array('B', [178, 0])) 07-25 09:46:53.682 MainThread cpppo INFO terminate ( each.( type_id.((byte)) : => enip.CIP.send_data.CPF.item.length = 4 (format b'<H' over array('B', [4, 0])) 07-25 09:46:53.686 MainThread cpppo INFO run ( unconnected_send.( select.((noop)) -- limit='enip.CIP.send_data.CPF.item__.unconnected_send..length' == 4; ending at symbol 20 vs. 20 07-25 09:46:53.697 MainThread cpppo INFO terminate ( read_tag.( service.((byte)) : => service = 204 (format b'B' over array('B', [204])) 07-25 09:46:53.702 MainThread cpppo INFO terminate ( status.( status.((byte)) : => status = 5 (format b'B' over array('B', [5])) 07-25 09:46:53.705 MainThread cpppo INFO terminate ( status.( status.((byte)) : => status_ext.size = 0 (format b'B' over array('B', [0])) 07-25 09:46:53.710 MainThread enip.cli INFO next Returning result: {'peer': ('10.10.135.120', 44818), 'enip': {'status': 0, 'sender_context': {'input': array('B', [48, 0, 0, 0, 0, 0, 0, 0])}, 'session_handle': 4128769, 'length': 20, 'CIP': {'send_data': {'interface': 0, 'CPF': {'count': 2, 'item': [{'length': 0, 'type_id': 0}, {'length': 4, 'unconnected_send': {'request': {'status': 5, 'input': array('B', [204, 0, 5, 0]), 'status_ext': {'size': 0}, 'read_tag': True, 'service': 204}}, 'type_id': 178}]}, 'timeout': 0}}, 'command': 111, 'input': array('B', [0, 0, 0, 0, 0, 0, 2, 0, 0, 0, 0, 0, 178, 0, 4, 0, 204, 0, 5, 0]), 'options': 0}} 07-25 09:46:53.744 MainThread enip.cli DETAIL collect Rcvd 0.110/ 5.000s { "peer": [ "10.10.135.120", 44818 ], "enip.status": 0, "enip.sender_context.input": "array('B', [48, 0, 0, 0, 0, 0, 0, 0])", "enip.session_handle": 4128769, "enip.length": 20, "enip.CIP.send_data.interface": 0, "enip.CIP.send_data.CPF.count": 2, "enip.CIP.send_data.CPF.item[0].length": 0, "enip.CIP.send_data.CPF.item[0].type_id": 0, "enip.CIP.send_data.CPF.item[1].length": 4, "enip.CIP.send_data.CPF.item[1].unconnected_send.request.status": 5, "enip.CIP.send_data.CPF.item[1].unconnected_send.request.input": "array('B', [204, 0, 5, 0])", "enip.CIP.send_data.CPF.item[1].unconnected_send.request.status_ext.size": 0, "enip.CIP.send_data.CPF.item[1].unconnected_send.request.read_tag": true, "enip.CIP.send_data.CPF.item[1].unconnected_send.request.service": 204, "enip.CIP.send_data.CPF.item[1].type_id": 178, "enip.CIP.send_data.timeout": 0, "enip.command": 111, "enip.input": "array('B', [0, 0, 0, 0, 0, 0, 2, 0, 0, 0, 0, 0, 178, 0, 4, 0, 204, 0, 5, 0])", "enip.options": 0 } 07-25 09:46:53.752 MainThread enip.cli DETAIL collect Receive 1 (Context b'0') 07-25 09:46:53.754 MainThread enip.cli DETAIL pipeline Completed 1/ 1; curr: 0 - last: 0 == 0 depth 07-25 09:46:53.757 MainThread enip.cli DETAIL validate Client Single Read Tag CIP1_Data_Log_Text.DATA[82] Request: { "path.segment[0].symbolic": "CIP1_Data_Log_Text", "path.segment[1].element": 0, "path.segment[2].symbolic": "DATA", "path.segment[3].element": 82, "read_tag.elements": 1, "service": 76, "input": "bytearray(b'L\x0f\x91\x12CIP1_Data_Log_Text(\x00\x91\x04DATA(R\x01\x00')" } 07-25 09:46:53.763 MainThread enip.cli DETAIL validate Yields Reply: { "status": 5, "input": "array('B', [204, 0, 5, 0])", "status_ext.size": 0, "read_tag": true, "service": 204 } 07-25 09:46:53.768 MainThread enip.cli DETAIL format_pat Formatted CIP1_Data_Log_Text.DATA[82] from: [{'symbolic': 'CIP1_Data_Log_Text'}, {'element': 0}, {'symbolic': 'DATA'}, {'element': 82}] 07-25 09:46:53.771 MainThread enip.cli WARNING validate Client Single Read Tag CIP1_Data_Log_Text.DATA[82] returned non-zero status: Status 5 07-25 09:46:53.772 MainThread enip.cli NORMAL validate CIP1_Data_Log_Text.DATA[82][ 82-82 ]+ 0 == None: 'Status 5 ' CIP1_Data_Log_Text.DATA[82][ 82-82 ]+ 0 == None: 'Status 5 ' 07-25 09:46:53.775 MainThread enip.cli DETAIL pipeline Pipelined 1/ 1; curr: 0 - last: 0 == 0 depth 07-25 09:46:53.777 MainThread enip.cli NORMAL main Client Tag I/O Average 4.705 TPS ( 0.213s ea). Here as you can see, the output I'm getting is None and Status is 5. Can you please help me solving this issue?

iodizedfate commented 6 years ago

I was having the same issue as you and found this work around.

Instead of CIP1_Data_Log_Text[0].DATA/82 try and use CIP1_Data_Log_Text[0].DATA[0]*82 where instead of 82 use the number that is presented when you call CIP1_Data_Log_Text[0].LEN. This should capture what you're looking for in an array of ASCII values of your string. I don't know how this will help in the command line portion of this but if you are using a script, then all you have to do is assign it to a variable and then use 

desired_string = ''.join(chr(i) for i in value)

where value is the variable holding the ASCII array and desired_string is the output you're looking for.

nisargpandyadattus commented 6 years ago

@iodizedfate Thanks..I tried this and it seems working..