Add debug logging around token expiration (#7461)

* Add debug logging around token expiration.

* Use FIRLogger instead of NSLog.

* Move log statement.

* Add another log statement when access token is updated.

Author: rosalyntan

FirebaseAuth/Sources/SystemService/FIRSecureTokenService.m

@@ -19,11 +19,14 @@
 #import "FirebaseAuth/Sources/Public/FirebaseAuth/FIRAuth.h"
 
 #import "FirebaseAuth/Sources/Auth/FIRAuthSerialTaskQueue.h"
+#import "FirebaseAuth/Sources/Auth/FIRAuth_Internal.h"
 #import "FirebaseAuth/Sources/Backend/FIRAuthBackend.h"
 #import "FirebaseAuth/Sources/Backend/FIRAuthRequestConfiguration.h"
 #import "FirebaseAuth/Sources/Backend/RPC/FIRSecureTokenRequest.h"
 #import "FirebaseAuth/Sources/Backend/RPC/FIRSecureTokenResponse.h"
 
+#import "FirebaseCore/Sources/Private/FirebaseCoreInternal.h"
+
 NS_ASSUME_NONNULL_BEGIN
 
 /** @var kAPIKeyCodingKey
@@ -111,6 +114,7 @@ - (void)fetchAccessTokenForcingRefresh:(BOOL)forceRefresh
       complete();
       callback(self->_accessToken, nil, NO);
     } else {
+      FIRLogDebug(kFIRLoggerAuth, @"I-AUT000017", @"Fetching new token from backend.");
       [self requestAccessToken:^(NSString *_Nullable token, NSError *_Nullable error,
                                  BOOL tokenUpdated) {
         complete();
@@ -189,6 +193,9 @@ - (void)requestAccessToken:(FIRFetchAccessTokenCallback)callback {
              self->_accessToken = [newAccessToken copy];
              self->_accessTokenExpirationDate = response.approximateExpirationDate;
              tokenUpdated = YES;
+             FIRLogDebug(kFIRLoggerAuth, @"I-AUT000017",
+                         @"Updated access token. Estimated expiration date: %@, current date: %@",
+                         self->_accessTokenExpirationDate, [NSDate date]);
            }
            NSString *newRefreshToken = response.refreshToken;
            if (newRefreshToken.length && ![newRefreshToken isEqualToString:self->_refreshToken]) {
@@ -200,7 +207,19 @@ - (void)requestAccessToken:(FIRFetchAccessTokenCallback)callback {
 }
 
 - (BOOL)hasValidAccessToken {
-  return _accessToken && [_accessTokenExpirationDate timeIntervalSinceNow] > kFiveMinutes;
+  BOOL hasValidAccessToken =
+      _accessToken && [_accessTokenExpirationDate timeIntervalSinceNow] > kFiveMinutes;
+  if (hasValidAccessToken) {
+    FIRLogDebug(kFIRLoggerAuth, @"I-AUT000017",
+                @"Has valid access token. Estimated expiration date: %@, current date: %@",
+                _accessTokenExpirationDate, [NSDate date]);
+  } else {
+    FIRLogDebug(
+        kFIRLoggerAuth, @"I-AUT000017",
+        @"Does not have valid access token. Estimated expiration date: %@, current date: %@",
+        _accessTokenExpirationDate, [NSDate date]);
+  }
+  return hasValidAccessToken;
 }
 
 @end

FirebaseAuth/Sources/User/FIRUser.m

@@ -881,18 +881,22 @@ - (void)getIDTokenResultWithCompletion:(nullable FIRAuthTokenResultCallback)comp
 - (void)getIDTokenResultForcingRefresh:(BOOL)forceRefresh
                             completion:(nullable FIRAuthTokenResultCallback)completion {
   dispatch_async(FIRAuthGlobalWorkQueue(), ^{
-    [self internalGetTokenForcingRefresh:forceRefresh
-                                callback:^(NSString *_Nullable token, NSError *_Nullable error) {
-                                  FIRAuthTokenResult *tokenResult;
-                                  if (token) {
-                                    tokenResult = [FIRAuthTokenResult tokenResultWithToken:token];
-                                  }
-                                  if (completion) {
-                                    dispatch_async(dispatch_get_main_queue(), ^{
-                                      completion(tokenResult, error);
-                                    });
-                                  }
-                                }];
+    [self
+        internalGetTokenForcingRefresh:forceRefresh
+                              callback:^(NSString *_Nullable token, NSError *_Nullable error) {
+                                FIRAuthTokenResult *tokenResult;
+                                if (token) {
+                                  tokenResult = [FIRAuthTokenResult tokenResultWithToken:token];
+                                  FIRLogDebug(kFIRLoggerAuth, @"I-AUT000017",
+                                              @"Actual token expiration date: %@, current date: %@",
+                                              tokenResult.expirationDate, [NSDate date]);
+                                }
+                                if (completion) {
+                                  dispatch_async(dispatch_get_main_queue(), ^{
+                                    completion(tokenResult, error);
+                                  });
+                                }
+                              }];
   });
 }