From 8fda97f30c958f4fd1f13e5d83112bf50a464c41 Mon Sep 17 00:00:00 2001
From: Tom Cherry <tomcherry@google.com>
Date: Wed, 22 Jul 2020 17:15:44 -0700
Subject: libbinder: Log 'Waiting for service...' message outside of retry loop

This is part of an effort to cut down on log spam.

Test: do not see duplicate 'Waiting for service' messages.
Change-Id: Ifa00c32ee184795b03e16b39ac70ff41ebf00331
---
 libs/binder/IServiceManager.cpp | 22 +++++++++++++++-------
 1 file changed, 15 insertions(+), 7 deletions(-)

(limited to 'libs/binder/IServiceManager.cpp')

diff --git a/libs/binder/IServiceManager.cpp b/libs/binder/IServiceManager.cpp
index 25c0b1944e..9aa82d908c 100644
--- a/libs/binder/IServiceManager.cpp
+++ b/libs/binder/IServiceManager.cpp
@@ -18,6 +18,9 @@
 
 #include <binder/IServiceManager.h>
 
+#include <inttypes.h>
+#include <unistd.h>
+
 #include <android/os/BnServiceCallback.h>
 #include <android/os/IServiceManager.h>
 #include <binder/IPCThreadState.h>
@@ -36,8 +39,6 @@
 
 #include "Static.h"
 
-#include <unistd.h>
-
 namespace android {
 
 using AidlServiceManager = android::os::IServiceManager;
@@ -219,7 +220,8 @@ sp<IBinder> ServiceManagerShim::getService(const String16& name) const
 
     const bool isVendorService =
         strcmp(ProcessState::self()->getDriverName().c_str(), "/dev/vndbinder") == 0;
-    const long timeout = uptimeMillis() + 5000;
+    const long timeout = 5000;
+    int64_t startTime = uptimeMillis();
     // Vendor code can't access system properties
     if (!gSystemBootCompleted && !isVendorService) {
 #ifdef __ANDROID__
@@ -233,15 +235,21 @@ sp<IBinder> ServiceManagerShim::getService(const String16& name) const
     // retry interval in millisecond; note that vendor services stay at 100ms
     const long sleepTime = gSystemBootCompleted ? 1000 : 100;
 
+    ALOGI("Waiting for service '%s' on '%s'...", String8(name).string(),
+          ProcessState::self()->getDriverName().c_str());
+
     int n = 0;
-    while (uptimeMillis() < timeout) {
+    while (uptimeMillis() - startTime < timeout) {
         n++;
-        ALOGI("Waiting for service '%s' on '%s'...", String8(name).string(),
-            ProcessState::self()->getDriverName().c_str());
         usleep(1000*sleepTime);
 
         sp<IBinder> svc = checkService(name);
-        if (svc != nullptr) return svc;
+        if (svc != nullptr) {
+            ALOGI("Waiting for service '%s' on '%s' successful after waiting %" PRIi64 "ms",
+                  String8(name).string(), ProcessState::self()->getDriverName().c_str(),
+                  uptimeMillis() - startTime);
+            return svc;
+        }
     }
     ALOGW("Service %s didn't start. Returning NULL", String8(name).string());
     return nullptr;
-- 
cgit v1.2.3-59-g8ed1b