ably-cocoa
ably-cocoa copied to clipboard
Connection sometimes performs extra retry when it should transition to `SUSPENDED` state
Issue description
ARTRealtime
will sometimes perform one more connection retry than it should — that is, it will perform a connection retry after connectionStateTtl
has been exceeded, violating RTN14e.
Steps to reproduce
The steps vary depending on whether you're viewing the code before or after PR #1613, which made some test changes.
- Before PR #1613: change
expectedTime
in testtest__059__Connection__connection_request_fails__connection_attempt_fails_for_any_recoverable_reason
from 3.0 to 4.9, and run the test a few times. - After PR #1613: change the
XCTAssertGreaterThanOrEqual
relating to the number of observed retries to anXCAssertEqual
.
Observed behaviour
The test fails because one more retry than expected was made.
Underlying issue
By adding logging to ARTRealtime
(see 6f738c5134562ff9889205e4c54803051b4269c6), we see the following messages:
2023-07-05 14:12:19.420393-0300 xctest[29178:1697374] VERBOSE: (ARTRealtime.m:674) RT:0x102d045a0 set connection lost time; expected suspension at 2023-07-05T17:12:24.320Z (ttl=4.900000)
2023-07-05 14:12:19.316145-0300 xctest[29178:1696902] VERBOSE: (ARTRealtime.m:1099) Scheduling timeout work in transportConnectForcingNewToken:newConnection:
2023-07-05 14:12:20.453626-0300 xctest[29178:1697372] VERBOSE: (ARTRealtime.m:1099) Scheduling timeout work in transportConnectForcingNewToken:newConnection:
2023-07-05 14:12:21.616243-0300 xctest[29178:1697374] VERBOSE: (ARTRealtime.m:1099) Scheduling timeout work in transportConnectForcingNewToken:newConnection:
2023-07-05 14:12:22.745132-0300 xctest[29178:1697374] VERBOSE: (ARTRealtime.m:1099) Scheduling timeout work in transportConnectForcingNewToken:newConnection:
2023-07-05 14:12:23.882761-0300 xctest[29178:1697374] VERBOSE: (ARTRealtime.m:1099) Scheduling timeout work in transportConnectForcingNewToken:newConnection:
2023-07-05 14:12:25.046635-0300 xctest[29178:1697372] VERBOSE: (ARTRealtime.m:1099) Scheduling timeout work in transportConnectForcingNewToken:newConnection:
Notice that the final "Scheduling timeout work" log message occurs after the date described by the "expected suspension at" log message. This suggests that the connection is only checking whether it should enter SUSPENDED
in the moment that a timeout occurs, and not before scheduling work that might time out.