NachoSoto
70365df383
Purchasing: fixed consumable purchases by fixing transaction-finishing ( #1965 )
...
Fixes #1964 , [TRIAGE-134], [TRIAGE-131], and possibly [TRIAGE-82].
Depends on #1967 , #1968 .
### Fixes:
- For `SK2` purchases we were never finishing transactions. We are now.
- For `SK1` purchases, transactions were finished _after_ the completion
block was invoked (and tests were very lenient checking that
_eventually_ this happened). This could have lead to race conditions.
- For SK2 only (at least in `SKTestSession`s), this fixes the ability to
purchase multiple consumable purchases.
This is the log from the failing test using SK2:
<details>
<summary>Open</summary>
```
2022-10-06 15:18:52.286813-0700 BackendIntegrationTestsHostApp[45464:7076968] [Purchases] - DEBUG: ℹ️ API request started: GET /v1/subscribers/$RCAnonymousID:6f630d50b8294288a2d0862629d766fb/offerings
2022-10-06 15:18:52.383594-0700 BackendIntegrationTestsHostApp[45464:7076968] [Purchases] - DEBUG: ℹ️ API request completed: GET /v1/subscribers/$RCAnonymousID:6f630d50b8294288a2d0862629d766fb/offerings 200
2022-10-06 15:18:52.388247-0700 BackendIntegrationTestsHostApp[45464:7076968] [Purchases] - DEBUG: ℹ️ No existing products cached, starting store products request for: ["com.revenuecat.weekly_1.99.3_day_intro", "consumable.10_coins", "com.revenuecat.annual_39.99.2_week_intro", "com.revenuecat.monthly_4.99.1_week_intro"]
2022-10-06 15:18:52.388382-0700 BackendIntegrationTestsHostApp[45464:7076968] [Purchases] - DEBUG: ℹ️ Found an existing request for products: ["com.revenuecat.monthly_4.99.1_week_intro", "com.revenuecat.annual_39.99.2_week_intro", "com.revenuecat.weekly_1.99.3_day_intro", "consumable.10_coins"], appending to completion
2022-10-06 15:18:52.388451-0700 BackendIntegrationTestsHostApp[45464:7076968] [Purchases] - DEBUG: ℹ️ GetOfferingsOperation: Finished
2022-10-06 15:18:52.388560-0700 BackendIntegrationTestsHostApp[45464:7076968] [Purchases] - DEBUG: ℹ️ Serial request done: GET subscribers/$RCAnonymousID%3A6f630d50b8294288a2d0862629d766fb/offerings, 0 requests left in the queue
2022-10-06 15:18:52.420210-0700 BackendIntegrationTestsHostApp[45464:7076968] [Purchases] - DEBUG: 😻 Store products request request received response
2022-10-06 15:18:52.420358-0700 BackendIntegrationTestsHostApp[45464:7076968] [Purchases] - DEBUG: ℹ️ Store products request finished
2022-10-06 15:18:52.421126-0700 BackendIntegrationTestsHostApp[45464:7076978] [Purchases] - DEBUG: ℹ️ Vending Offerings from cache
2022-10-06 15:18:52.421353-0700 BackendIntegrationTestsHostApp[45464:7076968] [Purchases] - INFO: 💰 Purchasing Product 'consumable.10_coins' from package in Offering 'coins'
2022-10-06 15:18:52.496438-0700 BackendIntegrationTestsHostApp[45464:7076968] [Purchases] - DEBUG: ℹ️ Force refreshing the receipt to get latest transactions from Apple.
2022-10-06 15:18:52.510974-0700 BackendIntegrationTestsHostApp[45464:7076903] [Purchases] - DEBUG: ℹ️ Loaded receipt from url file:///Users/nachosoto/Library/Developer/CoreSimulator/Devices/A3576DC2-355E-45BA-B32C-D2C0A3811BB4/data/Containers/Data/Application/BFD385C4-52BC-414B-9C1C-44522ED1222F/StoreKit/receipt
2022-10-06 15:18:52.511072-0700 BackendIntegrationTestsHostApp[45464:7076903] [Purchases] - DEBUG: ℹ️ Skipping products request because products were already cached. products: ["consumable.10_coins"]
2022-10-06 15:18:52.511181-0700 BackendIntegrationTestsHostApp[45464:7076903] [Purchases] - DEBUG: ℹ️ Skipping products request because products were already cached. products: ["consumable.10_coins"]
2022-10-06 15:18:52.511564-0700 BackendIntegrationTestsHostApp[45464:7076903] [Purchases] - DEBUG: ℹ️ Found 0 unsynced attributes for App User ID: $RCAnonymousID:6f630d50b8294288a2d0862629d766fb
2022-10-06 15:18:52.515448-0700 BackendIntegrationTestsHostApp[45464:7076978] [Purchases] - DEBUG: ℹ️ PostReceiptDataOperation: Started
2022-10-06 15:18:52.516403-0700 BackendIntegrationTestsHostApp[45464:7076978] [Purchases] - INFO: ℹ️ Receipt parsed successfully
2022-10-06 15:18:52.516763-0700 BackendIntegrationTestsHostApp[45464:7076978] [Purchases] - DEBUG: ℹ️ PostReceiptDataOperation: Posting receipt: {
"opaque_value" : "oX91ewAAAAA=",
"sha1_hash" : "GsyNpUKQ89SonYyj\/jpw8\/N5nr8=",
"bundle_id" : "com.revenuecat.StoreKitTestApp",
"in_app_purchases" : [
{
"quantity" : 1,
"product_id" : "consumable.10_coins",
"purchase_date" : "2022-10-06T22:18:52Z",
"transaction_id" : "0"
}
],
"application_version" : "1",
"creation_date" : "2022-10-06T22:18:52Z",
"expiration_date" : "4001-01-01T00:00:00Z"
}
2022-10-06 15:18:52.516825-0700 BackendIntegrationTestsHostApp[45464:7076978] [Purchases] - DEBUG: ℹ️ There are no requests currently running, starting request POST receipts
2022-10-06 15:18:52.518059-0700 BackendIntegrationTestsHostApp[45464:7076978] [Purchases] - DEBUG: ℹ️ API request started: POST /v1/receipts
2022-10-06 15:18:52.960048-0700 BackendIntegrationTestsHostApp[45464:7076966] [Purchases] - DEBUG: ℹ️ API request completed: POST /v1/receipts 200
2022-10-06 15:18:52.964274-0700 BackendIntegrationTestsHostApp[45464:7076966] [Purchases] - DEBUG: ℹ️ PostReceiptDataOperation: Finished
2022-10-06 15:18:52.964666-0700 BackendIntegrationTestsHostApp[45464:7076966] [Purchases] - DEBUG: ℹ️ Serial request done: POST receipts, 0 requests left in the queue
2022-10-06 15:18:52.966476-0700 BackendIntegrationTestsHostApp[45464:7076903] [Purchases] - DEBUG: ℹ️ Sending updated CustomerInfo to delegate.
2022-10-06 15:18:52.966697-0700 BackendIntegrationTestsHostApp[45464:7076966] [Purchases] - INFO: 😻 💰 Purchased product - 'consumable.10_coins'
2022-10-06 15:18:52.966973-0700 BackendIntegrationTestsHostApp[45464:7076966] [Purchases] - DEBUG: ℹ️ Vending Offerings from cache
2022-10-06 15:18:52.967284-0700 BackendIntegrationTestsHostApp[45464:7076966] [Purchases] - INFO: 💰 Purchasing Product 'consumable.10_coins' from package in Offering 'coins'
2022-10-06 15:18:52.991334-0700 BackendIntegrationTestsHostApp[45464:7076973] [Purchases] - DEBUG: ℹ️ Force refreshing the receipt to get latest transactions from Apple.
2022-10-06 15:18:53.015046-0700 BackendIntegrationTestsHostApp[45464:7076903] [Purchases] - DEBUG: ℹ️ Loaded receipt from url file:///Users/nachosoto/Library/Developer/CoreSimulator/Devices/A3576DC2-355E-45BA-B32C-D2C0A3811BB4/data/Containers/Data/Application/BFD385C4-52BC-414B-9C1C-44522ED1222F/StoreKit/receipt
2022-10-06 15:18:53.015174-0700 BackendIntegrationTestsHostApp[45464:7076903] [Purchases] - DEBUG: ℹ️ Skipping products request because products were already cached. products: ["consumable.10_coins"]
2022-10-06 15:18:53.015262-0700 BackendIntegrationTestsHostApp[45464:7076903] [Purchases] - DEBUG: ℹ️ Skipping products request because products were already cached. products: ["consumable.10_coins"]
2022-10-06 15:18:53.015419-0700 BackendIntegrationTestsHostApp[45464:7076903] [Purchases] - DEBUG: ℹ️ Found 0 unsynced attributes for App User ID: $RCAnonymousID:6f630d50b8294288a2d0862629d766fb
2022-10-06 15:18:53.015927-0700 BackendIntegrationTestsHostApp[45464:7076966] [Purchases] - DEBUG: ℹ️ PostReceiptDataOperation: Started
2022-10-06 15:18:53.016558-0700 BackendIntegrationTestsHostApp[45464:7076966] [Purchases] - INFO: ℹ️ Receipt parsed successfully
2022-10-06 15:18:53.016727-0700 BackendIntegrationTestsHostApp[45464:7076966] [Purchases] - DEBUG: ℹ️ PostReceiptDataOperation: Posting receipt: {
"opaque_value" : "LP9LZQwAAAA=",
"sha1_hash" : "WdANBTWr7wYWh8RYEgmGebO8DR8=",
"bundle_id" : "com.revenuecat.StoreKitTestApp",
"in_app_purchases" : [
{
"quantity" : 1,
"product_id" : "consumable.10_coins",
"purchase_date" : "2022-10-06T22:18:52Z",
"transaction_id" : "0"
}
],
"application_version" : "1",
"creation_date" : "2022-10-06T22:18:53Z",
"expiration_date" : "4001-01-01T00:00:00Z"
}
2022-10-06 15:18:53.016783-0700 BackendIntegrationTestsHostApp[45464:7076966] [Purchases] - DEBUG: ℹ️ There are no requests currently running, starting request POST receipts
2022-10-06 15:18:53.017602-0700 BackendIntegrationTestsHostApp[45464:7076966] [Purchases] - DEBUG: ℹ️ API request started: POST /v1/receipts
2022-10-06 15:18:53.411689-0700 BackendIntegrationTestsHostApp[45464:7076978] [Purchases] - DEBUG: ℹ️ API request completed: POST /v1/receipts 200
2022-10-06 15:18:53.413980-0700 BackendIntegrationTestsHostApp[45464:7076978] [Purchases] - DEBUG: ℹ️ PostReceiptDataOperation: Finished
2022-10-06 15:18:53.414147-0700 BackendIntegrationTestsHostApp[45464:7076978] [Purchases] - DEBUG: ℹ️ Serial request done: POST receipts, 0 requests left in the queue
2022-10-06 15:18:53.414927-0700 BackendIntegrationTestsHostApp[45464:7076978] [Purchases] - INFO: 😻 💰 Purchased product - 'consumable.10_coins'
2022-10-06 15:18:53.415505-0700 BackendIntegrationTestsHostApp[45464:7076978] [Purchases] - DEBUG: ℹ️ Vending CustomerInfo from cache.
```
</details>
With the fix, you can see transactions are now finished at the right
time:
<details>
<summary>Open</summary>
```
2022-10-07 11:08:01.967843-0700 BackendIntegrationTestsHostApp[45714:674592] [Purchases] - INFO: 💰 Purchasing Product 'consumable.10_coins' from package in Offering 'coins'
2022-10-07 11:08:02.123611-0700 BackendIntegrationTestsHostApp[45714:674592] [Purchases] - DEBUG: ℹ️ Force refreshing the receipt to get latest transactions from Apple.
2022-10-07 11:08:02.138918-0700 BackendIntegrationTestsHostApp[45714:674399] [Purchases] - DEBUG: ℹ️ Loaded receipt from url file:///Users/nachosoto/Library/Developer/CoreSimulator/Devices/F02A9A20-949B-4C9D-A01E-AB0CC7544F96/data/Containers/Data/Application/C52A5EFD-733F-46EC-84B7-734B6AF9D28C/StoreKit/receipt
2022-10-07 11:08:02.139013-0700 BackendIntegrationTestsHostApp[45714:674399] [Purchases] - DEBUG: ℹ️ Skipping products request because products were already cached. products: ["consumable.10_coins"]
2022-10-07 11:08:02.139095-0700 BackendIntegrationTestsHostApp[45714:674399] [Purchases] - DEBUG: ℹ️ Skipping products request because products were already cached. products: ["consumable.10_coins"]
2022-10-07 11:08:02.139481-0700 BackendIntegrationTestsHostApp[45714:674399] [Purchases] - DEBUG: ℹ️ Found 0 unsynced attributes for App User ID: $RCAnonymousID:bd74b9d10f2c48eea1d741a32f5acb16
2022-10-07 11:08:02.147220-0700 BackendIntegrationTestsHostApp[45714:674592] [Purchases] - DEBUG: ℹ️ PostReceiptDataOperation: Started
2022-10-07 11:08:02.148192-0700 BackendIntegrationTestsHostApp[45714:674592] [Purchases] - INFO: ℹ️ Receipt parsed successfully
2022-10-07 11:08:02.148552-0700 BackendIntegrationTestsHostApp[45714:674592] [Purchases] - DEBUG: ℹ️ PostReceiptDataOperation: Posting receipt: {
"opaque_value" : "\/3nevQ0AAAA=",
"sha1_hash" : "\/bAkxLQ6BPgUg3rR9jDR28dEfig=",
"bundle_id" : "com.revenuecat.StoreKitTestApp",
"in_app_purchases" : [
{
"quantity" : 1,
"product_id" : "consumable.10_coins",
"purchase_date" : "2022-10-07T18:08:02Z",
"transaction_id" : "0"
}
],
"application_version" : "1",
"creation_date" : "2022-10-07T18:08:02Z",
"expiration_date" : "4001-01-01T00:00:00Z"
}
2022-10-07 11:08:02.148604-0700 BackendIntegrationTestsHostApp[45714:674592] [Purchases] - DEBUG: ℹ️ There are no requests currently running, starting request POST receipts
2022-10-07 11:08:02.149748-0700 BackendIntegrationTestsHostApp[45714:674592] [Purchases] - DEBUG: ℹ️ API request started: POST /v1/receipts
2022-10-07 11:08:02.733225-0700 BackendIntegrationTestsHostApp[45714:674602] [Purchases] - DEBUG: ℹ️ API request completed: POST /v1/receipts 200
2022-10-07 11:08:02.734687-0700 BackendIntegrationTestsHostApp[45714:674602] [Purchases] - DEBUG: ℹ️ PostReceiptDataOperation: Finished
2022-10-07 11:08:02.734802-0700 BackendIntegrationTestsHostApp[45714:674602] [Purchases] - DEBUG: ℹ️ Serial request done: POST receipts, 0 requests left in the queue
2022-10-07 11:08:02.735631-0700 BackendIntegrationTestsHostApp[45714:674399] [Purchases] - DEBUG: ℹ️ Sending updated CustomerInfo to delegate.
2022-10-07 11:08:02.735700-0700 BackendIntegrationTestsHostApp[45714:674399] [Purchases] - INFO: 💰 Finishing transaction '0' for product 'consumable.10_coins'
2022-10-07 11:08:02.760613-0700 BackendIntegrationTestsHostApp[45714:674592] [Purchases] - INFO: 😻 💰 Purchased product - 'consumable.10_coins'
2022-10-07 11:08:02.760828-0700 BackendIntegrationTestsHostApp[45714:674590] [Purchases] - DEBUG: ℹ️ Vending Offerings from cache
2022-10-07 11:08:02.761032-0700 BackendIntegrationTestsHostApp[45714:674590] [Purchases] - INFO: 💰 Purchasing Product 'consumable.10_coins' from package in Offering 'coins'
2022-10-07 11:08:02.820835-0700 BackendIntegrationTestsHostApp[45714:674589] [Purchases] - DEBUG: ℹ️ Force refreshing the receipt to get latest transactions from Apple.
2022-10-07 11:08:02.839184-0700 BackendIntegrationTestsHostApp[45714:674399] [Purchases] - DEBUG: ℹ️ Loaded receipt from url file:///Users/nachosoto/Library/Developer/CoreSimulator/Devices/F02A9A20-949B-4C9D-A01E-AB0CC7544F96/data/Containers/Data/Application/C52A5EFD-733F-46EC-84B7-734B6AF9D28C/StoreKit/receipt
2022-10-07 11:08:02.839275-0700 BackendIntegrationTestsHostApp[45714:674399] [Purchases] - DEBUG: ℹ️ Skipping products request because products were already cached. products: ["consumable.10_coins"]
2022-10-07 11:08:02.839348-0700 BackendIntegrationTestsHostApp[45714:674399] [Purchases] - DEBUG: ℹ️ Skipping products request because products were already cached. products: ["consumable.10_coins"]
2022-10-07 11:08:02.839476-0700 BackendIntegrationTestsHostApp[45714:674399] [Purchases] - DEBUG: ℹ️ Found 0 unsynced attributes for App User ID: $RCAnonymousID:bd74b9d10f2c48eea1d741a32f5acb16
2022-10-07 11:08:02.839911-0700 BackendIntegrationTestsHostApp[45714:674589] [Purchases] - DEBUG: ℹ️ PostReceiptDataOperation: Started
2022-10-07 11:08:02.840457-0700 BackendIntegrationTestsHostApp[45714:674589] [Purchases] - INFO: ℹ️ Receipt parsed successfully
2022-10-07 11:08:02.840603-0700 BackendIntegrationTestsHostApp[45714:674589] [Purchases] - DEBUG: ℹ️ PostReceiptDataOperation: Posting receipt: {
"opaque_value" : "fXr9\/QYAAAA=",
"sha1_hash" : "zreYwGKGSaOEww1bsTRu8MylAas=",
"bundle_id" : "com.revenuecat.StoreKitTestApp",
"in_app_purchases" : [
{
"quantity" : 1,
"product_id" : "consumable.10_coins",
"purchase_date" : "2022-10-07T18:08:02Z",
"transaction_id" : "1"
}
],
"application_version" : "1",
"creation_date" : "2022-10-07T18:08:02Z",
"expiration_date" : "4001-01-01T00:00:00Z"
}
2022-10-07 11:08:02.840662-0700 BackendIntegrationTestsHostApp[45714:674589] [Purchases] - DEBUG: ℹ️ There are no requests currently running, starting request POST receipts
2022-10-07 11:08:02.841268-0700 BackendIntegrationTestsHostApp[45714:674589] [Purchases] - DEBUG: ℹ️ API request started: POST /v1/receipts
2022-10-07 11:08:03.313116-0700 BackendIntegrationTestsHostApp[45714:674589] [Purchases] - DEBUG: ℹ️ API request completed: POST /v1/receipts 200
2022-10-07 11:08:03.316115-0700 BackendIntegrationTestsHostApp[45714:674589] [Purchases] - DEBUG: ℹ️ PostReceiptDataOperation: Finished
2022-10-07 11:08:03.316342-0700 BackendIntegrationTestsHostApp[45714:674589] [Purchases] - DEBUG: ℹ️ Serial request done: POST receipts, 0 requests left in the queue
2022-10-07 11:08:03.317444-0700 BackendIntegrationTestsHostApp[45714:674399] [Purchases] - DEBUG: ℹ️ Sending updated CustomerInfo to delegate.
2022-10-07 11:08:03.317527-0700 BackendIntegrationTestsHostApp[45714:674399] [Purchases] - INFO: 💰 Finishing transaction '1' for product 'consumable.10_coins'
2022-10-07 11:08:03.342767-0700 BackendIntegrationTestsHostApp[45714:674602] [Purchases] - INFO: 😻 💰 Purchased product - 'consumable.10_coins'
```
</details>
[TRIAGE-134]:
https://revenuecats.atlassian.net/browse/TRIAGE-134?atlOrigin=eyJpIjoiNWRkNTljNzYxNjVmNDY3MDlhMDU5Y2ZhYzA5YTRkZjUiLCJwIjoiZ2l0aHViLWNvbS1KU1cifQ
[TRIAGE-131]:
https://revenuecats.atlassian.net/browse/TRIAGE-131?atlOrigin=eyJpIjoiNWRkNTljNzYxNjVmNDY3MDlhMDU5Y2ZhYzA5YTRkZjUiLCJwIjoiZ2l0aHViLWNvbS1KU1cifQ
[TRIAGE-82]:
https://revenuecats.atlassian.net/browse/TRIAGE-82?atlOrigin=eyJpIjoiNWRkNTljNzYxNjVmNDY3MDlhMDU5Y2ZhYzA5YTRkZjUiLCJwIjoiZ2l0aHViLWNvbS1KU1cifQ
2022-10-11 13:38:54 -07:00
NachoSoto
29c034dfc8
Converted CustomerInfo and related types to use Codable ( #1496 )
...
### Depends on:
- #1537
- #1540
- #1541
- #1543
- #1546
- #1547
- #1550
- #1551 ,
- #1565
### Changes
- Removed all custom deserialization code thanks to #1537 , #1541 , and #1543 .
- The format of the customer info response is now very concise and only in one place (`CustomerInfoResponse`) instead of being passed through dictionaries and magic strings everywhere.
- `CustomerInfo` was combining the dictionaries inside of `"subscriptions"` and `"non_subscriptions"`, despite them having different formats. This is now made explicit through type conversions between the two, (see `CustomerInfoResponse.allTransactionsByProductId`).
- Removed all custom `CustomerInfo` errors since deserialization is automatic, and the underlying `Error` information will be provided thanks to `ErrorUtils.logDecodingError`.
- `CustomerInfo` deserialization always wraps errors into `ErrorCode.customerInfoError`, which is now also covered in a new test.
- Added a new snapshot test that covers `CustomerInfo` serialization by storing the result in a JSON file.
### Other changes:
- `CustomerInfo` equality is now automatic through the `CustomerInfoResponse` `Equatable` conformance.
- Simplified `schemaVersion` handling
- All tests still use `CustomerInfo(data: [String: Any])`, but that method is only visible for tests now, and it uses the underlying `Decodable` implementation (see `CustomerInfo+TestExtensions.swift`).
- Added extra tests for `CustomerInfoResponse` that use a fixture `CustomerInfo.json`, which is easier to maintain than having JSON in code.
- `RawDataContainer` implementation is changed in #1565 .
### TODO:
- [x] Fix all tests
- [x] Update `RawValueContainer`
- [x] Consider recovering `CustomerInfoError`
- [x] Look at all previously logged errors
- [x] Finish `CustomerInfoResponseTests`
- [x] Handle all TODOs
- [x] Make `RawDataContainer` actually store all the original data: #1565
2022-05-24 14:22:11 -07:00
NachoSoto