commit 6c37b32a26e119df3ad7c2b178f53721bb26eb7d
author Robert Greenwalt <rgreenwalt@google.com> Tue May 22 16:07:46 2012 -0700
committer Robert Greenwalt <rgreenwalt@google.com> Thu May 24 10:47:10 2012 -0700
tree 688bc394884c3eb080a3592285c971ff5c578e53
parent eac31d5b9d9b346ce36c9790af864d3224e0524d

Modify logging to debug this issue

Logging exec time on startUsingNetworkFeature as we've had some reports suggesting it's
causing ANRs.
Remove some logging from NDC so it's local log is more useful.

bug:6492166
Change-Id: I258ff6c59bff2c65935242d50496d84720c5d493

services/java/com/android/server/NativeDaemonConnector.java

diff --git a/services/java/com/android/server/NativeDaemonConnector.java b/services/java/com/android/server/NativeDaemonConnector.java
index a15d3bb..f71125a 100644
--- a/services/java/com/android/server/NativeDaemonConnector.java
+++ b/services/java/com/android/server/NativeDaemonConnector.java
@@ -58,6 +58,7 @@
     private AtomicInteger mSequenceNumber;
 
     private static final int DEFAULT_TIMEOUT = 1 * 60 * 1000; /* 1 minute */
+    private static final long WARN_EXECUTE_DELAY_MS = 500; /* .5 sec */
 
     /** Lock held whenever communicating with native daemon. */
     private final Object mDaemonLock = new Object();
@@ -148,7 +149,6 @@
                                 mCallbackHandler.sendMessage(mCallbackHandler.obtainMessage(
                                         event.getCode(), event.getRawEvent()));
                             } else {
-                                log("POST<- {" + rawEvent + "}");
                                 mResponseQueue.add(event.getCmdNumber(), event);
                             }
                         } catch (IllegalArgumentException e) {
@@ -300,6 +300,7 @@
         final int sequenceNumber = mSequenceNumber.incrementAndGet();
         final StringBuilder cmdBuilder =
                 new StringBuilder(Integer.toString(sequenceNumber)).append(' ');
+        final long startTime = SystemClock.elapsedRealtime();
 
         makeCommand(cmdBuilder, cmd, args);
 
@@ -332,6 +333,11 @@
             events.add(event);
         } while (event.isClassContinue());
 
+        final long endTime = SystemClock.elapsedRealtime();
+        if (endTime - startTime > WARN_EXECUTE_DELAY_MS) {
+            loge("NDC Command {" + logCmd + "} took too long (" + (endTime - startTime) + "ms)");
+        }
+
         if (event.isClassClientError()) {
             throw new NativeDaemonArgumentException(logCmd, event);
         }
@@ -339,7 +345,6 @@
             throw new NativeDaemonFailureException(logCmd, event);
         }
 
-        log("RTN <- {" + logCmd + "}");
         return events.toArray(new NativeDaemonEvent[events.size()]);
     }