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