Clean up and clarify Crashlytics logging.

Made some log messages clearer and easier to understand, also
reduced noise by changing the log level on existing logs to:

E: Unexpected/error state, not recoverable. Crashlytics will not function.
W: Unexpected/error state, but recoverable.
D: SDK lifecycle logs ("what" is happening).
   - Unix-style "no news is good news" logging, if something goes
     wrong, it will appear in W or E logs.
V: Finer-grained logging ("how" things are happening).
   - "Success" logs, as well as logging of internally-stored values
     (e.g. current mapping file ID) are logged at this level.

Also modified a few logs to *only* print in an error case.

Author: mrwillis21

firebase-crashlytics-ndk/src/main/java/com/google/firebase/crashlytics/ndk/CrashpadController.java

@@ -55,7 +55,7 @@ public boolean initialize(String sessionId) {
         initSuccess = nativeApi.initialize(crashReportPath, context.getAssets());
       }
     } catch (IOException e) {
-      Logger.getLogger().e("Error initializing CrashlyticsNdk", e);
+      Logger.getLogger().e("Error initializing Crashlytics NDK", e);
     }
     return initSuccess;
   }
@@ -82,12 +82,14 @@ public SessionFiles getFilesForSession(String sessionId) {
     final File sessionFileDirectoryForMinidump = new File(sessionFileDirectory, "pending");
 
     Logger.getLogger()
-        .d("Minidump directory: " + sessionFileDirectoryForMinidump.getAbsolutePath());
+        .v("Minidump directory: " + sessionFileDirectoryForMinidump.getAbsolutePath());
 
     File minidump = getSingleFileWithExtension(sessionFileDirectoryForMinidump, ".dmp");
 
     Logger.getLogger()
-        .d("Minidump " + (minidump != null && minidump.exists() ? "exists" : "does not exist"));
+        .v(
+            "Minidump file "
+                + (minidump != null && minidump.exists() ? "exists" : "does not exist"));
 
     final SessionFiles.Builder builder = new SessionFiles.Builder();
     if (sessionFileDirectory != null

firebase-crashlytics-ndk/src/main/java/com/google/firebase/crashlytics/ndk/FirebaseCrashlyticsNdk.java

@@ -50,8 +50,9 @@ public boolean hasCrashDataForSession(@NonNull String sessionId) {
   @Override
   public boolean openSession(String sessionId) {
     final boolean initSuccess = controller.initialize(sessionId);
-    Logger.getLogger()
-        .i("Crashlytics NDK initialization " + (initSuccess ? "successful" : "FAILED"));
+    if (!initSuccess) {
+      Logger.getLogger().w("Failed to initialize Crashlytics NDK for session " + sessionId);
+    }
     return initSuccess;
   }
 

firebase-crashlytics/src/main/java/com/google/firebase/crashlytics/CrashlyticsAnalyticsListener.java

@@ -20,6 +20,7 @@
 import com.google.firebase.analytics.connector.AnalyticsConnector.AnalyticsConnectorListener;
 import com.google.firebase.crashlytics.internal.Logger;
 import com.google.firebase.crashlytics.internal.analytics.AnalyticsEventReceiver;
+import java.util.Locale;
 
 /**
  * Crashlytics listener for Firebase Analytics events. Processes incoming events and passes those
@@ -46,7 +47,10 @@ public void setBreadcrumbEventReceiver(@Nullable AnalyticsEventReceiver receiver
 
   @Override
   public void onMessageTriggered(int id, @Nullable Bundle extras) {
-    Logger.getLogger().d("Received Analytics message: " + id + " " + extras);
+    Logger.getLogger()
+        .v(
+            String.format(
+                Locale.US, "Analytics listener received message. ID: %d, Extras: %s", id, extras));
 
     if (extras == null) {
       return;

firebase-crashlytics/src/main/java/com/google/firebase/crashlytics/FirebaseCrashlytics.java

@@ -92,7 +92,6 @@ public class FirebaseCrashlytics {
 
     if (analyticsConnector != null) {
       // If FA is available, create a logger to log events from the Crashlytics origin.
-      Logger.getLogger().d("Firebase Analytics is available.");
       final CrashlyticsOriginAnalyticsEventLogger directAnalyticsEventLogger =
           new CrashlyticsOriginAnalyticsEventLogger(analyticsConnector);
 
@@ -107,7 +106,7 @@ public class FirebaseCrashlytics {
           subscribeToAnalyticsEvents(analyticsConnector, crashlyticsAnalyticsListener);
 
       if (analyticsConnectorHandle != null) {
-        Logger.getLogger().d("Firebase Analytics listener registered successfully.");
+        Logger.getLogger().d("Registered Firebase Analytics listener.");
         // Create the event receiver which will supply breadcrumb events to Crashlytics
         final BreadcrumbAnalyticsEventReceiver breadcrumbReceiver =
             new BreadcrumbAnalyticsEventReceiver();
@@ -132,7 +131,8 @@ public class FirebaseCrashlytics {
         // Set the blocking analytics event logger for Crashlytics.
         analyticsEventLogger = blockingAnalyticsEventLogger;
       } else {
-        Logger.getLogger().d("Firebase Analytics listener registration failed.");
+        Logger.getLogger()
+            .w("Could not register Firebase Analytics listener; a listener is already registered.");
         // FA is enabled, but the listener was not registered successfully.
         // We cannot listen for breadcrumbs.
         breadcrumbSource = new DisabledBreadcrumbSource();
@@ -142,7 +142,7 @@ public class FirebaseCrashlytics {
       }
     } else {
       // FA is entirely unavailable. We cannot listen for breadcrumbs or send events.
-      Logger.getLogger().d("Firebase Analytics is unavailable.");
+      Logger.getLogger().d("Firebase Analytics is not available.");
       breadcrumbSource = new DisabledBreadcrumbSource();
       analyticsEventLogger = new UnavailableAnalyticsEventLogger();
     }
@@ -161,7 +161,7 @@ public class FirebaseCrashlytics {
 
     final String googleAppId = app.getOptions().getApplicationId();
     final String mappingFileId = CommonUtils.getMappingFileId(context);
-    Logger.getLogger().d("Mapping file ID is: " + mappingFileId);
+    Logger.getLogger().v("Mapping file ID is: " + mappingFileId);
 
     final UnityVersionProvider unityVersionProvider = new ResourceUnityVersionProvider(context);
 
@@ -170,11 +170,11 @@ public class FirebaseCrashlytics {
       appData =
           AppData.create(context, idManager, googleAppId, mappingFileId, unityVersionProvider);
     } catch (PackageManager.NameNotFoundException e) {
-      Logger.getLogger().e("Could not retrieve app info, initialization failed.", e);
+      Logger.getLogger().e("Error retrieving app package info.", e);
       return null;
     }
 
-    Logger.getLogger().d("Installer package name is: " + appData.installerPackageName);
+    Logger.getLogger().v("Installer package name is: " + appData.installerPackageName);
 
     final ExecutorService threadPoolExecutor =
         ExecutorUtils.buildSingleThreadExecutorService("com.google.firebase.crashlytics.startup");
@@ -282,7 +282,7 @@ public static FirebaseCrashlytics getInstance() {
    */
   public void recordException(@NonNull Throwable throwable) {
     if (throwable == null) { // Users could call this with null despite the annotation.
-      Logger.getLogger().w("Crashlytics is ignoring a request to log a null exception.");
+      Logger.getLogger().v("A null value was passed to recordException. Ignoring.");
       return;
     }
     core.logException(throwable);

firebase-crashlytics/src/main/java/com/google/firebase/crashlytics/internal/analytics/BlockingAnalyticsEventLogger.java

@@ -51,23 +51,25 @@ public BlockingAnalyticsEventLogger(
   @Override
   public void logEvent(@NonNull String name, @Nullable Bundle params) {
     synchronized (latchLock) {
-      Logger.getLogger().d("Logging Crashlytics event to Firebase");
+      Logger.getLogger()
+          .v("Logging event " + name + " to Firebase Analytics with params " + params);
       this.eventLatch = new CountDownLatch(1);
       this.callbackReceived = false;
 
       baseAnalyticsEventLogger.logEvent(name, params);
 
-      Logger.getLogger().d("Awaiting app exception callback from FA...");
+      Logger.getLogger().v("Awaiting app exception callback from Analytics...");
       try {
         if (eventLatch.await(timeout, timeUnit)) {
           callbackReceived = true;
-          Logger.getLogger().d("App exception callback received from FA listener.");
+          Logger.getLogger().v("App exception callback received from Analytics listener.");
         } else {
           Logger.getLogger()
-              .d("Timeout exceeded while awaiting app exception callback from FA listener.");
+              .w("Timeout exceeded while awaiting app exception callback from Analytics listener.");
         }
       } catch (InterruptedException ie) {
-        Logger.getLogger().d("Interrupted while awaiting app exception callback from FA listener.");
+        Logger.getLogger()
+            .e("Interrupted while awaiting app exception callback from Analytics listener.");
       }
 
       this.eventLatch = null;

firebase-crashlytics/src/main/java/com/google/firebase/crashlytics/internal/common/CommonUtils.java

@@ -158,7 +158,7 @@ static Architecture getValue() {
       String arch = Build.CPU_ABI;
 
       if (TextUtils.isEmpty(arch)) {
-        Logger.getLogger().d("Architecture#getValue()::Build.CPU_ABI returned null or empty");
+        Logger.getLogger().v("Architecture#getValue()::Build.CPU_ABI returned null or empty");
         return UNKNOWN;
       }
 
@@ -195,7 +195,7 @@ public static synchronized long getTotalRamInBytes() {
             // leave in this handling since we don't know for certain it isn't.
             bytes = convertMemInfoToBytes(result, "GB", BYTES_IN_A_GIGABYTE);
           } else {
-            Logger.getLogger().d("Unexpected meminfo format while computing RAM: " + result);
+            Logger.getLogger().w("Unexpected meminfo format while computing RAM: " + result);
           }
         } catch (NumberFormatException e) {
           Logger.getLogger().e("Unexpected meminfo format while computing RAM: " + result, e);
@@ -606,7 +606,7 @@ public static String resolveUnityEditorVersion(Context context) {
     final int id = CommonUtils.getResourcesIdentifier(context, UNITY_EDITOR_VERSION, "string");
     if (id != 0) {
       version = context.getResources().getString(id);
-      Logger.getLogger().d("Unity Editor version is: " + version);
+      Logger.getLogger().v("Unity Editor version is: " + version);
     }
     return version;
   }

firebase-crashlytics/src/main/java/com/google/firebase/crashlytics/internal/common/CrashlyticsController.java

@@ -165,12 +165,7 @@ synchronized void handleUncaughtException(
       @NonNull final Throwable ex) {
 
     Logger.getLogger()
-        .d(
-            "Crashlytics is handling uncaught "
-                + "exception \""
-                + ex
-                + "\" from thread "
-                + thread.getName());
+        .d("Handling uncaught " + "exception \"" + ex + "\" from thread " + thread.getName());
 
     // Capture the time that the crash occurs and close over it so that the time doesn't
     // reflect when we get around to executing the task later.
@@ -258,7 +253,7 @@ private Task<Boolean> waitForReportAction() {
     }
 
     Logger.getLogger().d("Automatic data collection is disabled.");
-    Logger.getLogger().d("Notifying that unsent reports are available.");
+    Logger.getLogger().v("Notifying that unsent reports are available.");
     unsentReportsAvailable.trySetResult(true);
 
     // If data collection gets enabled while we are waiting for an action, go ahead and send the
@@ -289,7 +284,7 @@ boolean didCrashOnPreviousExecution() {
       return sessionId != null && nativeComponent.hasCrashDataForSession(sessionId);
     }
 
-    Logger.getLogger().d("Found previous crash marker.");
+    Logger.getLogger().v("Found previous crash marker.");
     crashMarker.remove();
 
     return Boolean.TRUE;
@@ -302,7 +297,7 @@ Task<Boolean> checkForUnsentReports() {
     // and 2) when there's a fatal crash. So no new reports will become available while the app is
     // running.
     if (!checkForUnsentReportsCalled.compareAndSet(false, true)) {
-      Logger.getLogger().d("checkForUnsentReports should only be called once per execution.");
+      Logger.getLogger().w("checkForUnsentReports should only be called once per execution.");
       return Tasks.forResult(false);
     }
     return unsentReportsAvailable.getTask();
@@ -321,11 +316,11 @@ Task<Void> deleteUnsentReports() {
   Task<Void> submitAllReports(Task<AppSettingsData> appSettingsDataTask) {
     if (!reportingCoordinator.hasReportsToSend()) {
       // Just notify the user that there are no reports and stop.
-      Logger.getLogger().d("No reports are available.");
+      Logger.getLogger().v("No crash reports are available to be sent.");
       unsentReportsAvailable.trySetResult(false);
       return Tasks.forResult(null);
     }
-    Logger.getLogger().d("Unsent reports are available.");
+    Logger.getLogger().v("Crash reports are available to be sent.");
 
     return waitForReportAction()
         .onSuccessTask(
@@ -339,14 +334,14 @@ public Task<Void> then(@Nullable Boolean send) throws Exception {
                       @Override
                       public Task<Void> call() throws Exception {
                         if (!send) {
-                          Logger.getLogger().d("Reports are being deleted.");
+                          Logger.getLogger().v("Deleting cached crash reports...");
                           deleteFiles(listAppExceptionMarkerFiles());
                           reportingCoordinator.removeAllReports();
                           unsentReportsHandled.trySetResult(null);
                           return Tasks.forResult(null);
                         }
 
-                        Logger.getLogger().d("Reports are being sent.");
+                        Logger.getLogger().d("Sending cached crash reports...");
 
                         // waitForReportAction guarantees we got user permission.
                         boolean dataCollectionToken = send;
@@ -367,7 +362,7 @@ public Task<Void> then(@Nullable AppSettingsData appSettingsData)
                                 if (appSettingsData == null) {
                                   Logger.getLogger()
                                       .w(
-                                          "Received null app settings, cannot send reports during app startup.");
+                                          "Received null app settings at app startup. Cannot send cached reports");
                                   return Tasks.forResult(null);
                                 }
                                 logAnalyticsAppExceptionEvents();
@@ -414,7 +409,7 @@ public void run() {
               final String currentSessionId = getCurrentSessionId();
               if (currentSessionId == null) {
                 Logger.getLogger()
-                    .d("Tried to write a non-fatal exception while no session was open.");
+                    .w("Tried to write a non-fatal exception while no session was open.");
                 return;
               }
               reportingCoordinator.persistNonFatalEvent(
@@ -526,18 +521,18 @@ boolean finalizeSessions() {
     backgroundWorker.checkRunningOnThread();
 
     if (isHandlingException()) {
-      Logger.getLogger().d("Skipping session finalization because a crash has already occurred.");
+      Logger.getLogger().w("Skipping session finalization because a crash has already occurred.");
       return Boolean.FALSE;
     }
 
-    Logger.getLogger().d("Finalizing previously open sessions.");
+    Logger.getLogger().v("Finalizing previously open sessions.");
     try {
       doCloseSessions(true);
     } catch (Exception e) {
       Logger.getLogger().e("Unable to finalize previously open sessions.", e);
       return false;
     }
-    Logger.getLogger().d("Closed all previously open sessions");
+    Logger.getLogger().v("Closed all previously open sessions.");
 
     return true;
   }
@@ -577,7 +572,7 @@ private void doCloseSessions(boolean skipCurrentSession) {
     List<String> sortedOpenSessions = reportingCoordinator.listSortedOpenSessionIds();
 
     if (sortedOpenSessions.size() <= offset) {
-      Logger.getLogger().d("No open sessions to be closed.");
+      Logger.getLogger().v("No open sessions to be closed.");
       return;
     }
 
@@ -588,7 +583,7 @@ private void doCloseSessions(boolean skipCurrentSession) {
       // data when we aren't including current.
       finalizePreviousNativeSession(mostRecentSessionIdToClose);
       if (!nativeComponent.finalizeSession(mostRecentSessionIdToClose)) {
-        Logger.getLogger().d("Could not finalize native session: " + mostRecentSessionIdToClose);
+        Logger.getLogger().w("Could not finalize native session: " + mostRecentSessionIdToClose);
       }
     }
 
@@ -627,7 +622,7 @@ private static File[] ensureFileArrayNotNull(File[] files) {
   // endregion
 
   private void finalizePreviousNativeSession(String previousSessionId) {
-    Logger.getLogger().d("Finalizing native report for session " + previousSessionId);
+    Logger.getLogger().v("Finalizing native report for session " + previousSessionId);
     NativeSessionFileProvider nativeSessionFileProvider =
         nativeComponent.getSessionFileProvider(previousSessionId);
     File minidumpFile = nativeSessionFileProvider.getMinidumpFile();
@@ -643,7 +638,7 @@ private void finalizePreviousNativeSession(String previousSessionId) {
     final File nativeSessionDirectory = new File(getNativeSessionFilesDir(), previousSessionId);
 
     if (!nativeSessionDirectory.mkdirs()) {
-      Logger.getLogger().d("Couldn't create native sessions directory");
+      Logger.getLogger().w("Couldn't create directory to store native session files, aborting.");
       return;
     }
 
@@ -673,7 +668,7 @@ private void doWriteAppExceptionMarker(long eventTime) {
     try {
       new File(getFilesDir(), APP_EXCEPTION_MARKER_PREFIX + eventTime).createNewFile();
     } catch (IOException e) {
-      Logger.getLogger().d("Could not write app exception marker.");
+      Logger.getLogger().w("Could not create app exception marker file.", e);
     }
   }
 
@@ -772,7 +767,7 @@ private Task<Void> logAnalyticsAppExceptionEvents() {
             Long.parseLong(markerFile.getName().substring(APP_EXCEPTION_MARKER_PREFIX.length()));
         events.add(logAnalyticsAppExceptionEvent(timestamp));
       } catch (NumberFormatException nfe) {
-        Logger.getLogger().d("Could not parse timestamp from file " + markerFile.getName());
+        Logger.getLogger().w("Could not parse timestamp from file " + markerFile.getName());
       }
       markerFile.delete();
     }
@@ -782,9 +777,10 @@ private Task<Void> logAnalyticsAppExceptionEvents() {
 
   private Task<Void> logAnalyticsAppExceptionEvent(long timestamp) {
     if (firebaseCrashExists()) {
-      Logger.getLogger().d("Skipping logging Crashlytics event to Firebase, FirebaseCrash exists");
+      Logger.getLogger().v("Skipping logging Crashlytics event to Firebase, FirebaseCrash exists");
       return Tasks.forResult(null);
     }
+    Logger.getLogger().d("Logging app exception event to Firebase Analytics");
     final ThreadPoolExecutor executor = new ScheduledThreadPoolExecutor(1);
     return Tasks.call(
         executor,