1 /* 2 * Copyright (C) 2016 The Android Open Source Project 3 * 4 * Licensed under the Apache License, Version 2.0 (the "License"); 5 * you may not use this file except in compliance with the License. 6 * You may obtain a copy of the License at 7 * 8 * http://www.apache.org/licenses/LICENSE-2.0 9 * 10 * Unless required by applicable law or agreed to in writing, software 11 * distributed under the License is distributed on an "AS IS" BASIS, 12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 13 * See the License for the specific language governing permissions and 14 * limitations under the License 15 */ 16 17 package android.telecom.Logging; 18 19 import android.annotation.NonNull; 20 import android.os.Parcel; 21 import android.os.Parcelable; 22 import android.telecom.Log; 23 import android.text.TextUtils; 24 25 import com.android.internal.annotations.VisibleForTesting; 26 27 import java.util.ArrayList; 28 29 /** 30 * Stores information about a thread's point of entry into that should persist until that thread 31 * exits. 32 * @hide 33 */ 34 public class Session { 35 36 public static final String LOG_TAG = "Session"; 37 38 public static final String START_SESSION = "START_SESSION"; 39 public static final String START_EXTERNAL_SESSION = "START_EXTERNAL_SESSION"; 40 public static final String CREATE_SUBSESSION = "CREATE_SUBSESSION"; 41 public static final String CONTINUE_SUBSESSION = "CONTINUE_SUBSESSION"; 42 public static final String END_SUBSESSION = "END_SUBSESSION"; 43 public static final String END_SESSION = "END_SESSION"; 44 45 public static final String SUBSESSION_SEPARATION_CHAR = "->"; 46 public static final String SESSION_SEPARATION_CHAR_CHILD = "_"; 47 public static final String EXTERNAL_INDICATOR = "E-"; 48 public static final String TRUNCATE_STRING = "..."; 49 50 // Prevent infinite recursion by setting a reasonable limit. 51 private static final int SESSION_RECURSION_LIMIT = 25; 52 53 /** 54 * Initial value of mExecutionEndTimeMs and the final value of {@link #getLocalExecutionTime()} 55 * if the Session is canceled. 56 */ 57 public static final int UNDEFINED = -1; 58 59 public static class Info implements Parcelable { 60 public final String sessionId; 61 public final String methodPath; 62 Info(String id, String path)63 private Info(String id, String path) { 64 sessionId = id; 65 methodPath = path; 66 } 67 getInfo(Session s)68 public static Info getInfo (Session s) { 69 // Create Info based on the truncated method path if the session is external, so we do 70 // not get multiple stacking external sessions (unless we have DEBUG level logging or 71 // lower). 72 return new Info(s.getFullSessionId(), s.getFullMethodPath( 73 !Log.DEBUG && s.isSessionExternal())); 74 } 75 76 /** Responsible for creating Info objects for deserialized Parcels. */ 77 public static final @android.annotation.NonNull Parcelable.Creator<Info> CREATOR = 78 new Parcelable.Creator<Info> () { 79 @Override 80 public Info createFromParcel(Parcel source) { 81 String id = source.readString(); 82 String methodName = source.readString(); 83 return new Info(id, methodName); 84 } 85 86 @Override 87 public Info[] newArray(int size) { 88 return new Info[size]; 89 } 90 }; 91 92 /** {@inheritDoc} */ 93 @Override describeContents()94 public int describeContents() { 95 return 0; 96 } 97 98 /** Writes Info object into a Parcel. */ 99 @Override writeToParcel(Parcel destination, int flags)100 public void writeToParcel(Parcel destination, int flags) { 101 destination.writeString(sessionId); 102 destination.writeString(methodPath); 103 } 104 } 105 106 private String mSessionId; 107 private String mShortMethodName; 108 private long mExecutionStartTimeMs; 109 private long mExecutionEndTimeMs = UNDEFINED; 110 private Session mParentSession; 111 private ArrayList<Session> mChildSessions; 112 private boolean mIsCompleted = false; 113 private boolean mIsExternal = false; 114 private int mChildCounter = 0; 115 // True if this is a subsession that has been started from the same thread as the parent 116 // session. This can happen if Log.startSession(...) is called multiple times on the same 117 // thread in the case of one Telecom entry point method calling another entry point method. 118 // In this case, we can just make this subsession "invisible," but still keep track of it so 119 // that the Log.endSession() calls match up. 120 private boolean mIsStartedFromActiveSession = false; 121 // Optionally provided info about the method/class/component that started the session in order 122 // to make Logging easier. This info will be provided in parentheses along with the session. 123 private String mOwnerInfo; 124 // Cache Full Method path so that recursive population of the full method path only needs to 125 // be calculated once. 126 private String mFullMethodPathCache; 127 Session(String sessionId, String shortMethodName, long startTimeMs, boolean isStartedFromActiveSession, String ownerInfo)128 public Session(String sessionId, String shortMethodName, long startTimeMs, 129 boolean isStartedFromActiveSession, String ownerInfo) { 130 setSessionId(sessionId); 131 setShortMethodName(shortMethodName); 132 mExecutionStartTimeMs = startTimeMs; 133 mParentSession = null; 134 mChildSessions = new ArrayList<>(5); 135 mIsStartedFromActiveSession = isStartedFromActiveSession; 136 mOwnerInfo = ownerInfo; 137 } 138 setSessionId(@onNull String sessionId)139 public void setSessionId(@NonNull String sessionId) { 140 if (sessionId == null) { 141 mSessionId = "?"; 142 } 143 mSessionId = sessionId; 144 } 145 getShortMethodName()146 public String getShortMethodName() { 147 return mShortMethodName; 148 } 149 setShortMethodName(String shortMethodName)150 public void setShortMethodName(String shortMethodName) { 151 if (shortMethodName == null) { 152 shortMethodName = ""; 153 } 154 mShortMethodName = shortMethodName; 155 } 156 setIsExternal(boolean isExternal)157 public void setIsExternal(boolean isExternal) { 158 mIsExternal = isExternal; 159 } 160 isExternal()161 public boolean isExternal() { 162 return mIsExternal; 163 } 164 setParentSession(Session parentSession)165 public void setParentSession(Session parentSession) { 166 mParentSession = parentSession; 167 } 168 addChild(Session childSession)169 public void addChild(Session childSession) { 170 if (childSession != null) { 171 mChildSessions.add(childSession); 172 } 173 } 174 removeChild(Session child)175 public void removeChild(Session child) { 176 if (child != null) { 177 mChildSessions.remove(child); 178 } 179 } 180 getExecutionStartTimeMilliseconds()181 public long getExecutionStartTimeMilliseconds() { 182 return mExecutionStartTimeMs; 183 } 184 setExecutionStartTimeMs(long startTimeMs)185 public void setExecutionStartTimeMs(long startTimeMs) { 186 mExecutionStartTimeMs = startTimeMs; 187 } 188 getParentSession()189 public Session getParentSession() { 190 return mParentSession; 191 } 192 getChildSessions()193 public ArrayList<Session> getChildSessions() { 194 return mChildSessions; 195 } 196 isSessionCompleted()197 public boolean isSessionCompleted() { 198 return mIsCompleted; 199 } 200 isStartedFromActiveSession()201 public boolean isStartedFromActiveSession() { 202 return mIsStartedFromActiveSession; 203 } 204 getInfo()205 public Info getInfo() { 206 return Info.getInfo(this); 207 } 208 209 @VisibleForTesting getSessionId()210 public String getSessionId() { 211 return mSessionId; 212 } 213 214 // Mark this session complete. This will be deleted by Log when all subsessions are complete 215 // as well. markSessionCompleted(long executionEndTimeMs)216 public void markSessionCompleted(long executionEndTimeMs) { 217 mExecutionEndTimeMs = executionEndTimeMs; 218 mIsCompleted = true; 219 } 220 getLocalExecutionTime()221 public long getLocalExecutionTime() { 222 if (mExecutionEndTimeMs == UNDEFINED) { 223 return UNDEFINED; 224 } 225 return mExecutionEndTimeMs - mExecutionStartTimeMs; 226 } 227 getNextChildId()228 public synchronized String getNextChildId() { 229 return String.valueOf(mChildCounter++); 230 } 231 232 // Builds full session id recursively getFullSessionId()233 private String getFullSessionId() { 234 return getFullSessionId(0); 235 } 236 237 // keep track of calls and bail if we hit the recursion limit getFullSessionId(int parentCount)238 private String getFullSessionId(int parentCount) { 239 if (parentCount >= SESSION_RECURSION_LIMIT) { 240 // Don't use Telecom's Log.w here or it will cause infinite recursion because it will 241 // try to add session information to this logging statement, which will cause it to hit 242 // this condition again and so on... 243 android.util.Slog.w(LOG_TAG, "getFullSessionId: Hit recursion limit!"); 244 return TRUNCATE_STRING + mSessionId; 245 } 246 // Cache mParentSession locally to prevent a concurrency problem where 247 // Log.endParentSessions() is called while a logging statement is running (Log.i, for 248 // example) and setting mParentSession to null in a different thread after the null check 249 // occurred. 250 Session parentSession = mParentSession; 251 if (parentSession == null) { 252 return mSessionId; 253 } else { 254 if (Log.VERBOSE) { 255 return parentSession.getFullSessionId(parentCount + 1) 256 // Append "_X" to subsession to show subsession designation. 257 + SESSION_SEPARATION_CHAR_CHILD + mSessionId; 258 } else { 259 // Only worry about the base ID at the top of the tree. 260 return parentSession.getFullSessionId(parentCount + 1); 261 } 262 263 } 264 } 265 getRootSession(String callingMethod)266 private Session getRootSession(String callingMethod) { 267 int currParentCount = 0; 268 Session topNode = this; 269 while (topNode.getParentSession() != null) { 270 if (currParentCount >= SESSION_RECURSION_LIMIT) { 271 // Don't use Telecom's Log.w here or it will cause infinite recursion because it 272 // will try to add session information to this logging statement, which will cause 273 // it to hit this condition again and so on... 274 android.util.Slog.w(LOG_TAG, "getRootSession: Hit recursion limit from " 275 + callingMethod); 276 break; 277 } 278 topNode = topNode.getParentSession(); 279 currParentCount++; 280 } 281 return topNode; 282 } 283 284 // Print out the full Session tree from any subsession node printFullSessionTree()285 public String printFullSessionTree() { 286 return getRootSession("printFullSessionTree").printSessionTree(); 287 } 288 289 // Recursively move down session tree using DFS, but print out each node when it is reached. printSessionTree()290 private String printSessionTree() { 291 StringBuilder sb = new StringBuilder(); 292 printSessionTree(0, sb, 0); 293 return sb.toString(); 294 } 295 printSessionTree(int tabI, StringBuilder sb, int currChildCount)296 private void printSessionTree(int tabI, StringBuilder sb, int currChildCount) { 297 // Prevent infinite recursion. 298 if (currChildCount >= SESSION_RECURSION_LIMIT) { 299 // Don't use Telecom's Log.w here or it will cause infinite recursion because it will 300 // try to add session information to this logging statement, which will cause it to hit 301 // this condition again and so on... 302 android.util.Slog.w(LOG_TAG, "printSessionTree: Hit recursion limit!"); 303 sb.append(TRUNCATE_STRING); 304 return; 305 } 306 sb.append(toString()); 307 for (Session child : mChildSessions) { 308 sb.append("\n"); 309 for (int i = 0; i <= tabI; i++) { 310 sb.append("\t"); 311 } 312 child.printSessionTree(tabI + 1, sb, currChildCount + 1); 313 } 314 } 315 316 // Recursively concatenate mShortMethodName with the parent Sessions to create full method 317 // path. if truncatePath is set to true, all other external sessions (except for the most 318 // recent) will be truncated to "..." getFullMethodPath(boolean truncatePath)319 public String getFullMethodPath(boolean truncatePath) { 320 StringBuilder sb = new StringBuilder(); 321 getFullMethodPath(sb, truncatePath, 0); 322 return sb.toString(); 323 } 324 getFullMethodPath(StringBuilder sb, boolean truncatePath, int parentCount)325 private synchronized void getFullMethodPath(StringBuilder sb, boolean truncatePath, 326 int parentCount) { 327 if (parentCount >= SESSION_RECURSION_LIMIT) { 328 // Don't use Telecom's Log.w here or it will cause infinite recursion because it will 329 // try to add session information to this logging statement, which will cause it to hit 330 // this condition again and so on... 331 android.util.Slog.w(LOG_TAG, "getFullMethodPath: Hit recursion limit!"); 332 sb.append(TRUNCATE_STRING); 333 return; 334 } 335 // Return cached value for method path. When returning the truncated path, recalculate the 336 // full path without using the cached value. 337 if (!TextUtils.isEmpty(mFullMethodPathCache) && !truncatePath) { 338 sb.append(mFullMethodPathCache); 339 return; 340 } 341 Session parentSession = getParentSession(); 342 boolean isSessionStarted = false; 343 if (parentSession != null) { 344 // Check to see if the session has been renamed yet. If it has not, then the session 345 // has not been continued. 346 isSessionStarted = !mShortMethodName.equals(parentSession.mShortMethodName); 347 parentSession.getFullMethodPath(sb, truncatePath, parentCount + 1); 348 sb.append(SUBSESSION_SEPARATION_CHAR); 349 } 350 // Encapsulate the external session's method name so it is obvious what part of the session 351 // is external or truncate it if we do not want the entire history. 352 if (isExternal()) { 353 if (truncatePath) { 354 sb.append(TRUNCATE_STRING); 355 } else { 356 sb.append("("); 357 sb.append(mShortMethodName); 358 sb.append(")"); 359 } 360 } else { 361 sb.append(mShortMethodName); 362 } 363 // If we are returning the truncated path, do not save that path as the full path. 364 if (isSessionStarted && !truncatePath) { 365 // Cache this value so that we do not have to do this work next time! 366 // We do not cache the value if the session being evaluated hasn't been continued yet. 367 mFullMethodPathCache = sb.toString(); 368 } 369 } 370 371 // Recursively move to the top of the tree to see if the parent session is external. isSessionExternal()372 private boolean isSessionExternal() { 373 return getRootSession("isSessionExternal").isExternal(); 374 } 375 376 @Override hashCode()377 public int hashCode() { 378 int result = mSessionId != null ? mSessionId.hashCode() : 0; 379 result = 31 * result + (mShortMethodName != null ? mShortMethodName.hashCode() : 0); 380 result = 31 * result + (int) (mExecutionStartTimeMs ^ (mExecutionStartTimeMs >>> 32)); 381 result = 31 * result + (int) (mExecutionEndTimeMs ^ (mExecutionEndTimeMs >>> 32)); 382 result = 31 * result + (mParentSession != null ? mParentSession.hashCode() : 0); 383 result = 31 * result + (mChildSessions != null ? mChildSessions.hashCode() : 0); 384 result = 31 * result + (mIsCompleted ? 1 : 0); 385 result = 31 * result + mChildCounter; 386 result = 31 * result + (mIsStartedFromActiveSession ? 1 : 0); 387 result = 31 * result + (mOwnerInfo != null ? mOwnerInfo.hashCode() : 0); 388 return result; 389 } 390 391 @Override equals(Object o)392 public boolean equals(Object o) { 393 if (this == o) return true; 394 if (o == null || getClass() != o.getClass()) return false; 395 396 Session session = (Session) o; 397 398 if (mExecutionStartTimeMs != session.mExecutionStartTimeMs) return false; 399 if (mExecutionEndTimeMs != session.mExecutionEndTimeMs) return false; 400 if (mIsCompleted != session.mIsCompleted) return false; 401 if (mChildCounter != session.mChildCounter) return false; 402 if (mIsStartedFromActiveSession != session.mIsStartedFromActiveSession) return false; 403 if (mSessionId != null ? 404 !mSessionId.equals(session.mSessionId) : session.mSessionId != null) 405 return false; 406 if (mShortMethodName != null ? !mShortMethodName.equals(session.mShortMethodName) 407 : session.mShortMethodName != null) 408 return false; 409 if (mParentSession != null ? !mParentSession.equals(session.mParentSession) 410 : session.mParentSession != null) 411 return false; 412 if (mChildSessions != null ? !mChildSessions.equals(session.mChildSessions) 413 : session.mChildSessions != null) 414 return false; 415 return mOwnerInfo != null ? mOwnerInfo.equals(session.mOwnerInfo) 416 : session.mOwnerInfo == null; 417 418 } 419 420 @Override toString()421 public String toString() { 422 if (mParentSession != null && mIsStartedFromActiveSession) { 423 // Log.startSession was called from within another active session. Use the parent's 424 // Id instead of the child to reduce confusion. 425 return mParentSession.toString(); 426 } else { 427 StringBuilder methodName = new StringBuilder(); 428 methodName.append(getFullMethodPath(false /*truncatePath*/)); 429 if (mOwnerInfo != null && !mOwnerInfo.isEmpty()) { 430 methodName.append("(InCall package: "); 431 methodName.append(mOwnerInfo); 432 methodName.append(")"); 433 } 434 return methodName.toString() + "@" + getFullSessionId(); 435 } 436 } 437 } 438