Merge "Transplant the Logging system from Telecom"
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;
+ }
+}