diff --git a/platforms/android/lib/src/main/java/com/shopify/checkoutkit/PreloadCache.kt b/platforms/android/lib/src/main/java/com/shopify/checkoutkit/PreloadCache.kt index 77c8812f8..f568c1e16 100644 --- a/platforms/android/lib/src/main/java/com/shopify/checkoutkit/PreloadCache.kt +++ b/platforms/android/lib/src/main/java/com/shopify/checkoutkit/PreloadCache.kt @@ -7,6 +7,8 @@ import androidx.lifecycle.DefaultLifecycleObserver import androidx.lifecycle.Lifecycle import androidx.lifecycle.LifecycleOwner +internal const val PRELOAD_CACHE_HIT_LOG_MESSAGE = "Returning cached preloaded WebView." + internal data class PreloadKey(val url: String) { companion object { fun forUrl(url: String): PreloadKey { @@ -118,7 +120,7 @@ internal class PreloadCache( ShopifyCheckoutKit.log.d(LOG_TAG, "Preloaded WebView is already presented; creating a new WebView.") null } else { - ShopifyCheckoutKit.log.d(LOG_TAG, "Returning cached preloaded WebView.") + ShopifyCheckoutKit.log.d(LOG_TAG, PRELOAD_CACHE_HIT_LOG_MESSAGE) observer = null cached.view.markPreloadConsumed() cached.view diff --git a/platforms/android/lib/src/test/java/com/shopify/checkoutkit/PreloadCacheTest.kt b/platforms/android/lib/src/test/java/com/shopify/checkoutkit/PreloadCacheTest.kt index f9d2d42a4..18540e4c5 100644 --- a/platforms/android/lib/src/test/java/com/shopify/checkoutkit/PreloadCacheTest.kt +++ b/platforms/android/lib/src/test/java/com/shopify/checkoutkit/PreloadCacheTest.kt @@ -12,6 +12,11 @@ import java.util.concurrent.TimeUnit @RunWith(RobolectricTestRunner::class) class PreloadCacheTest { + @Test + fun `cache-hit diagnostic stays aligned with sample observers`() { + assertThat(PRELOAD_CACHE_HIT_LOG_MESSAGE).isEqualTo("Returning cached preloaded WebView.") + } + @Test fun `retaining after presentation schedules expiry for the remaining ttl`() { var now = 1_000L diff --git a/platforms/android/samples/CheckoutKitAndroidDemo/app/src/main/java/com/shopify/checkoutkit/androiddemo/accessibility/AccessibilityIdentifiers.kt b/platforms/android/samples/CheckoutKitAndroidDemo/app/src/main/java/com/shopify/checkoutkit/androiddemo/accessibility/AccessibilityIdentifiers.kt index 95f9b7ad4..d457b45bf 100644 --- a/platforms/android/samples/CheckoutKitAndroidDemo/app/src/main/java/com/shopify/checkoutkit/androiddemo/accessibility/AccessibilityIdentifiers.kt +++ b/platforms/android/samples/CheckoutKitAndroidDemo/app/src/main/java/com/shopify/checkoutkit/androiddemo/accessibility/AccessibilityIdentifiers.kt @@ -3,6 +3,7 @@ package com.shopify.checkoutkit.androiddemo.accessibility object AccessibilityIdentifiers { const val APP_READY = "checkout-kit-sample-ready" const val PRELOAD_STATE_PREFIX = "preload-state-" + const val PRELOAD_CACHE_HIT_PREFIX = "preload-cache-hit-" object Cart { const val CHECKOUT_READY = "cart-checkout-ready" diff --git a/platforms/android/samples/CheckoutKitAndroidDemo/app/src/main/java/com/shopify/checkoutkit/androiddemo/cart/CartView.kt b/platforms/android/samples/CheckoutKitAndroidDemo/app/src/main/java/com/shopify/checkoutkit/androiddemo/cart/CartView.kt index f2658673c..93ca5dfc4 100644 --- a/platforms/android/samples/CheckoutKitAndroidDemo/app/src/main/java/com/shopify/checkoutkit/androiddemo/cart/CartView.kt +++ b/platforms/android/samples/CheckoutKitAndroidDemo/app/src/main/java/com/shopify/checkoutkit/androiddemo/cart/CartView.kt @@ -11,6 +11,7 @@ import androidx.compose.foundation.layout.Spacer import androidx.compose.foundation.layout.fillMaxSize import androidx.compose.foundation.layout.fillMaxWidth import androidx.compose.foundation.layout.padding +import androidx.compose.foundation.layout.size import androidx.compose.foundation.layout.width import androidx.compose.foundation.layout.wrapContentHeight import androidx.compose.foundation.layout.wrapContentSize @@ -63,6 +64,7 @@ fun CartView( val loading = cartViewModel.loadingState.collectAsState().value val checkoutPresentationMode = cartViewModel.checkoutPresentationMode.collectAsState().value val preloadStateTestId = cartViewModel.preloadStateTestId.collectAsState().value + val preloadCacheHitTestId = cartViewModel.preloadCacheHitTestId.collectAsState().value val activity = LocalActivity.current as ComponentActivity var mutableQuantity by remember { mutableStateOf>(mutableMapOf()) } @@ -91,12 +93,19 @@ fun CartView( it.title to it.quantity } - // Exposes the current preload state as a preload identifier. Column( modifier = Modifier .padding(top = 4.dp) .testTag(preloadStateTestId) ) { + // Keep a separate semantics node without adding a second child to the outer + // SpaceBetween column, which would shift short cart content to the bottom. + Box( + modifier = Modifier + .size(1.dp) + .testTag(preloadCacheHitTestId) + ) + CartLines( lines = state.cartLines, loading = loading, diff --git a/platforms/android/samples/CheckoutKitAndroidDemo/app/src/main/java/com/shopify/checkoutkit/androiddemo/cart/CartViewModel.kt b/platforms/android/samples/CheckoutKitAndroidDemo/app/src/main/java/com/shopify/checkoutkit/androiddemo/cart/CartViewModel.kt index b2d23fbd6..88de5a17c 100644 --- a/platforms/android/samples/CheckoutKitAndroidDemo/app/src/main/java/com/shopify/checkoutkit/androiddemo/cart/CartViewModel.kt +++ b/platforms/android/samples/CheckoutKitAndroidDemo/app/src/main/java/com/shopify/checkoutkit/androiddemo/cart/CartViewModel.kt @@ -13,6 +13,7 @@ import com.shopify.checkoutkit.CheckoutPresentation import com.shopify.checkoutkit.CheckoutProtocol import com.shopify.checkoutkit.PreloadState import com.shopify.checkoutkit.ShopifyCheckoutKit +import com.shopify.checkoutkit.androiddemo.BuildConfig import com.shopify.checkoutkit.androiddemo.MainActivity import com.shopify.checkoutkit.androiddemo.R import com.shopify.checkoutkit.androiddemo.cart.data.CartRepository @@ -23,6 +24,8 @@ import com.shopify.checkoutkit.androiddemo.common.SnackbarEvent import com.shopify.checkoutkit.androiddemo.common.logs.LogLevel import com.shopify.checkoutkit.androiddemo.common.logs.Logger import com.shopify.checkoutkit.androiddemo.common.navigation.Screen +import com.shopify.checkoutkit.androiddemo.e2e.PreloadCacheHitLog +import com.shopify.checkoutkit.androiddemo.e2e.PreloadCacheHitMarker import com.shopify.checkoutkit.androiddemo.e2e.PreloadStateMarker import com.shopify.checkoutkit.androiddemo.settings.PreferencesManager import com.shopify.checkoutkit.androiddemo.settings.authentication.data.AuthenticationState @@ -36,9 +39,12 @@ import kotlinx.coroutines.Dispatchers import kotlinx.coroutines.flow.MutableStateFlow import kotlinx.coroutines.flow.StateFlow import kotlinx.coroutines.flow.asStateFlow +import kotlinx.coroutines.flow.SharingStarted import kotlinx.coroutines.flow.distinctUntilChanged import kotlinx.coroutines.flow.drop import kotlinx.coroutines.flow.filter +import kotlinx.coroutines.flow.map +import kotlinx.coroutines.flow.stateIn import kotlinx.coroutines.launch import kotlinx.serialization.encodeToString import kotlinx.serialization.json.Json @@ -62,9 +68,26 @@ class CartViewModel( private val _checkoutPresentationMode = MutableStateFlow(CheckoutPresentationMode.CheckoutKitSheet) val checkoutPresentationMode: StateFlow = _checkoutPresentationMode.asStateFlow() + private val _preloadState = MutableStateFlow(PreloadState.Idle) private val _preloadStateTestId = MutableStateFlow(PreloadStateMarker.testId(PreloadState.Idle)) val preloadStateTestId: StateFlow = _preloadStateTestId.asStateFlow() + // The SDK's log sink is internal, so the cache hit is observed from this process's own + // Logcat and republished as an identifier. Gate the hit when the log arrives so an entry + // consumed while still loading cannot later count as a ready cache hit. + private val preloadCacheHitLog = PreloadCacheHitLog( + isPreloadReady = { _preloadState.value is PreloadState.Ready } + ).also { + if (BuildConfig.DEBUG) it.start(viewModelScope) + } + val preloadCacheHitTestId: StateFlow = preloadCacheHitLog.observed + .map { PreloadCacheHitMarker.testId(it) } + .stateIn( + viewModelScope, + SharingStarted.Eagerly, + PreloadCacheHitMarker.testId(false) + ) + private var demoBuyerIdentityEnabled = false private var checkoutPreloadingEnabled = true private var windowOpenHandler = WindowOpenHandler.Default @@ -176,10 +199,16 @@ class CartViewModel( Timber.i("Preloading checkout") ShopifyCheckoutKit.preload(url, activity) { state -> Timber.i("Preload state changed to $state") + _preloadState.value = state _preloadStateTestId.value = PreloadStateMarker.testId(state) } } + override fun onCleared() { + preloadCacheHitLog.close() + super.onCleared() + } + fun continueShopping(navController: NavController) { Timber.i("Continue shopping clicked, navigating to products") navController.navigate(Screen.Products.route) diff --git a/platforms/android/samples/CheckoutKitAndroidDemo/app/src/main/java/com/shopify/checkoutkit/androiddemo/e2e/PreloadCacheHitMarker.kt b/platforms/android/samples/CheckoutKitAndroidDemo/app/src/main/java/com/shopify/checkoutkit/androiddemo/e2e/PreloadCacheHitMarker.kt new file mode 100644 index 000000000..b0d9f9705 --- /dev/null +++ b/platforms/android/samples/CheckoutKitAndroidDemo/app/src/main/java/com/shopify/checkoutkit/androiddemo/e2e/PreloadCacheHitMarker.kt @@ -0,0 +1,130 @@ +package com.shopify.checkoutkit.androiddemo.e2e + +import android.os.Process +import com.shopify.checkoutkit.androiddemo.accessibility.AccessibilityIdentifiers +import java.io.BufferedReader +import java.io.InputStreamReader +import java.util.concurrent.atomic.AtomicBoolean +import kotlinx.coroutines.CancellationException +import kotlinx.coroutines.CoroutineDispatcher +import kotlinx.coroutines.CoroutineScope +import kotlinx.coroutines.Dispatchers +import kotlinx.coroutines.Job +import kotlinx.coroutines.flow.MutableStateFlow +import kotlinx.coroutines.flow.StateFlow +import kotlinx.coroutines.flow.asStateFlow +import kotlinx.coroutines.launch +import timber.log.Timber + +/** Maps whether the SDK reported a ready preload cache hit to an identifier. */ +object PreloadCacheHitMarker { + fun testId(observed: Boolean): String = + "${AccessibilityIdentifiers.PRELOAD_CACHE_HIT_PREFIX}${text(observed)}" + + fun text(observed: Boolean): String = if (observed) "observed" else "none" +} + +/** A Logcat stream plus the resources that must be closed to stop reading it. */ +class LogStream( + val lines: Sequence, + private val closeAction: () -> Unit = {}, +) { + private val closed = AtomicBoolean(false) + + fun close() { + if (closed.compareAndSet(false, true)) closeAction() + } +} + +/** + * Watches this app's UID-scoped Logcat for a ready SDK cache hit. + * + * The SDK log sink is internal, so the sample reads its own logs instead of installing a logger. + */ +class PreloadCacheHitLog( + private val openLines: () -> LogStream = ::followOwnLogcat, + private val isPreloadReady: () -> Boolean = { false }, + private val reportError: (Throwable) -> Unit = { + Timber.e(it, "Failed to observe the preload cache-hit diagnostic") + }, +) { + companion object { + /** Must stay in step with PreloadCache.kt, which logs this on a cache hit. */ + const val DIAGNOSTIC = "Returning cached preloaded WebView." + + /** Starts at the newest entry so earlier runs cannot create a false hit. */ + private fun followOwnLogcat(): LogStream { + val process = ProcessBuilder( + "logcat", "-T", "1", "--pid=${Process.myPid()}", "PreloadCache:D", "*:S" + ).redirectErrorStream(true).start() + val reader = BufferedReader(InputStreamReader(process.inputStream)) + + return LogStream(reader.lineSequence()) { + process.destroy() + runCatching { reader.close() } + } + } + } + + private val _observed = MutableStateFlow(false) + val observed: StateFlow = _observed.asStateFlow() + + private val resourceLock = Any() + private var stream: LogStream? = null + private var job: Job? = null + private var closed = false + + fun start(scope: CoroutineScope, dispatcher: CoroutineDispatcher = Dispatchers.IO): Job { + check(job == null) { "Preload cache-hit observation already started" } + + return scope.launch(dispatcher) { + try { + val opened = openLines() + val shouldRead = synchronized(resourceLock) { + if (closed) { + false + } else { + stream = opened + true + } + } + + if (!shouldRead) { + opened.close() + return@launch + } + + opened.lines.forEach(::record) + } catch (error: Exception) { + val shouldReport = synchronized(resourceLock) { !closed } && error !is CancellationException + if (shouldReport) reportError(error) + } finally { + closeStream() + } + }.also { job = it } + } + + fun close() { + val opened = synchronized(resourceLock) { + if (closed) return + closed = true + stream.also { stream = null } + } + + opened?.close() + job?.cancel() + } + + fun record(line: String) { + if (line.contains(DIAGNOSTIC) && isPreloadReady()) { + _observed.value = true + } + } + + private fun closeStream() { + val opened = synchronized(resourceLock) { + stream.also { stream = null } + } + opened?.close() + } +} diff --git a/platforms/android/samples/CheckoutKitAndroidDemo/app/src/test/java/com/shopify/checkoutkit/androiddemo/e2e/PreloadCacheHitMarkerTest.kt b/platforms/android/samples/CheckoutKitAndroidDemo/app/src/test/java/com/shopify/checkoutkit/androiddemo/e2e/PreloadCacheHitMarkerTest.kt new file mode 100644 index 000000000..f821fe830 --- /dev/null +++ b/platforms/android/samples/CheckoutKitAndroidDemo/app/src/test/java/com/shopify/checkoutkit/androiddemo/e2e/PreloadCacheHitMarkerTest.kt @@ -0,0 +1,133 @@ +package com.shopify.checkoutkit.androiddemo.e2e + +import java.util.concurrent.CountDownLatch +import java.util.concurrent.TimeUnit +import java.util.concurrent.atomic.AtomicBoolean +import kotlinx.coroutines.CoroutineScope +import kotlinx.coroutines.Dispatchers +import kotlinx.coroutines.SupervisorJob +import kotlinx.coroutines.cancel +import kotlinx.coroutines.runBlocking +import kotlinx.coroutines.withTimeout +import org.assertj.core.api.Assertions.assertThat +import org.junit.Test + +class PreloadCacheHitMarkerTest { + @Test + fun `marker ids match the maestro flow assertions`() { + assertThat(PreloadCacheHitMarker.testId(observed = true)).isEqualTo("preload-cache-hit-observed") + assertThat(PreloadCacheHitMarker.testId(observed = false)).isEqualTo("preload-cache-hit-none") + } + + @Test + fun `records the cache-hit diagnostic when the preload is ready`() { + val log = PreloadCacheHitLog(isPreloadReady = { true }) + + assertThat(log.observed.value).isFalse() + + log.record("08-17 18:53:55.395 5398 5398 D PreloadCache: Returning cached preloaded WebView.") + + assertThat(log.observed.value).isTrue() + } + + @Test + fun `ignores a cache hit before the preload is ready`() { + var ready = false + val log = PreloadCacheHitLog(isPreloadReady = { ready }) + + log.record("D PreloadCache: Returning cached preloaded WebView.") + + assertThat(log.observed.value).isFalse() + + ready = true + log.record("D PreloadCache: Returning cached preloaded WebView.") + + assertThat(log.observed.value).isTrue() + } + + @Test + fun `ignores unrelated lines`() { + val log = PreloadCacheHitLog(isPreloadReady = { true }) + + log.record("D PreloadCache: Preloading checkout") + log.record("I Timber: Preload state changed to Ready") + + assertThat(log.observed.value).isFalse() + } + + @Test + fun `reads the injected line source`() { + runBlocking { + val lines = listOf( + "D PreloadCache: Preloading checkout", + "D PreloadCache: Returning cached preloaded WebView." + ) + val streamClosed = AtomicBoolean(false) + val log = PreloadCacheHitLog( + openLines = { + LogStream(lines.asSequence()) { + streamClosed.set(true) + } + }, + isPreloadReady = { true }, + ) + + log.start(this, Dispatchers.Unconfined).join() + + assertThat(log.observed.value).isTrue() + assertThat(streamClosed.get()).isTrue() + } + } + + @Test + fun `reports a logcat reader failure`() { + runBlocking { + val failure = IllegalStateException("logcat unavailable") + var reported: Throwable? = null + val log = PreloadCacheHitLog( + openLines = { throw failure }, + reportError = { reported = it }, + ) + + log.start(this, Dispatchers.Unconfined).join() + + assertThat(reported).isSameAs(failure) + } + } + + @Test + fun `close releases a blocking logcat stream`() { + runBlocking { + val reading = CountDownLatch(1) + val release = CountDownLatch(1) + val streamClosed = AtomicBoolean(false) + val lines = sequence { + reading.countDown() + release.await() + } + val log = PreloadCacheHitLog( + openLines = { + LogStream(lines) { + streamClosed.set(true) + release.countDown() + } + }, + ) + val scope = CoroutineScope(SupervisorJob() + Dispatchers.IO) + val job = log.start(scope) + + try { + assertThat(reading.await(5, TimeUnit.SECONDS)).isTrue() + + log.close() + withTimeout(5_000) { job.join() } + + assertThat(streamClosed.get()).isTrue() + } finally { + log.close() + release.countDown() + scope.cancel() + } + } + } +} diff --git a/platforms/swift/Samples/CheckoutKitSwiftDemo/CheckoutKitSwiftDemo/Sources/Accessibility/AccessibilityIdentifiers.swift b/platforms/swift/Samples/CheckoutKitSwiftDemo/CheckoutKitSwiftDemo/Sources/Accessibility/AccessibilityIdentifiers.swift index 28d942d09..56bd34c03 100644 --- a/platforms/swift/Samples/CheckoutKitSwiftDemo/CheckoutKitSwiftDemo/Sources/Accessibility/AccessibilityIdentifiers.swift +++ b/platforms/swift/Samples/CheckoutKitSwiftDemo/CheckoutKitSwiftDemo/Sources/Accessibility/AccessibilityIdentifiers.swift @@ -1,6 +1,7 @@ enum AccessibilityIdentifiers { static let appReady = "checkout-kit-sample-ready" static let preloadStatePrefix = "preload-state-" + static let preloadCacheHitPrefix = "preload-cache-hit-" enum Cart { static let checkoutReady = "cart-checkout-ready" diff --git a/platforms/swift/Samples/CheckoutKitSwiftDemo/CheckoutKitSwiftDemo/Sources/App/AppDelegate.swift b/platforms/swift/Samples/CheckoutKitSwiftDemo/CheckoutKitSwiftDemo/Sources/App/AppDelegate.swift index 479f11352..43ec803dc 100644 --- a/platforms/swift/Samples/CheckoutKitSwiftDemo/CheckoutKitSwiftDemo/Sources/App/AppDelegate.swift +++ b/platforms/swift/Samples/CheckoutKitSwiftDemo/CheckoutKitSwiftDemo/Sources/App/AppDelegate.swift @@ -28,7 +28,7 @@ class AppDelegate: UIResponder, UIApplicationDelegate { ShopifyCheckoutKit.configure { $0.appearance = .app(.automatic) $0.tintColor = ColorPalette.primaryColor - $0.logger = FileLogger("log.txt") + $0.logger = ObservingLogger(wrapping: FileLogger("log.txt")) $0.logLevel = checkoutKitLogLevel $0.preloading.enabled = checkoutPreloadingEnabled } diff --git a/platforms/swift/Samples/CheckoutKitSwiftDemo/CheckoutKitSwiftDemo/Sources/E2E/PreloadCacheHitMarker.swift b/platforms/swift/Samples/CheckoutKitSwiftDemo/CheckoutKitSwiftDemo/Sources/E2E/PreloadCacheHitMarker.swift new file mode 100644 index 000000000..d70f31719 --- /dev/null +++ b/platforms/swift/Samples/CheckoutKitSwiftDemo/CheckoutKitSwiftDemo/Sources/E2E/PreloadCacheHitMarker.swift @@ -0,0 +1,65 @@ +import Foundation +import ShopifyCheckoutKit + +/// Maps whether the SDK reported a ready preload cache hit to an identifier. +enum PreloadCacheHitMarker { + static func testId(observed: Bool) -> String { + "\(AccessibilityIdentifiers.preloadCacheHitPrefix)\(text(observed: observed))" + } + + static func text(observed: Bool) -> String { + observed ? "observed" : "none" + } +} + +/// Watches SDK logs and publishes whether a ready preload was reused. +/// +/// `@unchecked Sendable` is safe because every published write runs on the main thread. +final class PreloadCacheHitLog: ObservableObject, @unchecked Sendable { + /// Must stay in step with the SDK diagnostic that CheckoutWebView emits on a ready cache hit. + static let diagnostic = "Presenting preloaded checkout from cache" + + static let shared = PreloadCacheHitLog() + + @Published private(set) var observed = false + + func record(_ message: String) { + guard message.contains(Self.diagnostic) else { return } + + // The SDK logs off the main thread, and `observed` drives a SwiftUI identifier. + if Thread.isMainThread { + observed = true + } else { + DispatchQueue.main.async { self.observed = true } + } + } + + func reset() { + if Thread.isMainThread { + observed = false + } else { + DispatchQueue.main.async { self.observed = false } + } + } +} + +/// Forwards every message to the sample's real logger, and lets the observer see it first. +final class ObservingLogger: Logger { + private let wrapped: Logger + private let observer: PreloadCacheHitLog + + init(wrapping wrapped: Logger, observer: PreloadCacheHitLog = .shared) { + self.wrapped = wrapped + self.observer = observer + } + + func log(_ message: String) { + observer.record(message) + wrapped.log(message) + } + + func clearLogs() { + observer.reset() + wrapped.clearLogs() + } +} diff --git a/platforms/swift/Samples/CheckoutKitSwiftDemo/CheckoutKitSwiftDemo/Sources/Scenes/Cart/CartView.swift b/platforms/swift/Samples/CheckoutKitSwiftDemo/CheckoutKitSwiftDemo/Sources/Scenes/Cart/CartView.swift index 8d5f10643..e7d56dceb 100644 --- a/platforms/swift/Samples/CheckoutKitSwiftDemo/CheckoutKitSwiftDemo/Sources/Scenes/Cart/CartView.swift +++ b/platforms/swift/Samples/CheckoutKitSwiftDemo/CheckoutKitSwiftDemo/Sources/Scenes/Cart/CartView.swift @@ -15,6 +15,7 @@ struct CartView: View { @State private var preloadStateTestId = PreloadStateMarker.testId(for: .idle) @ObservedObject var cartManager: CartManager = .shared + @ObservedObject private var preloadCacheHitLog: PreloadCacheHitLog = .shared @AppStorage(AppStorageKeys.applePayStyle.rawValue) var applePayStyle: ApplePayStyleOption = .automatic @@ -41,6 +42,16 @@ struct CartView: View { .accessibilityElement(children: .contain) .accessibilityIdentifier(preloadStateTestId) + // Keep this marker separate: stacking identifiers on one accessibility element + // hides one from Maestro. + Color.clear + .frame(width: 1, height: 1) + .allowsHitTesting(false) + .accessibilityElement() + .accessibilityIdentifier( + PreloadCacheHitMarker.testId(observed: preloadCacheHitLog.observed) + ) + VStack(spacing: DesignSystem.buttonSpacing) { if let cartID = cartManager.cart?.id { if #available(iOS 16, *) { diff --git a/platforms/swift/Samples/CheckoutKitSwiftDemo/CheckoutKitSwiftDemoTests/E2E/PreloadCacheHitMarkerTests.swift b/platforms/swift/Samples/CheckoutKitSwiftDemo/CheckoutKitSwiftDemoTests/E2E/PreloadCacheHitMarkerTests.swift new file mode 100644 index 000000000..29ee9b62c --- /dev/null +++ b/platforms/swift/Samples/CheckoutKitSwiftDemo/CheckoutKitSwiftDemoTests/E2E/PreloadCacheHitMarkerTests.swift @@ -0,0 +1,75 @@ +@testable import CheckoutKitSwiftDemo +import ShopifyCheckoutKit +import XCTest + +class PreloadCacheHitMarkerTests: XCTestCase { + func testMarkerTextsMatchTheMaestroFlowAssertions() { + XCTAssertEqual(PreloadCacheHitMarker.testId(observed: true), "preload-cache-hit-observed") + XCTAssertEqual(PreloadCacheHitMarker.testId(observed: false), "preload-cache-hit-none") + } + + func testTheObserverRecordsTheReadyCacheHitDiagnostic() { + let observer = PreloadCacheHitLog() + + XCTAssertFalse(observer.observed) + + observer.record("14:02:11: Presenting preloaded checkout from cache for https://example.com") + + XCTAssertTrue(observer.observed) + } + + func testTheObserverIgnoresUnrelatedMessages() { + let observer = PreloadCacheHitLog() + + observer.record("Preload state changed to ready") + observer.record("Presenting cached entry") + + XCTAssertFalse(observer.observed) + } + + func testResetClearsTheObservation() { + let observer = PreloadCacheHitLog() + observer.record(PreloadCacheHitLog.diagnostic) + + observer.reset() + + XCTAssertFalse(observer.observed) + } + + func testTheLoggerForwardsEveryMessageToTheWrappedLogger() { + let spy = SpyLogger() + let observer = PreloadCacheHitLog() + let logger = ObservingLogger(wrapping: spy, observer: observer) + + logger.log("first") + logger.log(PreloadCacheHitLog.diagnostic) + + XCTAssertEqual(spy.messages, ["first", PreloadCacheHitLog.diagnostic]) + XCTAssertTrue(observer.observed) + } + + func testClearingLogsAlsoClearsTheObservation() { + let spy = SpyLogger() + let observer = PreloadCacheHitLog() + let logger = ObservingLogger(wrapping: spy, observer: observer) + logger.log(PreloadCacheHitLog.diagnostic) + + logger.clearLogs() + + XCTAssertFalse(observer.observed) + XCTAssertTrue(spy.didClear) + } +} + +private final class SpyLogger: Logger, @unchecked Sendable { + private(set) var messages: [String] = [] + private(set) var didClear = false + + func log(_ message: String) { + messages.append(message) + } + + func clearLogs() { + didClear = true + } +} diff --git a/platforms/swift/Sources/ShopifyCheckoutKit/CheckoutWebView.swift b/platforms/swift/Sources/ShopifyCheckoutKit/CheckoutWebView.swift index d537654f7..9b85a5bee 100644 --- a/platforms/swift/Sources/ShopifyCheckoutKit/CheckoutWebView.swift +++ b/platforms/swift/Sources/ShopifyCheckoutKit/CheckoutWebView.swift @@ -293,6 +293,7 @@ struct UIApplicationExternalURLHandler: ExternalURLHandling { @MainActor class CheckoutWebView: WKWebView { static let preloadCache = PreloadCache() + static let preloadCacheHitLogMessage = "Presenting preloaded checkout from cache" private static let purposeHeader = "Shopify-Purpose" private static let prefetchPurpose = "prefetch" @@ -393,11 +394,16 @@ class CheckoutWebView: WKWebView { return CheckoutWebView(entryPoint: entryPoint) } + let cacheWasReady = preloadCache.state == .ready guard let cachedView = preloadCache.view(for: PreloadKey(url: url, entryPoint: entryPoint)) else { return CheckoutWebView(entryPoint: entryPoint) } OSLogger.shared.debug("Presenting cached entry") + let configuration = ShopifyCheckoutKit.configuration + if cacheWasReady, configuration.logLevel == .debug { + configuration.logger.log(preloadCacheHitLogMessage) + } return cachedView } diff --git a/platforms/swift/Tests/ShopifyCheckoutKitTests/CheckoutWebViewTests.swift b/platforms/swift/Tests/ShopifyCheckoutKitTests/CheckoutWebViewTests.swift index b56d44f98..61484222e 100644 --- a/platforms/swift/Tests/ShopifyCheckoutKitTests/CheckoutWebViewTests.swift +++ b/platforms/swift/Tests/ShopifyCheckoutKitTests/CheckoutWebViewTests.swift @@ -329,15 +329,79 @@ class CheckoutWebViewTests: XCTestCase { XCTAssertTrue(CheckoutWebView.preloadCache.hasEntry()) } + func testMatchingPresentLogsTheCacheHitThroughTheConfiguredLoggerAtDebugLevel() { + withRecordingLogger(logLevel: .debug) { logger in + // Keep this literal independent from preloadCacheHitLogMessage: the sample parses + // this exact diagnostic across the SDK boundary. + let expectedMessage = "Presenting preloaded checkout from cache" + ShopifyCheckoutKit.preload(checkout: url) + CheckoutWebView.preloadCache.transition(to: .ready) + + XCTAssertFalse(logger.messages.contains(expectedMessage)) + + _ = CheckoutWebView.for(checkout: CheckoutURLDecorator.decorate(url)) + + XCTAssertEqual(logger.messages.filter { $0 == expectedMessage }.count, 1) + } + } + + func testMatchingPresentDoesNotLogTheCacheHitBeforePreloadIsReady() { + withRecordingLogger(logLevel: .debug) { logger in + ShopifyCheckoutKit.preload(checkout: url) + + _ = CheckoutWebView.for(checkout: CheckoutURLDecorator.decorate(url)) + + XCTAssertFalse(logger.messages.contains(CheckoutWebView.preloadCacheHitLogMessage)) + } + } + + func testMatchingPresentDoesNotLogTheCacheHitThroughTheConfiguredLoggerAboveDebugLevel() { + withRecordingLogger(logLevel: .warn) { logger in + ShopifyCheckoutKit.preload(checkout: url) + CheckoutWebView.preloadCache.transition(to: .ready) + + _ = CheckoutWebView.for(checkout: CheckoutURLDecorator.decorate(url)) + + XCTAssertFalse(logger.messages.contains(CheckoutWebView.preloadCacheHitLogMessage)) + } + } + + func testFreshPresentDoesNotLogTheCacheHit() { + withRecordingLogger(logLevel: .debug) { logger in + _ = CheckoutWebView.for(checkout: CheckoutURLDecorator.decorate(url)) + + XCTAssertFalse(logger.messages.contains(CheckoutWebView.preloadCacheHitLogMessage)) + } + } + func testPresentWithDifferentURLDoesNotReusePreloadedWebView() throws { - ShopifyCheckoutKit.preload(checkout: url) - let otherURL = try XCTUnwrap(URL(string: "https://shopify1.shopify.com/checkouts/cn/456")) + try withRecordingLogger(logLevel: .debug) { logger in + ShopifyCheckoutKit.preload(checkout: url) + CheckoutWebView.preloadCache.transition(to: .ready) + let otherURL = try XCTUnwrap(URL(string: "https://shopify1.shopify.com/checkouts/cn/456")) - let fresh = CheckoutWebView.for(checkout: EmbeddedCheckoutProtocol.url(for: otherURL)) + let fresh = CheckoutWebView.for(checkout: EmbeddedCheckoutProtocol.url(for: otherURL)) - XCTAssertNil(fresh.url) - XCTAssertFalse(CheckoutWebView.preloadCache.hasEntry()) - XCTAssertFalse(CheckoutWebView.preloadCache.hasActiveKeepAlive()) + XCTAssertNil(fresh.url) + XCTAssertFalse(CheckoutWebView.preloadCache.hasEntry()) + XCTAssertFalse(CheckoutWebView.preloadCache.hasActiveKeepAlive()) + XCTAssertFalse(logger.messages.contains(CheckoutWebView.preloadCacheHitLogMessage)) + } + } + + private func withRecordingLogger( + logLevel: LogLevel, + perform: (RecordingLogger) throws -> Void + ) rethrows { + let originalConfiguration = ShopifyCheckoutKit.configuration + defer { ShopifyCheckoutKit.configuration = originalConfiguration } + let logger = RecordingLogger() + var configuration = originalConfiguration + configuration.logger = logger + configuration.logLevel = logLevel + ShopifyCheckoutKit.configuration = configuration + + try perform(logger) } func testPresentWithDifferentEntryPointDoesNotReusePreloadedWebView() { @@ -1287,6 +1351,27 @@ private actor RecordingBridgeClient: CheckoutCommunicationProtocol { } } +final class RecordingLogger: Logger, @unchecked Sendable { + private let lock = NSLock() + private var storage: [String] = [] + + var messages: [String] { + lock.withLock { storage } + } + + func log(_ message: String) { + lock.withLock { + storage.append(message) + } + } + + func clearLogs() { + lock.withLock { + storage.removeAll() + } + } +} + @MainActor class LoadedRequestObservableWebView: CheckoutWebView { var lastLoadedURLRequest: URLRequest?