Skip to content

Added verbose logs for Purchases and StoreKit1Wrapper lifetime#2082

Merged
NachoSoto merged 1 commit into
mainfrom
init-logs
Nov 26, 2022
Merged

Added verbose logs for Purchases and StoreKit1Wrapper lifetime#2082
NachoSoto merged 1 commit into
mainfrom
init-logs

Conversation

@NachoSoto

@NachoSoto NachoSoto commented Nov 23, 2022

Copy link
Copy Markdown
Contributor

Depends on #2080.
This will help debug CSDK-517.

Examples:

- VERBOSE: Purchases.init: created new Purchases instance: Purchases (0x00006000037af800)
StoreKit Wrapper: left(<RevenueCat.StoreKit1Wrapper: 0x600000b6d3a0>)
- VERBOSE: Purchases.deinit: Purchases (0x0000600003f82600)

@NachoSoto NachoSoto added the test label Nov 23, 2022
@NachoSoto NachoSoto requested a review from a team November 23, 2022 17:14
@NachoSoto NachoSoto changed the title Added verbose logs for Purchases and StoreKit1Wrapper Added verbose logs for Purchases and StoreKit1Wrapper lifetime Nov 23, 2022
Base automatically changed from verbose-log-level to main November 26, 2022 00:56
Depends on #2080.
This will help debug [CSDK-517].

### Examples:
```
- VERBOSE: Purchases.init: created new Purchases instance: Purchases (0x00006000037af800)
StoreKit Wrapper: left(<RevenueCat.StoreKit1Wrapper: 0x600000b6d3a0>)
- VERBOSE: Purchases.deinit: Purchases (0x0000600003f82600)
```
@NachoSoto NachoSoto enabled auto-merge (squash) November 26, 2022 01:00
@NachoSoto NachoSoto merged commit de84ccd into main Nov 26, 2022
@NachoSoto NachoSoto deleted the init-logs branch November 26, 2022 01:09
NachoSoto added a commit that referenced this pull request Nov 29, 2022
Equivalent to #2082.
This change will help continue debugging [CSDK-517].

While debugging locally I ran into this crash:
```
Test Case '-[StoreKitUnitTests.UserDefaultsDefaultTests testDefaultIsRevenueCatSuiteIfStandardDoesNotContainUserID]' started.
RevenueCat/DeviceCache.swift:85: Fatal error: [Purchases] - Cached appUserID has been deleted from user defaults.
This leaves the SDK in an undetermined state. Please make sure that RevenueCat
entries in user defaults don't get deleted by anything other than the SDK.
More info: https://rev.cat/userdefaults-crash
```

But that should have been impossible because the current test had not initialized `Purchases` or `DeviceCache`, which showed that there was a leaking `DeviceCache` from another test.
NachoSoto added a commit that referenced this pull request Dec 20, 2022
…tances in memory

We allow calling `Purchases.configure` multiple times. Likely a programmer error, but it's common in tests, or for example in `Purchase Tester` where users can re-configure the SDK at runtime (#1999).
When this happens, the SDK was creating the new instance before clearing the old one from memory (clear thanks to #2082, notice how the first `deinit` happens after the second `init`):
```
[Purchases] - VERBOSE: Purchases.init: created new Purchases instance: Purchases (0x0000600003ca4200)
[Purchases] - INFO: ℹ️ Purchases instance already set. Did you mean to configure two Purchases objects?
[Purchases] - VERBOSE: Purchases.init: created new Purchases instance: Purchases (0x0000600003c8a100)
[Purchases] - VERBOSE: Purchases.deinit: Purchases (0x0000600003ca4200)
[Purchases] - VERBOSE: Purchases.deinit: Purchases (0x0000600003c8a100)
```

With this change, we avoid that, which could also avoid issues with concurrent requests ([CSDK-517]):
```
[Purchases] - VERBOSE: Purchases.init: created new Purchases instance: Purchases (0x0000600002b6e600)
[Purchases] - INFO: ℹ️ Purchases instance already set. Did you mean to configure two Purchases objects?
[Purchases] - VERBOSE: Purchases.deinit: Purchases (0x0000600002b6e600)
[Purchases] - VERBOSE: Purchases.init: created new Purchases instance: Purchases (0x0000600002b68100)
[Purchases] - VERBOSE: Purchases.deinit: Purchases (0x0000600002b68100)
```
NachoSoto added a commit that referenced this pull request Dec 21, 2022
…tances in memory (#2180)

We allow calling `Purchases.configure` multiple times. Likely a
programmer error, but it's common in tests, or for example in `Purchase
Tester` where users can re-configure the SDK at runtime (#1999), which
is where I saw this issue.

When this happens, the SDK was creating the new instance before clearing
the old one from memory (clear thanks to #2082). Notice how the first
`deinit` happens **after** the second `init`:
```
[Purchases] - VERBOSE: Purchases.init: created new Purchases instance: Purchases (0x0000600003ca4200)
[Purchases] - INFO: ℹ️ Purchases instance already set. Did you mean to configure two Purchases objects?
[Purchases] - VERBOSE: Purchases.init: created new Purchases instance: Purchases (0x0000600003c8a100)
[Purchases] - VERBOSE: Purchases.deinit: Purchases (0x0000600003ca4200)
[Purchases] - VERBOSE: Purchases.deinit: Purchases (0x0000600003c8a100)
```

With this change, we avoid that, which could also avoid issues with
concurrent requests ([CSDK-517]):
```
[Purchases] - VERBOSE: Purchases.init: created new Purchases instance: Purchases (0x0000600002b6e600)
[Purchases] - INFO: ℹ️ Purchases instance already set. Did you mean to configure two Purchases objects?
[Purchases] - VERBOSE: Purchases.deinit: Purchases (0x0000600002b6e600)
[Purchases] - VERBOSE: Purchases.init: created new Purchases instance: Purchases (0x0000600002b68100)
[Purchases] - VERBOSE: Purchases.deinit: Purchases (0x0000600002b68100)
```

Unfortunately we don't have an easy way to test this, especially
considering that we prohibit multiple instances in tests (#2100).

[CSDK-517]:
https://revenuecats.atlassian.net/browse/CSDK-517?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.

3 participants