12:00:32.707 Running procedure: 8.14.2.15
12:00:32.712 This procedure is enabled because the following options:
12:00:32.712 - supports.binaryInputChangeEvents == true
12:00:32.712 - timesync.binaryInputChangeWithRelativeTime == true
12:00:32.712 step: 1
12:00:32.712 - Read(0x01) fir: 1 fin: 1 con: 0 uns: 0 seq: 0x01
12:00:32.712 - g2v0, All Objects
12:00:32.712 --A-> Read(0x01) fir: 1 fin: 1 con: 0 uns: 0 seq: 0x01
12:00:32.712 g2v0, All Objects
12:00:32.713 --T-> fir: 1 fin: 1 seq: 0
12:00:32.713 --L-> master: 1 pri: 1 fcb: 0 fcv: 0 func: UNCONFIRMED_USER_DATA(0x04) 0xC4 length: 11 dest: 1024 src: 1
12:00:32.713 --P-> 05 64 0B C4 00 04 01 00 CA 8A
12:00:32.713 C0 C1 01 02 00 06 95 76
12:00:32.714 steps: 2 to 3
12:00:32.714 - Read a single fragment response w/ sequence(0x01)
12:00:32.714 - If the response is not Null, verify that the device requests an application layer confirmation.
12:00:32.715 <-P-- 05 64 0A 44 01 00 00 04 67 88
12:00:32.715 C0 C1 81 90 00 73 EE
12:00:32.715 <-L-- master: 0 pri: 1 fcb: 0 fcv: 0 func: UNCONFIRMED_USER_DATA(0x04) 0x44 length: 10 dest: 1 src: 1024
12:00:32.715 <-T-- fir: 1 fin: 1 seq: 0
12:00:32.716 <-A-- Response(0x81) fir: 1 fin: 1 con: 0 uns: 0 seq: 0x01 IIN(DeviceRestart, NeedTime)
12:00:32.716 step: 4
12:00:32.716 - Generate several Binary Input Change Events
12:00:32.717 Updated BI 65535: value=true, flags=81, timestamp=DNPTime(1586534432716)
12:00:32.717 Updated BI 41: value=true, flags=81, timestamp=DNPTime(1586534432717)
12:00:32.717 Updated BI 65535: value=false, flags=1, timestamp=DNPTime(1586534432717)
12:00:32.718 step: 5
12:00:32.718 - Wait for 65536 milliseconds
12:01:38.254 step: 6
12:01:38.254 - Generate several Binary Input Change Events
12:01:38.255 Updated BI 1024: value=true, flags=81, timestamp=DNPTime(1586534498254)
12:01:38.255 Updated BI 1024: value=false, flags=1, timestamp=DNPTime(1586534498255)
12:01:38.256 Updated BI 1024: value=true, flags=81, timestamp=DNPTime(1586534498255)
12:01:38.256 step: 7
12:01:38.256 - Read(0x01) fir: 1 fin: 1 con: 0 uns: 0 seq: 0x02
12:01:38.256 - g2v3, All Objects
12:01:38.257 --A-> Read(0x01) fir: 1 fin: 1 con: 0 uns: 0 seq: 0x02
12:01:38.257 g2v3, All Objects
12:01:38.257 --T-> fir: 1 fin: 1 seq: 0
12:01:38.257 --L-> master: 1 pri: 1 fcb: 0 fcv: 0 func: UNCONFIRMED_USER_DATA(0x04) 0xC4 length: 11 dest: 1024 src: 1
12:01:38.258 --P-> 05 64 0B C4 00 04 01 00 CA 8A
12:01:38.258 C0 C2 01 02 03 06 34 A3
12:01:38.261 steps: 8 to 14
12:01:38.261 - Read a single fragment response w/ sequence(0x02)
12:01:38.261 - Verify the device responds with previous data followed by the new events in time order
12:01:38.261 - If the variation contains timestamps, verify that they are reasonable according to the resolution specified in the Device Profile
12:01:38.261 - Verify that an application layer confirmation is requested.
12:01:38.261 - Validate that a g51v1 or g51v2 precedes the g2v3 in each fragment of the response
12:01:38.261 - Validation that only g51v1, g51v2 and g2v3 appears in the response
12:01:38.261 - Validate that each group of events that occurred more than 0xFFFF milliseconds apart are preceded by a new CTO object
12:01:38.261 - Verify that flag behavior complies with Section 2, Note #5.
12:01:38.262 <-P-- 05 64 46 44 01 00 00 04 A8 F1
12:01:38.262 C1 E2 81 90 00 33 02 07 01 CC 3F D2 64 71 01 02 A9 46
12:01:38.262 03 28 03 00 FF FF 81 00 00 29 00 81 01 00 FF FF FD C8
12:01:38.262 01 01 00 33 02 07 01 CE 3F D3 64 71 01 02 03 28 BA 68
12:01:38.262 03 00 00 04 81 00 00 00 04 01 01 00 00 04 81 01 4C AD
12:01:38.262 00 FF FF
12:01:38.263 <-L-- master: 0 pri: 1 fcb: 0 fcv: 0 func: UNCONFIRMED_USER_DATA(0x04) 0x44 length: 70 dest: 1 src: 1024
12:01:38.263 <-T-- fir: 1 fin: 1 seq: 1
12:01:38.266 <-A-- Response(0x81) fir: 1 fin: 1 con: 1 uns: 0 seq: 0x02 IIN(DeviceRestart, NeedTime)
12:01:38.266 g51v2, 1-Byte Count, count: 1
12:01:38.266 time: 1586534432716
12:01:38.266 g2v3, 2-Byte Count and Index, count: 3
12:01:38.266 [65535] - flags: 0x81 cto: 0
12:01:38.266 [41] - flags: 0x81 cto: 1
12:01:38.266 [65535] - flags: 0x01 cto: 1
12:01:38.266 g51v2, 1-Byte Count, count: 1
12:01:38.266 time: 1586534498254
12:01:38.266 g2v3, 2-Byte Count and Index, count: 3
12:01:38.266 [1024] - flags: 0x81 cto: 0
12:01:38.266 [1024] - flags: 0x01 cto: 1
12:01:38.266 [1024] - flags: 0x81 cto: 1
12:01:38.267 --A-> Confirm(0x00) fir: 1 fin: 1 con: 0 uns: 0 seq: 0x02
12:01:38.267 --T-> fir: 1 fin: 1 seq: 0
12:01:38.267 --L-> master: 1 pri: 1 fcb: 0 fcv: 0 func: UNCONFIRMED_USER_DATA(0x04) 0xC4 length: 8 dest: 1024 src: 1
12:01:38.268 --P-> 05 64 08 C4 00 04 01 00 9A 19
12:01:38.268 C0 C2 00 D6 8D
12:01:38.270 step: 15
12:01:38.270 - Read(0x01) fir: 1 fin: 1 con: 0 uns: 0 seq: 0x03
12:01:38.270 - g2v0, All Objects
12:01:38.270 --A-> Read(0x01) fir: 1 fin: 1 con: 0 uns: 0 seq: 0x03
12:01:38.270 g2v0, All Objects
12:01:38.270 --T-> fir: 1 fin: 1 seq: 0
12:01:38.271 --L-> master: 1 pri: 1 fcb: 0 fcv: 0 func: UNCONFIRMED_USER_DATA(0x04) 0xC4 length: 11 dest: 1024 src: 1
12:01:38.271 --P-> 05 64 0B C4 00 04 01 00 CA 8A
12:01:38.271 C0 C3 01 02 00 06 99 30
12:01:38.273 step: 16
12:01:38.273 - Read a single fragment response w/ sequence(0x03)
12:01:38.273 - Verify that the response is empty
12:01:38.273 <-P-- 05 64 0A 44 01 00 00 04 67 88
12:01:38.273 C2 C3 81 90 00 D6 60
12:01:38.273 <-L-- master: 0 pri: 1 fcb: 0 fcv: 0 func: UNCONFIRMED_USER_DATA(0x04) 0x44 length: 10 dest: 1 src: 1024
12:01:38.274 <-T-- fir: 1 fin: 1 seq: 2
12:01:38.274 <-A-- Response(0x81) fir: 1 fin: 1 con: 0 uns: 0 seq: 0x03 IIN(DeviceRestart, NeedTime)
12:01:38.274 Passed procedure: 8.14.2.15