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