Skip to content

Logging: avoid logging "updating offerings" when request is cached#2904

Merged
NachoSoto merged 1 commit into
mainfrom
offerings-log-once
Aug 8, 2023
Merged

Logging: avoid logging "updating offerings" when request is cached#2904
NachoSoto merged 1 commit into
mainfrom
offerings-log-once

Conversation

@NachoSoto

Copy link
Copy Markdown
Contributor

I noticed this in our logs:

[offering] DEBUG: ℹ️ No cached Offerings, fetching from network
[purchases] VERBOSE: Updating all caches
[offering] DEBUG: ℹ️ Offerings cache is stale, updating from network in foreground
[offering] DEBUG: ℹ️ Offerings cache is stale, updating from network in foreground
[network] DEBUG: ℹ️ Network operation 'GetOfferingsOperation' found with the same cache key 'GetOfferingsOpe...'. Skipping request.
[network] DEBUG: ℹ️ GetOfferingsOperation: Started

The double "updating from network" can be confusing, so this fixes it so it's only logged if the request will actually be started. Also added/updated our tests to verify the correct logs as well as caching behavior.

@NachoSoto NachoSoto requested a review from aboedo July 26, 2023 17:14
@NachoSoto

Copy link
Copy Markdown
Contributor Author

@aboedo sorry I merged #2896 too early. Do you mind approving this again? 😇

@NachoSoto NachoSoto force-pushed the nacho/sdk-3243-422s-fix-bug-where-transactions-are-misidentified-as branch from f1e9ecb to cc0f2f2 Compare July 27, 2023 10:31
@NachoSoto NachoSoto force-pushed the offerings-log-once branch from 25346af to ff1e7be Compare July 31, 2023 09:37
@NachoSoto NachoSoto changed the base branch from nacho/sdk-3243-422s-fix-bug-where-transactions-are-misidentified-as to main July 31, 2023 09:37
@NachoSoto NachoSoto changed the base branch from main to nacho/sdk-3243-422s-fix-bug-where-transactions-are-misidentified-as July 31, 2023 13:45
@NachoSoto NachoSoto force-pushed the offerings-log-once branch from ff1e7be to 081dad7 Compare July 31, 2023 13:46
@codecov

codecov Bot commented Jul 31, 2023

Copy link
Copy Markdown

Codecov Report

Merging #2904 (081dad7) into main (8ac59d0) will decrease coverage by 0.06%.
Report is 2 commits behind head on main.
The diff coverage is 92.50%.

❗ Current head 081dad7 differs from pull request most recent head 49befff. Consider uploading reports for the commit 49befff to get more accurate results

@@            Coverage Diff             @@
##             main    #2904      +/-   ##
==========================================
- Coverage   86.65%   86.59%   -0.06%     
==========================================
  Files         218      217       -1     
  Lines       15559    15536      -23     
==========================================
- Hits        13482    13453      -29     
- Misses       2077     2083       +6     
Files Changed Coverage Δ
...s/LocalReceiptParsing/Helpers/ReceiptStrings.swift 84.28% <50.00%> (ø)
...s/Purchasing/Purchases/PurchasesOrchestrator.swift 87.40% <91.30%> (-0.04%) ⬇️
Sources/Logging/Strings/PurchaseStrings.swift 89.28% <100.00%> (+0.04%) ⬆️
Sources/Networking/OfferingsAPI.swift 100.00% <100.00%> (ø)
...tworking/Operations/PostReceiptDataOperation.swift 92.76% <100.00%> (+0.14%) ⬆️
Sources/Purchasing/OfferingsManager.swift 93.44% <100.00%> (-0.11%) ⬇️
...ing/StoreKitAbstractions/SK1StoreTransaction.swift 100.00% <100.00%> (ø)

... and 6 files with indirect coverage changes

@NachoSoto NachoSoto force-pushed the nacho/sdk-3243-422s-fix-bug-where-transactions-are-misidentified-as branch 4 times, most recently from 3dc2c5b to c2e8da0 Compare August 7, 2023 22:40
Base automatically changed from nacho/sdk-3243-422s-fix-bug-where-transactions-are-misidentified-as to main August 7, 2023 22:57
I noticed this in our logs:
```
[offering] DEBUG: ℹ️ No cached Offerings, fetching from network
[purchases] VERBOSE: Updating all caches
[offering] DEBUG: ℹ️ Offerings cache is stale, updating from network in foreground
[offering] DEBUG: ℹ️ Offerings cache is stale, updating from network in foreground
[network] DEBUG: ℹ️ Network operation 'GetOfferingsOperation' found with the same cache key 'GetOfferingsOpe...'. Skipping request.
[network] DEBUG: ℹ️ GetOfferingsOperation: Started
```

The double "updating from network" can be confusing, so this fixes it so it's only logged if the request will actually be started.
Also added/updated our tests to verify the correct logs as well as caching behavior.
@NachoSoto NachoSoto force-pushed the offerings-log-once branch from 081dad7 to 49befff Compare August 7, 2023 23:16
@NachoSoto NachoSoto enabled auto-merge (squash) August 7, 2023 23:16
@NachoSoto NachoSoto merged commit def42cc into main Aug 8, 2023
@NachoSoto NachoSoto deleted the offerings-log-once branch August 8, 2023 00:35
NachoSoto added a commit that referenced this pull request Aug 9, 2023
_This release is compatible with Xcode 15 beta 6 and visionOS beta 3_

### Bugfixes
* `visionOS`: support for `Xcode 15 beta 6` (#2989) via NachoSoto
(@NachoSoto)
* `CachingProductsManager`: avoid crash when caching different products
with same identifier (#2979) via NachoSoto (@NachoSoto)
* `PurchasesOrchestrator`: disambiguate transactions from the queue
(#2890) via NachoSoto (@NachoSoto)
### Performance Improvements
* `StoreKit2TransactionListener`: handle transactions asynchronously
(#2910) via NachoSoto (@NachoSoto)
### Other Changes
* `Atomic`: avoid race conditions modifying dictionaries (#2981) via
NachoSoto (@NachoSoto)
* `Logging`: avoid logging "updating offerings" when request is cached
(#2904) via NachoSoto (@NachoSoto)
* `StoreKit2TransactionListener`: converted into an `actor` (#2909) via
NachoSoto (@NachoSoto)
* `Integration Tests`: added more observer mode tests (#2905) via
NachoSoto (@NachoSoto)
* Created `PostedTransactionCache` (#2911) via NachoSoto (@NachoSoto)
* `IntroEligibility`: changed products to `Set<String>` (#2976) via
NachoSoto (@NachoSoto)
* `AdServices`: Rename `postAdServicesTokenIfNeeded()` to
`postAdServicesTokenOncePerInstallIfNeeded()` (#2968) via Josh Holtz
(@joshdholtz)
* `SK1StoreProduct`: changed `productType` warning to debug (#2957) via
NachoSoto (@NachoSoto)
* `PrivacyInfo.xcprivacy`: added `UserDefaults` to access API types
(#2913) via NachoSoto (@NachoSoto)
* `Integration Tests`: new test to verify that SK1 purchases don't leave
SK2 unfinished transactions (#2906) via NachoSoto (@NachoSoto)
* `Logging`: log entire cache key with verbose logs (#2888) via
NachoSoto (@NachoSoto)
* `StoreProduct`: added test covering warning log (#2897) via NachoSoto
(@NachoSoto)
* `CustomEntitlementComputation`: use custom API key (#2879) via Toni
Rico (@tonidero)
* `CachingProductsManager`: removed duplicate log and added tests
(#2898) via NachoSoto (@NachoSoto)
* `Xcode 15 beta 5`: fixed test compilation (#2885) via NachoSoto
(@NachoSoto)

---------

Co-authored-by: NachoSoto <ignaciosoto90@gmail.com>
MarkVillacampa pushed a commit that referenced this pull request Sep 6, 2023
…2904)

I noticed this in our logs:
```
[offering] DEBUG: ℹ️ No cached Offerings, fetching from network
[purchases] VERBOSE: Updating all caches
[offering] DEBUG: ℹ️ Offerings cache is stale, updating from network in foreground
[offering] DEBUG: ℹ️ Offerings cache is stale, updating from network in foreground
[network] DEBUG: ℹ️ Network operation 'GetOfferingsOperation' found with the same cache key 'GetOfferingsOpe...'. Skipping request.
[network] DEBUG: ℹ️ GetOfferingsOperation: Started
```

The double "updating from network" can be confusing, so this fixes it so
it's only logged if the request will actually be started. Also
added/updated our tests to verify the correct logs as well as caching
behavior.
MarkVillacampa pushed a commit that referenced this pull request Sep 6, 2023
_This release is compatible with Xcode 15 beta 6 and visionOS beta 3_

### Bugfixes
* `visionOS`: support for `Xcode 15 beta 6` (#2989) via NachoSoto
(@NachoSoto)
* `CachingProductsManager`: avoid crash when caching different products
with same identifier (#2979) via NachoSoto (@NachoSoto)
* `PurchasesOrchestrator`: disambiguate transactions from the queue
(#2890) via NachoSoto (@NachoSoto)
### Performance Improvements
* `StoreKit2TransactionListener`: handle transactions asynchronously
(#2910) via NachoSoto (@NachoSoto)
### Other Changes
* `Atomic`: avoid race conditions modifying dictionaries (#2981) via
NachoSoto (@NachoSoto)
* `Logging`: avoid logging "updating offerings" when request is cached
(#2904) via NachoSoto (@NachoSoto)
* `StoreKit2TransactionListener`: converted into an `actor` (#2909) via
NachoSoto (@NachoSoto)
* `Integration Tests`: added more observer mode tests (#2905) via
NachoSoto (@NachoSoto)
* Created `PostedTransactionCache` (#2911) via NachoSoto (@NachoSoto)
* `IntroEligibility`: changed products to `Set<String>` (#2976) via
NachoSoto (@NachoSoto)
* `AdServices`: Rename `postAdServicesTokenIfNeeded()` to
`postAdServicesTokenOncePerInstallIfNeeded()` (#2968) via Josh Holtz
(@joshdholtz)
* `SK1StoreProduct`: changed `productType` warning to debug (#2957) via
NachoSoto (@NachoSoto)
* `PrivacyInfo.xcprivacy`: added `UserDefaults` to access API types
(#2913) via NachoSoto (@NachoSoto)
* `Integration Tests`: new test to verify that SK1 purchases don't leave
SK2 unfinished transactions (#2906) via NachoSoto (@NachoSoto)
* `Logging`: log entire cache key with verbose logs (#2888) via
NachoSoto (@NachoSoto)
* `StoreProduct`: added test covering warning log (#2897) via NachoSoto
(@NachoSoto)
* `CustomEntitlementComputation`: use custom API key (#2879) via Toni
Rico (@tonidero)
* `CachingProductsManager`: removed duplicate log and added tests
(#2898) via NachoSoto (@NachoSoto)
* `Xcode 15 beta 5`: fixed test compilation (#2885) via NachoSoto
(@NachoSoto)

---------

Co-authored-by: NachoSoto <ignaciosoto90@gmail.com>
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