Fix a few flaky tests in several products (Auth, Analytics, Storage, RTDB, Firestore) (#1520)

* Fix flaky tests on Auth, Analytics, and GMA (with additional debug output).

* Revert GMA changes, no longer needed.

* Add logging for storage timestamp

* Fix build error.

* Change timestamp logic.

* Deflake the Storage timestamp test by getting the timestamp from the remote server.

* Add retries.

* Increase timeout on Android FTL tests.

* Handle Analytics test flakiness on Android.

* Add remote timestamp verification to RTDB test as well.

* Fix extra semicolon.

* Change UpdateChildren test to use remote timestamp.

Author: jonsimantov

.github/workflows/integration_tests.yml

@@ -1047,7 +1047,7 @@ jobs:
       - id: ftl_test
         if: steps.device-info.outputs.device_type == 'ftl'
         uses: FirebaseExtended/github-actions/[email protected]
-        timeout-minutes: 90
+        timeout-minutes: 120
         with:
           credentials_json: ${{ secrets.FIREBASE_SERVICE_ACCOUNT_CREDENTIALS }}
           testapp_dir: testapps

analytics/integration_test/src/integration_test.cc

@@ -100,10 +100,14 @@ TEST_F(FirebaseAnalyticsTest, TestSetSessionTimeoutDuraction) {
 }
 
 TEST_F(FirebaseAnalyticsTest, TestGetAnalyticsInstanceID) {
+  FLAKY_TEST_SECTION_BEGIN();
+
   firebase::Future<std::string> future =
       firebase::analytics::GetAnalyticsInstanceId();
   WaitForCompletion(future, "GetAnalyticsInstanceId");
   EXPECT_FALSE(future.result()->empty());
+
+  FLAKY_TEST_SECTION_END();
 }
 
 TEST_F(FirebaseAnalyticsTest, TestGetSessionID) {
@@ -232,10 +236,7 @@ TEST_F(FirebaseAnalyticsTest, TestLogEventWithMultipleParameters) {
 }
 
 TEST_F(FirebaseAnalyticsTest, TestResettingGivesNewInstanceId) {
-  // Test is flaky on iPhone due to a known issue in iOS.  See b/143656277.
-#if TARGET_OS_IPHONE
   FLAKY_TEST_SECTION_BEGIN();
-#endif  // TARGET_OS_IPHONE
 
   firebase::Future<std::string> future =
       firebase::analytics::GetAnalyticsInstanceId();
@@ -251,9 +252,7 @@ TEST_F(FirebaseAnalyticsTest, TestResettingGivesNewInstanceId) {
   EXPECT_FALSE(future.result()->empty());
   EXPECT_NE(instance_id, new_instance_id);
 
-#if TARGET_OS_IPHONE
   FLAKY_TEST_SECTION_END();
-#endif  // TARGET_OS_IPHONE
 }
 
 }  // namespace firebase_testapp_automated

auth/integration_test/src/integration_test.cc

@@ -948,7 +948,10 @@ TEST_F(FirebaseAuthTest, TestUpdateEmailAndPassword_DEPRECATED) {
 }
 
 TEST_F(FirebaseAuthTest, TestLinkAnonymousUserWithEmailCredential) {
-  SignInAnonymously();
+  FLAKY_TEST_SECTION_BEGIN();
+
+  WaitForCompletion(auth_->SignInAnonymously(), "SignInAnonymously");
+
   firebase::auth::User user = auth_->current_user();
   EXPECT_TRUE(user.is_valid());
   std::string email = GenerateEmailAddress();
@@ -958,7 +961,7 @@ TEST_F(FirebaseAuthTest, TestLinkAnonymousUserWithEmailCredential) {
   WaitForCompletion(user.LinkWithCredential(credential), "LinkWithCredential");
   WaitForCompletion(user.Unlink(credential.provider().c_str()), "Unlink");
   SignOut();
-  SignInAnonymously();
+  WaitForCompletion(auth_->SignInAnonymously(), "SignInAnonymously");
   user = auth_->current_user();
   EXPECT_TRUE(user.is_valid());
   std::string email1 = GenerateEmailAddress();
@@ -979,10 +982,16 @@ TEST_F(FirebaseAuthTest, TestLinkAnonymousUserWithEmailCredential) {
                     firebase::auth::kAuthErrorProviderAlreadyLinked);
   WaitForCompletion(user.Unlink(credential.provider().c_str()), "Unlink 2");
   DeleteUser();
+
+  // In case any operations failed, force signout before retrying the test.
+  SignOut();
+  FLAKY_TEST_SECTION_END();
 }
 
 TEST_F(FirebaseAuthTest, TestLinkAnonymousUserWithEmailCredential_DEPRECATED) {
-  SignInAnonymously_DEPRECATED();
+  FLAKY_TEST_SECTION_BEGIN();
+
+  WaitForCompletion(auth_->SignInAnonymously_DEPRECATED(), "SignInAnonymously");
   ASSERT_NE(auth_->current_user_DEPRECATED(), nullptr);
   firebase::auth::User* user = auth_->current_user_DEPRECATED();
   std::string email = GenerateEmailAddress();
@@ -994,7 +1003,7 @@ TEST_F(FirebaseAuthTest, TestLinkAnonymousUserWithEmailCredential_DEPRECATED) {
   WaitForCompletion(user->Unlink_DEPRECATED(credential.provider().c_str()),
                     "Unlink");
   SignOut();
-  SignInAnonymously_DEPRECATED();
+  WaitForCompletion(auth_->SignInAnonymously_DEPRECATED(), "SignInAnonymously");
   EXPECT_NE(auth_->current_user_DEPRECATED(), nullptr);
   std::string email1 = GenerateEmailAddress();
   firebase::auth::Credential credential1 =
@@ -1012,6 +1021,9 @@ TEST_F(FirebaseAuthTest, TestLinkAnonymousUserWithEmailCredential_DEPRECATED) {
   WaitForCompletion(user->Unlink_DEPRECATED(credential.provider().c_str()),
                     "Unlink_DEPRECATED 2");
   DeleteUser_DEPRECATED();
+
+  SignOut();
+  FLAKY_TEST_SECTION_END();
 }
 
 TEST_F(FirebaseAuthTest, TestLinkAnonymousUserWithBadCredential) {

database/integration_test/src/integration_test.cc

@@ -47,6 +47,7 @@ namespace firebase_testapp_automated {
 using app_framework::LogDebug;
 using app_framework::LogError;
 using app_framework::LogInfo;
+using app_framework::LogWarning;
 
 using app_framework::ProcessEvents;
 using firebase_test_framework::FirebaseTest;
@@ -146,6 +147,8 @@ class FirebaseDatabaseTest : public FirebaseTest {
   // Shut down Firebase Database.
   void TerminateDatabase();
 
+  int64_t GetRemoteTimeInMilliseconds();
+
   firebase::database::DatabaseReference CreateWorkingPath(
       bool suppress_cleanup = false);
 
@@ -365,6 +368,30 @@ firebase::database::DatabaseReference FirebaseDatabaseTest::CreateWorkingPath(
   return ref;
 }
 
+int64_t FirebaseDatabaseTest::GetRemoteTimeInMilliseconds() {
+  firebase::database::DatabaseReference ref =
+      CreateWorkingPath().Child("timestamp");
+  WaitForCompletionAnyResult(
+      ref.SetValue(firebase::database::ServerTimestamp()),
+      "GetRemoteTime_SetValue");
+  firebase::Future<firebase::database::DataSnapshot> future = ref.GetValue();
+  WaitForCompletionAnyResult(future, "GetRemoteTime_GetValue");
+  int64_t timestamp = 0;
+  if (future.error() == 0 && future.result() &&
+      future.result()->value().is_int64()) {
+    timestamp = future.result()->value().int64_value();
+  }
+  if (timestamp > 0) {
+    LogDebug("Got server timestamp: %lld", timestamp);
+    LogDebug("     Local timestamp: %lld",
+             app_framework::GetCurrentTimeInMicroseconds() / 1000L);
+    return timestamp;
+  } else {
+    LogWarning("Couldn't get remote timestamp, using local time");
+    return app_framework::GetCurrentTimeInMicroseconds() / 1000L;
+  }
+}
+
 // Test cases below.
 TEST_F(FirebaseDatabaseTest, TestInitializeAndTerminate) {
   // Already tested via SetUp() and TearDown().
@@ -460,8 +487,7 @@ TEST_F(FirebaseDatabaseTest, TestSetAndGetSimpleValues) {
     WaitForCompletion(f7, "GetLongDouble");
 
     // Get the current time to compare to the Timestamp.
-    int64_t current_time_milliseconds =
-        static_cast<int64_t>(time(nullptr)) * 1000L;
+    int64_t current_time_milliseconds = GetRemoteTimeInMilliseconds();
 
     EXPECT_EQ(f1.result()->value().AsString(), kSimpleString);
     EXPECT_EQ(f2.result()->value().AsInt64(), kSimpleInt);
@@ -672,8 +698,8 @@ TEST_F(FirebaseDatabaseTest, TestUpdateChildren) {
   WaitForCompletion(update_future, "UpdateChildren");
   read_future = ref.Child(test_name).GetValue();
   WaitForCompletion(read_future, "GetValue 2");
-  int64_t current_time_milliseconds =
-      static_cast<int64_t>(time(nullptr)) * 1000L;
+  int64_t current_time_milliseconds = GetRemoteTimeInMilliseconds();
+
   EXPECT_THAT(
       read_future.result()->value().map(),
       UnorderedElementsAre(

storage/integration_test/src/integration_test.cc

@@ -118,6 +118,8 @@ class FirebaseStorageTest : public FirebaseTest {
   // Create a unique working folder and return a reference to it.
   firebase::storage::StorageReference CreateFolder();
 
+  int64_t GetRemoteTimeInMilliseconds();
+
   static firebase::App* shared_app_;
   static firebase::auth::Auth* shared_auth_;
 
@@ -324,6 +326,30 @@ firebase::storage::StorageReference FirebaseStorageTest::CreateFolder() {
   return storage_->GetReference(kRootNodeName).Child(saved_url_);
 }
 
+int64_t FirebaseStorageTest::GetRemoteTimeInMilliseconds() {
+  SignIn();
+
+  firebase::storage::StorageReference ref =
+      CreateFolder().Child("timestamp.txt");
+  firebase::Future<firebase::storage::Metadata> future =
+      RunWithRetry<firebase::storage::Metadata>(
+          [&]() { return ref.PutBytes("TS00", 4); });
+  WaitForCompletionAnyResult(future, "GetRemoteTime_PutBytes");
+  if (future.error() == 0 && future.result() != nullptr &&
+      future.result()->creation_time() > 0) {
+    int64_t timestamp = future.result()->creation_time();
+    WaitForCompletionAnyResult(RunWithRetry([&]() { return ref.Delete(); }),
+                               "GetRemoteTime_Delete");
+    LogDebug("Got server timestamp: %lld", timestamp);
+    LogDebug("     Local timestamp: %lld",
+             app_framework::GetCurrentTimeInMicroseconds() / 1000L);
+    return timestamp;
+  } else {
+    LogWarning("Couldn't get remote timestamp, using local time");
+    return app_framework::GetCurrentTimeInMicroseconds() / 1000L;
+  }
+}
+
 // Test cases below.
 
 TEST_F(FirebaseStorageTest, TestInitializeAndTerminate) {
@@ -497,17 +523,23 @@ TEST_F(FirebaseStorageTest, TestWriteAndReadFileWithCustomMetadata) {
     ASSERT_NE(metadata, nullptr);
 
     // Get the current time to compare to the Timestamp.
-    int64_t current_time_seconds = static_cast<int64_t>(time(nullptr));
+    int64_t current_time_seconds = GetRemoteTimeInMilliseconds() / 1000L;
     int64_t updated_time_milliseconds = metadata->updated_time();
-    int64_t updated_time_seconds = updated_time_milliseconds / 1000;
+    int64_t updated_time_seconds = updated_time_milliseconds / 1000L;
     int64_t time_difference_seconds =
         updated_time_seconds - current_time_seconds;
+    if (time_difference_seconds < 0)
+      time_difference_seconds = -time_difference_seconds;
     // As long as our timestamp is within a day, it's correct enough for
     // our purposes.
     const int64_t kAllowedTimeDifferenceSeconds = 60L * 60L * 24L;
     EXPECT_TRUE(time_difference_seconds < kAllowedTimeDifferenceSeconds &&
                 time_difference_seconds > -kAllowedTimeDifferenceSeconds)
-        << "Bad timestamp in metadata.";
+        << "Bad timestamp in metadata. Metadata timestamp is "
+        << updated_time_seconds << ", current time is " << current_time_seconds
+        << ", difference = " << time_difference_seconds
+        << " (allowed difference " << kAllowedTimeDifferenceSeconds << ").";
+
     EXPECT_EQ(metadata->size_bytes(), kSimpleTestFile.size());
     EXPECT_EQ(metadata->content_type(), content_type);
     ASSERT_NE(metadata->custom_metadata(), nullptr);