Transplant the Logging system from Telecom
This change is the preliminary transplant of the functionality from
Telecom into android.telecom. It is currently not being used
anywhere and is not hooked into Telecom yet. It will be after this
change is committed.
Test: Refactoring CL. Existing tests still pass
Bug: 26571395
Change-Id: I406975e686c6eaab7e31b1efa426b3406c8e90cf
diff --git a/telecomm/java/android/telecom/Log.java b/telecomm/java/android/telecom/Log.java
index a965342..ecda3cd 100644
--- a/telecomm/java/android/telecom/Log.java
+++ b/telecomm/java/android/telecom/Log.java
@@ -18,9 +18,15 @@
import android.net.Uri;
import android.os.AsyncTask;
+import android.telecom.Logging.EventManager;
+import android.telecom.Logging.Session;
+import android.telecom.Logging.SessionManager;
import android.telephony.PhoneNumberUtils;
import android.text.TextUtils;
+import com.android.internal.annotations.VisibleForTesting;
+import com.android.internal.util.IndentingPrintWriter;
+
import java.security.MessageDigest;
import java.security.NoSuchAlgorithmException;
import java.util.IllegalFormatException;
@@ -31,24 +37,270 @@
*
* @hide
*/
-final public class Log {
+public class Log {
- // Generic tag for all Telecom Framework logging
- private static final String TAG = "TelecomFramework";
+ private static final long EXTENDED_LOGGING_DURATION_MILLIS = 60000 * 30; // 30 minutes
- public static final boolean FORCE_LOGGING = false; /* STOP SHIP if true */
+ private static final int EVENTS_TO_CACHE = 10;
+ private static final int EVENTS_TO_CACHE_DEBUG = 20;
+
+ // Generic tag for all Telecom logging
+ @VisibleForTesting
+ public static String TAG = "TelecomFramework";
+
+ private static final boolean FORCE_LOGGING = false; /* STOP SHIP if true */
public static final boolean DEBUG = isLoggable(android.util.Log.DEBUG);
public static final boolean INFO = isLoggable(android.util.Log.INFO);
public static final boolean VERBOSE = isLoggable(android.util.Log.VERBOSE);
public static final boolean WARN = isLoggable(android.util.Log.WARN);
public static final boolean ERROR = isLoggable(android.util.Log.ERROR);
+ // Used to synchronize singleton logging lazy initialization
+ private static final Object sSingletonSync = new Object();
+ private static EventManager sEventManager;
+ private static SessionManager sSessionManager;
+
+ /**
+ * Tracks whether user-activated extended logging is enabled.
+ */
+ private static boolean sIsUserExtendedLoggingEnabled = false;
+
+ /**
+ * The time when user-activated extended logging should be ended. Used to determine when
+ * extended logging should automatically be disabled.
+ */
+ private static long sUserExtendedLoggingStopTime = 0;
+
+ private Log() {
+ }
+
+ public static void d(String prefix, String format, Object... args) {
+ if (sIsUserExtendedLoggingEnabled) {
+ maybeDisableLogging();
+ android.util.Slog.i(TAG, buildMessage(prefix, format, args));
+ } else if (DEBUG) {
+ android.util.Slog.d(TAG, buildMessage(prefix, format, args));
+ }
+ }
+
+ public static void d(Object objectPrefix, String format, Object... args) {
+ if (sIsUserExtendedLoggingEnabled) {
+ maybeDisableLogging();
+ android.util.Slog.i(TAG, buildMessage(getPrefixFromObject(objectPrefix), format, args));
+ } else if (DEBUG) {
+ android.util.Slog.d(TAG, buildMessage(getPrefixFromObject(objectPrefix), format, args));
+ }
+ }
+
+ public static void i(String prefix, String format, Object... args) {
+ if (INFO) {
+ android.util.Slog.i(TAG, buildMessage(prefix, format, args));
+ }
+ }
+
+ public static void i(Object objectPrefix, String format, Object... args) {
+ if (INFO) {
+ android.util.Slog.i(TAG, buildMessage(getPrefixFromObject(objectPrefix), format, args));
+ }
+ }
+
+ public static void v(String prefix, String format, Object... args) {
+ if (sIsUserExtendedLoggingEnabled) {
+ maybeDisableLogging();
+ android.util.Slog.i(TAG, buildMessage(prefix, format, args));
+ } else if (VERBOSE) {
+ android.util.Slog.v(TAG, buildMessage(prefix, format, args));
+ }
+ }
+
+ public static void v(Object objectPrefix, String format, Object... args) {
+ if (sIsUserExtendedLoggingEnabled) {
+ maybeDisableLogging();
+ android.util.Slog.i(TAG, buildMessage(getPrefixFromObject(objectPrefix), format, args));
+ } else if (VERBOSE) {
+ android.util.Slog.v(TAG, buildMessage(getPrefixFromObject(objectPrefix), format, args));
+ }
+ }
+
+ public static void w(String prefix, String format, Object... args) {
+ if (WARN) {
+ android.util.Slog.w(TAG, buildMessage(prefix, format, args));
+ }
+ }
+
+ public static void w(Object objectPrefix, String format, Object... args) {
+ if (WARN) {
+ android.util.Slog.w(TAG, buildMessage(getPrefixFromObject(objectPrefix), format, args));
+ }
+ }
+
+ public static void e(String prefix, Throwable tr, String format, Object... args) {
+ if (ERROR) {
+ android.util.Slog.e(TAG, buildMessage(prefix, format, args), tr);
+ }
+ }
+
+ public static void e(Object objectPrefix, Throwable tr, String format, Object... args) {
+ if (ERROR) {
+ android.util.Slog.e(TAG, buildMessage(getPrefixFromObject(objectPrefix), format, args),
+ tr);
+ }
+ }
+
+ public static void wtf(String prefix, Throwable tr, String format, Object... args) {
+ android.util.Slog.wtf(TAG, buildMessage(prefix, format, args), tr);
+ }
+
+ public static void wtf(Object objectPrefix, Throwable tr, String format, Object... args) {
+ android.util.Slog.wtf(TAG, buildMessage(getPrefixFromObject(objectPrefix), format, args),
+ tr);
+ }
+
+ public static void wtf(String prefix, String format, Object... args) {
+ String msg = buildMessage(prefix, format, args);
+ android.util.Slog.wtf(TAG, msg, new IllegalStateException(msg));
+ }
+
+ public static void wtf(Object objectPrefix, String format, Object... args) {
+ String msg = buildMessage(getPrefixFromObject(objectPrefix), format, args);
+ android.util.Slog.wtf(TAG, msg, new IllegalStateException(msg));
+ }
+
+ /**
+ * The ease of use methods below only act mostly as proxies to the Session and Event Loggers.
+ * They also control the lazy loaders of the singleton instances, which will never be loaded if
+ * the proxy methods aren't used.
+ *
+ * Please see each method's documentation inside of their respective implementations in the
+ * loggers.
+ */
+
+ public static void startSession(String shortMethodName) {
+ getSessionManager().startSession(shortMethodName, null);
+ }
+
+ public static void startSession(String shortMethodName, String callerIdentification) {
+ getSessionManager().startSession(shortMethodName, callerIdentification);
+ }
+
+ public static Session createSubsession() {
+ return getSessionManager().createSubsession();
+ }
+
+ public static void cancelSubsession(Session subsession) {
+ getSessionManager().cancelSubsession(subsession);
+ }
+
+ public static void continueSession(Session subsession, String shortMethodName) {
+ getSessionManager().continueSession(subsession, shortMethodName);
+ }
+
+ public static void endSession() {
+ getSessionManager().endSession();
+ }
+
+ public static String getSessionId() {
+ // If the Session logger has not been initialized, then there have been no sessions logged.
+ // Don't load it now!
+ synchronized (sSingletonSync) {
+ if (sSessionManager != null) {
+ return getSessionManager().getSessionId();
+ } else {
+ return "";
+ }
+ }
+ }
+
+ public static void addEvent(EventManager.Loggable recordEntry, String event) {
+ getEventManager().event(recordEntry, event, null);
+ }
+
+ public static void addEvent(EventManager.Loggable recordEntry, String event, Object data) {
+ getEventManager().event(recordEntry, event, data);
+ }
+
+ public static void addEvent(EventManager.Loggable recordEntry, String event, String format,
+ Object... args) {
+ getEventManager().event(recordEntry, event, format, args);
+ }
+
+ public static void registerEventListener(EventManager.EventListener e) {
+ getEventManager().registerEventListener(e);
+ }
+
+ public static void addRequestResponsePair(EventManager.TimedEventPair p) {
+ getEventManager().addRequestResponsePair(p);
+ }
+
+ public static void dumpEvents(IndentingPrintWriter pw) {
+ // If the Events logger has not been initialized, then there have been no events logged.
+ // Don't load it now!
+ synchronized (sSingletonSync) {
+ if (sEventManager != null) {
+ getEventManager().dumpEvents(pw);
+ } else {
+ pw.println("No Historical Events Logged.");
+ }
+ }
+ }
+
+ /**
+ * Enable or disable extended telecom logging.
+ *
+ * @param isExtendedLoggingEnabled {@code true} if extended logging should be enabled,
+ * {@code false} if it should be disabled.
+ */
+ public static void setIsExtendedLoggingEnabled(boolean isExtendedLoggingEnabled) {
+ // If the state hasn't changed, bail early.
+ if (sIsUserExtendedLoggingEnabled == isExtendedLoggingEnabled) {
+ return;
+ }
+
+ if (sEventManager != null) {
+ sEventManager.changeEventCacheSize(isExtendedLoggingEnabled ?
+ EVENTS_TO_CACHE_DEBUG : EVENTS_TO_CACHE);
+ }
+
+ sIsUserExtendedLoggingEnabled = isExtendedLoggingEnabled;
+ if (sIsUserExtendedLoggingEnabled) {
+ sUserExtendedLoggingStopTime = System.currentTimeMillis()
+ + EXTENDED_LOGGING_DURATION_MILLIS;
+ } else {
+ sUserExtendedLoggingStopTime = 0;
+ }
+ }
+
+ private static EventManager getEventManager() {
+ // Checking for null again outside of synchronization because we only need to synchronize
+ // during the lazy loading of the events logger. We don't need to synchronize elsewhere.
+ if (sEventManager == null) {
+ synchronized (sSingletonSync) {
+ if (sEventManager == null) {
+ sEventManager = new EventManager(Log::getSessionId);
+ return sEventManager;
+ }
+ }
+ }
+ return sEventManager;
+ }
+
+ private static SessionManager getSessionManager() {
+ // Checking for null again outside of synchronization because we only need to synchronize
+ // during the lazy loading of the session logger. We don't need to synchronize elsewhere.
+ if (sSessionManager == null) {
+ synchronized (sSingletonSync) {
+ if (sSessionManager == null) {
+ sSessionManager = new SessionManager();
+ return sSessionManager;
+ }
+ }
+ }
+ return sSessionManager;
+ }
+
private static MessageDigest sMessageDigest;
- private static final Object sMessageDigestLock = new Object();
- private Log() {}
-
- public static void initMd5Sum() {
+ static void initMd5Sum() {
new AsyncTask<Void, Void, Void>() {
@Override
public Void doInBackground(Void... args) {
@@ -58,96 +310,69 @@
} catch (NoSuchAlgorithmException e) {
md = null;
}
- synchronized (sMessageDigestLock) {
- sMessageDigest = md;
- }
+ sMessageDigest = md;
return null;
}
}.execute();
}
+ public static void setTag(String tag) {
+ TAG = tag;
+ }
+
+ /**
+ * If user enabled extended logging is enabled and the time limit has passed, disables the
+ * extended logging.
+ */
+ private static void maybeDisableLogging() {
+ if (!sIsUserExtendedLoggingEnabled) {
+ return;
+ }
+
+ if (sUserExtendedLoggingStopTime < System.currentTimeMillis()) {
+ sUserExtendedLoggingStopTime = 0;
+ sIsUserExtendedLoggingEnabled = false;
+ }
+ }
+
public static boolean isLoggable(int level) {
return FORCE_LOGGING || android.util.Log.isLoggable(TAG, level);
}
- public static void d(String prefix, String format, Object... args) {
- if (DEBUG) {
- android.util.Log.d(TAG, buildMessage(prefix, format, args));
+ public static String piiHandle(Object pii) {
+ if (pii == null || VERBOSE) {
+ return String.valueOf(pii);
}
- }
- public static void d(Object objectPrefix, String format, Object... args) {
- if (DEBUG) {
- android.util.Log.d(TAG, buildMessage(getPrefixFromObject(objectPrefix), format, args));
+ StringBuilder sb = new StringBuilder();
+ if (pii instanceof Uri) {
+ Uri uri = (Uri) pii;
+ String scheme = uri.getScheme();
+
+ if (!TextUtils.isEmpty(scheme)) {
+ sb.append(scheme).append(":");
+ }
+
+ String textToObfuscate = uri.getSchemeSpecificPart();
+ if (PhoneAccount.SCHEME_TEL.equals(scheme)) {
+ for (int i = 0; i < textToObfuscate.length(); i++) {
+ char c = textToObfuscate.charAt(i);
+ sb.append(PhoneNumberUtils.isDialable(c) ? "*" : c);
+ }
+ } else if (PhoneAccount.SCHEME_SIP.equals(scheme)) {
+ for (int i = 0; i < textToObfuscate.length(); i++) {
+ char c = textToObfuscate.charAt(i);
+ if (c != '@' && c != '.') {
+ c = '*';
+ }
+ sb.append(c);
+ }
+ } else {
+ sb.append(pii(pii));
+ }
}
- }
- public static void i(String prefix, String format, Object... args) {
- if (INFO) {
- android.util.Log.i(TAG, buildMessage(prefix, format, args));
- }
- }
-
- public static void i(Object objectPrefix, String format, Object... args) {
- if (INFO) {
- android.util.Log.i(TAG, buildMessage(getPrefixFromObject(objectPrefix), format, args));
- }
- }
-
- public static void v(String prefix, String format, Object... args) {
- if (VERBOSE) {
- android.util.Log.v(TAG, buildMessage(prefix, format, args));
- }
- }
-
- public static void v(Object objectPrefix, String format, Object... args) {
- if (VERBOSE) {
- android.util.Log.v(TAG, buildMessage(getPrefixFromObject(objectPrefix), format, args));
- }
- }
-
- public static void w(String prefix, String format, Object... args) {
- if (WARN) {
- android.util.Log.w(TAG, buildMessage(prefix, format, args));
- }
- }
-
- public static void w(Object objectPrefix, String format, Object... args) {
- if (WARN) {
- android.util.Log.w(TAG, buildMessage(getPrefixFromObject(objectPrefix), format, args));
- }
- }
-
- public static void e(String prefix, Throwable tr, String format, Object... args) {
- if (ERROR) {
- android.util.Log.e(TAG, buildMessage(prefix, format, args), tr);
- }
- }
-
- public static void e(Object objectPrefix, Throwable tr, String format, Object... args) {
- if (ERROR) {
- android.util.Log.e(TAG, buildMessage(getPrefixFromObject(objectPrefix), format, args),
- tr);
- }
- }
-
- public static void wtf(String prefix, Throwable tr, String format, Object... args) {
- android.util.Log.wtf(TAG, buildMessage(prefix, format, args), tr);
- }
-
- public static void wtf(Object objectPrefix, Throwable tr, String format, Object... args) {
- android.util.Log.wtf(TAG, buildMessage(getPrefixFromObject(objectPrefix), format, args),
- tr);
- }
-
- public static void wtf(String prefix, String format, Object... args) {
- String msg = buildMessage(prefix, format, args);
- android.util.Log.wtf(TAG, msg, new IllegalStateException(msg));
- }
-
- public static void wtf(Object objectPrefix, String format, Object... args) {
- String msg = buildMessage(getPrefixFromObject(objectPrefix), format, args);
- android.util.Log.wtf(TAG, msg, new IllegalStateException(msg));
+ return sb.toString();
}
/**
@@ -158,47 +383,18 @@
public static String pii(Object pii) {
if (pii == null || VERBOSE) {
return String.valueOf(pii);
- } if (pii instanceof Uri) {
- return piiUri((Uri) pii);
}
return "[" + secureHash(String.valueOf(pii).getBytes()) + "]";
}
- private static String piiUri(Uri handle) {
- StringBuilder sb = new StringBuilder();
- String scheme = handle.getScheme();
- if (!TextUtils.isEmpty(scheme)) {
- sb.append(scheme).append(":");
- }
- String value = handle.getSchemeSpecificPart();
- if (!TextUtils.isEmpty(value)) {
- for (int i = 0; i < value.length(); i++) {
- char c = value.charAt(i);
- if (PhoneNumberUtils.isStartsPostDial(c)) {
- sb.append(c);
- } else if (PhoneNumberUtils.isDialable(c)) {
- sb.append("*");
- } else if (('a' <= c && c <= 'z') || ('A' <= c && c <= 'Z')) {
- sb.append("*");
- } else {
- sb.append(c);
- }
- }
- }
- return sb.toString();
-
- }
-
private static String secureHash(byte[] input) {
- synchronized (sMessageDigestLock) {
- if (sMessageDigest != null) {
- sMessageDigest.reset();
- sMessageDigest.update(input);
- byte[] result = sMessageDigest.digest();
- return encodeHex(result);
- } else {
- return "Uninitialized SHA1";
- }
+ if (sMessageDigest != null) {
+ sMessageDigest.reset();
+ sMessageDigest.update(input);
+ byte[] result = sMessageDigest.digest();
+ return encodeHex(result);
+ } else {
+ return "Uninitialized SHA1";
}
}
@@ -221,15 +417,19 @@
}
private static String buildMessage(String prefix, String format, Object... args) {
+ // Incorporate thread ID and calling method into prefix
+ String sessionName = getSessionId();
+ String sessionPostfix = TextUtils.isEmpty(sessionName) ? "" : ": " + sessionName;
+
String msg;
try {
msg = (args == null || args.length == 0) ? format
: String.format(Locale.US, format, args);
} catch (IllegalFormatException ife) {
- wtf("Log", ife, "IllegalFormatException: formatString='%s' numArgs=%d", format,
+ e("Log", ife, "IllegalFormatException: formatString='%s' numArgs=%d", format,
args.length);
msg = format + " (An error occurred while formatting the message.)";
}
- return String.format(Locale.US, "%s: %s", prefix, msg);
+ return String.format(Locale.US, "%s: %s%s", prefix, msg, sessionPostfix);
}
}
diff --git a/telecomm/java/android/telecom/Logging/EventManager.java b/telecomm/java/android/telecom/Logging/EventManager.java
new file mode 100644
index 0000000..8e7a393
--- /dev/null
+++ b/telecomm/java/android/telecom/Logging/EventManager.java
@@ -0,0 +1,365 @@
+/*
+ * Copyright (C) 2016 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License
+ */
+
+package android.telecom.Logging;
+
+import android.annotation.NonNull;
+import android.telecom.Log;
+import android.text.TextUtils;
+
+import com.android.internal.util.IndentingPrintWriter;
+
+import java.text.DateFormat;
+import java.text.SimpleDateFormat;
+import java.util.ArrayList;
+import java.util.Collections;
+import java.util.Date;
+import java.util.HashMap;
+import java.util.IllegalFormatException;
+import java.util.LinkedList;
+import java.util.List;
+import java.util.Locale;
+import java.util.Map;
+import java.util.concurrent.LinkedBlockingQueue;
+
+/**
+ * A utility class that provides the ability to define Events that a subsystem deems important, and
+ * then relate those events to other events so that information can be extracted. For example, a
+ * START and FINISH event can be defined and when a START and then FINISH occurs in a sequence, the
+ * time it took to complete that sequence can be saved to be retrieved later.
+ * @hide
+ */
+
+public class EventManager {
+
+ public static final String TAG = "Logging.Events";
+ public static final int DEFAULT_EVENTS_TO_CACHE = 10; // Arbitrarily chosen.
+
+ public interface Loggable {
+ /**
+ * @return a unique String ID that will allow the Event to be recognized later in the logs.
+ */
+ String getId();
+
+ /**
+ * @return Formatted information about the state that will be printed out later in the logs.
+ */
+ String getDescription();
+ }
+
+ private final Map<Loggable, EventRecord> mCallEventRecordMap = new HashMap<>();
+ private LinkedBlockingQueue<EventRecord> mEventRecords =
+ new LinkedBlockingQueue<>(DEFAULT_EVENTS_TO_CACHE);
+
+ private List<EventListener> mEventListeners = new ArrayList<>();
+
+ public interface EventListener {
+ /**
+ * Notifies the implementation of this method that a new event record has been added.
+ * @param eventRecord Reference to the recently added EventRecord
+ */
+ void eventRecordAdded(EventRecord eventRecord);
+ }
+
+ private SessionManager.ISessionIdQueryHandler mSessionIdHandler;
+ /**
+ * Maps from request events to a list of possible response events. Used to track
+ * end-to-end timing for critical user-facing operations in Telecom.
+ */
+ public final Map<String, List<TimedEventPair>> requestResponsePairs = new HashMap<>();
+
+ private static final Object mSync = new Object();
+
+ /**
+ * Stores the various events.
+ * Also stores all request-response pairs amongst the events.
+ */
+ public static class TimedEventPair {
+ private static final long DEFAULT_TIMEOUT = 3000L;
+
+ String mRequest;
+ String mResponse;
+ String mName;
+ long mTimeoutMillis = DEFAULT_TIMEOUT;
+
+ public TimedEventPair(String request, String response, String name) {
+ this.mRequest = request;
+ this.mResponse = response;
+ this.mName = name;
+ }
+
+ public TimedEventPair(String request, String response, String name, long timeoutMillis) {
+ this.mRequest = request;
+ this.mResponse = response;
+ this.mName = name;
+ this.mTimeoutMillis = timeoutMillis;
+ }
+ }
+
+ public void addRequestResponsePair(TimedEventPair p) {
+ if (requestResponsePairs.containsKey(p.mRequest)) {
+ requestResponsePairs.get(p.mRequest).add(p);
+ } else {
+ ArrayList<TimedEventPair> responses = new ArrayList<>();
+ responses.add(p);
+ requestResponsePairs.put(p.mRequest, responses);
+ }
+ }
+
+ public static class Event {
+ public String eventId;
+ public String sessionId;
+ public long time;
+ public Object data;
+
+ public Event(String eventId, String sessionId, long time, Object data) {
+ this.eventId = eventId;
+ this.sessionId = sessionId;
+ this.time = time;
+ this.data = data;
+ }
+ }
+
+ public class EventRecord {
+ public class EventTiming extends TimedEvent<String> {
+ public String name;
+ public long time;
+
+ public EventTiming(String name, long time) {
+ this.name = name;
+ this.time = time;
+ }
+
+ public String getKey() {
+ return name;
+ }
+
+ public long getTime() {
+ return time;
+ }
+ }
+
+ private class PendingResponse {
+ String requestEventId;
+ long requestEventTimeMillis;
+ long timeoutMillis;
+ String name;
+
+ public PendingResponse(String requestEventId, long requestEventTimeMillis,
+ long timeoutMillis, String name) {
+ this.requestEventId = requestEventId;
+ this.requestEventTimeMillis = requestEventTimeMillis;
+ this.timeoutMillis = timeoutMillis;
+ this.name = name;
+ }
+ }
+
+ private final DateFormat sDateFormat = new SimpleDateFormat("HH:mm:ss.SSS");
+ private final List<Event> mEvents = new LinkedList<>();
+ private final Loggable mRecordEntry;
+
+ public EventRecord(Loggable recordEntry) {
+ mRecordEntry = recordEntry;
+ }
+
+ public Loggable getRecordEntry() {
+ return mRecordEntry;
+ }
+
+ public void addEvent(String event, String sessionId, Object data) {
+ mEvents.add(new Event(event, sessionId, System.currentTimeMillis(), data));
+ Log.i("Event", "RecordEntry %s: %s, %s", mRecordEntry.getId(), event, data);
+ }
+
+ public List<Event> getEvents() {
+ return mEvents;
+ }
+
+ public List<EventTiming> extractEventTimings() {
+ if (mEvents == null) {
+ return Collections.emptyList();
+ }
+
+ LinkedList<EventTiming> result = new LinkedList<>();
+ Map<String, PendingResponse> pendingResponses = new HashMap<>();
+ for (Event event : mEvents) {
+ if (requestResponsePairs.containsKey(event.eventId)) {
+ // This event expects a response, so add that expected response to the maps
+ // of pending events.
+ for (EventManager.TimedEventPair p : requestResponsePairs.get(event.eventId)) {
+ pendingResponses.put(p.mResponse, new PendingResponse(event.eventId,
+ event.time, p.mTimeoutMillis, p.mName));
+ }
+ }
+
+ PendingResponse pendingResponse = pendingResponses.remove(event.eventId);
+ if (pendingResponse != null) {
+ long elapsedTime = event.time - pendingResponse.requestEventTimeMillis;
+ if (elapsedTime < pendingResponse.timeoutMillis) {
+ result.add(new EventTiming(pendingResponse.name, elapsedTime));
+ }
+ }
+ }
+
+ return result;
+ }
+
+ public void dump(IndentingPrintWriter pw) {
+ pw.print(mRecordEntry.getDescription());
+
+ pw.increaseIndent();
+ for (Event event : mEvents) {
+ pw.print(sDateFormat.format(new Date(event.time)));
+ pw.print(" - ");
+ pw.print(event.eventId);
+ if (event.data != null) {
+ pw.print(" (");
+ Object data = event.data;
+
+ if (data instanceof Loggable) {
+ // If the data is another Loggable, then change the data to the
+ // Entry's Event ID instead.
+ EventRecord record = mCallEventRecordMap.get(data);
+ if (record != null) {
+ data = "RecordEntry " + record.mRecordEntry.getId();
+ }
+ }
+
+ pw.print(data);
+ pw.print(")");
+ }
+ if (!TextUtils.isEmpty(event.sessionId)) {
+ pw.print(":");
+ pw.print(event.sessionId);
+ }
+ pw.println();
+ }
+
+ pw.println("Timings (average for this call, milliseconds):");
+ pw.increaseIndent();
+ Map<String, Double> avgEventTimings = EventTiming.averageTimings(extractEventTimings());
+ List<String> eventNames = new ArrayList<>(avgEventTimings.keySet());
+ Collections.sort(eventNames);
+ for (String eventName : eventNames) {
+ pw.printf("%s: %.2f\n", eventName, avgEventTimings.get(eventName));
+ }
+ pw.decreaseIndent();
+ pw.decreaseIndent();
+ }
+ }
+
+ public EventManager(@NonNull SessionManager.ISessionIdQueryHandler l) {
+ mSessionIdHandler = l;
+ }
+
+ public void event(Loggable recordEntry, String event, Object data) {
+ String currentSessionID = mSessionIdHandler.getSessionId();
+
+ if (recordEntry == null) {
+ Log.i(TAG, "Non-call EVENT: %s, %s", event, data);
+ return;
+ }
+ synchronized (mEventRecords) {
+ if (!mCallEventRecordMap.containsKey(recordEntry)) {
+ EventRecord newRecord = new EventRecord(recordEntry);
+ addEventRecord(newRecord);
+ }
+
+ EventRecord record = mCallEventRecordMap.get(recordEntry);
+ record.addEvent(event, currentSessionID, data);
+ }
+ }
+
+ public void event(Loggable recordEntry, String event, String format, Object... args) {
+ String msg;
+ try {
+ msg = (args == null || args.length == 0) ? format
+ : String.format(Locale.US, format, args);
+ } catch (IllegalFormatException ife) {
+ Log.e("Log", ife, "IllegalFormatException: formatString='%s' numArgs=%d", format,
+ args.length);
+ msg = format + " (An error occurred while formatting the message.)";
+ }
+
+ event(recordEntry, event, msg);
+ }
+
+ public void dumpEvents(IndentingPrintWriter pw) {
+ pw.println("Historical Events:");
+ pw.increaseIndent();
+ for (EventRecord eventRecord : mEventRecords) {
+ eventRecord.dump(pw);
+ }
+ pw.decreaseIndent();
+ }
+
+ public void changeEventCacheSize(int newSize) {
+
+ // Resize the event queue.
+ LinkedBlockingQueue<EventRecord> oldEventLog = mEventRecords;
+ mEventRecords = new LinkedBlockingQueue<>(newSize);
+ mCallEventRecordMap.clear();
+
+ oldEventLog.forEach((newRecord -> {
+ Loggable recordEntry = newRecord.getRecordEntry();
+ // Copy the existing queue into the new one.
+ // First remove the oldest entry if no new ones exist.
+ if (mEventRecords.remainingCapacity() == 0) {
+ EventRecord record = mEventRecords.poll();
+ if (record != null) {
+ mCallEventRecordMap.remove(record.getRecordEntry());
+ }
+ }
+
+ // Now add a new entry
+ mEventRecords.add(newRecord);
+ mCallEventRecordMap.put(recordEntry, newRecord);
+
+ // Don't worry about notifying mEventListeners, since we are just resizing the records.
+ }));
+ }
+
+ public void registerEventListener(EventListener e) {
+ if (e != null) {
+ synchronized (mSync) {
+ mEventListeners.add(e);
+ }
+ }
+ }
+
+ private void addEventRecord(EventRecord newRecord) {
+ Loggable recordEntry = newRecord.getRecordEntry();
+
+ // First remove the oldest entry if no new ones exist.
+ if (mEventRecords.remainingCapacity() == 0) {
+ EventRecord record = mEventRecords.poll();
+ if (record != null) {
+ mCallEventRecordMap.remove(record.getRecordEntry());
+ }
+ }
+
+ // Now add a new entry
+ mEventRecords.add(newRecord);
+ mCallEventRecordMap.put(recordEntry, newRecord);
+
+ // TODO: Add Implementation of this in Telecom for Analytics
+ synchronized (mSync) {
+ for (EventListener l : mEventListeners) {
+ l.eventRecordAdded(newRecord);
+ }
+ }
+ }
+}
diff --git a/telecomm/java/android/telecom/Logging/Session.java b/telecomm/java/android/telecom/Logging/Session.java
new file mode 100644
index 0000000..14f4a0f
--- /dev/null
+++ b/telecomm/java/android/telecom/Logging/Session.java
@@ -0,0 +1,223 @@
+/*
+ * Copyright (C) 2016 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License
+ */
+
+package android.telecom.Logging;
+
+import android.annotation.NonNull;
+
+import java.util.ArrayList;
+
+/**
+ * The session that stores information about a thread's point of entry into the Telecom code that
+ * persists until the thread exits Telecom.
+ * @hide
+ */
+public class Session {
+
+ public static final String START_SESSION = "START_SESSION";
+ public static final String CREATE_SUBSESSION = "CREATE_SUBSESSION";
+ public static final String CONTINUE_SUBSESSION = "CONTINUE_SUBSESSION";
+ public static final String END_SUBSESSION = "END_SUBSESSION";
+ public static final String END_SESSION = "END_SESSION";
+
+ public static final int UNDEFINED = -1;
+
+ private String mSessionId;
+ private String mShortMethodName;
+ private long mExecutionStartTimeMs;
+ private long mExecutionEndTimeMs = UNDEFINED;
+ private Session mParentSession;
+ private ArrayList<Session> mChildSessions;
+ private boolean mIsCompleted = false;
+ private int mChildCounter = 0;
+ // True if this is a subsession that has been started from the same thread as the parent
+ // session. This can happen if Log.startSession(...) is called multiple times on the same
+ // thread in the case of one Telecom entry point method calling another entry point method.
+ // In this case, we can just make this subsession "invisible," but still keep track of it so
+ // that the Log.endSession() calls match up.
+ private boolean mIsStartedFromActiveSession = false;
+ // Optionally provided info about the method/class/component that started the session in order
+ // to make Logging easier. This info will be provided in parentheses along with the session.
+ private String mOwnerInfo;
+
+ public Session(String sessionId, String shortMethodName, long startTimeMs, long threadID,
+ boolean isStartedFromActiveSession, String ownerInfo) {
+ setSessionId(sessionId);
+ setShortMethodName(shortMethodName);
+ mExecutionStartTimeMs = startTimeMs;
+ mParentSession = null;
+ mChildSessions = new ArrayList<>(5);
+ mIsStartedFromActiveSession = isStartedFromActiveSession;
+ mOwnerInfo = ownerInfo;
+ }
+
+ public void setSessionId(@NonNull String sessionId) {
+ if (sessionId == null) {
+ mSessionId = "?";
+ }
+ mSessionId = sessionId;
+ }
+
+ public String getShortMethodName() {
+ return mShortMethodName;
+ }
+
+ public void setShortMethodName(String shortMethodName) {
+ if (shortMethodName == null) {
+ shortMethodName = "";
+ }
+ mShortMethodName = shortMethodName;
+ }
+
+ public void setParentSession(Session parentSession) {
+ mParentSession = parentSession;
+ }
+
+ public void addChild(Session childSession) {
+ if (childSession != null) {
+ mChildSessions.add(childSession);
+ }
+ }
+
+ public void removeChild(Session child) {
+ if (child != null) {
+ mChildSessions.remove(child);
+ }
+ }
+
+ public long getExecutionStartTimeMilliseconds() {
+ return mExecutionStartTimeMs;
+ }
+
+ public void setExecutionStartTimeMs(long startTimeMs) {
+ mExecutionStartTimeMs = startTimeMs;
+ }
+
+ public Session getParentSession() {
+ return mParentSession;
+ }
+
+ public ArrayList<Session> getChildSessions() {
+ return mChildSessions;
+ }
+
+ public boolean isSessionCompleted() {
+ return mIsCompleted;
+ }
+
+ public boolean isStartedFromActiveSession() {
+ return mIsStartedFromActiveSession;
+ }
+
+ // Mark this session complete. This will be deleted by Log when all subsessions are complete
+ // as well.
+ public void markSessionCompleted(long executionEndTimeMs) {
+ mExecutionEndTimeMs = executionEndTimeMs;
+ mIsCompleted = true;
+ }
+
+ public long getLocalExecutionTime() {
+ if (mExecutionEndTimeMs == UNDEFINED) {
+ return UNDEFINED;
+ }
+ return mExecutionEndTimeMs - mExecutionStartTimeMs;
+ }
+
+ public synchronized String getNextChildId() {
+ return String.valueOf(mChildCounter++);
+ }
+
+ @Override
+ public boolean equals(Object obj) {
+ if (!(obj instanceof Session)) {
+ return false;
+ }
+ if (obj == this) {
+ return true;
+ }
+ Session otherSession = (Session) obj;
+ return (mSessionId.equals(otherSession.mSessionId)) &&
+ (mShortMethodName.equals(otherSession.mShortMethodName)) &&
+ mExecutionStartTimeMs == otherSession.mExecutionStartTimeMs &&
+ mParentSession == otherSession.mParentSession &&
+ mChildSessions.equals(otherSession.mChildSessions) &&
+ mIsCompleted == otherSession.mIsCompleted &&
+ mExecutionEndTimeMs == otherSession.mExecutionEndTimeMs &&
+ mChildCounter == otherSession.mChildCounter &&
+ mIsStartedFromActiveSession == otherSession.mIsStartedFromActiveSession &&
+ mOwnerInfo == otherSession.mOwnerInfo;
+ }
+
+ // Builds full session id recursively
+ private String getFullSessionId() {
+ // Cache mParentSession locally to prevent a concurrency problem where
+ // Log.endParentSessions() is called while a logging statement is running (Log.i, for
+ // example) and setting mParentSession to null in a different thread after the null check
+ // occurred.
+ Session parentSession = mParentSession;
+ if (parentSession == null) {
+ return mSessionId;
+ } else {
+ return parentSession.getFullSessionId() + "_" + mSessionId;
+ }
+ }
+
+ // Print out the full Session tree from any subsession node
+ public String printFullSessionTree() {
+ // Get to the top of the tree
+ Session topNode = this;
+ while (topNode.getParentSession() != null) {
+ topNode = topNode.getParentSession();
+ }
+ return topNode.printSessionTree();
+ }
+
+ // Recursively move down session tree using DFS, but print out each node when it is reached.
+ public String printSessionTree() {
+ StringBuilder sb = new StringBuilder();
+ printSessionTree(0, sb);
+ return sb.toString();
+ }
+
+ private void printSessionTree(int tabI, StringBuilder sb) {
+ sb.append(toString());
+ for (Session child : mChildSessions) {
+ sb.append("\n");
+ for (int i = 0; i <= tabI; i++) {
+ sb.append("\t");
+ }
+ child.printSessionTree(tabI + 1, sb);
+ }
+ }
+
+ @Override
+ public String toString() {
+ if (mParentSession != null && mIsStartedFromActiveSession) {
+ // Log.startSession was called from within another active session. Use the parent's
+ // Id instead of the child to reduce confusion.
+ return mParentSession.toString();
+ } else {
+ StringBuilder methodName = new StringBuilder();
+ methodName.append(mShortMethodName);
+ if (mOwnerInfo != null && !mOwnerInfo.isEmpty()) {
+ methodName.append("(InCall package: ");
+ methodName.append(mOwnerInfo);
+ methodName.append(")");
+ }
+ return methodName.toString() + "@" + getFullSessionId();
+ }
+ }
+}
diff --git a/telecomm/java/android/telecom/Logging/SessionManager.java b/telecomm/java/android/telecom/Logging/SessionManager.java
new file mode 100644
index 0000000..a4e8977
--- /dev/null
+++ b/telecomm/java/android/telecom/Logging/SessionManager.java
@@ -0,0 +1,344 @@
+/*
+ * Copyright (C) 2016 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License
+ */
+
+package android.telecom.Logging;
+
+import android.content.Context;
+import android.os.Handler;
+import android.os.Looper;
+import android.provider.Settings;
+import android.util.Base64;
+
+import com.android.internal.annotations.VisibleForTesting;
+
+import java.nio.ByteBuffer;
+import java.util.ArrayList;
+import java.util.Arrays;
+import java.util.Iterator;
+import java.util.List;
+import java.util.concurrent.ConcurrentHashMap;
+
+/**
+ * TODO: Create better Sessions Documentation
+ * @hide
+ */
+
+public class SessionManager {
+
+ // Currently using 3 letters, So don't exceed 64^3
+ private static final long SESSION_ID_ROLLOVER_THRESHOLD = 262144;
+
+ // This parameter can be overridden in Telecom's Timeouts class.
+ public static final long DEFAULT_SESSION_TIMEOUT_MS = 30000L; // 30 seconds
+
+ private static String LOGGING_TAG = "Logging";
+
+ private static final String TIMEOUTS_PREFIX = "telecom.";
+
+ // Synchronized in all method calls
+ private int sCodeEntryCounter = 0;
+ private Context mContext;
+
+ @VisibleForTesting
+ public ConcurrentHashMap<Integer, Session> sSessionMapper = new ConcurrentHashMap<>(100);
+ @VisibleForTesting
+ public Handler sSessionCleanupHandler = new Handler(Looper.getMainLooper());
+ @VisibleForTesting
+ public java.lang.Runnable sCleanStaleSessions = () ->
+ cleanupStaleSessions(getSessionCleanupTimeoutMs());
+
+ // Overridden in LogTest to skip query to ContentProvider
+ private interface ISessionCleanupTimeoutMs {
+ long get();
+ }
+
+ @VisibleForTesting
+ public ISessionCleanupTimeoutMs sSessionCleanupTimeoutMs = () -> {
+ // mContext may be null in some cases, such as testing. For these cases, use the
+ // default value.
+ if (mContext == null) {
+ return DEFAULT_SESSION_TIMEOUT_MS;
+ }
+ return getCleanupTimeout(mContext);
+ };
+
+ // Usage is synchronized on this class.
+ private List<ISessionListener> mSessionListeners = new ArrayList<>();
+
+ public interface ISessionListener {
+ /**
+ * This method is run when a full Session has completed.
+ * @param sessionName The name of the Session that has completed.
+ * @param timeMs The time it took to complete in ms.
+ */
+ void sessionComplete(String sessionName, long timeMs);
+ }
+
+ public interface ISessionIdQueryHandler {
+ String getSessionId();
+ }
+
+ public void setContext(Context context) {
+ mContext = context;
+ }
+
+ public SessionManager() {
+ }
+
+ private long getSessionCleanupTimeoutMs() {
+ return sSessionCleanupTimeoutMs.get();
+ }
+
+ private synchronized void resetStaleSessionTimer() {
+ sSessionCleanupHandler.removeCallbacksAndMessages(null);
+ // Will be null in Log Testing
+ if (sCleanStaleSessions != null) {
+ sSessionCleanupHandler.postDelayed(sCleanStaleSessions, getSessionCleanupTimeoutMs());
+ }
+ }
+
+ /**
+ * Call at an entry point to the Telecom code to track the session. This code must be
+ * accompanied by a Log.endSession().
+ */
+ public synchronized void startSession(String shortMethodName,
+ String callerIdentification) {
+ resetStaleSessionTimer();
+ int threadId = getCallingThreadId();
+ Session activeSession = sSessionMapper.get(threadId);
+ // We have called startSession within an active session that has not ended... Register this
+ // session as a subsession.
+ if (activeSession != null) {
+ Session childSession = createSubsession(true);
+ continueSession(childSession, shortMethodName);
+ return;
+ }
+ Session newSession = new Session(getNextSessionID(), shortMethodName,
+ System.currentTimeMillis(), threadId, false, callerIdentification);
+ sSessionMapper.put(threadId, newSession);
+
+ android.telecom.Log.v(LOGGING_TAG, Session.START_SESSION);
+ }
+
+
+ /**
+ * Notifies the logging system that a subsession will be run at a later point and
+ * allocates the resources. Returns a session object that must be used in
+ * Log.continueSession(...) to start the subsession.
+ */
+ public Session createSubsession() {
+ return createSubsession(false);
+ }
+
+ private synchronized Session createSubsession(boolean isStartedFromActiveSession) {
+ int threadId = getCallingThreadId();
+ Session threadSession = sSessionMapper.get(threadId);
+ if (threadSession == null) {
+ android.telecom.Log.d(LOGGING_TAG, "Log.createSubsession was called with no session " +
+ "active.");
+ return null;
+ }
+ // Start execution time of the session will be overwritten in continueSession(...).
+ Session newSubsession = new Session(threadSession.getNextChildId(),
+ threadSession.getShortMethodName(), System.currentTimeMillis(), threadId,
+ isStartedFromActiveSession, null);
+ threadSession.addChild(newSubsession);
+ newSubsession.setParentSession(threadSession);
+
+ if (!isStartedFromActiveSession) {
+ android.telecom.Log.v(LOGGING_TAG, Session.CREATE_SUBSESSION + " " +
+ newSubsession.toString());
+ } else {
+ android.telecom.Log.v(LOGGING_TAG, Session.CREATE_SUBSESSION +
+ " (Invisible subsession)");
+ }
+ return newSubsession;
+ }
+
+ /**
+ * Cancels a subsession that had Log.createSubsession() called on it, but will never have
+ * Log.continueSession(...) called on it due to an error. Allows the subsession to be cleaned
+ * gracefully instead of being removed by the sSessionCleanupHandler forcefully later.
+ */
+ public synchronized void cancelSubsession(Session subsession) {
+ if (subsession == null) {
+ return;
+ }
+
+ subsession.markSessionCompleted(0);
+ endParentSessions(subsession);
+ }
+
+ /**
+ * Starts the subsession that was created in Log.CreateSubsession. The Log.endSession() method
+ * must be called at the end of this method. The full session will complete when all
+ * subsessions are completed.
+ */
+ public synchronized void continueSession(Session subsession, String shortMethodName) {
+ if (subsession == null) {
+ return;
+ }
+ resetStaleSessionTimer();
+ String callingMethodName = subsession.getShortMethodName();
+ subsession.setShortMethodName(callingMethodName + "->" + shortMethodName);
+ subsession.setExecutionStartTimeMs(System.currentTimeMillis());
+ Session parentSession = subsession.getParentSession();
+ if (parentSession == null) {
+ android.telecom.Log.d(LOGGING_TAG, "Log.continueSession was called with no session " +
+ "active for method %s.", shortMethodName);
+ return;
+ }
+
+ sSessionMapper.put(getCallingThreadId(), subsession);
+ if (!subsession.isStartedFromActiveSession()) {
+ android.telecom.Log.v(LOGGING_TAG, Session.CONTINUE_SUBSESSION);
+ } else {
+ android.telecom.Log.v(LOGGING_TAG, Session.CONTINUE_SUBSESSION +
+ " (Invisible Subsession) with Method " + shortMethodName);
+ }
+ }
+
+ /**
+ * Ends the current session/subsession. Must be called after a Log.startSession(...) and
+ * Log.continueSession(...) call.
+ */
+ public synchronized void endSession() {
+ int threadId = getCallingThreadId();
+ Session completedSession = sSessionMapper.get(threadId);
+ if (completedSession == null) {
+ android.telecom.Log.w(LOGGING_TAG, "Log.endSession was called with no session active.");
+ return;
+ }
+
+ completedSession.markSessionCompleted(System.currentTimeMillis());
+ if (!completedSession.isStartedFromActiveSession()) {
+ android.telecom.Log.v(LOGGING_TAG, Session.END_SUBSESSION + " (dur: " +
+ completedSession.getLocalExecutionTime() + " mS)");
+ } else {
+ android.telecom.Log.v(LOGGING_TAG, Session.END_SUBSESSION +
+ " (Invisible Subsession) (dur: " + completedSession.getLocalExecutionTime() +
+ " ms)");
+ }
+ // Remove after completed so that reference still exists for logging the end events
+ Session parentSession = completedSession.getParentSession();
+ sSessionMapper.remove(threadId);
+ endParentSessions(completedSession);
+ // If this subsession was started from a parent session using Log.startSession, return the
+ // ThreadID back to the parent after completion.
+ if (parentSession != null && !parentSession.isSessionCompleted() &&
+ completedSession.isStartedFromActiveSession()) {
+ sSessionMapper.put(threadId, parentSession);
+ }
+ }
+
+ // Recursively deletes all complete parent sessions of the current subsession if it is a leaf.
+ private void endParentSessions(Session subsession) {
+ // Session is not completed or not currently a leaf, so we can not remove because a child is
+ // still running
+ if (!subsession.isSessionCompleted() || subsession.getChildSessions().size() != 0) {
+ return;
+ }
+
+ Session parentSession = subsession.getParentSession();
+ if (parentSession != null) {
+ subsession.setParentSession(null);
+ parentSession.removeChild(subsession);
+ endParentSessions(parentSession);
+ } else {
+ // All of the subsessions have been completed and it is time to report on the full
+ // running time of the session.
+ long fullSessionTimeMs =
+ System.currentTimeMillis() - subsession.getExecutionStartTimeMilliseconds();
+ android.telecom.Log.v(LOGGING_TAG, Session.END_SESSION + " (dur: " + fullSessionTimeMs
+ + " ms): " + subsession.toString());
+ // TODO: Add analytics hook
+ for (ISessionListener l : mSessionListeners) {
+ l.sessionComplete(subsession.getShortMethodName(), fullSessionTimeMs);
+ }
+ }
+ }
+
+ public String getSessionId() {
+ Session currentSession = sSessionMapper.get(getCallingThreadId());
+ return currentSession != null ? currentSession.toString() : "";
+ }
+
+ public synchronized void registerSessionListener(ISessionListener l) {
+ if (l != null) {
+ mSessionListeners.add(l);
+ }
+ }
+
+ private synchronized String getNextSessionID() {
+ Integer nextId = sCodeEntryCounter++;
+ if (nextId >= SESSION_ID_ROLLOVER_THRESHOLD) {
+ restartSessionCounter();
+ nextId = sCodeEntryCounter++;
+ }
+ return getBase64Encoding(nextId);
+ }
+
+ @VisibleForTesting
+ public synchronized void restartSessionCounter() {
+ sCodeEntryCounter = 0;
+ }
+
+ @VisibleForTesting
+ public String getBase64Encoding(int number) {
+ byte[] idByteArray = ByteBuffer.allocate(4).putInt(number).array();
+ idByteArray = Arrays.copyOfRange(idByteArray, 2, 4);
+ return Base64.encodeToString(idByteArray, Base64.NO_WRAP | Base64.NO_PADDING);
+ }
+
+ public int getCallingThreadId() {
+ return android.os.Process.myTid();
+ }
+
+ @VisibleForTesting
+ private synchronized void cleanupStaleSessions(long timeoutMs) {
+ String logMessage = "Stale Sessions Cleaned:\n";
+ boolean isSessionsStale = false;
+ long currentTimeMs = System.currentTimeMillis();
+ // Remove references that are in the Session Mapper (causing GC to occur) on
+ // sessions that are lasting longer than LOGGING_SESSION_TIMEOUT_MS.
+ // If this occurs, then there is most likely a Session active that never had
+ // Log.endSession called on it.
+ for (Iterator<ConcurrentHashMap.Entry<Integer, Session>> it =
+ sSessionMapper.entrySet().iterator(); it.hasNext(); ) {
+ ConcurrentHashMap.Entry<Integer, Session> entry = it.next();
+ Session session = entry.getValue();
+ if (currentTimeMs - session.getExecutionStartTimeMilliseconds() > timeoutMs) {
+ it.remove();
+ logMessage += session.printFullSessionTree() + "\n";
+ isSessionsStale = true;
+ }
+ }
+ if (isSessionsStale) {
+ android.telecom.Log.w(LOGGING_TAG, logMessage);
+ } else {
+ android.telecom.Log.v(LOGGING_TAG, "No stale logging sessions needed to be cleaned...");
+ }
+ }
+
+ /**
+ * Returns the amount of time after a Logging session has been started that Telecom is set to
+ * perform a sweep to check and make sure that the session is still not incomplete (stale).
+ */
+ private long getCleanupTimeout(Context context) {
+ return Settings.Secure.getLong(context.getContentResolver(), TIMEOUTS_PREFIX +
+ "stale_session_cleanup_timeout_millis", DEFAULT_SESSION_TIMEOUT_MS);
+ }
+}
diff --git a/telecomm/java/android/telecom/Logging/TimedEvent.java b/telecomm/java/android/telecom/Logging/TimedEvent.java
new file mode 100644
index 0000000..6785e92
--- /dev/null
+++ b/telecomm/java/android/telecom/Logging/TimedEvent.java
@@ -0,0 +1,50 @@
+/*
+ * Copyright (C) 2016 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License
+ */
+
+package android.telecom.Logging;
+
+import java.util.Collection;
+import java.util.HashMap;
+import java.util.Map;
+
+/**
+ * @hide
+ */
+public abstract class TimedEvent<T> {
+ public abstract long getTime();
+ public abstract T getKey();
+
+ public static <T> Map<T, Double> averageTimings(Collection<? extends TimedEvent<T>> events) {
+ HashMap<T, Integer> counts = new HashMap<>();
+ HashMap<T, Double> result = new HashMap<>();
+
+ for (TimedEvent<T> entry : events) {
+ if (counts.containsKey(entry.getKey())) {
+ counts.put(entry.getKey(), counts.get(entry.getKey()) + 1);
+ result.put(entry.getKey(), result.get(entry.getKey()) + entry.getTime());
+ } else {
+ counts.put(entry.getKey(), 1);
+ result.put(entry.getKey(), (double) entry.getTime());
+ }
+ }
+
+ for (Map.Entry<T, Double> entry : result.entrySet()) {
+ result.put(entry.getKey(), entry.getValue() / counts.get(entry.getKey()));
+ }
+
+ return result;
+ }
+}