RTU client server communication

From Phobos Wiki
Jump to: navigation, search

MarkTomm 25. september 2017, kell 16:05 (EEST)

Connections

The IEC 104 TCP was documented on 25.09.2017 when there was an issue with connection. GWM iec 104 server closed the connection every ~20 seconds because it was 101-to-104 with GWMIO and GWMIO was disconnected.

IEC 104 TCP

Client log when server disconnects

2017-09-25 15:48:44.975 [INFO] Gateway.Port16.port - Close connection, connection reset by peer
2017-09-25 15:48:44.977 [DEBUG] Gateway.Port16.link - CommunicationBad
2017-09-25 15:48:44.977 [ERROR] Gateway.Port16.port - Request disconnect, no connection
2017-09-25 15:48:44.977 [ERROR] Gateway.Port16 - Timeout, suppressing following timeout messages!
2017-09-25 15:48:44.997 [DEBUG] Gateway.Port16 - StatusDi: no connection
2017-09-25 15:48:45.000 [ERROR] Gateway.Port16 - Remove from polling
2017-09-25 15:48:45.000 [INFO] Gateway.Port16 - Reset communication

Client log when it connects

2017-09-25 15:48:45.980 [INFO] Gateway.Port16.port - Connecting to 10.0.0.173:2404
2017-09-25 15:48:45.982 [INFO] Gateway.Port16.port - Connected to 10.0.0.173:2404
2017-09-25 15:48:45.982 [TRACE] Gateway.Port16.port - Clear communication buffers
2017-09-25 15:48:45.982 [DEBUG] Gateway.Port16 - Port open!
2017-09-25 15:48:45.982 [DEBUG] Gateway.Port16 - Retry/Establish communication
2017-09-25 15:48:45.983 [INFO] Gateway.Port16 - Enable polling
2017-09-25 15:48:45.983 [INFO] Gateway.Port16 - Reset communication done
2017-09-25 15:48:45.983 [TRACE] Gateway.Port16.port.link - Port connected
2017-09-25 15:48:46.003 [DEBUG] Gateway.Port16.port.write.link - UFormat: STARTDT_ACT
2017-09-25 15:48:46.009 [TRACE] Gateway.Port16.port.write -  68 04 07 00 00 00
2017-09-25 15:48:46.011 [TRACE] Gateway.Port16.port.read -  68 04 0B 00 00 00
2017-09-25 15:48:46.012 [DEBUG] Gateway.Port16.port.read.link - UFormat: STARTDT_CON
2017-09-25 15:48:46.012 [DEBUG] Gateway.Port16.link - CommunicationOk
2017-09-25 15:48:46.012 [TRACE] Gateway.Port16 - Status DI needs updating!
2017-09-25 15:48:46.012 [DEBUG] Gateway.Port16 - StatusDi: connected

Server log when it disconnects

2017-09-01 15:56:48.669 [DEBUG] Gateway.104port.link - CommunicationBad
2017-09-01 15:56:48.669 [ERROR] Gateway.104port.port - Request disconnect, subdevice removed from polling
2017-09-01 15:56:48.670 [INFO] Gateway.104port.port - Close connection, Force disconnect
2017-09-01 15:56:48.670 [ERROR] Gateway.104port - Timeout, suppressing following timeout messages!
2017-09-01 15:56:49.001 [DEBUG] Gateway.104port.db - Time cn (11) event: 57409 time: 2017-Sep-01 15:56:49.000063, buffered

Server log when client connects after reset

2017-09-01 16:09:40.069 [TRACE] Gateway.104port.port - Clear communication buffers
2017-09-01 16:09:40.070 [INFO] Gateway.104port.port - Incoming connection from 10.0.0.231 established.
2017-09-01 16:09:40.070 [TRACE] Gateway.104port.port.link - Port connected
2017-09-01 16:09:40.070 [DEBUG] Gateway.104port - Port open!
2017-09-01 16:09:40.070 [DEBUG] Gateway.104port - Retry/Establish communication
2017-09-01 16:09:40.070 [INFO] Gateway.104port - Enable polling
2017-09-01 16:09:40.070 [INFO] Gateway.104port - Reset communication
2017-09-01 16:09:40.071 [INFO] Gateway.104port - Reset communication done
2017-09-01 16:09:40.097 [TRACE] Gateway.104port.port.read -  68 04 07 00 00 00
2017-09-01 16:09:40.097 [DEBUG] Gateway.104port.port.read.link - UFormat: STARTDT_ACT
2017-09-01 16:09:40.098 [TRACE] Gateway.104port.link - Received U format message with "Start Data Transfer Activation" from master. Reissue "Port connected" to port buffer. This will clear buffers counters and timers.
2017-09-01 16:09:40.098 [TRACE] Gateway.104port.port.link - Port connected
2017-09-01 16:09:40.098 [DEBUG] Gateway.104port.port.write.link - UFormat: STARTDT_CON
2017-09-01 16:09:40.098 [DEBUG] Gateway.104port.link - CommunicationOk
2017-09-01 16:09:40.098 [DEBUG] Gateway.104port - StatusDi: connected
2017-09-01 16:09:40.098 [INFO] Gateway.104port - Connected
2017-09-01 16:09:40.098 [INFO] Gateway.104port - Refresh all values
2017-09-01 16:11:46.093 [TRACE] Gateway.104port.port.write -  68 04 0B 00 00 00

Server log when client reconnects after sudden disconnect

2017-09-01 15:56:49.675 [TRACE] Gateway.104port.port - Clear communication buffers
2017-09-01 15:56:49.676 [DEBUG] Gateway.104port - Port open!
2017-09-01 15:56:49.676 [DEBUG] Gateway.104port - Retry/Establish communication
2017-09-01 15:56:49.676 [INFO] Gateway.104port - Enable polling
2017-09-01 15:56:49.676 [INFO] Gateway.104port - Reset communication
2017-09-01 15:56:49.676 [INFO] Gateway.104port - Reset communication done
2017-09-01 15:56:49.676 [TRACE] Gateway.104port.port.link - Port connected
2017-09-01 15:56:49.677 [INFO] Gateway.104port.port - Incoming connection from 10.0.0.231 established.
2017-09-01 15:56:49.703 [TRACE] Gateway.104port.port.read -  68 04 07 00 00 00
2017-09-01 15:56:49.703 [DEBUG] Gateway.104port.port.read.link - UFormat: STARTDT_ACT
2017-09-01 15:56:49.703 [TRACE] Gateway.104port.link - Received U format message with "Start Data Transfer Activation" from master. Reissue "Port connected" to port buffer. This will clear buffers counters and timers.
2017-09-01 15:56:49.703 [TRACE] Gateway.104port.port.link - Port connected
2017-09-01 15:56:49.703 [DEBUG] Gateway.104port.port.write.link - UFormat: STARTDT_CON
2017-09-01 15:56:49.703 [DEBUG] Gateway.104port.link - CommunicationOk
2017-09-01 15:56:49.704 [DEBUG] Gateway.104port - StatusDi: connected
2017-09-01 15:56:49.704 [TRACE] Gateway.104port.port.write -  68 04 0B 00 00 00

Commands

IEC 101UB Serial

IEC 101UB Serial SCADA CMD (Select & Execute) to IEC 101UB IED

Port6 - IEC 101UB Scada

DO5T - IED which recv cmd

DI24T - other IED not used in this example

2017-09-26 16:15:28.120 [TRACE] telem-gw6e.Port6.port.read -  68 0A 0A 68 73 01 2D
2017-09-26 16:15:28.136 [TRACE] telem-gw6e.Port6.port.read -  01 06 01 00 C9 00 81 F3 16
2017-09-26 16:15:28.137 [TRACE] telem-gw6e.Port6.link - [IEC60870 101 UB Slave Link] RecvVarLenFrame CTRL_FCV(16) CTRL_FCB(32) CTRL_FN(3) LINK_ADDR(1) ADDR_LEN(1)
2017-09-26 16:15:28.137 [TRACE] telem-gw6e.Port6.link - [IEC60870 101 UB Slave Link] SendFixLenFrame CTRL_ACD(0) CTRL_FN(0) LINK_ADDR(1) ADDR_LEN(1)
2017-09-26 16:15:28.137 [INFO] telem-gw6e.Port6.db - DO1 (201) control: 2 flags: Select Command Activation  time: 2017-Sep-26 16:15:28.137173, recv
2017-09-26 16:15:28.137 [DEBUG] Gateway.Filter.Update - [DO_5_1_1_filter] DO_1_1_value = 2 flags: Select Activation Select Command Activation  time: 2017-Sep-26 13:15:28.137173
2017-09-26 16:15:28.137 [TRACE] Gateway.Filter.AddToBuffer - [DO_5_1_1_filter] DO_1_1_buf << 2 flags: Select Activation Confirmation Select Command Activation  time: 2017-Sep-26 13:15:28.137173
2017-09-26 16:15:28.137 [DEBUG] telem-gw6e.Port5.DO5T.db - DO1 (1) event: 2 flags: Select Command Activation  time: 2017-Sep-26 16:15:28.137173, buffered
2017-09-26 16:15:28.241 [TRACE] telem-gw6e.Port5.DI24T.link - [IEC60870 101 UB Master Link] SendFixedFrame CTRL_FCV(1) CTRL_FCB(0) CTRL_FN(CTRL_REQUEST_CLASS_2 - 11) LINK_ADDR(1) ADDR_LEN(1)
2017-09-26 16:15:28.241 [TRACE] telem-gw6e.Port5.port.write -  10 5B 01 5C 16
2017-09-26 16:15:28.258 [TRACE] telem-gw6e.Port5.port.read -  10 09 01
2017-09-26 16:15:28.274 [TRACE] telem-gw6e.Port5.port.read -  0A 16
2017-09-26 16:15:28.274 [TRACE] telem-gw6e.Port5.DI24T.link - [IEC60870 101 UB Master Link] RecvFixLenFrame. CTRL_ACD(0) CTRL_FN(CTRL_NO_DATA - 9) LINK_ADDR(1) ADDR_LEN(1)
2017-09-26 16:15:28.274 [INFO] telem-gw6e.Port5.DO5T.db - DO1 (1) control: 2 flags: Select Command Activation  time: 2017-Sep-26 16:15:28.137173, sent
2017-09-26 16:15:28.274 [TRACE] IEC.setEvent - [Core -> Prot] (Input Events) add event EVENTCODE_DIGITAL_OUTPUT_COMMAND
2017-09-26 16:15:28.437 [TRACE] telem-gw6e.Port6.port.write -  10 00 01 01 16
2017-09-26 16:15:28.568 [TRACE] telem-gw6e.Port6.port.read -  10 5B 01 5C
2017-09-26 16:15:28.575 [TRACE] telem-gw6e.Port5.ControlStateLogger - register obj_id: 0 arg: 1
2017-09-26 16:15:28.575 [TRACE] telem-gw6e.Port5.ControlStateLogger - SELECT 1
2017-09-26 16:15:28.576 [TRACE] telem-gw6e.Port5.DO5T.link - [IEC60870 101 UB Master Link] SendVarLenFrame CTRL_FCV(1) CTRL_FCB(1) CTRL_FN(CTRL_USER_DATA - 3) LINK_ADDR(3) ADDR_LEN(1)
2017-09-26 16:15:28.576 [TRACE] telem-gw6e.Port5.port.write -  68 0A 0A 68 73 03 2E 01 06 03 00 01 00 82 31 16
2017-09-26 16:15:28.584 [TRACE] telem-gw6e.Port6.port.read -  16
2017-09-26 16:15:28.584 [TRACE] telem-gw6e.Port6 - [IEC60870 101 UB Data] class 2 data available: no
2017-09-26 16:15:28.584 [TRACE] telem-gw6e.Port6.link - [IEC60870 101 UB Slave Link] SendFixLenFrame CTRL_ACD(0) CTRL_FN(9) LINK_ADDR(1) ADDR_LEN(1)
2017-09-26 16:15:28.610 [TRACE] telem-gw6e.Port5.port.read -  10 20 03 23 16
2017-09-26 16:15:28.610 [TRACE] telem-gw6e.Port5.DO5T.link - [IEC60870 101 UB Master Link] RecvFixLenFrame. CTRL_ACD(1) CTRL_FN(CTRL_ACK - 0) LINK_ADDR(3) ADDR_LEN(1)
2017-09-26 16:15:28.884 [TRACE] telem-gw6e.Port6.port.write -  10 09 01 0A 16
2017-09-26 16:15:28.912 [TRACE] telem-gw6e.Port5.DI24T.link - [IEC60870 101 UB Master Link] SendFixedFrame CTRL_FCV(1) CTRL_FCB(1) CTRL_FN(CTRL_REQUEST_CLASS_2 - 11) LINK_ADDR(1) ADDR_LEN(1)
2017-09-26 16:15:28.912 [TRACE] telem-gw6e.Port5.port.write -  10 7B 01 7C 16
2017-09-26 16:15:28.930 [TRACE] telem-gw6e.Port5.port.read -  10 09 01 0A
2017-09-26 16:15:28.946 [TRACE] telem-gw6e.Port5.port.read -  16
2017-09-26 16:15:28.946 [TRACE] telem-gw6e.Port5.DI24T.link - [IEC60870 101 UB Master Link] RecvFixLenFrame. CTRL_ACD(0) CTRL_FN(CTRL_NO_DATA - 9) LINK_ADDR(1) ADDR_LEN(1)
2017-09-26 16:15:29.016 [TRACE] telem-gw6e.Port6.port.read -  68
2017-09-26 16:15:29.032 [TRACE] telem-gw6e.Port6.port.read -  0A 0A 68 73 01 2D 01 06 01 00 C9 00 01 73 16
2017-09-26 16:15:29.032 [TRACE] telem-gw6e.Port6.link - [IEC60870 101 UB Slave Link] RecvVarLenFrame CTRL_FCV(16) CTRL_FCB(32) CTRL_FN(3) LINK_ADDR(1) ADDR_LEN(1)
2017-09-26 16:15:29.032 [TRACE] telem-gw6e.Port6.link - [IEC60870 101 UB Slave Link] SendFixLenFrame CTRL_ACD(0) CTRL_FN(0) LINK_ADDR(1) ADDR_LEN(1)
2017-09-26 16:15:29.032 [INFO] telem-gw6e.Port6.db - DO1 (201) control: 2 flags: Activation  time: 2017-Sep-26 16:15:29.032667, recv
2017-09-26 16:15:29.032 [DEBUG] Gateway.Filter.Update - [DO_5_1_1_filter] DO_1_1_value = 2 flags: Execute Activation Activation  time: 2017-Sep-26 13:15:29.032667
2017-09-26 16:15:29.032 [TRACE] Gateway.Filter.AddToBuffer - [DO_5_1_1_filter] DO_1_1_buf << 2 flags: Execute Activation Confirmation Activation  time: 2017-Sep-26 13:15:29.032667
2017-09-26 16:15:29.032 [DEBUG] telem-gw6e.Port5.DO5T.db - DO1 (1) event: 2 flags: Activation  time: 2017-Sep-26 16:15:29.032667, buffered
2017-09-26 16:15:29.248 [INFO] telem-gw6e.Port5.DO5T.db - DO1 (1) control: 2 flags: Activation  time: 2017-Sep-26 16:15:29.032667, sent
2017-09-26 16:15:29.248 [TRACE] IEC.setEvent - [Core -> Prot] (Input Events) add event EVENTCODE_DIGITAL_OUTPUT_COMMAND
2017-09-26 16:15:29.250 [TRACE] telem-gw6e.Port5.ControlStateLogger - register obj_id: 0 arg: 1
2017-09-26 16:15:29.250 [TRACE] telem-gw6e.Port5.ControlStateLogger - ACTIVATION 1
2017-09-26 16:15:29.250 [TRACE] telem-gw6e.Port5.ControlStateLogger - register obj_id: 0 arg: 1
2017-09-26 16:15:29.250 [TRACE] telem-gw6e.Port5.ControlStateLogger - RESPONSE 1
2017-09-26 16:15:29.250 [TRACE] telem-gw6e.Port5.DO5T.link - [IEC60870 101 UB Master Link] SendVarLenFrame CTRL_FCV(1) CTRL_FCB(0) CTRL_FN(CTRL_USER_DATA - 3) LINK_ADDR(3) ADDR_LEN(1)
2017-09-26 16:15:29.250 [TRACE] telem-gw6e.Port5.port.write -  68 0A 0A 68 53 03 2E 01 06 03 00 01 00 02 91 16
2017-09-26 16:15:29.281 [TRACE] telem-gw6e.Port5.port.read -  10 20 03 23 16
2017-09-26 16:15:29.281 [TRACE] telem-gw6e.Port5.DO5T.link - [IEC60870 101 UB Master Link] RecvFixLenFrame. CTRL_ACD(1) CTRL_FN(CTRL_ACK - 0) LINK_ADDR(3) ADDR_LEN(1)
2017-09-26 16:15:29.332 [TRACE] telem-gw6e.Port6.port.write -  10 00 01 01 16
2017-09-26 16:15:29.448 [TRACE] telem-gw6e.Port6.port.read -  10 5B 01 5C 16
2017-09-26 16:15:29.448 [TRACE] telem-gw6e.Port6 - [IEC60870 101 UB Data] class 2 data available: no
2017-09-26 16:15:29.448 [TRACE] telem-gw6e.Port6.link - [IEC60870 101 UB Slave Link] SendFixLenFrame CTRL_ACD(0) CTRL_FN(9) LINK_ADDR(1) ADDR_LEN(1)
2017-09-26 16:15:29.584 [TRACE] telem-gw6e.Port5.DI24T.link - [IEC60870 101 UB Master Link] SendFixedFrame CTRL_FCV(1) CTRL_FCB(0) CTRL_FN(CTRL_REQUEST_CLASS_2 - 11) LINK_ADDR(1) ADDR_LEN(1)
2017-09-26 16:15:29.584 [TRACE] telem-gw6e.Port5.port.write -  10 5B 01 5C 16
2017-09-26 16:15:29.602 [TRACE] telem-gw6e.Port5.port.read -  10 09 01 0A
2017-09-26 16:15:29.618 [TRACE] telem-gw6e.Port5.port.read -  16
2017-09-26 16:15:29.618 [TRACE] telem-gw6e.Port5.DI24T.link - [IEC60870 101 UB Master Link] RecvFixLenFrame. CTRL_ACD(0) CTRL_FN(CTRL_NO_DATA - 9) LINK_ADDR(1) ADDR_LEN(1)
2017-09-26 16:15:29.748 [TRACE] telem-gw6e.Port6.port.write -  10 09 01 0A 16
2017-09-26 16:15:29.863 [TRACE] telem-gw6e.Port6.port.read -  10 7B 01 7C 16
2017-09-26 16:15:29.863 [TRACE] telem-gw6e.Port6 - [IEC60870 101 UB Data] class 2 data available: no
2017-09-26 16:15:29.863 [TRACE] telem-gw6e.Port6.link - [IEC60870 101 UB Slave Link] SendFixLenFrame CTRL_ACD(0) CTRL_FN(9) LINK_ADDR(1) ADDR_LEN(1)
2017-09-26 16:15:29.922 [TRACE] telem-gw6e.Port5.DO5T.link - [IEC60870 101 UB Master Link] SendFixedFrame CTRL_FCV(1) CTRL_FCB(1) CTRL_FN(CTRL_REQUEST_CLASS_1 - 10) LINK_ADDR(3) ADDR_LEN(1)
2017-09-26 16:15:29.922 [TRACE] telem-gw6e.Port5.port.write -  10 7A 03 7D 16
2017-09-26 16:15:29.938 [TRACE] telem-gw6e.Port5.port.read -  68
2017-09-26 16:15:29.954 [TRACE] telem-gw6e.Port5.port.read -  0A 0A 68 28 03 2E 01 07 03 00 01 00 82 E7 16
2017-09-26 16:15:29.954 [TRACE] telem-gw6e.Port5.DO5T.link - [IEC60870 101 UB Master Link] RecvVarLenFrame CTRL_PRM(0) CTRL_ACD(1) CTRL_FN(CTRL_DATA - 8) LINK_ADDR(3) ADDR_LEN(1)
2017-09-26 16:15:29.954 [TRACE] telem-gw6e.Port5.ControlStateLogger - found SELECT obj_addr = 1 obj_id = 0
2017-09-26 16:15:29.954 [TRACE] telem-gw6e.Port5.ControlStateLogger - register obj_id: 0 arg: 0
2017-09-26 16:15:29.954 [TRACE] telem-gw6e.Port5.ControlStateLogger - SELECT 0
2017-09-26 16:15:29.954 [INFO] telem-gw6e.Port5.DO5T.db - DO1 (1) response: 2 flags: Activation  time: 2017-Sep-26 16:15:29.032667, recv
2017-09-26 16:15:29.954 [TRACE] Gateway.Filter.AddToBuffer - [DO_5_1_1_resp_filter] DO_5_1_1_buf << 2 flags: Execute Activation OK GwTime Activation  time: 2017-Sep-26 13:15:29.954604
2017-09-26 16:15:29.954 [DEBUG] telem-gw6e.Port6.db - DO1 (201) event: 2 flags: GwTime Activation  time: 2017-Sep-26 16:15:29.954604, buffered
2017-09-26 16:15:30.163 [TRACE] telem-gw6e.Port6.port.write -  10 09 01 0A 16
2017-09-26 16:15:30.257 [TRACE] telem-gw6e.Port5.DI24T.link - [IEC60870 101 UB Master Link] SendFixedFrame CTRL_FCV(1) CTRL_FCB(1) CTRL_FN(CTRL_REQUEST_CLASS_2 - 11) LINK_ADDR(1) ADDR_LEN(1)
2017-09-26 16:15:30.257 [TRACE] telem-gw6e.Port5.port.write -  10 7B 01 7C 16
2017-09-26 16:15:30.273 [TRACE] telem-gw6e.Port5.port.read -  10 09 01
2017-09-26 16:15:30.289 [TRACE] telem-gw6e.Port5.port.read -  0A 16
2017-09-26 16:15:30.289 [TRACE] telem-gw6e.Port5.DI24T.link - [IEC60870 101 UB Master Link] RecvFixLenFrame. CTRL_ACD(0) CTRL_FN(CTRL_NO_DATA - 9) LINK_ADDR(1) ADDR_LEN(1)
2017-09-26 16:15:30.295 [TRACE] telem-gw6e.Port6.port.read -  10 5B 01 5C 16
2017-09-26 16:15:30.295 [TRACE] telem-gw6e.Port6 - [IEC60870 101 UB Data] class 2 data available: no
2017-09-26 16:15:30.295 [TRACE] telem-gw6e.Port6 - [IEC60870 101 UB Data] class 1 data state: digital output response
2017-09-26 16:15:30.295 [TRACE] telem-gw6e.Port6.link - [IEC60870 101 UB Slave Link] SendFixLenFrame CTRL_ACD(1) CTRL_FN(9) LINK_ADDR(1) ADDR_LEN(1)
2017-09-26 16:15:30.593 [TRACE] telem-gw6e.Port5.DO5T.link - [IEC60870 101 UB Master Link] SendFixedFrame CTRL_FCV(1) CTRL_FCB(0) CTRL_FN(CTRL_REQUEST_CLASS_1 - 10) LINK_ADDR(3) ADDR_LEN(1)
2017-09-26 16:15:30.593 [TRACE] telem-gw6e.Port5.port.write -  10 5A 03 5D 16
2017-09-26 16:15:30.595 [TRACE] telem-gw6e.Port6.port.write -  10 29 01 2A 16
2017-09-26 16:15:30.609 [TRACE] telem-gw6e.Port5.port.read -  68
2017-09-26 16:15:30.625 [TRACE] telem-gw6e.Port5.port.read -  0A 0A 68 28 03 2E 01 07 03 00 01 00 02 67 16
2017-09-26 16:15:30.626 [TRACE] telem-gw6e.Port5.DO5T.link - [IEC60870 101 UB Master Link] RecvVarLenFrame CTRL_PRM(0) CTRL_ACD(1) CTRL_FN(CTRL_DATA - 8) LINK_ADDR(3) ADDR_LEN(1)
2017-09-26 16:15:30.626 [TRACE] telem-gw6e.Port5.ControlStateLogger - found ACTIVATION obj_addr = 1 obj_id = 0
2017-09-26 16:15:30.626 [TRACE] telem-gw6e.Port5.ControlStateLogger - register obj_id: 0 arg: 0
2017-09-26 16:15:30.626 [TRACE] telem-gw6e.Port5.ControlStateLogger - ACTIVATION 0
2017-09-26 16:15:30.727 [TRACE] telem-gw6e.Port6.port.read -  10 7A 01 7B
2017-09-26 16:15:30.743 [TRACE] telem-gw6e.Port6.port.read -  16
2017-09-26 16:15:30.744 [TRACE] telem-gw6e.Port6 - [IEC60870 101 UB Data] class 1 data state: digital output response
2017-09-26 16:15:30.744 [TRACE] telem-gw6e.Port6 - [IEC60870 101 UB Data] class 1 data available: yes
2017-09-26 16:15:30.746 [INFO] telem-gw6e.Port6.db - DO1 (201) response: 2 flags: GwTime Activation  time: 2017-Sep-26 16:15:29.954604, sent
2017-09-26 16:15:30.746 [TRACE] IEC.setEvent - [Core -> Prot] (Input Events) add event EVENTCODE_DIGITAL_OUTPUT_RESPONSE
2017-09-26 16:15:30.747 [TRACE] telem-gw6e.Port6.link - mSendBuffer.Count() 8 req1:1 req2:0
2017-09-26 16:15:30.747 [TRACE] telem-gw6e.Port6.link - sending mSendBuffer.Count() 8 req1:1 req2:0
2017-09-26 16:15:30.747 [TRACE] telem-gw6e.Port6.link - [IEC60870 101 UB Slave Link] SendVarLenFrame CTRL_ACD(1) CTRL_FN(8) LINK_ADDR(1) ADDR_LEN(1)
2017-09-26 16:15:30.928 [TRACE] telem-gw6e.Port5.DI24T.link - [IEC60870 101 UB Master Link] SendFixedFrame CTRL_FCV(1) CTRL_FCB(0) CTRL_FN(CTRL_REQUEST_CLASS_2 - 11) LINK_ADDR(1) ADDR_LEN(1)
2017-09-26 16:15:30.928 [TRACE] telem-gw6e.Port5.port.write -  10 5B 01 5C 16
2017-09-26 16:15:30.945 [TRACE] telem-gw6e.Port5.port.read -  10 09 01 0A
2017-09-26 16:15:30.961 [TRACE] telem-gw6e.Port5.port.read -  16
2017-09-26 16:15:30.961 [TRACE] telem-gw6e.Port5.DI24T.link - [IEC60870 101 UB Master Link] RecvFixLenFrame. CTRL_ACD(0) CTRL_FN(CTRL_NO_DATA - 9) LINK_ADDR(1) ADDR_LEN(1)
2017-09-26 16:15:31.047 [TRACE] telem-gw6e.Port6.link - mSendBuffer.Count() 0 req1:0 req2:0
2017-09-26 16:15:31.047 [TRACE] telem-gw6e.Port6.port.write -  68 0A 0A 68 28 01 2D 01 07 01 00 C9 00 01 29 16
2017-09-26 16:15:31.191 [TRACE] telem-gw6e.Port6.port.read -  10 5A 01 5B 16
2017-09-26 16:15:31.191 [TRACE] telem-gw6e.Port6 - [IEC60870 101 UB Data] class 1 data available: no
2017-09-26 16:15:31.191 [TRACE] telem-gw6e.Port6.link - [IEC60870 101 UB Slave Link] SendFixLenFrame CTRL_ACD(0) CTRL_FN(9) LINK_ADDR(1) ADDR_LEN(1)
2017-09-26 16:15:31.264 [TRACE] telem-gw6e.Port5.DO5T.link - [IEC60870 101 UB Master Link] SendFixedFrame CTRL_FCV(1) CTRL_FCB(1) CTRL_FN(CTRL_REQUEST_CLASS_1 - 10) LINK_ADDR(3) ADDR_LEN(1)
2017-09-26 16:15:31.264 [TRACE] telem-gw6e.Port5.port.write -  10 7A 03 7D 16
2017-09-26 16:15:31.281 [TRACE] telem-gw6e.Port5.port.read -  68
2017-09-26 16:15:31.297 [TRACE] telem-gw6e.Port5.port.read -  0A 0A 68 28 03 2E 01 0A 03 00 01 00 02 6A 16
2017-09-26 16:15:31.297 [TRACE] telem-gw6e.Port5.DO5T.link - [IEC60870 101 UB Master Link] RecvVarLenFrame CTRL_PRM(0) CTRL_ACD(1) CTRL_FN(CTRL_DATA - 8) LINK_ADDR(3) ADDR_LEN(1)
2017-09-26 16:15:31.297 [TRACE] telem-gw6e.Port5.ControlStateLogger - found RESPONSE obj_addr = 1 obj_id = 0
2017-09-26 16:15:31.297 [TRACE] telem-gw6e.Port5.ControlStateLogger - register obj_id: 0 arg: 0
2017-09-26 16:15:31.297 [TRACE] telem-gw6e.Port5.ControlStateLogger - RESPONSE 0

View in VINCI:

Vincido.png