content: /*
   * 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.os.Process;
  import android.provider.Settings;
  import android.telecom.Log;
  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.
      private static final long DEFAULT_SESSION_TIMEOUT_MS = 30000L; // 30 seconds
      private static final 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> mSessionMapper = new ConcurrentHashMap<>(100);
      @VisibleForTesting
      public java.lang.Runnable mCleanStaleSessions = () ->
              cleanupStaleSessions(getSessionCleanupTimeoutMs());
      private Handler mSessionCleanupHandler = new Handler(Looper.getMainLooper());
  
      // Overridden in LogTest to skip query to ContentProvider
      private interface ISessionCleanupTimeoutMs {
          long get();
      }
  
      // Overridden in tests to provide test Thread IDs
      public interface ICurrentThreadId {
          int get();
      }
  
      @VisibleForTesting
      public ICurrentThreadId mCurrentThreadId = Process::myTid;
  
      private ISessionCleanupTimeoutMs mSessionCleanupTimeoutMs = () -> {
          // 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 mSessionCleanupTimeoutMs.get();
      }
  
      private synchronized void resetStaleSessionTimer() {
          mSessionCleanupHandler.removeCallbacksAndMessages(null);
          // Will be null in Log Testing
          if (mCleanStaleSessions != null) {
              mSessionCleanupHandler.postDelayed(mCleanStaleSessions, getSessionCleanupTimeoutMs());
          }
      }
  
      /**
       * Determines whether or not to start a new session or continue an existing session based on
       * the {@link Session.Info} info passed into startSession. If info is null, a new Session is
       * created. This code must be accompanied by endSession() at the end of the Session.
       */
      public synchronized void startSession(Session.Info info, String shortMethodName,
              String callerIdentification) {
          // Start a new session normally if the
          if(info == null) {
              startSession(shortMethodName, callerIdentification);
          } else {
              startExternalSession(info, shortMethodName);
          }
      }
  
      /**
       * 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 = mSessionMapper.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;
          } else {
              // Only Log that we are starting the parent session.
              Log.d(LOGGING_TAG, Session.START_SESSION);
          }
          Session newSession = new Session(getNextSessionID(), shortMethodName,
                  System.currentTimeMillis(), false, callerIdentification);
          mSessionMapper.put(threadId, newSession);
      }
  
      /**
       * Registers an external Session with the Manager using that external Session's sessionInfo.
       * Log.endSession will still need to be called at the end of the session.
       * @param sessionInfo Describes the external Session's information.
       * @param shortMethodName The method name of the new session that is being started.
       */
      public synchronized void startExternalSession(Session.Info sessionInfo,
              String shortMethodName) {
          if(sessionInfo == null) {
              return;
          }
  
          int threadId = getCallingThreadId();
          Session threadSession = mSessionMapper.get(threadId);
          if (threadSession != null) {
              // We should never get into a situation where there is already an active session AND
              // an external session is added. We are just using that active session.
              Log.w(LOGGING_TAG, "trying to start an external session with a session " +
                      "already active.");
              return;
          }
  
          // Create Session from Info and add to the sessionMapper under this ID.
          Log.d(LOGGING_TAG, Session.START_EXTERNAL_SESSION);
          Session externalSession = new Session(Session.EXTERNAL_INDICATOR + sessionInfo.sessionId,
                  sessionInfo.methodPath, System.currentTimeMillis(),
                  false /*isStartedFromActiveSession*/, null);
          externalSession.setIsExternal(true);
          // Mark the external session as already completed, since we have no way of knowing when
          // the external session actually has completed.
          externalSession.markSessionCompleted(Session.UNDEFINED);
          // Track the external session with the SessionMapper so that we can create and continue
          // an active subsession based on it.
          mSessionMapper.put(threadId, externalSession);
          // Create a subsession from this external Session parent node
          Session childSession = createSubsession();
          continueSession(childSession, shortMethodName);
      }
  
      /**
       * 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 = mSessionMapper.get(threadId);
          if (threadSession == null) {
              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(),
                  isStartedFromActiveSession, null);
          threadSession.addChild(newSubsession);
          newSubsession.setParentSession(threadSession);
  
          if (!isStartedFromActiveSession) {
              Log.v(LOGGING_TAG, Session.CREATE_SUBSESSION + " " +
                      newSubsession.toString());
          } else {
              Log.v(LOGGING_TAG, Session.CREATE_SUBSESSION +
                      " (Invisible subsession)");
          }
          return newSubsession;
      }
  
      /**
       * Retrieve the information of the currently active Session. This information is parcelable and
       * is used to create an external Session ({@link #startExternalSession(Session.Info, String)}).
       * If there is no Session active, this method will return null.
       */
      public synchronized Session.Info getExternalSession() {
          int threadId = getCallingThreadId();
          Session threadSession = mSessionMapper.get(threadId);
          if (threadSession == null) {
              Log.d(LOGGING_TAG, "Log.getExternalSession was called with no session " +
                      "active.");
              return null;
          }
  
          return threadSession.getInfo();
      }
  
      /**
       * 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 mSessionCleanupHandler forcefully later.
       */
      public synchronized void cancelSubsession(Session subsession) {
          if (subsession == null) {
              return;
          }
  
          subsession.markSessionCompleted(Session.UNDEFINED);
          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();
          subsession.setShortMethodName(shortMethodName);
          subsession.setExecutionStartTimeMs(System.currentTimeMillis());
          Session parentSession = subsession.getParentSession();
          if (parentSession == null) {
              Log.i(LOGGING_TAG, "Log.continueSession was called with no session " +
                      "active for method " + shortMethodName);
              return;
          }
  
          mSessionMapper.put(getCallingThreadId(), subsession);
          if (!subsession.isStartedFromActiveSession()) {
              Log.v(LOGGING_TAG, Session.CONTINUE_SUBSESSION);
          } else {
              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 = mSessionMapper.get(threadId);
          if (completedSession == null) {
              Log.w(LOGGING_TAG, "Log.endSession was called with no session active.");
              return;
          }
  
          completedSession.markSessionCompleted(System.currentTimeMillis());
          if (!completedSession.isStartedFromActiveSession()) {
              Log.v(LOGGING_TAG, Session.END_SUBSESSION + " (dur: " +
                      completedSession.getLocalExecutionTime() + " mS)");
          } else {
              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();
          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()) {
              mSessionMapper.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);
              // Report the child session of the external session as being complete to the listeners,
              // not the external session itself.
              if (parentSession.isExternal()) {
                  long fullSessionTimeMs =
                          System.currentTimeMillis() - subsession.getExecutionStartTimeMilliseconds();
                  notifySessionCompleteListeners(subsession.getShortMethodName(), fullSessionTimeMs);
              }
              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();
              Log.d(LOGGING_TAG, Session.END_SESSION + " (dur: " + fullSessionTimeMs
                      + " ms): " + subsession.toString());
              if (!subsession.isExternal()) {
                  notifySessionCompleteListeners(subsession.getShortMethodName(), fullSessionTimeMs);
              }
          }
      }
  
      private void notifySessionCompleteListeners(String methodName, long sessionTimeMs) {
          for (ISessionListener l : mSessionListeners) {
              l.sessionComplete(methodName, sessionTimeMs);
          }
      }
  
      public String getSessionId() {
          Session currentSession = mSessionMapper.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);
      }
  
      private synchronized void restartSessionCounter() {
          sCodeEntryCounter = 0;
      }
  
      private 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);
      }
  
      private int getCallingThreadId() {
          return mCurrentThreadId.get();
      }
  
      @VisibleForTesting
      public 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 =
               mSessionMapper.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) {
              Log.w(LOGGING_TAG, logMessage);
          } else {
              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);
      }
  }
  