Android/frameworks_base
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Merge "Add support for new SessionManager and EventManager tests"

Browse Source
This commit is contained in:
Brad Ebinger
2016-10-18 21:22:18 +00:00
committed by Gerrit Code Review
parent ff5c3ad08b 096d2829ed
commit 42598f4a96
3 changed files with 104 additions and 56 deletions
Download Patch File Download Diff File Expand all files Collapse all files

14
telecomm/java/android/telecom/Logging/EventManager.java
View File

@@ -20,6 +20,7 @@ import android.annotation.NonNull;
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 @@ import java.util.concurrent.LinkedBlockingQueue;
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 @@ public class EventManager {
* 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 @@ public class EventManager {
}
}
@VisibleForTesting
public LinkedBlockingQueue<EventRecord> getEventRecords() {
return mEventRecords;
}
@VisibleForTesting
public Map<Loggable, EventRecord> getCallEventRecordMap() {
return mCallEventRecordMap;
}
private void addEventRecord(EventRecord newRecord) {
Loggable recordEntry = newRecord.getRecordEntry();

69
telecomm/java/android/telecom/Logging/Session.java
View File

@@ -33,6 +33,10 @@ public class Session {
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 @@ public class Session {
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
@@ -203,6 +186,50 @@ public class Session {
}
}
@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) {

77
telecomm/java/android/telecom/Logging/SessionManager.java
View File

@@ -19,6 +19,7 @@ package android.telecom.Logging;
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 @@ public class SessionManager {
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 @@ public class SessionManager {
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 @@ public class SessionManager {
}
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 @@ public class SessionManager {
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 @@ public class SessionManager {
}
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 @@ public class SessionManager {
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 @@ public class SessionManager {
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 @@ public class SessionManager {
/**
* 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 @@ public class SessionManager {
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 class SessionManager {
*/
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 @@ public class SessionManager {
// 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 class SessionManager {
}
public String getSessionId() {
Session currentSession = sSessionMapper.get(getCallingThreadId());
Session currentSession = mSessionMapper.get(getCallingThreadId());
return currentSession != null ? currentSession.toString() : "";
}
@@ -304,7 +313,7 @@ public class SessionManager {
}
public int getCallingThreadId() {
return android.os.Process.myTid();
return mCurrentThreadId.get();
}
@VisibleForTesting
@@ -317,7 +326,7 @@ public class SessionManager {
// 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 @@ public class SessionManager {
}
}
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...");
}
}