8.2.1.2.4 Binary Output, SBO, Execute Issued After Timeout (revision 3.1r1, subset level 3)

Device under test: Step Function I/O dnp3 outstation

05:24:15.902 Running procedure: 8.2.1.2.4
05:24:15.905 This procedure is enabled because the following options:
05:24:15.905 - supports.binaryOutput.commands == true
05:24:15.905 step: 1
05:24:15.905 - Select(0x03) fir: 1 fin: 1 con: 0 uns: 0 seq: 0x00
05:24:15.905 - g12v1, 1-Byte Count and Index, count: 1
05:24:15.905 - [0] - code: 0x03 (LATCH_ON, NUL) count: 1 onTime: 100 offTime: 200 status: 0 (SUCCESS)
05:24:15.905 --A-> Select(0x03) fir: 1 fin: 1 con: 0 uns: 0 seq: 0x00
05:24:15.905 g12v1, 1-Byte Count and Index, count: 1
05:24:15.905 [0] - code: 0x03 (LATCH_ON, NUL) count: 1 onTime: 100 offTime: 200 status: 0 (SUCCESS)
05:24:15.905 --T-> fir: 1 fin: 1 seq: 0
05:24:15.905 --L-> master: 1 pri: 1 fcb: 0 fcv: 0 func: UNCONFIRMED_USER_DATA(0x04) 0xC4 length: 24 dest: 1024 src: 1
05:24:15.906 --P-> 05 64 18 C4 00 04 01 00 5B 61
05:24:15.906 C0 C0 03 0C 01 17 01 00 03 01 64 00 00 00 C8 00 FD 11
05:24:15.906 00 00 00 FF FF
05:24:15.906 step: 2
05:24:15.906 - Read a single fragment response w/ sequence(0x00)
05:24:15.906 - Verify the response contains the exact object header:
05:24:15.906 - g12v1, 1-Byte Count and Index, count: 1
05:24:15.906 - [0] - code: 0x03 (LATCH_ON, NUL) count: 1 onTime: 100 offTime: 200 status: 0 (SUCCESS)
05:24:15.906 - Verify that the IIN field does not contain bits IIN(ParamError, ObjectUnknown, FuncNotSupported)
05:24:15.907 <-P-- 05 64 1A 44 01 00 00 04 A6 F0
05:24:15.907 C0 C0 81 90 00 0C 01 17 01 00 03 01 64 00 00 00 9C 9A
05:24:15.907 C8 00 00 00 00 78 FB
05:24:15.907 <-L-- master: 0 pri: 1 fcb: 0 fcv: 0 func: UNCONFIRMED_USER_DATA(0x04) 0x44 length: 26 dest: 1 src: 1024
05:24:15.907 <-T-- fir: 1 fin: 1 seq: 0
05:24:15.907 <-A-- Response(0x81) fir: 1 fin: 1 con: 0 uns: 0 seq: 0x00 IIN(DeviceRestart, NeedTime)
05:24:15.907 g12v1, 1-Byte Count and Index, count: 1
05:24:15.907 [0] - code: 0x03 (LATCH_ON, NUL) count: 1 onTime: 100 offTime: 200 status: 0 (SUCCESS)
05:24:15.907 step: 3
05:24:15.907 - Wait for 3000 milliseconds
05:24:18.908 step: 4
05:24:18.908 - Operate(0x04) fir: 1 fin: 1 con: 0 uns: 0 seq: 0x01
05:24:18.908 - g12v1, 1-Byte Count and Index, count: 1
05:24:18.908 - [0] - code: 0x03 (LATCH_ON, NUL) count: 1 onTime: 100 offTime: 200 status: 0 (SUCCESS)
05:24:18.908 - Read a single fragment response w/ sequence(0x01)
05:24:18.908 - Verify the response contains the exact object header:
05:24:18.908 - g12v1, 1-Byte Count and Index, count: 1
05:24:18.908 - [0] - code: 0x03 (LATCH_ON, NUL) count: 1 onTime: 100 offTime: 200 status: 1 (TIMEOUT)
05:24:18.908 --A-> Operate(0x04) fir: 1 fin: 1 con: 0 uns: 0 seq: 0x01
05:24:18.908 g12v1, 1-Byte Count and Index, count: 1
05:24:18.908 [0] - code: 0x03 (LATCH_ON, NUL) count: 1 onTime: 100 offTime: 200 status: 0 (SUCCESS)
05:24:18.908 --T-> fir: 1 fin: 1 seq: 0
05:24:18.908 --L-> master: 1 pri: 1 fcb: 0 fcv: 0 func: UNCONFIRMED_USER_DATA(0x04) 0xC4 length: 24 dest: 1024 src: 1
05:24:18.908 --P-> 05 64 18 C4 00 04 01 00 5B 61
05:24:18.908 C0 C1 04 0C 01 17 01 00 03 01 64 00 00 00 C8 00 35 C7
05:24:18.908 00 00 00 FF FF
05:24:18.910 <-P-- 05 64 1A 44 01 00 00 04 A6 F0
05:24:18.910 C1 C1 81 90 00 0C 01 17 01 00 03 01 64 00 00 00 08 B9
05:24:18.910 C8 00 00 00 01 26 CD
05:24:18.910 <-L-- master: 0 pri: 1 fcb: 0 fcv: 0 func: UNCONFIRMED_USER_DATA(0x04) 0x44 length: 26 dest: 1 src: 1024
05:24:18.910 <-T-- fir: 1 fin: 1 seq: 1
05:24:18.910 <-A-- Response(0x81) fir: 1 fin: 1 con: 0 uns: 0 seq: 0x01 IIN(DeviceRestart, NeedTime)
05:24:18.910 g12v1, 1-Byte Count and Index, count: 1
05:24:18.910 [0] - code: 0x03 (LATCH_ON, NUL) count: 1 onTime: 100 offTime: 200 status: 1 (TIMEOUT)
05:24:18.910 step: 5
05:24:18.910 - Check that no binary control point operated
05:24:19.911 [PLG] Binary output did NOT operate
05:24:19.911 Passed procedure: 8.2.1.2.4