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 com.android.server.telecom.tests; 18 19 import static org.junit.Assert.assertEquals; 20 import static org.junit.Assert.assertFalse; 21 import static org.junit.Assert.assertNotNull; 22 import static org.junit.Assert.assertNull; 23 import static org.junit.Assert.assertTrue; 24 import static org.junit.Assert.fail; 25 26 import android.telecom.Log; 27 import android.telecom.Logging.Session; 28 import android.telecom.Logging.SessionManager; 29 30 import com.android.server.telecom.flags.Flags; 31 32 import androidx.test.filters.SmallTest; 33 34 import org.junit.After; 35 import org.junit.Before; 36 import org.junit.Test; 37 import org.junit.runner.RunWith; 38 import org.junit.runners.JUnit4; 39 40 import java.lang.ref.WeakReference; 41 42 /** 43 * Unit tests for android.telecom.Logging.SessionManager 44 */ 45 46 @RunWith(JUnit4.class) 47 public class SessionManagerTest extends TelecomTestCase { 48 49 private static final String TEST_PARENT_NAME = "testParent"; 50 private static final int TEST_PARENT_THREAD_ID = 0; 51 private static final String TEST_CHILD_NAME = "testChild"; 52 private static final int TEST_CHILD_THREAD_ID = 1; 53 private static final int TEST_DELAY_TIME = 100; // ms 54 55 private SessionManager mTestSessionManager; 56 // Used to verify sessionComplete callback 57 private long mfullSessionCompleteTime = Session.UNDEFINED; 58 private String mFullSessionMethodName = ""; 59 60 @Override 61 @Before setUp()62 public void setUp() throws Exception { 63 super.setUp(); 64 mTestSessionManager = new SessionManager(null); 65 mTestSessionManager.registerSessionListener(((sessionName, timeMs) -> { 66 mfullSessionCompleteTime = timeMs; 67 mFullSessionMethodName = sessionName; 68 })); 69 } 70 71 @Override 72 @After tearDown()73 public void tearDown() throws Exception { 74 mFullSessionMethodName = ""; 75 mfullSessionCompleteTime = Session.UNDEFINED; 76 mTestSessionManager = null; 77 super.tearDown(); 78 } 79 80 /** 81 * Starts a Session on the current thread and verifies that it exists in the HashMap 82 */ 83 @SmallTest 84 @Test testStartSession()85 public void testStartSession() { 86 assertTrue(mTestSessionManager.mSessionMapper.isEmpty()); 87 88 // Set the thread Id to 0 89 mTestSessionManager.mCurrentThreadId = () -> TEST_PARENT_THREAD_ID; 90 mTestSessionManager.startSession(TEST_PARENT_NAME, null); 91 92 Session testSession = mTestSessionManager.mSessionMapper.get(TEST_PARENT_THREAD_ID); 93 assertEquals(TEST_PARENT_NAME, testSession.getShortMethodName()); 94 assertFalse(testSession.isSessionCompleted()); 95 assertFalse(testSession.isStartedFromActiveSession()); 96 } 97 98 /** 99 * Starts two sessions in the same thread. The first session will be parented to the second 100 * session and the second session will be attached to that thread ID. 101 */ 102 @SmallTest 103 @Test testStartInvisibleChildSession()104 public void testStartInvisibleChildSession() { 105 assertTrue(mTestSessionManager.mSessionMapper.isEmpty()); 106 107 // Set the thread Id to 0 for the parent 108 mTestSessionManager.mCurrentThreadId = () -> TEST_PARENT_THREAD_ID; 109 mTestSessionManager.startSession(TEST_PARENT_NAME, null); 110 // Create invisible child session - same Thread ID as parent 111 mTestSessionManager.startSession(TEST_CHILD_NAME, null); 112 113 // There should only be one session in the mapper (the child) 114 assertEquals(1, mTestSessionManager.mSessionMapper.size()); 115 Session testChildSession = mTestSessionManager.mSessionMapper.get(TEST_PARENT_THREAD_ID); 116 assertEquals( TEST_CHILD_NAME, testChildSession.getShortMethodName()); 117 assertTrue(testChildSession.isStartedFromActiveSession()); 118 assertNotNull(testChildSession.getParentSession()); 119 assertEquals(TEST_PARENT_NAME, testChildSession.getParentSession().getShortMethodName()); 120 assertFalse(testChildSession.isSessionCompleted()); 121 assertFalse(testChildSession.getParentSession().isSessionCompleted()); 122 } 123 124 /** 125 * End the active Session and verify that it is completed and removed from mSessionMapper. 126 */ 127 @SmallTest 128 @Test testEndSession()129 public void testEndSession() { 130 assertTrue(mTestSessionManager.mSessionMapper.isEmpty()); 131 // Set the thread Id to 0 132 mTestSessionManager.mCurrentThreadId = () -> TEST_PARENT_THREAD_ID; 133 mTestSessionManager.startSession(TEST_PARENT_NAME, null); 134 Session testSession = mTestSessionManager.mSessionMapper.get(TEST_PARENT_THREAD_ID); 135 136 assertEquals(1, mTestSessionManager.mSessionMapper.size()); 137 try { 138 // Make sure execution time is > 0 139 Thread.sleep(1); 140 } catch (InterruptedException ignored) {} 141 mTestSessionManager.endSession(); 142 143 assertTrue(testSession.isSessionCompleted()); 144 assertTrue(testSession.getLocalExecutionTime() > 0); 145 assertTrue(mTestSessionManager.mSessionMapper.isEmpty()); 146 } 147 148 /** 149 * Ends an active invisible child session and verifies that the parent session is moved back 150 * into mSessionMapper. 151 */ 152 @SmallTest 153 @Test testEndInvisibleChildSession()154 public void testEndInvisibleChildSession() { 155 assertTrue(mTestSessionManager.mSessionMapper.isEmpty()); 156 // Set the thread Id to 0 for the parent 157 mTestSessionManager.mCurrentThreadId = () -> TEST_PARENT_THREAD_ID; 158 mTestSessionManager.startSession(TEST_PARENT_NAME, null); 159 // Create invisible child session - same Thread ID as parent 160 mTestSessionManager.startSession(TEST_CHILD_NAME, null); 161 Session testChildSession = mTestSessionManager.mSessionMapper.get(TEST_PARENT_THREAD_ID); 162 163 mTestSessionManager.endSession(); 164 165 // There should only be one session in the mapper (the parent) 166 assertEquals(1, mTestSessionManager.mSessionMapper.size()); 167 Session testParentSession = mTestSessionManager.mSessionMapper.get(TEST_PARENT_THREAD_ID); 168 assertEquals(TEST_PARENT_NAME, testParentSession.getShortMethodName()); 169 assertFalse(testParentSession.isStartedFromActiveSession()); 170 assertTrue(testChildSession.isSessionCompleted()); 171 assertFalse(testParentSession.isSessionCompleted()); 172 } 173 174 /** 175 * Creates a subsession (child Session) of the current session and prepares it to be continued 176 * in a different thread. 177 */ 178 @SmallTest 179 @Test testCreateSubsession()180 public void testCreateSubsession() { 181 mTestSessionManager.mCurrentThreadId = () -> TEST_PARENT_THREAD_ID; 182 mTestSessionManager.startSession(TEST_PARENT_NAME, null); 183 184 Session testSession = mTestSessionManager.createSubsession(); 185 186 assertEquals(1, mTestSessionManager.mSessionMapper.size()); 187 Session parentSession = mTestSessionManager.mSessionMapper.get(TEST_PARENT_THREAD_ID); 188 assertNotNull(testSession.getParentSession()); 189 assertEquals(TEST_PARENT_NAME, testSession.getParentSession().getShortMethodName()); 190 assertEquals(TEST_PARENT_NAME, parentSession.getShortMethodName()); 191 assertTrue(parentSession.getChildSessions().contains(testSession)); 192 assertFalse(testSession.isSessionCompleted()); 193 assertFalse(testSession.isStartedFromActiveSession()); 194 assertTrue(testSession.getChildSessions().isEmpty()); 195 } 196 197 /** 198 * Cancels a subsession that was started before it was continued and verifies that it is 199 * marked as completed and never added to mSessionMapper. 200 */ 201 @SmallTest 202 @Test testCancelSubsession()203 public void testCancelSubsession() { 204 mTestSessionManager.mCurrentThreadId = () -> TEST_PARENT_THREAD_ID; 205 mTestSessionManager.startSession(TEST_PARENT_NAME, null); 206 Session parentSession = mTestSessionManager.mSessionMapper.get(TEST_PARENT_THREAD_ID); 207 Session testSession = mTestSessionManager.createSubsession(); 208 209 mTestSessionManager.cancelSubsession(testSession); 210 211 assertTrue(testSession.isSessionCompleted()); 212 assertFalse(parentSession.isSessionCompleted()); 213 assertEquals(Session.UNDEFINED, testSession.getLocalExecutionTime()); 214 assertNull(testSession.getParentSession()); 215 } 216 217 218 /** 219 * Continues a subsession in a different thread and verifies that both the new subsession and 220 * its parent are in mSessionMapper. 221 */ 222 @SmallTest 223 @Test testContinueSubsession()224 public void testContinueSubsession() { 225 mTestSessionManager.mCurrentThreadId = () -> TEST_PARENT_THREAD_ID; 226 mTestSessionManager.startSession(TEST_PARENT_NAME, null); 227 Session parentSession = mTestSessionManager.mSessionMapper.get(TEST_PARENT_THREAD_ID); 228 Session testSession = mTestSessionManager.createSubsession(); 229 230 mTestSessionManager.mCurrentThreadId = () -> TEST_CHILD_THREAD_ID; 231 mTestSessionManager.continueSession(testSession, TEST_CHILD_NAME); 232 233 assertEquals(2, mTestSessionManager.mSessionMapper.size()); 234 assertEquals(testSession, mTestSessionManager.mSessionMapper.get(TEST_CHILD_THREAD_ID)); 235 assertEquals(parentSession, testSession.getParentSession()); 236 assertFalse(parentSession.isStartedFromActiveSession()); 237 assertFalse(parentSession.isSessionCompleted()); 238 assertFalse(testSession.isSessionCompleted()); 239 assertFalse(testSession.isStartedFromActiveSession()); 240 } 241 242 /** 243 * Ends a subsession that exists in a different thread and verifies that it is completed and 244 * no longer exists in mSessionMapper. 245 */ 246 @SmallTest 247 @Test testEndSubsession()248 public void testEndSubsession() { 249 mTestSessionManager.mCurrentThreadId = () -> TEST_PARENT_THREAD_ID; 250 mTestSessionManager.startSession(TEST_PARENT_NAME, null); 251 Session parentSession = mTestSessionManager.mSessionMapper.get(TEST_PARENT_THREAD_ID); 252 Session testSession = mTestSessionManager.createSubsession(); 253 mTestSessionManager.mCurrentThreadId = () -> TEST_CHILD_THREAD_ID; 254 mTestSessionManager.continueSession(testSession, TEST_CHILD_NAME); 255 256 mTestSessionManager.endSession(); 257 258 assertTrue(testSession.isSessionCompleted()); 259 assertNull(mTestSessionManager.mSessionMapper.get(TEST_CHILD_THREAD_ID)); 260 assertFalse(parentSession.isSessionCompleted()); 261 assertEquals(parentSession, mTestSessionManager.mSessionMapper.get(TEST_PARENT_THREAD_ID)); 262 } 263 264 /** 265 * When there are subsessions in multiple threads, the parent session may end before the 266 * subsessions themselves. When the subsession ends, we need to recursively clean up the parent 267 * sessions that are complete as well and note the completion time of the entire chain. 268 */ 269 @SmallTest 270 @Test testEndSubsessionWithParentComplete()271 public void testEndSubsessionWithParentComplete() { 272 mTestSessionManager.mCurrentThreadId = () -> TEST_PARENT_THREAD_ID; 273 mTestSessionManager.startSession(TEST_PARENT_NAME, null); 274 Session parentSession = mTestSessionManager.mSessionMapper.get(TEST_PARENT_THREAD_ID); 275 Session childSession = mTestSessionManager.createSubsession(); 276 mTestSessionManager.mCurrentThreadId = () -> TEST_CHILD_THREAD_ID; 277 mTestSessionManager.continueSession(childSession, TEST_CHILD_NAME); 278 // Switch to the parent session ID and end the session. 279 mTestSessionManager.mCurrentThreadId = () -> TEST_PARENT_THREAD_ID; 280 mTestSessionManager.endSession(); 281 assertTrue(parentSession.isSessionCompleted()); 282 assertFalse(childSession.isSessionCompleted()); 283 284 mTestSessionManager.mCurrentThreadId = () -> TEST_CHILD_THREAD_ID; 285 try { 286 Thread.sleep(TEST_DELAY_TIME); 287 } catch (InterruptedException ignored) {} 288 mTestSessionManager.endSession(); 289 290 assertEquals(0, mTestSessionManager.mSessionMapper.size()); 291 assertTrue(parentSession.getChildSessions().isEmpty()); 292 assertNull(childSession.getParentSession()); 293 assertTrue(childSession.isSessionCompleted()); 294 assertEquals(TEST_PARENT_NAME, mFullSessionMethodName); 295 // Reduce flakiness by assuming that the true completion time is within a threshold of 296 // +-50 ms 297 assertTrue(mfullSessionCompleteTime >= TEST_DELAY_TIME / 2); 298 assertTrue(mfullSessionCompleteTime <= TEST_DELAY_TIME * 1.5); 299 } 300 301 /** 302 * Tests that starting an external session packages up the parent session information and 303 * correctly generates the child session. 304 */ 305 @SmallTest 306 @Test testStartExternalSession()307 public void testStartExternalSession() { 308 mTestSessionManager.mCurrentThreadId = () -> TEST_PARENT_THREAD_ID; 309 mTestSessionManager.startSession(TEST_PARENT_NAME, null); 310 Session.Info sessionInfo = 311 mTestSessionManager.mSessionMapper.get(TEST_PARENT_THREAD_ID).getInfo(); 312 mTestSessionManager.mCurrentThreadId = () -> TEST_CHILD_THREAD_ID; 313 314 mTestSessionManager.startExternalSession(sessionInfo, TEST_CHILD_NAME); 315 316 Session externalSession = mTestSessionManager.mSessionMapper.get(TEST_CHILD_THREAD_ID); 317 assertNotNull(externalSession); 318 assertFalse(externalSession.isSessionCompleted()); 319 assertEquals(TEST_CHILD_NAME, externalSession.getShortMethodName()); 320 // First subsession of the parent external Session, so the session will be _0. 321 assertEquals("0", externalSession.getSessionId()); 322 } 323 324 /** 325 * Verifies that ending an external session tears down the session correctly and removes the 326 * external session from mSessionMapper. 327 */ 328 @SmallTest 329 @Test testEndExternalSession()330 public void testEndExternalSession() { 331 mTestSessionManager.mCurrentThreadId = () -> TEST_PARENT_THREAD_ID; 332 mTestSessionManager.startSession(TEST_PARENT_NAME, null); 333 Session.Info sessionInfo = 334 mTestSessionManager.mSessionMapper.get(TEST_PARENT_THREAD_ID).getInfo(); 335 mTestSessionManager.mCurrentThreadId = () -> TEST_CHILD_THREAD_ID; 336 mTestSessionManager.startExternalSession(sessionInfo, TEST_CHILD_NAME); 337 Session externalSession = mTestSessionManager.mSessionMapper.get(TEST_CHILD_THREAD_ID); 338 339 try { 340 // Make sure execution time is > 0 341 Thread.sleep(1); 342 } catch (InterruptedException ignored) {} 343 mTestSessionManager.endSession(); 344 345 assertTrue(externalSession.isSessionCompleted()); 346 assertTrue(externalSession.getLocalExecutionTime() > 0); 347 assertNull(mTestSessionManager.mSessionMapper.get(TEST_CHILD_THREAD_ID)); 348 } 349 350 /** 351 * Verifies that the callback to inform that the top level parent Session has completed is not 352 * the external Session, but the one subsession underneath. 353 */ 354 @SmallTest 355 @Test testEndExternalSessionListenerCallback()356 public void testEndExternalSessionListenerCallback() { 357 mTestSessionManager.mCurrentThreadId = () -> TEST_PARENT_THREAD_ID; 358 mTestSessionManager.startSession(TEST_PARENT_NAME, null); 359 Session.Info sessionInfo = 360 mTestSessionManager.mSessionMapper.get(TEST_PARENT_THREAD_ID).getInfo(); 361 mTestSessionManager.mCurrentThreadId = () -> TEST_CHILD_THREAD_ID; 362 mTestSessionManager.startExternalSession(sessionInfo, TEST_CHILD_NAME); 363 364 try { 365 // Make sure execution time is recorded correctly 366 Thread.sleep(TEST_DELAY_TIME); 367 } catch (InterruptedException ignored) {} 368 mTestSessionManager.endSession(); 369 370 assertEquals(TEST_CHILD_NAME, mFullSessionMethodName); 371 assertTrue(mfullSessionCompleteTime >= TEST_DELAY_TIME / 2); 372 assertTrue(mfullSessionCompleteTime <= TEST_DELAY_TIME * 1.5); 373 } 374 375 /** 376 * Verifies that the recursive method for getting the full ID works correctly. 377 */ 378 @SmallTest 379 @Test testFullMethodPath()380 public void testFullMethodPath() { 381 mTestSessionManager.mCurrentThreadId = () -> TEST_PARENT_THREAD_ID; 382 mTestSessionManager.startSession(TEST_PARENT_NAME, null); 383 Session testSession = mTestSessionManager.createSubsession(); 384 mTestSessionManager.mCurrentThreadId = () -> TEST_CHILD_THREAD_ID; 385 mTestSessionManager.continueSession(testSession, TEST_CHILD_NAME); 386 387 String fullId = mTestSessionManager.getSessionId(); 388 389 assertTrue(fullId.contains(TEST_PARENT_NAME + Session.SUBSESSION_SEPARATION_CHAR 390 + TEST_CHILD_NAME)); 391 } 392 393 /** 394 * Make sure that the cleanup timer runs correctly and the GC collects the stale sessions 395 * correctly to ensure that there are no dangling sessions. 396 */ 397 @SmallTest 398 @Test testStaleSessionCleanupTimer()399 public void testStaleSessionCleanupTimer() { 400 mTestSessionManager.mCurrentThreadId = () -> TEST_PARENT_THREAD_ID; 401 mTestSessionManager.startSession(TEST_PARENT_NAME, null); 402 WeakReference<Session> sessionRef = new WeakReference<>( 403 mTestSessionManager.mSessionMapper.get(TEST_PARENT_THREAD_ID)); 404 try { 405 // Make sure that the sleep time is always > delay time. 406 Thread.sleep(2 * TEST_DELAY_TIME); 407 mTestSessionManager.cleanupStaleSessions(TEST_DELAY_TIME); 408 Runtime.getRuntime().gc(); 409 // Give it a second for GC to run. 410 Thread.sleep(1000); 411 } catch (InterruptedException ignored) {} 412 413 assertTrue(mTestSessionManager.mSessionMapper.isEmpty()); 414 assertNull(sessionRef.get()); 415 } 416 417 /** 418 * If Telecom gets into a situation where there are MANY sub-sessions created in a deep tree, 419 * ensure that cleanup still happens properly. 420 */ 421 @SmallTest 422 @Test testManySubsessionCleanupStress()423 public void testManySubsessionCleanupStress() { 424 // This test will mostly likely fail with recursion due to stack overflow 425 if (!Flags.endSessionImprovements()) return; 426 Log.setIsExtendedLoggingEnabled(false); 427 mTestSessionManager.mCurrentThreadId = () -> TEST_PARENT_THREAD_ID; 428 mTestSessionManager.startSession(TEST_PARENT_NAME, null); 429 Session parentSession = mTestSessionManager.mSessionMapper.get(TEST_PARENT_THREAD_ID); 430 Session subsession; 431 try { 432 for (int i = 0; i < 10000; i++) { 433 subsession = mTestSessionManager.createSubsession(); 434 mTestSessionManager.endSession(); 435 mTestSessionManager.continueSession(subsession, TEST_CHILD_NAME + i); 436 } 437 mTestSessionManager.endSession(); 438 } catch (Exception e) { 439 fail("Exception: " + e); 440 } 441 assertTrue(mTestSessionManager.mSessionMapper.isEmpty()); 442 assertTrue(parentSession.isSessionCompleted()); 443 assertTrue(parentSession.getChildSessions().isEmpty()); 444 } 445 } 446