Integration Tests: improve flaky tests
#3163
Conversation
We get a lot of flaky failures on `OfflineStoreKitIntegrationTests` (example: https://app.circleci.com/pipelines/github/RevenueCat/purchases-ios/14843/workflows/a3cffa7c-da25-4811-931d-fc241befee0f/jobs/118214/tests). I managed to reproduce locally running some of these 100+ times on a loop until they failed. I traced the issue to this sequence: - SK2 purchase - `StoreKit.Transaction.unfinished` is empty This is likely due to a race condition. In practice, when computing offline `CustomerInfo`, we never check it right away, since we need to wait for the server to return a 500. To make tests more realistic, I introduced a delay in `HTTPClient` returning fake 5xx errors. I haven't been able to reproduce this issue again, so this should make `OfflineStoreKitIntegrationTests` more reliable. I've also added a new debug log that could help debug similar issues, because `Strings.offline.computed_offline_customer_info` was not very complete.
| @@ -113,7 +113,7 @@ extension NetworkStrings: LogMessage { | |||
|
|
|||
| #if DEBUG | |||
| case let .api_request_forcing_server_error(request): | |||
| return "Returning fake HTTP 500 error for '\(request.description)'" | |||
| return "Returning fake HTTP 500 error for \(request.description)" | |||
There was a problem hiding this comment.
This ended up with double quotes:
Returning fake HTTP 500 error for 'POST '/v1/receipts''
| Logger.info(Strings.offlineEntitlements.computed_offline_customer_info( | ||
| products, offlineCustomerInfo.entitlements | ||
| )) | ||
| Logger.debug(Strings.offlineEntitlements.computed_offline_customer_info_details( |
There was a problem hiding this comment.
I improved these logs to be able to debug future issues here. Initially I wasn't sure if PurchasedProductsFetcher was working correctly.
Do we have a radar for this? It doesn't seem like expected behavior. Just to clarify, we check unfinished after we get the response from await purchase, right? |
| completionHandler?( | ||
| .failure(.errorResponse(Self.serverErrorResponse, .internalServerError)) | ||
| ) | ||
| DispatchQueue.main.asyncAfter(deadline: .now() + .milliseconds(300)) { |
There was a problem hiding this comment.
the intent behind this isn't obvious at first glance so let's make sure to add a comment here
There was a problem hiding this comment.
Good point, I always think it's in git history but that's easily lost.
Yup
Nope. I'll file one 👍🏻 |
Codecov ReportPatch coverage:
Additional details and impacted files@@ Coverage Diff @@
## main #3163 +/- ##
==========================================
+ Coverage 86.61% 86.63% +0.01%
==========================================
Files 220 220
Lines 15715 15738 +23
==========================================
+ Hits 13611 13634 +23
Misses 2104 2104
☔ View full report in Codecov by Sentry. |
|
Filed: |
**This is an automatic release.** ### Bugfixes * Fix runtime crash in SK2TransactionListener in iOS < 15 (#3206) via Toni Rico (@tonidero) ### Performance Improvements * `OperationDispatcher`: add support for "long" delays (#3168) via NachoSoto (@NachoSoto) ### Other Changes * `Integration Tests`: add tests for ghost transfer behavior (#3135) via NachoSoto (@NachoSoto) * `Xcode`: removed `purchases-ios` SPM reference (#3166) via NachoSoto (@NachoSoto) * `Integration Tests`: another flaky failure (#3165) via NachoSoto (@NachoSoto) * `Integration Tests`: fix flaky test failure due to leftover transaction (#3167) via NachoSoto (@NachoSoto) * `Xcode 13`: removed last `Swift 5.7` checks (#3161) via NachoSoto (@NachoSoto) * `Integration Tests`: improve flaky tests (#3163) via NachoSoto (@NachoSoto) * `Codable`: improved decoding errors (#3153) via NachoSoto (@NachoSoto) * Refactor: extract `HealthOperation` (#3154) via NachoSoto (@NachoSoto) * `Xcode 13`: remove conditional code (#3147) via NachoSoto (@NachoSoto) * `CircleCI`: change all jobs to use `Xcode 14.x` and replace `xcode-install` with `xcodes` (#2421) via NachoSoto (@NachoSoto)
We get a lot of flaky failures on
OfflineStoreKitIntegrationTests(example: https://app.circleci.com/pipelines/github/RevenueCat/purchases-ios/14843/workflows/a3cffa7c-da25-4811-931d-fc241befee0f/jobs/118214/tests).I managed to reproduce locally running some of these 100+ times on a loop until they failed.
I traced the issue to this sequence:
StoreKit.Transaction.unfinishedis emptyThis is likely due to a race condition. In practice, when computing offline
CustomerInfo, we never check it right away, since we need to wait for the server to return a 500.I filed a Radar for this:
FB13133387.To make tests more realistic, I introduced a delay in
HTTPClientreturning fake 5xx errors. I haven't been able to reproduce this issue again, so this should makeOfflineStoreKitIntegrationTestsmore reliable.I've also added a new debug log that could help debug similar issues, because
Strings.offline.computed_offline_customer_infowas not very complete.