2022-09-20 20:42:02.321066+0200 App[9050:367586] [Purchases] - DEBUG: 👤 Identifying App User ID
2022-09-20 20:42:02.325790+0200 App[9050:367586] [Purchases] - DEBUG: ℹ️ Debug logging enabled
2022-09-20 20:42:02.325857+0200 App[9050:367586] [Purchases] - DEBUG: ℹ️ SDK Version - 4.12.0-SNAPSHOT
2022-09-20 20:42:02.325888+0200 App[9050:367586] [Purchases] - DEBUG: ℹ️ Bundle ID - app.App.purple
2022-09-20 20:42:02.326548+0200 App[9050:367586] [Purchases] - DEBUG: 👤 Initial App User ID set
2022-09-20 20:42:02.335976+0200 App[9050:367586] [Purchases] - DEBUG: ℹ️ setting reserved attribute: $[ID]
2022-09-20 20:42:02.336034+0200 App[9050:367823] [Purchases] - DEBUG: ℹ️ PostAdServicesTokenOperation: Started
2022-09-20 20:42:02.336148+0200 App[9050:367823] [Purchases] - DEBUG: ℹ️ There are no requests currently running, starting request POST subscribers/[ID]/adservices_attribution
2022-09-20 20:42:02.336792+0200 App[9050:367586] [Purchases] - DEBUG: ℹ️ Attribute set locally: [SubscriberAttribute] key: $[ID] value: [Value] setTime: 2022-09-20 18:42:02 +0000. It will be synced to the backend when the app backgrounds/foregrounds or when a purchase is made.
2022-09-20 20:42:02.339244+0200 App[9050:367823] [Purchases] - DEBUG: ℹ️ API request started: POST /v1/subscribers/[ID]/adservices_attribution
2022-09-20 20:42:02.340735+0200 App[9050:367586] [Purchases] - DEBUG: ℹ️ Delegate set
2022-09-20 20:42:02.538667+0200 App[9050:367586] [Purchases] - DEBUG: ℹ️ applicationDidBecomeActive
2022-09-20 20:42:02.538735+0200 App[9050:367586] [Purchases] - DEBUG: ℹ️ CustomerInfo cache is stale, updating from network in foreground.
2022-09-20 20:42:02.538819+0200 App[9050:367586] [Purchases] - DEBUG: ℹ️ Offerings cache is stale, updating caches
2022-09-20 20:42:02.539071+0200 App[9050:367586] [Purchases] - DEBUG: ℹ️ CustomerInfo cache is stale, updating from network in foreground.
2022-09-20 20:42:02.539162+0200 App[9050:367586] [Purchases] - DEBUG: ℹ️ CustomerInfo cache is stale, updating from network in foreground.
2022-09-20 20:42:02.923390+0200 App[9050:367824] [Purchases] - DEBUG: ℹ️ API request completed: POST /v1/subscribers/[ID]/adservices_attribution 200
2022-09-20 20:42:02.926004+0200 App[9050:367824] [Purchases] - DEBUG: ℹ️ AdServices attribution token successfully posted
2022-09-20 20:42:02.926061+0200 App[9050:367824] [Purchases] - DEBUG: ℹ️ PostAdServicesTokenOperation: Finished
2022-09-20 20:42:02.926152+0200 App[9050:367824] [Purchases] - DEBUG: ℹ️ Serial request done: POST subscribers/[ID]/adservices_attribution, 0 requests left in the queue
2022-09-20 20:42:02.926172+0200 App[9050:367837] [Purchases] - DEBUG: ℹ️ PostSubscriberAttributesOperation: Started
2022-09-20 20:42:02.926289+0200 App[9050:367837] [Purchases] - DEBUG: ℹ️ There are no requests currently running, starting request POST subscribers/[ID]/attributes
2022-09-20 20:42:02.928549+0200 App[9050:367837] [Purchases] - DEBUG: ℹ️ API request started: POST /v1/subscribers/[ID]/attributes
2022-09-20 20:42:03.152853+0200 App[9050:367841] [Purchases] - DEBUG: ℹ️ API request completed: POST /v1/subscribers/[ID]/attributes 200
2022-09-20 20:42:03.155772+0200 App[9050:367841] [Purchases] - INFO: ℹ️ Marking attributes as synced for App User ID: [ID]:
2022-09-20 20:42:03.156122+0200 App[9050:367841] [Purchases] - DEBUG: ℹ️ Found 1 unsynced attributes for App User ID: [ID]
2022-09-20 20:42:03.156329+0200 App[9050:367841] [Purchases] - DEBUG: ℹ️ Unsynced attributes: ["$[ID]": [SubscriberAttribute] key: $[ID] value: [Value] setTime: 2022-09-20 18:42:02 +0000]
2022-09-20 20:42:03.157475+0200 App[9050:367841] [Purchases] - DEBUG: 😻 Subscriber attributes synced successfully for App User ID: [ID]
2022-09-20 20:42:03.157983+0200 App[9050:367841] [Purchases] - WARN: ⚠️ The appUserID passed to logIn is the same as the one already cached. No action will be taken.
2022-09-20 20:42:03.158123+0200 App[9050:367841] [Purchases] - DEBUG: ℹ️ PostSubscriberAttributesOperation: Finished
2022-09-20 20:42:03.158227+0200 App[9050:367586] [Purchases] - DEBUG: ℹ️ CustomerInfo cache is stale, updating from network in foreground.
2022-09-20 20:42:03.158295+0200 App[9050:367841] [Purchases] - DEBUG: ℹ️ Serial request done: POST subscribers/[ID]/attributes, 0 requests left in the queue
2022-09-20 20:42:03.158593+0200 App[9050:367836] [Purchases] - DEBUG: ℹ️ GetCustomerInfoOperation: Started
2022-09-20 20:42:03.158751+0200 App[9050:367836] [Purchases] - DEBUG: ℹ️ There are no requests currently running, starting request GET subscribers/[ID]
2022-09-20 20:42:03.159880+0200 App[9050:367836] [Purchases] - DEBUG: ℹ️ API request started: GET /v1/subscribers/[ID]
2022-09-20 20:42:03.312053+0200 App[9050:367839] [Purchases] - DEBUG: ℹ️ API request completed: GET /v1/subscribers/[ID] 200
2022-09-20 20:42:03.350931+0200 App[9050:367839] [Purchases] - DEBUG: ℹ️ Sending latest CustomerInfo to delegate.
2022-09-20 20:42:03.351062+0200 App[9050:367839] [Purchases] - DEBUG: 😻 CustomerInfo updated from network.
2022-09-20 20:42:03.353068+0200 App[9050:367839] [Purchases] - DEBUG: 😻 CustomerInfo updated from network.
2022-09-20 20:42:03.354286+0200 App[9050:367839] [Purchases] - DEBUG: 😻 CustomerInfo updated from network.
2022-09-20 20:42:03.355587+0200 App[9050:367839] [Purchases] - DEBUG: 😻 CustomerInfo updated from network.
2022-09-20 20:42:03.356945+0200 App[9050:367839] [Purchases] - DEBUG: 😻 CustomerInfo updated from network.
2022-09-20 20:42:03.357054+0200 App[9050:367839] [Purchases] - DEBUG: ℹ️ GetCustomerInfoOperation: Finished
2022-09-20 20:42:03.357209+0200 App[9050:367839] [Purchases] - DEBUG: ℹ️ Serial request done: GET subscribers/[ID], 0 requests left in the queue
2022-09-20 20:42:03.357360+0200 App[9050:367841] [Purchases] - DEBUG: ℹ️ GetOfferingsOperation: Started
2022-09-20 20:42:03.357430+0200 App[9050:367841] [Purchases] - DEBUG: ℹ️ There are no requests currently running, starting request GET subscribers/[ID]/offerings
2022-09-20 20:42:03.358558+0200 App[9050:367841] [Purchases] - DEBUG: ℹ️ API request started: GET /v1/subscribers/[ID]/offerings
2022-09-20 20:42:03.359383+0200 App[9050:367586] [Purchases] - DEBUG: ℹ️ Vending CustomerInfo from cache.
2022-09-20 20:42:03.363562+0200 App[9050:367586] [Purchases] - DEBUG: ℹ️ Vending CustomerInfo from cache.
2022-09-20 20:42:03.366867+0200 App[9050:367586] [Purchases] - DEBUG: ℹ️ Vending CustomerInfo from cache.
2022-09-20 20:42:03.369884+0200 App[9050:367586] [Purchases] - DEBUG: ℹ️ Vending CustomerInfo from cache.
2022-09-20 20:42:03.476212+0200 App[9050:367837] [Purchases] - DEBUG: ℹ️ API request completed: GET /v1/subscribers/[ID]/offerings 200
2022-09-20 20:42:03.480112+0200 App[9050:367839] [Purchases] - DEBUG: ℹ️ No existing products cached, starting store products request for: ["App_29_99_1q_1w0", "App_119_99_1y_3d0", "App_119_99_1y_1w0", "App_59_99_2q_1w0"]
2022-09-20 20:42:03.480112+0200 App[9050:367837] [Purchases] - DEBUG: ℹ️ GetOfferingsOperation: Finished
2022-09-20 20:42:03.480357+0200 App[9050:367837] [Purchases] - DEBUG: ℹ️ Serial request done: GET subscribers/[ID]/offerings, 0 requests left in the queue
2022-09-20 20:42:03.480581+0200 App[9050:367841] [Purchases] - DEBUG: ℹ️ PostSubscriberAttributesOperation: Started
2022-09-20 20:42:03.480680+0200 App[9050:367841] [Purchases] - DEBUG: ℹ️ There are no requests currently running, starting request POST subscribers/[ID]/attributes
2022-09-20 20:42:03.481579+0200 App[9050:367839] [Purchases] - DEBUG: ℹ️ Found an existing request for products: ["App_119_99_1y_1w0", "App_59_99_2q_1w0", "App_119_99_1y_3d0", "App_29_99_1q_1w0"], appending to completion
2022-09-20 20:42:03.481711+0200 App[9050:367839] [Purchases] - DEBUG: ℹ️ Found an existing request for products: ["App_59_99_2q_1w0", "App_119_99_1y_1w0", "App_119_99_1y_3d0", "App_29_99_1q_1w0"], appending to completion
2022-09-20 20:42:03.482920+0200 App[9050:367841] [Purchases] - DEBUG: ℹ️ API request started: POST /v1/subscribers/[ID]/attributes
2022-09-20 20:42:03.499886+0200 App[9050:367841] [Purchases] - DEBUG: 😻 Store products request finished
2022-09-20 20:42:03.499890+0200 App[9050:367839] [Purchases] - DEBUG: 😻 Store products request request received response
2022-09-20 20:42:03.821825+0200 App[9050:367841] [Purchases] - DEBUG: ℹ️ API request completed: POST /v1/subscribers/[ID]/attributes 200
2022-09-20 20:42:03.822236+0200 App[9050:367841] [Purchases] - INFO: ℹ️ Marking attributes as synced for App User ID: [ID]:
2022-09-20 20:42:03.822354+0200 App[9050:367841] [Purchases] - DEBUG: ℹ️ Found 0 unsynced attributes for App User ID: [ID]
giri[9050:367841] [Purchases] - DEBUG: 😻 Subscriber attributes synced successfully for App User ID: [ID]
2022-09-20 20:42:03.822462+0200 App[9050:367841] [Purchases] - DEBUG: ℹ️ PostSubscriberAttributesOperation: Finished
2022-09-20 20:42:03.822565+0200 App[9050:367841] [Purchases] - DEBUG: ℹ️ Serial request done: POST subscribers/[ID]/attributes, 0 requests left in the queue
2022-09-20 20:42:04.041245+0200 App[9050:367586] [Purchases] - DEBUG: ℹ️ Vending Offerings from cache
2022-09-20 20:42:04.064308+0200 App[9050:367586] [Purchases] - DEBUG: ℹ️ Unable to load receipt, ensure you are logged in to a valid Apple account.
2022-09-20 20:42:04.064542+0200 App[9050:367839] [Purchases] - DEBUG: ℹ️ Skipping products request because products were already cached. products: ["App_119_99_1y_1w0"]
2022-09-20 20:42:04.065324+0200 App[9050:367839] [Purchases] - DEBUG: ℹ️ GetIntroEligibilityOperation: Started
2022-09-20 20:42:04.065496+0200 App[9050:367839] [Purchases] - WARN: 🍎‼️ App running on sandbox without a receipt file. Unable to determine into eligibility unless you've purchased before and there is a receipt available.
2022-09-20 20:42:04.065715+0200 App[9050:367839] [Purchases] - DEBUG: ℹ️ GetIntroEligibilityOperation: Finished