Add support for new SessionManager and EventManager tests
Test: Ran new unit tests
Bug: 26571395
Change-Id: I6d14d7c05b8fdc8dc1319a81f0e41f7bcd989b85
diff --git a/telecomm/java/android/telecom/Logging/EventManager.java b/telecomm/java/android/telecom/Logging/EventManager.java
index 8e7a393..0849804 100644
--- a/telecomm/java/android/telecom/Logging/EventManager.java
+++ b/telecomm/java/android/telecom/Logging/EventManager.java
@@ -20,6 +20,7 @@
import android.telecom.Log;
import android.text.TextUtils;
+import com.android.internal.annotations.VisibleForTesting;
import com.android.internal.util.IndentingPrintWriter;
import java.text.DateFormat;
@@ -46,6 +47,7 @@
public class EventManager {
public static final String TAG = "Logging.Events";
+ @VisibleForTesting
public static final int DEFAULT_EVENTS_TO_CACHE = 10; // Arbitrarily chosen.
public interface Loggable {
@@ -79,7 +81,7 @@
* 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 final Map<String, List<TimedEventPair>> requestResponsePairs = new HashMap<>();
private static final Object mSync = new Object();
@@ -340,6 +342,16 @@
}
}
+ @VisibleForTesting
+ public LinkedBlockingQueue<EventRecord> getEventRecords() {
+ return mEventRecords;
+ }
+
+ @VisibleForTesting
+ public Map<Loggable, EventRecord> getCallEventRecordMap() {
+ return mCallEventRecordMap;
+ }
+
private void addEventRecord(EventRecord newRecord) {
Loggable recordEntry = newRecord.getRecordEntry();
diff --git a/telecomm/java/android/telecom/Logging/Session.java b/telecomm/java/android/telecom/Logging/Session.java
index 14f4a0f..510abdd 100644
--- a/telecomm/java/android/telecom/Logging/Session.java
+++ b/telecomm/java/android/telecom/Logging/Session.java
@@ -33,6 +33,10 @@
public static final String END_SUBSESSION = "END_SUBSESSION";
public static final String END_SESSION = "END_SESSION";
+ /**
+ * Initial value of mExecutionEndTimeMs and the final value of {@link #getLocalExecutionTime()}
+ * if the Session is canceled.
+ */
public static final int UNDEFINED = -1;
private String mSessionId;
@@ -140,27 +144,6 @@
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
@@ -204,6 +187,50 @@
}
@Override
+ public int hashCode() {
+ int result = mSessionId != null ? mSessionId.hashCode() : 0;
+ result = 31 * result + (mShortMethodName != null ? mShortMethodName.hashCode() : 0);
+ result = 31 * result + (int) (mExecutionStartTimeMs ^ (mExecutionStartTimeMs >>> 32));
+ result = 31 * result + (int) (mExecutionEndTimeMs ^ (mExecutionEndTimeMs >>> 32));
+ result = 31 * result + (mParentSession != null ? mParentSession.hashCode() : 0);
+ result = 31 * result + (mChildSessions != null ? mChildSessions.hashCode() : 0);
+ result = 31 * result + (mIsCompleted ? 1 : 0);
+ result = 31 * result + mChildCounter;
+ result = 31 * result + (mIsStartedFromActiveSession ? 1 : 0);
+ result = 31 * result + (mOwnerInfo != null ? mOwnerInfo.hashCode() : 0);
+ return result;
+ }
+
+ @Override
+ public boolean equals(Object o) {
+ if (this == o) return true;
+ if (o == null || getClass() != o.getClass()) return false;
+
+ Session session = (Session) o;
+
+ if (mExecutionStartTimeMs != session.mExecutionStartTimeMs) return false;
+ if (mExecutionEndTimeMs != session.mExecutionEndTimeMs) return false;
+ if (mIsCompleted != session.mIsCompleted) return false;
+ if (mChildCounter != session.mChildCounter) return false;
+ if (mIsStartedFromActiveSession != session.mIsStartedFromActiveSession) return false;
+ if (mSessionId != null ?
+ !mSessionId.equals(session.mSessionId) : session.mSessionId != null)
+ return false;
+ if (mShortMethodName != null ? !mShortMethodName.equals(session.mShortMethodName)
+ : session.mShortMethodName != null)
+ return false;
+ if (mParentSession != null ? !mParentSession.equals(session.mParentSession)
+ : session.mParentSession != null)
+ return false;
+ if (mChildSessions != null ? !mChildSessions.equals(session.mChildSessions)
+ : session.mChildSessions != null)
+ return false;
+ return mOwnerInfo != null ? mOwnerInfo.equals(session.mOwnerInfo)
+ : session.mOwnerInfo == null;
+
+ }
+
+ @Override
public String toString() {
if (mParentSession != null && mIsStartedFromActiveSession) {
// Log.startSession was called from within another active session. Use the parent's
diff --git a/telecomm/java/android/telecom/Logging/SessionManager.java b/telecomm/java/android/telecom/Logging/SessionManager.java
index a4e8977..90daee0 100644
--- a/telecomm/java/android/telecom/Logging/SessionManager.java
+++ b/telecomm/java/android/telecom/Logging/SessionManager.java
@@ -19,6 +19,7 @@
import android.content.Context;
import android.os.Handler;
import android.os.Looper;
+import android.os.Process;
import android.provider.Settings;
import android.util.Base64;
@@ -53,11 +54,11 @@
private Context mContext;
@VisibleForTesting
- public ConcurrentHashMap<Integer, Session> sSessionMapper = new ConcurrentHashMap<>(100);
+ public ConcurrentHashMap<Integer, Session> mSessionMapper = new ConcurrentHashMap<>(100);
@VisibleForTesting
- public Handler sSessionCleanupHandler = new Handler(Looper.getMainLooper());
+ public Handler mSessionCleanupHandler = new Handler(Looper.getMainLooper());
@VisibleForTesting
- public java.lang.Runnable sCleanStaleSessions = () ->
+ public java.lang.Runnable mCleanStaleSessions = () ->
cleanupStaleSessions(getSessionCleanupTimeoutMs());
// Overridden in LogTest to skip query to ContentProvider
@@ -65,8 +66,16 @@
long get();
}
+ // Overridden in tests to provide test Thread IDs
+ public interface ICurrentThreadId {
+ int get();
+ }
+
@VisibleForTesting
- public ISessionCleanupTimeoutMs sSessionCleanupTimeoutMs = () -> {
+ public ICurrentThreadId mCurrentThreadId = Process::myTid;
+
+ @VisibleForTesting
+ public ISessionCleanupTimeoutMs mSessionCleanupTimeoutMs = () -> {
// mContext may be null in some cases, such as testing. For these cases, use the
// default value.
if (mContext == null) {
@@ -99,14 +108,14 @@
}
private long getSessionCleanupTimeoutMs() {
- return sSessionCleanupTimeoutMs.get();
+ return mSessionCleanupTimeoutMs.get();
}
private synchronized void resetStaleSessionTimer() {
- sSessionCleanupHandler.removeCallbacksAndMessages(null);
+ mSessionCleanupHandler.removeCallbacksAndMessages(null);
// Will be null in Log Testing
- if (sCleanStaleSessions != null) {
- sSessionCleanupHandler.postDelayed(sCleanStaleSessions, getSessionCleanupTimeoutMs());
+ if (mCleanStaleSessions != null) {
+ mSessionCleanupHandler.postDelayed(mCleanStaleSessions, getSessionCleanupTimeoutMs());
}
}
@@ -118,7 +127,7 @@
String callerIdentification) {
resetStaleSessionTimer();
int threadId = getCallingThreadId();
- Session activeSession = sSessionMapper.get(threadId);
+ Session activeSession = mSessionMapper.get(threadId);
// We have called startSession within an active session that has not ended... Register this
// session as a subsession.
if (activeSession != null) {
@@ -128,9 +137,9 @@
}
Session newSession = new Session(getNextSessionID(), shortMethodName,
System.currentTimeMillis(), threadId, false, callerIdentification);
- sSessionMapper.put(threadId, newSession);
+ mSessionMapper.put(threadId, newSession);
- android.telecom.Log.v(LOGGING_TAG, Session.START_SESSION);
+ android.util.Slog.v(LOGGING_TAG, Session.START_SESSION);
}
@@ -145,9 +154,9 @@
private synchronized Session createSubsession(boolean isStartedFromActiveSession) {
int threadId = getCallingThreadId();
- Session threadSession = sSessionMapper.get(threadId);
+ Session threadSession = mSessionMapper.get(threadId);
if (threadSession == null) {
- android.telecom.Log.d(LOGGING_TAG, "Log.createSubsession was called with no session " +
+ android.util.Slog.d(LOGGING_TAG, "Log.createSubsession was called with no session " +
"active.");
return null;
}
@@ -159,10 +168,10 @@
newSubsession.setParentSession(threadSession);
if (!isStartedFromActiveSession) {
- android.telecom.Log.v(LOGGING_TAG, Session.CREATE_SUBSESSION + " " +
+ android.util.Slog.v(LOGGING_TAG, Session.CREATE_SUBSESSION + " " +
newSubsession.toString());
} else {
- android.telecom.Log.v(LOGGING_TAG, Session.CREATE_SUBSESSION +
+ android.util.Slog.v(LOGGING_TAG, Session.CREATE_SUBSESSION +
" (Invisible subsession)");
}
return newSubsession;
@@ -171,14 +180,14 @@
/**
* 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.
+ * gracefully instead of being removed by the mSessionCleanupHandler forcefully later.
*/
public synchronized void cancelSubsession(Session subsession) {
if (subsession == null) {
return;
}
- subsession.markSessionCompleted(0);
+ subsession.markSessionCompleted(Session.UNDEFINED);
endParentSessions(subsession);
}
@@ -197,16 +206,16 @@
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);
+ android.util.Slog.d(LOGGING_TAG, "Log.continueSession was called with no session " +
+ "active for method " + shortMethodName);
return;
}
- sSessionMapper.put(getCallingThreadId(), subsession);
+ mSessionMapper.put(getCallingThreadId(), subsession);
if (!subsession.isStartedFromActiveSession()) {
- android.telecom.Log.v(LOGGING_TAG, Session.CONTINUE_SUBSESSION);
+ android.util.Slog.v(LOGGING_TAG, Session.CONTINUE_SUBSESSION);
} else {
- android.telecom.Log.v(LOGGING_TAG, Session.CONTINUE_SUBSESSION +
+ android.util.Slog.v(LOGGING_TAG, Session.CONTINUE_SUBSESSION +
" (Invisible Subsession) with Method " + shortMethodName);
}
}
@@ -217,30 +226,30 @@
*/
public synchronized void endSession() {
int threadId = getCallingThreadId();
- Session completedSession = sSessionMapper.get(threadId);
+ Session completedSession = mSessionMapper.get(threadId);
if (completedSession == null) {
- android.telecom.Log.w(LOGGING_TAG, "Log.endSession was called with no session active.");
+ android.util.Slog.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: " +
+ android.util.Slog.v(LOGGING_TAG, Session.END_SUBSESSION + " (dur: " +
completedSession.getLocalExecutionTime() + " mS)");
} else {
- android.telecom.Log.v(LOGGING_TAG, Session.END_SUBSESSION +
+ android.util.Slog.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);
+ mSessionMapper.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);
+ mSessionMapper.put(threadId, parentSession);
}
}
@@ -262,7 +271,7 @@
// running time of the session.
long fullSessionTimeMs =
System.currentTimeMillis() - subsession.getExecutionStartTimeMilliseconds();
- android.telecom.Log.v(LOGGING_TAG, Session.END_SESSION + " (dur: " + fullSessionTimeMs
+ android.util.Slog.d(LOGGING_TAG, Session.END_SESSION + " (dur: " + fullSessionTimeMs
+ " ms): " + subsession.toString());
// TODO: Add analytics hook
for (ISessionListener l : mSessionListeners) {
@@ -272,7 +281,7 @@
}
public String getSessionId() {
- Session currentSession = sSessionMapper.get(getCallingThreadId());
+ Session currentSession = mSessionMapper.get(getCallingThreadId());
return currentSession != null ? currentSession.toString() : "";
}
@@ -304,7 +313,7 @@
}
public int getCallingThreadId() {
- return android.os.Process.myTid();
+ return mCurrentThreadId.get();
}
@VisibleForTesting
@@ -317,7 +326,7 @@
// 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(); ) {
+ mSessionMapper.entrySet().iterator(); it.hasNext(); ) {
ConcurrentHashMap.Entry<Integer, Session> entry = it.next();
Session session = entry.getValue();
if (currentTimeMs - session.getExecutionStartTimeMilliseconds() > timeoutMs) {
@@ -327,9 +336,9 @@
}
}
if (isSessionsStale) {
- android.telecom.Log.w(LOGGING_TAG, logMessage);
+ android.util.Slog.w(LOGGING_TAG, logMessage);
} else {
- android.telecom.Log.v(LOGGING_TAG, "No stale logging sessions needed to be cleaned...");
+ android.util.Slog.v(LOGGING_TAG, "No stale logging sessions needed to be cleaned...");
}
}