Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

StoreKitIntegrationTests: print AppleReceipt data whenever verifyEntitlementWentThrough fails #1929

Merged
merged 4 commits into from
Sep 21, 2022

Conversation

NachoSoto
Copy link
Contributor

@NachoSoto NachoSoto commented Sep 21, 2022

This will help us debug flaky tests.

Example:

INFO: 😻💰 Purchased product - 'com.revenuecat.monthly_4.99.1_week_intro'
DEBUG: ℹ️ Force refreshing the receipt to get latest transactions from Apple.
DEBUG: ℹ️ Loaded receipt from url file:///Users/nachosoto/Library/Developer/CoreSimulator/Devices/A3576DC2-355E-45BA-B32C-D2C0A3811BB4/data/Containers/Data/Application/EDF3B7C8-A4BD-4629-813E-0934528AF02E/StoreKit/receipt
INFO: ℹ️ Receipt parsed successfully
INFO: ℹ️ Receipt content:
["inAppPurchases": [], "creationDate": 2022-09-21 21:00:07 +0000, "opaqueValue": 8 bytes, "applicationVersion": "1", "originalApplicationVersion": "", "bundleId": "com.revenuecat.StoreKitTestApp", "expirationDate": 4001-01-01 00:00:00 +0000, "sha1Hash": 20 bytes]
/Users/nachosoto/dev/purchases-ios/Tests/BackendIntegrationTests/StoreKitIntegrationTests.swift:64: error: -[BackendIntegrationTests.StoreKit2IntegrationTests testCanPurchaseProduct] : failed - Expected Entitlement. Got: [:]
expected to have Dictionary<String, EntitlementInfo> with count 1, got 0
Actual Value: [:]

I've also added the receipt as a test attachment so we can download it from CircleCI:

Screenshot 2022-09-21 at 14 33 01

…yEntitlementWentThrough` fails

This will help us debug flaky tests.
Example:
> INFO: 😻💰 Purchased product - 'com.revenuecat.monthly_4.99.1_week_intro'
DEBUG: ℹ️ Force refreshing the receipt to get latest transactions from Apple.
DEBUG: ℹ️ Loaded receipt from url file:///Users/nachosoto/Library/Developer/CoreSimulator/Devices/A3576DC2-355E-45BA-B32C-D2C0A3811BB4/data/Containers/Data/Application/EDF3B7C8-A4BD-4629-813E-0934528AF02E/StoreKit/receipt
INFO: ℹ️ Receipt parsed successfully
INFO: ℹ️ Receipt content:
["inAppPurchases": [], "creationDate": 2022-09-21 21:00:07 +0000, "opaqueValue": 8 bytes, "applicationVersion": "1", "originalApplicationVersion": "<unknown>", "bundleId": "com.revenuecat.StoreKitTestApp", "expirationDate": 4001-01-01 00:00:00 +0000, "sha1Hash": 20 bytes]
/Users/nachosoto/dev/purchases-ios/Tests/BackendIntegrationTests/StoreKitIntegrationTests.swift:64: error: -[BackendIntegrationTests.StoreKit2IntegrationTests testCanPurchaseProduct] : failed - Expected Entitlement. Got: [:]
expected to have Dictionary<String, EntitlementInfo> with count 1, got 0
Actual Value: [:]
@NachoSoto NachoSoto added the test label Sep 21, 2022
@NachoSoto NachoSoto requested review from aboedo and a team September 21, 2022 21:05
Comment on lines +1054 to +1058
#if DEBUG

/// - Returns: the parsed `AppleReceipt`
///
/// - Warning: this is only meant for integration tests, as a way to debug purchase failures.
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

❤️

I think this would be a useful thing to have in general with #if debug and just post it to debug logs.
I bet it would save us a ton of work debugging customer issues

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

we could have it print whenever a transaction goes through

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I thought about that. Are you not worried about performance implications of forcing a receipt refresh and parsing every time?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Not too worried about it for debug builds.
The refresh part we wouldn't really need to do, we'd just parse whatever we're about to send the backend.
And the parsing is pretty fast in my experience. Haven't tested it again in a while, but the parser goes through the receipt only once, and leverages array slices to ensure we're not copying chunks of the receipt to different places to memory.

The loading of the file from disk is probably the heaviest bit, and that's already done once, we could reuse it.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Makes sense, so you'd change ReceiptRefreshPolicy to .onlyIfEmpty or .never?

Let me merge this, and I'll open a separate PR for that change.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[CSDK-478]

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done in #1940. Instead of #if DEBUG I've checked if Logger.logLevel == .debug so that it can always be enabled if needed.

@NachoSoto NachoSoto force-pushed the integration-test-failure-print-receipt branch from 83407b4 to 328633f Compare September 21, 2022 21:30
@NachoSoto NachoSoto force-pushed the integration-test-failure-print-receipt branch from 328633f to f5baa1b Compare September 21, 2022 21:33
@NachoSoto NachoSoto merged commit c4cfdb1 into main Sep 21, 2022
@NachoSoto NachoSoto deleted the integration-test-failure-print-receipt branch September 21, 2022 21:56
NachoSoto added a commit that referenced this pull request Sep 27, 2022
**This is an automatic release.**

### New Features
* 🚨 `StoreKit 2` is now enabled by default 🚨 (#1922) via NachoSoto
(@NachoSoto)
* Extracted `PurchasesType` and `PurchasesSwiftType` (#1912) via
NachoSoto (@NachoSoto)
### Bugfixes
* `StoreKit 1`: changed result of cancelled purchases to be consistent
with `StoreKit 2` (#1910) via NachoSoto (@NachoSoto)
* `PaymentQueueWrapper`: handle promotional purchase requests from App
Store when SK1 is disabled (#1901) via NachoSoto (@NachoSoto)
### Other Changes
* Fixed iOS 12 tests (#1936) via NachoSoto (@NachoSoto)
* `CacheableNetworkOperation`: fixed race condition in new test (#1932)
via NachoSoto (@NachoSoto)
* `BasePurchasesTests`: changed default back to SK1 (#1935) via
NachoSoto (@NachoSoto)
* `Logger`: refactored default `LogLevel` definition (#1934) via
NachoSoto (@NachoSoto)
* `AppleReceipt`: refactored declarations into nested types (#1933) via
NachoSoto (@NachoSoto)
* `Integration Tests`: relaunch tests when retrying failures (#1925) via
NachoSoto (@NachoSoto)
* `CircleCI`: downgraded release jobs to Xcode 13.x (#1927) via
NachoSoto (@NachoSoto)
* `ErrorUtils`: added test to verify that `PublicError`s can be
`catch`'d as `ErrorCode` (#1924) via NachoSoto (@NachoSoto)
* `StoreKitIntegrationTests`: print `AppleReceipt` data whenever
`verifyEntitlementWentThrough` fails (#1929) via NachoSoto (@NachoSoto)
* `OperationQueue`: log debug message when requests are found in cache
and skipped (#1926) via NachoSoto (@NachoSoto)
* `GetCustomerInfoAPI`: avoid making a request if there's any
`PostReceiptDataOperation` in progress (#1911) via NachoSoto
(@NachoSoto)
* `PurchaseTester`: allow HTTP requests and enable setting `ProxyURL`
(#1917) via NachoSoto (@NachoSoto)
NachoSoto added a commit that referenced this pull request Sep 27, 2022
NachoSoto added a commit that referenced this pull request Sep 27, 2022
…abled (#1940)

For [CSDK-478].
Follow up to #1929.

### Example:
> DEBUG: ℹ️ PostReceiptDataOperation: Started
INFO: ℹ️ Receipt parsed successfully
DEBUG: ℹ️ PostReceiptDataOperation: Posting receipt: {
  "opaque_value" : "Rn\/39QYAAAA=",
  "sha1_hash" : "Ii8Z7ocZm524eJcWFOvVauNrNHs=",
  "bundle_id" : "com.revenuecat.StoreKitTestApp",
  "in_app_purchases" : [
    {
      "quantity" : 1,
      "product_id" : "com.revenuecat.monthly_4.99.1_week_intro",
      "purchase_date" : "2022-09-27T19:09:47Z",
      "transaction_id" : "0",
      "is_in_intro_offer_period" : true,
      "expires_date" : "2022-09-27T19:09:57Z"
    }
  ],
  "application_version" : "1",
  "creation_date" : "2022-09-27T19:09:47Z",
  "expiration_date" : "4001-01-01T00:00:00Z"
}
DEBUG: ℹ️ There are no requests currently running, starting request POST
receipts
DEBUG: ℹ️ API request started: POST /v1/receipts
DEBUG: ℹ️ API request completed: POST /v1/receipts 200
DEBUG: ℹ️ PostReceiptDataOperation: Finished
DEBUG: ℹ️ Serial request done: POST receipts, 0 requests left in the
queue
DEBUG: ℹ️ Sending updated CustomerInfo to delegate.
INFO: 😻💰 Purchased product - 'com.revenuecat.monthly_4.99.1_week_intro'
INFO: 💰 Finishing transaction com.revenuecat.monthly_4.99.1_week_intro 0
()

[CSDK-478]:
https://revenuecats.atlassian.net/browse/CSDK-478?atlOrigin=eyJpIjoiNWRkNTljNzYxNjVmNDY3MDlhMDU5Y2ZhYzA5YTRkZjUiLCJwIjoiZ2l0aHViLWNvbS1KU1cifQ
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants