[SDK-547] Reduce excess JWT auth token requests (timer race)

CHANGELOG.md

@@ -3,6 +3,8 @@ All notable changes to this project will be documented in this file.
 This project adheres to [Semantic Versioning](http://semver.org/).
 
 ## [Unreleased]
+### Fixed
+- Fixed a race in JWT auth refresh scheduling that could leave overlapping timers active and repeatedly call `IterableAuthHandler.onAuthTokenRequested()`. Refresh scheduling now has a single task owner, rejects stale or duplicate tasks, and logs each schedule, skip, fire, cancellation, and error with its refresh reason.
 
 ## [3.10.0]
 ### Added

iterableapi/src/main/java/com/iterable/iterableapi/IterableApi.java

@@ -627,7 +627,7 @@ private void retrieveEmailAndUserId() {
                 getAuthManager().queueExpirationRefresh(_authToken);
             } else {
                 IterableLogger.d(TAG, "Auth token found as null. Rescheduling auth token refresh");
-                getAuthManager().scheduleAuthTokenRefresh(authManager.getNextRetryInterval(), true, null);
+                getAuthManager().scheduleAuthTokenRefresh(authManager.getNextRetryInterval(), IterableAuthRefreshReason.STORED_TOKEN_MISSING, null);
             }
         }
     }
@@ -1997,4 +1997,4 @@ public void trackEmbeddedSession(@NonNull IterableEmbeddedSession session) {
 
 //endregion
 
-}
+}

iterableapi/src/main/java/com/iterable/iterableapi/IterableAuthManager.java

@@ -31,6 +31,13 @@ enum AuthState {
         UNKNOWN
     }
 
+    private enum RefreshCancellationReason {
+        AUTH_RESET,
+        TOKEN_REPLACED,
+        EXPLICIT_CLEAR,
+        APP_BACKGROUNDED
+    }
+
     /**
      * Listener interface for components that need to react when a new auth token is ready.
      */
@@ -44,14 +51,17 @@ interface AuthTokenReadyListener {
     private final IterableActivityMonitor activityMonitor;
     @VisibleForTesting
     Timer timer;
+    @VisibleForTesting
+    volatile TimerTask scheduledRefreshTask;
+    @VisibleForTesting
+    volatile IterableAuthRefreshReason scheduledRefreshReason;
     private boolean hasFailedPriorAuth;
     private boolean pendingAuth;
     private boolean requiresAuthRefresh;
     RetryPolicy authRetryPolicy;
     boolean pauseAuthRetry;
     int retryCount;
     private boolean isLastAuthTokenValid;
-    private volatile boolean isTimerScheduled;
     private volatile boolean isInForeground = true; // Assume foreground initially
 
     private volatile AuthState authState = AuthState.UNKNOWN;
@@ -130,7 +140,7 @@ public void pauseAuthRetries(boolean pauseRetry) {
     }
 
     void reset() {
-        clearRefreshTimer();
+        clearRefreshTimer(RefreshCancellationReason.AUTH_RESET);
         setIsLastAuthTokenValid(false);
     }
 
@@ -222,7 +232,11 @@ private void handleAuthTokenSuccess(String authToken, IterableHelper.SuccessHand
         } else {
             handleAuthFailure(authToken, AuthFailureReason.AUTH_TOKEN_NULL);
             IterableApi.getInstance().setAuthToken(authToken);
-            scheduleAuthTokenRefresh(getNextRetryInterval(), false, null);
+            scheduleAuthTokenRefresh(
+                    getNextRetryInterval(),
+                    IterableAuthRefreshReason.AUTH_HANDLER_RETRY,
+                    null
+            );
             return;
         }
         reSyncAuth();
@@ -234,32 +248,50 @@ private void handleAuthTokenFailure(Throwable throwable) {
         IterableLogger.e(TAG, "Error while requesting Auth Token", throwable);
         handleAuthFailure(null, AuthFailureReason.AUTH_TOKEN_GENERATION_ERROR);
         pendingAuth = false;
-        scheduleAuthTokenRefresh(getNextRetryInterval(), false, null);
+        scheduleAuthTokenRefresh(
+                getNextRetryInterval(),
+                IterableAuthRefreshReason.AUTH_HANDLER_RETRY,
+                null
+        );
     }
 
     public void queueExpirationRefresh(@Nullable String encodedJWT) {
-        clearRefreshTimer();
+        clearRefreshTimer(RefreshCancellationReason.TOKEN_REPLACED);
         try {
             if (encodedJWT == null) {
                 IterableLogger.d(TAG, "JWT is null. Scheduling token refresh");
-                if (!isTimerScheduled) {
-                    scheduleAuthTokenRefresh(getNextRetryInterval(), false, null);
-                }
+                scheduleAuthTokenRefresh(
+                        getNextRetryInterval(),
+                        IterableAuthRefreshReason.TOKEN_MISSING,
+                        null
+                );
                 return;
             }
 
             long expirationTimeSeconds = decodedExpiration(encodedJWT);
             long triggerExpirationRefreshTime = expirationTimeSeconds * 1000L - expiringAuthTokenRefreshPeriod - IterableUtil.currentTimeMillis();
             if (triggerExpirationRefreshTime > 0) {
-                scheduleAuthTokenRefresh(triggerExpirationRefreshTime, true, null);
+                scheduleAuthTokenRefresh(
+                        triggerExpirationRefreshTime,
+                        IterableAuthRefreshReason.TOKEN_EXPIRING,
+                        null
+                );
             } else {
-                scheduleAuthTokenRefresh(getNextRetryInterval(), true, null);
+                scheduleAuthTokenRefresh(
+                        getNextRetryInterval(),
+                        IterableAuthRefreshReason.TOKEN_EXPIRED,
+                        null
+                );
             }
         } catch (Exception e) {
             IterableLogger.e(TAG, "Error while parsing JWT for the expiration", e);
             isLastAuthTokenValid = false;
             handleAuthFailure(encodedJWT, AuthFailureReason.AUTH_TOKEN_PAYLOAD_INVALID);
-            scheduleAuthTokenRefresh(getNextRetryInterval(), false, null);
+            scheduleAuthTokenRefresh(
+                    getNextRetryInterval(),
+                    IterableAuthRefreshReason.TOKEN_INVALID,
+                    null
+            );
         }
     }
 
@@ -270,7 +302,11 @@ void resetFailedAuth() {
     void reSyncAuth() {
         if (requiresAuthRefresh) {
             requiresAuthRefresh = false;
-            scheduleAuthTokenRefresh(getNextRetryInterval(), false, null);
+            scheduleAuthTokenRefresh(
+                    getNextRetryInterval(),
+                    IterableAuthRefreshReason.DEFERRED_REFRESH,
+                    null
+            );
         }
     }
 
@@ -291,30 +327,120 @@ long getNextRetryInterval() {
         return nextRetryInterval;
     }
 
-    void scheduleAuthTokenRefresh(long timeDuration, boolean isScheduledRefresh, final IterableHelper.SuccessHandler successCallback) {
-        if ((pauseAuthRetry && !isScheduledRefresh) || isTimerScheduled) {
-            // we only stop schedule token refresh if it is called from retry (in case of failure). The normal auth token refresh schedule would work
+    synchronized void scheduleAuthTokenRefresh(
+            long timeDuration,
+            IterableAuthRefreshReason reason,
+            final IterableHelper.SuccessHandler successCallback
+    ) {
+        if (pauseAuthRetry && !reason.ignoresRetryPolicy()) {
+            IterableLogger.d(
+                    TAG,
+                    "auth_refresh action=skip reason="
+                            + reason
+                            + " cause=retry_paused"
+            );
+            return;
+        }
+        if (scheduledRefreshTask != null) {
+            IterableLogger.d(
+                    TAG,
+                    "auth_refresh action=skip reason="
+                            + reason
+                            + " cause=already_scheduled pending_reason="
+                            + scheduledRefreshReason
+            );
             return;
         }
         if (timer == null) {
             timer = new Timer(true);
         }
 
-        try {
-            timer.schedule(new TimerTask() {
-                @Override
-                public void run() {
-                    if (api.getEmail() != null || api.getUserId() != null) {
-                        api.getAuthManager().requestNewAuthToken(false, successCallback, isScheduledRefresh);
-                    } else {
-                        IterableLogger.w(TAG, "Email or userId is not available. Skipping token refresh");
-                    }
-                    isTimerScheduled = false;
+        final TimerTask refreshTask = new TimerTask() {
+            @Override
+            public void run() {
+                if (!isCurrentRefreshTask(this, reason)) {
+                    return;
+                }
+
+                if (api.getEmail() != null || api.getUserId() != null) {
+                    dispatchRefreshTask(this, reason, successCallback);
+                } else {
+                    releaseRefreshTask(this);
+                    IterableLogger.w(
+                            TAG,
+                            "auth_refresh action=skip reason="
+                                    + reason
+                                    + " cause=identity_missing"
+                    );
                 }
-            }, timeDuration);
-            isTimerScheduled = true;
+            }
+        };
+
+        try {
+            scheduledRefreshTask = refreshTask;
+            scheduledRefreshReason = reason;
+            timer.schedule(refreshTask, timeDuration);
+            IterableLogger.d(
+                    TAG,
+                    "auth_refresh action=schedule reason="
+                            + reason
+                            + " delay_ms="
+                            + timeDuration
+            );
         } catch (Exception e) {
-            IterableLogger.e(TAG, "timer exception: " + timer, e);
+            releaseRefreshTask(refreshTask);
+            if (timer != null) {
+                timer.cancel();
+                timer = null;
+            }
+            IterableLogger.e(
+                    TAG,
+                    "auth_refresh action=error reason="
+                            + reason
+                            + " cause=schedule_failed",
+                    e
+            );
+        }
+    }
+
+    private synchronized boolean isCurrentRefreshTask(
+            TimerTask task,
+            IterableAuthRefreshReason reason
+    ) {
+        if (scheduledRefreshTask != task) {
+            IterableLogger.d(
+                    TAG,
+                    "auth_refresh action=ignore reason="
+                            + reason
+                            + " cause=stale_task"
+            );
+            return false;
+        }
+        return true;
+    }
+
+    private synchronized void dispatchRefreshTask(
+            TimerTask task,
+            IterableAuthRefreshReason reason,
+            IterableHelper.SuccessHandler successCallback
+    ) {
+        if (!isCurrentRefreshTask(task, reason)) {
+            return;
+        }
+        scheduledRefreshTask = null;
+        scheduledRefreshReason = null;
+        IterableLogger.d(TAG, "auth_refresh action=fire reason=" + reason);
+        api.getAuthManager().requestNewAuthToken(
+                false,
+                successCallback,
+                reason.ignoresRetryPolicy()
+        );
+    }
+
+    private synchronized void releaseRefreshTask(TimerTask task) {
+        if (scheduledRefreshTask == task) {
+            scheduledRefreshTask = null;
+            scheduledRefreshReason = null;
         }
     }
 
@@ -363,10 +489,28 @@ private void checkAndHandleAuthRefresh() {
     }
 
     void clearRefreshTimer() {
+        clearRefreshTimer(RefreshCancellationReason.EXPLICIT_CLEAR);
+    }
+
+    private synchronized void clearRefreshTimer(RefreshCancellationReason reason) {
+        IterableAuthRefreshReason cancelledReason = scheduledRefreshReason;
+        if (scheduledRefreshTask != null) {
+            scheduledRefreshTask.cancel();
+        }
         if (timer != null) {
             timer.cancel();
             timer = null;
-            isTimerScheduled = false;
+        }
+        scheduledRefreshTask = null;
+        scheduledRefreshReason = null;
+        if (cancelledReason != null) {
+            IterableLogger.d(
+                    TAG,
+                    "auth_refresh action=cancel reason="
+                            + cancelledReason
+                            + " cause="
+                            + reason
+            );
         }
     }
 
@@ -386,10 +530,9 @@ public void onSwitchToBackground() {
         try {
             IterableLogger.d(TAG, "App switched to background - disabling auth token requests");
             isInForeground = false;
-            clearRefreshTimer();
+            clearRefreshTimer(RefreshCancellationReason.APP_BACKGROUNDED);
         } catch (Exception e) {
             IterableLogger.e(TAG, "Error while switching to background", e);
         }
     }
 }
-

iterableapi/src/main/java/com/iterable/iterableapi/IterableAuthRefreshReason.java

@@ -0,0 +1,28 @@
+package com.iterable.iterableapi;
+
+/**
+ * Explains why the SDK scheduled an auth token refresh.
+ *
+ * The reason also defines whether the refresh is part of the normal token lifecycle or a retry
+ * that must respect the configured retry pause and maximum.
+ */
+enum IterableAuthRefreshReason {
+    TOKEN_EXPIRING(true),
+    TOKEN_EXPIRED(true),
+    STORED_TOKEN_MISSING(true),
+    TOKEN_MISSING(false),
+    TOKEN_INVALID(false),
+    AUTH_HANDLER_RETRY(false),
+    DEFERRED_REFRESH(false),
+    JWT_401(false);
+
+    private final boolean ignoresRetryPolicy;
+
+    IterableAuthRefreshReason(boolean ignoresRetryPolicy) {
+        this.ignoresRetryPolicy = ignoresRetryPolicy;
+    }
+
+    boolean ignoresRetryPolicy() {
+        return ignoresRetryPolicy;
+    }
+}

iterableapi/src/main/java/com/iterable/iterableapi/IterableKeychain.kt

@@ -16,7 +16,7 @@ class IterableKeychain {
         private const val PLAINTEXT_SUFFIX = "_plaintext"
         private const val CRYPTO_OPERATION_TIMEOUT_MS = 500L
         private const val KEY_ENCRYPTION_ENABLED = "iterable-encryption-enabled"
-        
+
         private val cryptoExecutor = Executors.newSingleThreadExecutor()
     }
 
@@ -116,7 +116,7 @@ class IterableKeychain {
         } else if (hasPlainText) {
             return sharedPrefs.getString(key, null)
         }
-        
+
         val encryptedValue = sharedPrefs.getString(key, null) ?: return null
         return try {
             encryptor?.let { runWithTimeout { it.decrypt(encryptedValue) } }