Add missing logs to ProductsFetcherSK2 #1780

beylmk · 2022-07-28T15:14:11Z

While investigating #1765, I noticed logs between the ProductsFetcherSK1 and ProductsFetcherSK2 don't match, causing confusion. This PR adds some missing logs to ProductsFetcherSK2

beylmk · 2022-07-28T15:23:41Z

Sources/Purchasing/StoreKit2/ProductsFetcherSK2.swift

                return cachedProducts
            }
+
+            Logger.debug(
+                Strings.offering.no_cached_requests_and_products_starting_skproduct_request(identifiers: identifiers)


this one doesn't perfectly translate, since we don't cache requests for sk2....maybe we should?

maybe we should?

It's not trivial with async, I think that's why we don't do it.

The "no cached requests" part of the message isn't a big deal, but the latter part of the message would be weird here:

starting SKProducts request for

Since that's SK1. So maybe it makes sense to add a new string?

…gLevel` is disabled I realized in #1780 that we might be doing unnecessary work creating messages that are never logged. This is a small optimization to prevent that.

NachoSoto

Thanks for doing this!

NachoSoto · 2022-07-28T15:24:59Z

Sources/Purchasing/StoreKit2/ProductsFetcherSK2.swift

@@ -29,10 +29,17 @@ actor ProductsFetcherSK2 {
    func products(identifiers: Set<String>) async throws -> Set<SK2StoreProduct> {
        do {
            if let cachedProducts = await self.cachedProducts(withIdentifiers: identifiers) {
+                let cachedIdentifiers = Set(cachedProducts.map { $0.productIdentifier })
+                Logger.debug(Strings.offering.products_already_cached(identifiers: cachedIdentifiers))


NachoSoto · 2022-07-28T15:32:48Z

Sources/Purchasing/StoreKit2/ProductsFetcherSK2.swift

+                let cachedIdentifiers = Set(cachedProducts.map { $0.productIdentifier })
+                Logger.debug(Strings.offering.products_already_cached(identifiers: cachedIdentifiers))


I was thinking that creating this Set was unnecessary if debug logs are disabled.
I just submitted #1781 to improve this.
To avoid creating this Set unnecessarily I would inline this:

Suggested change

let cachedIdentifiers = Set(cachedProducts.map { $0.productIdentifier })

Logger.debug(Strings.offering.products_already_cached(identifiers: cachedIdentifiers))

Logger.debug(Strings.offering.products_already_cached(identifiers:

Set(cachedProducts.map { $0.productIdentifier })

))

NachoSoto · 2022-07-28T15:34:55Z

Sources/Purchasing/StoreKit2/ProductsFetcherSK2.swift

                return cachedProducts
            }
+
+            Logger.debug(
+                Strings.offering.no_cached_requests_and_products_starting_skproduct_request(identifiers: identifiers)


maybe we should?

It's not trivial with async, I think that's why we don't do it.

The "no cached requests" part of the message isn't a big deal, but the latter part of the message would be weird here:

starting SKProducts request for

Since that's SK1. So maybe it makes sense to add a new string?

NachoSoto · 2022-07-28T15:35:37Z

Sources/Purchasing/StoreKit2/ProductsFetcherSK2.swift

            let storeKitProducts = try await StoreKit.Product.products(for: identifiers)
+            Logger.rcSuccess(Strings.storeKit.skproductsrequest_received_response)


Ditto here. Alternatively we could change these strings to be agnostic of the types? So something like "product request received response", etc.

well we do have a completion handler up the call chain in ProductsManager.sk2Products:

func sk2Products(withIdentifiers identifiers: Set<String>, completion: @escaping (Result<Set<SK2StoreProduct>, Error>) -> Void)

...so we could theoretically hold a map of identifiers -> handlers there like ProductsFetcherSK1 does 🤷

…cussion

beylmk · 2022-07-28T17:24:04Z

Sources/Purchasing/ProductsManager.swift

@@ -119,9 +121,11 @@ private extension ProductsManager {
            productsFetcherSK1.products(withIdentifiers: removedProductIdentifiers, completion: { result in
                switch result {
                case.success:
-                    Logger.debug(Strings.storeKit.skproductsrequest_finished)
+                    // this one is duplicate, though other in ProductsFetcherSK1 is rcSuccess


options i see are:
*. remove duplication -- need to look into hierarchy of logging, when would rcSuccess happen vs debug?

ensure sk2 has the same duplication

I don't think we've looked into these logs very much in detail, so this refactor is great 👍🏻

rcSuccess is just a success LogIntent, but still LogLevel.debug. I think that's good for these success cases.

beylmk · 2022-07-28T21:58:51Z

@NachoSoto comments should be addressed, except for a couple open conversations... curious what you think about:

caching the callbacks for sk2 products requests
those log duplications...left comments for discussion

NachoSoto

I think this is good, looks like the only 2 things left:

Don't mention SKProduct in SK2
Consistent debug / success / error calls.

NachoSoto · 2022-07-28T22:00:14Z

Sources/Logging/Strings/StoreKitStrings.swift


        case .skproductsrequest_timed_out(let afterTimeInSeconds):
            return "SKProductsRequest took longer than \(afterTimeInSeconds) seconds, " +
            "cancelling request and returning an empty set. This seems to be an App Store quirk. " +
            "If this is happening to you consistently, you might want to try using a new Sandbox account. " +
            "More information: https://rev.cat/skproductsrequest-hangs"

-        case .skproductsrequest_finished:
+        case .store_product_request_did_finish:
            return "SKProductsRequest did finish"


This can change as well:

Suggested change

return "SKProductsRequest did finish"

return "Store product request did finish"

NachoSoto · 2022-07-28T22:00:45Z

Sources/Logging/Strings/StoreKitStrings.swift

+
+        case .no_cached_requests_and_products_starting_skproduct_request(let identifiers):
+            return "No existing requests and " +
+                "products not cached, starting SKProducts request for: \(identifiers)"


Ditto, you're still using this in SK2, maybe change it to Store product request?

was leaving this one in case we decided to cache requests... might be worth a different string until we decide to cache

We cache products, just not concurrent requests, which might be good enough?

NachoSoto · 2022-07-28T22:01:52Z

Sources/Purchasing/ProductsManager.swift

@@ -119,9 +121,11 @@ private extension ProductsManager {
            productsFetcherSK1.products(withIdentifiers: removedProductIdentifiers, completion: { result in
                switch result {
                case.success:
-                    Logger.debug(Strings.storeKit.skproductsrequest_finished)
+                    // this one is duplicate, though other in ProductsFetcherSK1 is rcSuccess


I don't think we've looked into these logs very much in detail, so this refactor is great 👍🏻

rcSuccess is just a success LogIntent, but still LogLevel.debug. I think that's good for these success cases.

NachoSoto · 2022-07-28T22:02:08Z

Sources/Purchasing/ProductsManager.swift

                case .failure(let error):
-                    Logger.debug(Strings.storeKit.skproductsrequest_failed(error: error))
+                    // this one is duplicate, though other in ProductsFetcherSK1 is appleError


Yeah I'd say this one should be appleError too.

NachoSoto · 2022-07-28T22:03:55Z

Sources/Purchasing/ProductsManager.swift

@@ -119,9 +121,11 @@ private extension ProductsManager {
            productsFetcherSK1.products(withIdentifiers: removedProductIdentifiers, completion: { result in
                switch result {
                case.success:


Hun looks like this is missing a space?

Suggested change

case.success:

case .success:

…gLevel` is disabled (#1781) I realized in #1780 that we might be doing unnecessary work creating messages that are never logged. This is a small optimization to prevent that.

NachoSoto · 2022-08-01T21:38:12Z

Sources/Logging/Strings/StoreKitStrings.swift

-        case .skproductsrequest_failed(let error):
-            return "SKProductsRequest failed! error: \(error.localizedDescription)"
+        case .store_products_request_failed(let error):
+            return "Store products request failed! error: \(error.localizedDescription)"


Nit:

Suggested change

return "Store products request failed! error: \(error.localizedDescription)"

return "Store products request failed! Error: \(error.localizedDescription)"

NachoSoto · 2022-08-01T21:38:42Z

Sources/Purchasing/ProductsManager.swift

                } catch {
-                    Logger.debug(Strings.storeKit.skproductsrequest_failed(error: error))
+                    Logger.debug(Strings.storeKit.store_products_request_failed(error: error))


Nit: For consistency I'd keep the "finished" wording, or change this to did_fail as well.

sorry, i'm lost, which finished wording?

store_products_request_failed vs store_product_request_did_finish vs store_product_request_received_response.
I would use "did {fail/finish/receive}" for all, or the past tense, for consistency.

Just mentioning that since you changed skproductsrequest_finished to store_product_request_did_finish

oh got it, i was looking for "finished" in that string you commented on. monday brain, thanks

Add logs for parity with ProductsFetcherSK1

55a91d0

beylmk requested a review from a team July 28, 2022 15:14

beylmk changed the title ~~Add logs for parity with ProductsFetcherSK1~~ Add missing logs to ProductsFetcherSK2 Jul 28, 2022

beylmk commented Jul 28, 2022

View reviewed changes

add missing log about cached products

31b7005

beylmk force-pushed the sk2-products-fetcher-logs branch from 805b8a6 to 31b7005 Compare July 28, 2022 15:27

NachoSoto mentioned this pull request Jul 28, 2022

Logger: wrap message in @autoclosure to avoid creating when LogLevel is disabled #1781

Merged

NachoSoto reviewed Jul 28, 2022

View reviewed changes

Maddie Beyl added 3 commits July 28, 2022 13:13

Make products request strings storefront-agnostic

965d85a

pull skproducts request string to storekit strings

ac73aae

Fix for lint, add two more missing logs for sk2, add comments for dis…

7713332

…cussion

beylmk commented Jul 28, 2022

View reviewed changes

Maddie Beyl added 2 commits July 28, 2022 13:29

lint fix

8eff1fd

Merge branch 'main' into sk2-products-fetcher-logs

c7c6f99

NachoSoto reviewed Jul 28, 2022

View reviewed changes

Maddie Beyl added 2 commits August 1, 2022 15:24

Merge branch 'main' into sk2-products-fetcher-logs

20abf07

Update last couple skproduct-specific strings, remove duplicate logs

159a388

NachoSoto approved these changes Aug 1, 2022

View reviewed changes

Maddie Beyl added 2 commits August 1, 2022 16:50

Fix casing

8109ee8

quick string updates

9fcbd95

beylmk merged commit 33840f6 into main Aug 1, 2022

beylmk deleted the sk2-products-fetcher-logs branch August 1, 2022 22:15

vegaro added the pr:fix A bug fix label Aug 5, 2022

This was referenced Aug 8, 2022

Release/4.10.0 #1799

Closed

Release/4.10.0 #1800

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add missing logs to ProductsFetcherSK2 #1780

Add missing logs to ProductsFetcherSK2 #1780

beylmk commented Jul 28, 2022

beylmk Jul 28, 2022

NachoSoto Jul 28, 2022

NachoSoto left a comment

NachoSoto Jul 28, 2022

NachoSoto Jul 28, 2022

NachoSoto Jul 28, 2022

NachoSoto Jul 28, 2022

beylmk Jul 28, 2022 •

edited

Loading

beylmk Jul 28, 2022

NachoSoto Jul 28, 2022

beylmk commented Jul 28, 2022

NachoSoto left a comment

NachoSoto Jul 28, 2022

NachoSoto Jul 28, 2022

beylmk Jul 29, 2022

NachoSoto Jul 29, 2022

NachoSoto Jul 28, 2022

NachoSoto Jul 28, 2022

NachoSoto Jul 28, 2022

NachoSoto Aug 1, 2022

NachoSoto Aug 1, 2022

beylmk Aug 1, 2022

NachoSoto Aug 1, 2022

beylmk Aug 1, 2022

		let cachedIdentifiers = Set(cachedProducts.map { $0.productIdentifier })
		Logger.debug(Strings.offering.products_already_cached(identifiers: cachedIdentifiers))

		let storeKitProducts = try await StoreKit.Product.products(for: identifiers)
		Logger.rcSuccess(Strings.storeKit.skproductsrequest_received_response)

	return "SKProductsRequest did finish"
	return "Store product request did finish"

	return "Store products request failed! error: \(error.localizedDescription)"
	return "Store products request failed! Error: \(error.localizedDescription)"

Add missing logs to ProductsFetcherSK2 #1780

Add missing logs to ProductsFetcherSK2 #1780

Conversation

beylmk commented Jul 28, 2022

Choose a reason for hiding this comment

Choose a reason for hiding this comment

NachoSoto left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

beylmk Jul 28, 2022 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

beylmk commented Jul 28, 2022

NachoSoto left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

beylmk Jul 28, 2022 •

edited

Loading