Closed johanfforsberg closed 9 years ago
Hi, Johan;
Thanks for the report! Perhaps hit the client with a couple or three -v
options to increase the debugging details for me...
The output will be big so of you can capture it in a file that will
probably be best.
On Tuesday, November 11, 2014, Johan Forsberg notifications@github.com wrote:
Hi,
this looks like a nice project and I started looking into whether it might be useful for writing tests for an EtherIP communication project we have. We're using a C EtherIP library from http://ics-web.sns.ornl.gov/kasemir/etherip/ and it's working fine for communicating with our Allen-Bradley PLCs.
However, I have trouble getting that library to talk to the cpppo test server and I'm wondering if this should even be expected to work. This is what I'm doing:
Starting the test server:
python -m cpppo.server.enip --print SCADA=INT[1]
and then I run the test program included with the EtherIP library:
./ether_ip_test -v 10 -i 127.0.0.1 -p 44818 SCADA
The result is "No response" and the server prints out the following traceback:
11-11 15:36:36.861 7f610f4ef700 enip.lgx ERROR process EtherNet/IP CIP error at 0 total bytes: '' -^ (byte 0)
11-11 15:36:36.861 7f610f4ef700 enip.srv ERROR enip_srv Failed request: { "request.addr": [ "127.0.0.1", 59815 ], "request.enip.command": 4, "request.enip.length": 0, "request.enip.options": 0, "request.enip.sender_context.input": "array('c', 'Funstuff')", "request.enip.session_handle": 0, "request.enip.status": 0 } 11-11 15:36:36.862 7f610f4ef700 enip.srv ERROR enip_srv EtherNet/IP error at 24 total bytes: '\x04\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00Funstuff\x00\x00\x00\x00' -------------------------------------------------------------------------^ (byte 24)
Failed with exception: Traceback (most recent call last): File "/home/johfor/.local/lib/python2.7/site-packages/cpppo/server/enip/main.py", line 664, in enip_srv if enip_process( addr, data=data, kwds ): File "/home/johfor/.local/lib/python2.7/site-packages/cpppo/server/enip/logix.py", line 681, in process source.chain( data.request.enip.input ) File "/home/johfor/.local/lib/python2.7/site-packages/cpppo/dotdict.py", line 201, in getattr** raise AttributeError( str( exc )) AttributeError: 'input'
11-11 15:36:36.863 7f610f4ef700 network WARNING run enip_srv server failure: 'input' Traceback (most recent call last): File "/home/johfor/.local/lib/python2.7/site-packages/cpppo/server/network.py", line 131, in run super( server_thread, self ).run() File "/usr/lib/python2.7/threading.py", line 763, in run self.*target(_self.__args, _self.kwargs) File "/home/johfor/.local/lib/python2.7/site-packages/cpppo/server/enip/main.py", line 664, in enip_srv if enip_process( addr, data=data, **kwds ): File "/home/johfor/.local/lib/python2.7/site-packages/cpppo/server/enip/logix.py", line 681, in process source.chain( data.request.enip.input ) File "/home/johfor/.local/lib/python2.7/site-packages/cpppo/dotdict.py", line 201, in getattr** raise AttributeError( str( exc )) AttributeError: 'input'
— Reply to this email directly or view it on GitHub https://github.com/pjkundert/cpppo/issues/1.
-pjk
Ah, that was fast! :)
I did the exact same test with more verbosity and it wasn't horribly huge so I'm pasting it anyway. Here you go:
$ python -m cpppo.server.enip -vvv --print SCADA=INT[1]
11-11 15:58:52.491 7f186a96f740 enip.srv NORMAL main Delaying all responses by 0.0 seconds
11-11 15:58:52.491 7f186a96f740 enip.srv NORMAL main Creating tag: SCADA=INT[1]
11-11 15:58:52.492 7f186a96f740 root NORMAL main EtherNet/IP Simulator: ('0.0.0.0', 44818)
11-11 15:58:52.492 7f186a96f740 network NORMAL server_mai enip_srv server PID [23078] running on ('0.0.0.0', 44818)
11-11 15:58:52.492 7f186a96f740 network NORMAL server_mai enip_srv server PID [23078] responding to external done/disable signal
11-11 15:58:55.192 7f1868043700 network INFO run enip_srv server TID [23078/139742801049344] starting on ('127.0.0.1', 59900)
11-11 15:58:55.193 7f1868043700 enip.srv NORMAL enip_srv EtherNet/IP Server enip_59900 begins serving peer ('127.0.0.1', 59900)
11-11 15:58:55.194 7f1868043700 enip.srv DETAIL enip_srv Transaction begins
11-11 15:58:55.194 7f1868043700 cpppo INFO transition ((empty)) <non trans>
11-11 15:58:55.195 7f1868043700 enip.srv DETAIL enip_srv Transaction receive after 0.001s ( 24 bytes in 0.000/ 0.100s)
11-11 15:58:55.195 7f1868043700 enip.srv DETAIL enip_srv ( enip_59900.( header.((empty)) recv: 24: '\x04\x00\x00...0\x00\x00\x00'
11-11 15:58:55.196 7f1868043700 cpppo INFO terminate ( header.( command.((byte)) : => request.enip.command = 4 (format '<H' over array('c', '\x04\x00'))
11-11 15:58:55.196 7f1868043700 cpppo INFO terminate ( header.( command.((byte)) : => request.enip.length = 0 (format '<H' over array('c', '\x00\x00'))
11-11 15:58:55.197 7f1868043700 cpppo INFO terminate ( header.( command.((byte)) : => request.enip.session_handle = 0 (format '<I' over array('c', '\x00\x00\x00\x00'))
11-11 15:58:55.198 7f1868043700 cpppo INFO terminate ( header.( command.((byte)) : => request.enip.status = 0 (format '<I' over array('c', '\x00\x00\x00\x00'))
11-11 15:58:55.199 7f1868043700 cpppo INFO terminate ( header.( command.((byte)) : => request.enip.options = 0 (format '<I' over array('c', '\x00\x00\x00\x00'))
11-11 15:58:55.200 7f1868043700 enip.srv DETAIL enip_srv Transaction parsed after 0.006s
11-11 15:58:55.200 7f1868043700 enip.dev DETAIL __init__ Identity, Class ID 0x0001, Instance ID 1 created
11-11 15:58:55.200 7f1868043700 enip.dev DETAIL lookup Class 1/0x0001, Instance 1, Attribute None ==> None
11-11 15:58:55.200 7f1868043700 enip.dev DETAIL lookup Class 1/0x0001, Instance 0, Attribute None ==> None
11-11 15:58:55.201 7f1868043700 enip.dev INFO __init__ meta-Identity, Class ID 0x0001, Instance ID 0 created
11-11 15:58:55.201 7f1868043700 enip.dev DETAIL lookup Class 1/0x0001, Instance 0, Attribute None ==> None
11-11 15:58:55.201 7f1868043700 enip.dev DETAIL lookup Class 1/0x0001, Instance 0, Attribute None ==> meta-Identity
11-11 15:58:55.203 7f1868043700 enip.dev DETAIL __init__ Logix, Class ID 0x0002, Instance ID 1 created
11-11 15:58:55.203 7f1868043700 enip.dev DETAIL lookup Class 2/0x0002, Instance 1, Attribute None ==> None
11-11 15:58:55.204 7f1868043700 enip.dev DETAIL lookup Class 2/0x0002, Instance 0, Attribute None ==> None
11-11 15:58:55.204 7f1868043700 enip.dev INFO __init__ meta-Logix, Class ID 0x0002, Instance ID 0 created
11-11 15:58:55.204 7f1868043700 enip.dev DETAIL lookup Class 2/0x0002, Instance 0, Attribute None ==> None
11-11 15:58:55.204 7f1868043700 enip.dev DETAIL lookup Class 2/0x0002, Instance 0, Attribute None ==> meta-Logix
11-11 15:58:55.205 7f1868043700 enip.dev DETAIL __init__ Connection_Manager, Class ID 0x0006, Instance ID 1 created
11-11 15:58:55.205 7f1868043700 enip.dev DETAIL lookup Class 6/0x0006, Instance 1, Attribute None ==> None
11-11 15:58:55.205 7f1868043700 enip.dev DETAIL lookup Class 6/0x0006, Instance 0, Attribute None ==> None
11-11 15:58:55.205 7f1868043700 enip.dev INFO __init__ meta-Connection_Manager, Class ID 0x0006, Instance ID 0 created
11-11 15:58:55.205 7f1868043700 enip.dev DETAIL lookup Class 6/0x0006, Instance 0, Attribute None ==> None
11-11 15:58:55.205 7f1868043700 enip.dev DETAIL lookup Class 6/0x0006, Instance 0, Attribute None ==> meta-Connection_Manager
11-11 15:58:55.206 7f1868043700 enip.dev DETAIL __init__ Unknown_Object, Class ID 0x0066, Instance ID 1 created
11-11 15:58:55.206 7f1868043700 enip.dev DETAIL lookup Class 102/0x0066, Instance 1, Attribute None ==> None
11-11 15:58:55.206 7f1868043700 enip.dev DETAIL lookup Class 102/0x0066, Instance 0, Attribute None ==> None
11-11 15:58:55.206 7f1868043700 enip.dev INFO __init__ meta-Unknown_Object, Class ID 0x0066, Instance ID 0 created
11-11 15:58:55.207 7f1868043700 enip.dev DETAIL lookup Class 102/0x0066, Instance 0, Attribute None ==> None
11-11 15:58:55.207 7f1868043700 enip.dev DETAIL lookup Class 102/0x0066, Instance 0, Attribute None ==> meta-Unknown_Object
11-11 15:58:55.207 7f1868043700 enip.dev DETAIL __init__ UCMM, Class ID 0x9999, Instance ID 1 created
11-11 15:58:55.208 7f1868043700 enip.dev DETAIL lookup Class 39321/0x9999, Instance 1, Attribute None ==> None
11-11 15:58:55.208 7f1868043700 enip.dev DETAIL lookup Class 39321/0x9999, Instance 0, Attribute None ==> None
11-11 15:58:55.208 7f1868043700 enip.dev INFO __init__ meta-UCMM, Class ID 0x9999, Instance ID 0 created
11-11 15:58:55.208 7f1868043700 enip.dev DETAIL lookup Class 39321/0x9999, Instance 0, Attribute None ==> None
11-11 15:58:55.208 7f1868043700 enip.dev DETAIL lookup Class 39321/0x9999, Instance 0, Attribute None ==> meta-UCMM
11-11 15:58:55.208 7f1868043700 enip.lgx DETAIL process EtherNet/IP CIP Request (Client ('127.0.0.1', 59900)): setup tag: ('SCADA', {'attribute': SCADA INT[ 1] == 0, 'error': 0})
11-11 15:58:55.208 7f1868043700 enip.dev DETAIL lookup Class 2/0x0002, Instance 1, Attribute None ==> Logix
11-11 15:58:55.208 7f1868043700 enip.lgx NORMAL process Logix.SCADA INT[ 1] == 0 Attribute 1 added
11-11 15:58:55.208 7f1868043700 enip.dev DETAIL lookup Class 2/0x0002, Instance 1, Attribute 1 ==> SCADA INT[ 1] == 0
11-11 15:58:55.209 7f1868043700 enip.lgx ERROR process EtherNet/IP CIP error at 0 total bytes:
''
-^ (byte 0)
11-11 15:58:55.209 7f1868043700 enip.srv ERROR enip_srv Failed request: {
"request.addr": [
"127.0.0.1",
59900
],
"request.enip.command": 4,
"request.enip.length": 0,
"request.enip.options": 0,
"request.enip.sender_context.input": "array('c', 'Funstuff')",
"request.enip.session_handle": 0,
"request.enip.status": 0
}
11-11 15:58:55.209 7f1868043700 enip.lgx DETAIL process EtherNet/IP CIP Request (Client ('127.0.0.1', 59900)): {
"addr": [
"127.0.0.1",
59900
]
}
11-11 15:58:55.209 7f1868043700 enip.dev INFO request (0x9999, 1) UCMM Request: {
"addr": [
"127.0.0.1",
59900
]
}
11-11 15:58:55.209 7f1868043700 enip.dev DETAIL request EtherNet/IP (Client ('127.0.0.1', 59900)) Session Terminated: '(Unknown)'
11-11 15:58:55.209 7f1868043700 enip.dev INFO request UCMM Response: {
"addr": [
"127.0.0.1",
59900
]
}
11-11 15:58:55.209 7f1868043700 enip.lgx DETAIL process EtherNet/IP CIP Response (Client ('127.0.0.1', 59900)): {
"addr": [
"127.0.0.1",
59900
]
}
11-11 15:58:55.210 7f1868043700 enip.srv ERROR enip_srv EtherNet/IP error at 24 total bytes:
'\x04\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00Funstuff\x00\x00\x00\x00'
-------------------------------------------------------------------------^ (byte 24)
Failed with exception:
Traceback (most recent call last):
File "/home/johfor/.local/lib/python2.7/site-packages/cpppo/server/enip/main.py", line 664, in enip_srv
if enip_process( addr, data=data, **kwds ):
File "/home/johfor/.local/lib/python2.7/site-packages/cpppo/server/enip/logix.py", line 681, in process
source.chain( data.request.enip.input )
File "/home/johfor/.local/lib/python2.7/site-packages/cpppo/dotdict.py", line 201, in __getattr__
raise AttributeError( str( exc ))
AttributeError: 'input'
11-11 15:58:55.210 7f1868043700 enip.srv NORMAL enip_srv enip_59900 done; processed 1 request over 24 bytes/ 24 received (0 connections remain)
11-11 15:58:55.211 7f1868043700 network WARNING run enip_srv server failure: 'input'
Traceback (most recent call last):
File "/home/johfor/.local/lib/python2.7/site-packages/cpppo/server/network.py", line 131, in run
super( server_thread, self ).run()
File "/usr/lib/python2.7/threading.py", line 763, in run
self.__target(*self.__args, **self.__kwargs)
File "/home/johfor/.local/lib/python2.7/site-packages/cpppo/server/enip/main.py", line 664, in enip_srv
if enip_process( addr, data=data, **kwds ):
File "/home/johfor/.local/lib/python2.7/site-packages/cpppo/server/enip/logix.py", line 681, in process
source.chain( data.request.enip.input )
File "/home/johfor/.local/lib/python2.7/site-packages/cpppo/dotdict.py", line 201, in __getattr__
raise AttributeError( str( exc ))
AttributeError: 'input'
11-11 15:58:55.211 7f1868043700 network INFO run enip_srv server TID [23078/139742801049344] stopping on ('127.0.0.1', 59900)
11-11 15:58:55.293 7f186a96f740 network INFO join enip_srv server TID [23078/139742801049344] complete on ('127.0.0.1', 59900)
In case it tells you anything, I also ran the EtherIP test program with max verbosity:
$ ./ether_ip_test -v 10 -i 127.0.0.1 -p 44818 SCADA
Tag 'SCADA'
EIP connectWithTimeout(127.0.0.1:0xAF12, 5 sec, 0 msec)
EIP connected to 127.0.0.1:0xAF12 on socket 3
EIP sending ListServices encapsulation command
EncapsulationHeader:
UINT command = 0x04 (ListServices)
UINT length = 0
UDINT session = 0x00000000
UDINT status = 0x00000000 (OK)
USINT context[8]= 'Funstuff'
UDINT options = 0x00000000
Data sent (24 bytes):
00000000 04 00 00 00 00 00 00 00 00 00 00 00 46 75 6E 73 - ............Funs
00000010 74 75 66 66 00 00 00 00 - tuff....
EIP end-of-data after receiving 0 bytes
Data Received (0 bytes):
EIP list_services: No response
EIP_startup: target 127.0.0.1 does not respond
EIP disconnecting socket 3
EIP sending UnRegisterSession encapsulation command, session ID 0x00000000
EncapsulationHeader:
UINT command = 0x66 (UnRegisterSession)
UINT length = 0
UDINT session = 0x00000000
UDINT status = 0x00000000 (OK)
USINT context[8]= 'Funstuff'
UDINT options = 0x00000000
Data sent (24 bytes):
00000000 66 00 00 00 00 00 00 00 00 00 00 00 46 75 6E 73 - f...........Funs
00000010 74 75 66 66 00 00 00 00 - tuff....
EIP disconnecting socket 0
connect1 test runs, 0.0209179 seconds -> 20.917892 ms / tag
The ListServices (EtherNet/IP service 0x04) request has not yet been implemented. Up to this point, we've been using cpppo's EtherNet/IP CIP functionality with industrial scanning software that doesn't require this service. I am implementing it now...
Sounds great! It would be pretty cool if we could use cpppo for the client too, as it's a bit of a pain to build the C library and develop a python binding for it.
I'd be happy to provide more information or testing.
I have implemented ListServices in version 3.3.0; these tests now pass. Thanks so much for the report! Let me know if you see anything else, or if you need a hand integrating your solution.
Hi,
this looks like a nice project and I started looking into whether it might be useful for writing tests for an EtherIP communication project we have. We're using a C EtherIP library from http://ics-web.sns.ornl.gov/kasemir/etherip/ and it's working fine for communicating with our Allen-Bradley PLCs.
However, I have trouble getting that library to talk to the cpppo test server and I'm wondering if this should even be expected to work. This is what I'm doing:
Starting the test server:
and then I run the test program included with the EtherIP library:
The result is "No response" and the server prints out the following traceback: