Fix authentication delay when WebView forces a token refresh (home-assistant#691)

Refs home-assistant#592. I believe the issue is that the referenced module in the frontend is refreshing the token itself, and that's causing our expiration logic to be incorrect -- we think we have a valid token, but it's actually been replaced.

We do eventually recover when one of our own network requests yields an invalid token response, but that's _after_ we've already told the WebView about the token we believed was valid. The frontend will then retry in 10 seconds, but not before considering the token we provided as an invalid login attempt and throwing a log.

This also resolves some threading issues with the cache wrapping refresh token, whose goal was to avoid issuing more than one request at once. Since the WebView callbacks were happening on the on the main queue, and the Alamofire responses on the utility queue, it was possible for both to mutate and kick off refreshes at once, which would also log login failures.

This also adds some logs to try and understand the issues that may be happening in that ticket if this doesn't resolve them.

Author: zacwest

HomeAssistant/Views/WebViewController.swift

@@ -711,9 +711,10 @@ extension WebViewController: WKScriptMessageHandler {
         } else if message.name == "updateThemeColors" {
             self.handleThemeUpdate(messageBody)
         } else if message.name == "getExternalAuth", let callbackName = messageBody["callback"] {
+            let force = messageBody["force"] as? Bool ?? false
             if let tokenManager = Current.tokenManager {
-                Current.Log.verbose("getExternalAuth called")
-                tokenManager.authDictionaryForWebView.done { dictionary in
+                Current.Log.verbose("getExternalAuth called, forced: \(force)")
+                tokenManager.authDictionaryForWebView(forceRefresh: force).done { dictionary in
                     let jsonData = try? JSONSerialization.data(withJSONObject: dictionary, options: [])
                     if let jsonString = String(data: jsonData!, encoding: .utf8) {
                         // swiftlint:disable:next line_length

Shared/Authentication/TokenManager.swift

@@ -19,7 +19,32 @@ public class TokenManager: RequestAdapter, RequestRetrier {
 
     private var tokenInfo: TokenInfo?
     private var authenticationAPI: AuthenticationAPI
-    private var refreshPromiseCache: Promise<String>?
+
+    private class RefreshPromiseCache {
+        // we can be asked to refresh from any queue - alamofire's utility queue, webview's main queue, so guard
+        // accessing the underlying promise here without being on the queue is programmer error
+        let queue: DispatchQueue
+        private let queueSpecific = DispatchSpecificKey<Bool>()
+
+        init() {
+            queue = DispatchQueue(label: "refresh-promise-cache-mutex", qos: .userInitiated)
+            queue.setSpecific(key: queueSpecific, value: true)
+        }
+
+        private var underlyingPromise: Promise<String>?
+
+        var promise: Promise<String>? {
+            get {
+                assert(DispatchQueue.getSpecific(key: queueSpecific) == true)
+                return underlyingPromise
+            }
+            set {
+                assert(DispatchQueue.getSpecific(key: queueSpecific) == true)
+                underlyingPromise = newValue
+            }
+        }
+    }
+    private let refreshPromiseCache = RefreshPromiseCache()
     private let connectionInfo: ConnectionInfo
 
     public var isAuthenticated: Bool {
@@ -66,19 +91,25 @@ public class TokenManager: RequestAdapter, RequestRetrier {
         }
     }
 
-    public var authDictionaryForWebView: Promise<[String: Any]> {
-        return firstly {
-                self.bearerToken
-            }.map { _ -> [String: Any] in
-                // TokenInfo is refreshed at this point.
-                guard let info = self.tokenInfo  else {
-                    throw TokenError.tokenUnavailable
-                }
+    public func authDictionaryForWebView(forceRefresh: Bool) -> Promise<[String: Any]> {
+        return firstly { () -> Promise<String> in
+            if forceRefresh {
+                Current.Log.info("forcing a refresh of token")
+                return refreshToken
+            } else {
+                Current.Log.info("using existing token")
+                return bearerToken
+            }
+        }.map { _ -> [String: Any] in
+            // TokenInfo is refreshed at this point.
+            guard let info = self.tokenInfo  else {
+                throw TokenError.tokenUnavailable
+            }
 
-                var dictionary: [String: Any] = [:]
-                dictionary["access_token"] = info.accessToken
-                dictionary["expires_in"] = Int(info.expiration.timeIntervalSince(Current.date()))
-                return dictionary
+            var dictionary: [String: Any] = [:]
+            dictionary["access_token"] = info.accessToken
+            dictionary["expires_in"] = Int(info.expiration.timeIntervalSince(Current.date()))
+            return dictionary
         }
     }
 
@@ -220,41 +251,55 @@ public class TokenManager: RequestAdapter, RequestRetrier {
         return connectionInfo.checkURLMatches(url)
     }
 
-    private var newCodePromise: Promise<Void>?
     private var refreshToken: Promise<String> {
-        guard let tokenInfo = self.tokenInfo else {
-            return Promise(error: TokenError.tokenUnavailable)
-        }
-
-        if let refreshPromise = self.refreshPromiseCache {
-            return refreshPromise
-        }
-
-        let promise: Promise<String> =
-            self.authenticationAPI.refreshTokenWith(tokenInfo: tokenInfo).map { tokenInfo in
-            self.refreshPromiseCache = nil
-            Current.settingsStore.tokenInfo = tokenInfo
-            self.tokenInfo = tokenInfo
-            return tokenInfo.accessToken
-        }.ensure {
-            self.refreshPromiseCache = nil
-        }
+        refreshPromiseCache.queue.sync {
+            guard let tokenInfo = self.tokenInfo else {
+                Current.Log.error("no token info, can't refresh")
+                return Promise(error: TokenError.tokenUnavailable)
+            }
 
-        promise.catch { error in
-            if let networkError = error as? AFError, let statusCode = networkError.responseCode,
-                statusCode == 400 {
-                /// Server rejected the refresh token. All is lost.
-                let event = ClientEvent(text: "Refresh token is invalid, showing onboarding", type: .networkRequest)
-                Current.clientEventStore.addEvent(event)
+            if let refreshPromise = self.refreshPromiseCache.promise {
+                Current.Log.info("using cached refreshToken promise")
+                return refreshPromise
+            }
 
-                self.tokenInfo = nil
-                Current.settingsStore.tokenInfo = nil
-                Current.signInRequiredCallback?(.error)
+            let promise: Promise<String> = firstly {
+                self.authenticationAPI.refreshTokenWith(tokenInfo: tokenInfo)
+            }.map { tokenInfo in
+                Current.Log.info("storing refresh token")
+                Current.settingsStore.tokenInfo = tokenInfo
+                self.tokenInfo = tokenInfo
+                return tokenInfo.accessToken
+            }.ensure(on: refreshPromiseCache.queue) {
+                Current.Log.info("reset cached refreshToken promise")
+                self.refreshPromiseCache.promise = nil
+            }.tap { result in
+                switch result {
+                case .rejected(let error):
+                    Current.Log.error("refresh token got error: \(error)")
+
+                    if let networkError = error as? AFError, let statusCode = networkError.responseCode,
+                        statusCode == 400 {
+                        /// Server rejected the refresh token. All is lost.
+                        let event = ClientEvent(
+                            text: "Refresh token is invalid, showing onboarding",
+                            type: .networkRequest
+                        )
+                        Current.clientEventStore.addEvent(event)
+
+                        self.tokenInfo = nil
+                        Current.settingsStore.tokenInfo = nil
+                        Current.signInRequiredCallback?(.error)
+                    }
+                case .fulfilled:
+                    Current.Log.info("refresh token got success")
+                }
             }
-        }
 
-        self.refreshPromiseCache = promise
-        return promise
+            Current.Log.info("starting refreshToken cache")
+            self.refreshPromiseCache.promise = promise
+            return promise
+        }
     }
 }