1 /* 2 * Copyright (C) 2024 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 @file:OptIn(DelicateCoroutinesApi::class, ExperimentalCoroutinesApi::class) 18 19 package com.android.test.tracing.coroutines 20 21 import android.platform.test.annotations.EnableFlags 22 import com.android.app.tracing.coroutines.CoroutineTraceName 23 import com.android.app.tracing.coroutines.TraceContextElement 24 import com.android.app.tracing.coroutines.coroutineScopeTraced 25 import com.android.app.tracing.coroutines.launchTraced 26 import com.android.app.tracing.coroutines.traceCoroutine 27 import com.android.app.tracing.coroutines.withContextTraced 28 import com.android.systemui.Flags.FLAG_COROUTINE_TRACING 29 import kotlin.coroutines.EmptyCoroutineContext 30 import kotlinx.coroutines.CompletableDeferred 31 import kotlinx.coroutines.CoroutineScope 32 import kotlinx.coroutines.CoroutineStart 33 import kotlinx.coroutines.DelicateCoroutinesApi 34 import kotlinx.coroutines.ExperimentalCoroutinesApi 35 import kotlinx.coroutines.cancelChildren 36 import kotlinx.coroutines.coroutineScope 37 import kotlinx.coroutines.delay 38 import kotlinx.coroutines.launch 39 import kotlinx.coroutines.withContext 40 import org.junit.Assert.assertEquals 41 import org.junit.Assert.assertTrue 42 import org.junit.Test 43 44 @EnableFlags(FLAG_COROUTINE_TRACING) 45 class CoroutineTracingTest : TestBase() { 46 47 @Test simpleTraceSectionnull48 fun simpleTraceSection() = 49 runTest(finalEvent = 2) { 50 expect(1, "1^main") 51 delay(1) 52 expect(2, "1^main") 53 } 54 55 @Test traceSectionFromScopenull56 fun traceSectionFromScope() = 57 runTest(finalEvent = 2) { 58 traceCoroutine("hello") { 59 expect(1, "1^main", "hello") 60 delay(1) 61 expect(2, "1^main", "hello") 62 } 63 } 64 65 @Test testCoroutineScopenull66 fun testCoroutineScope() = 67 runTest(finalEvent = 2) { 68 coroutineScope { expect(1, "1^main") } 69 expect(2, "1^main") 70 } 71 72 @Test simpleNestedTraceSectionnull73 fun simpleNestedTraceSection() = 74 runTest(finalEvent = 10) { 75 expect(1, "1^main") 76 delay(1) 77 expect(2, "1^main") 78 traceCoroutine("hello") { 79 expect(3, "1^main", "hello") 80 delay(1) 81 expect(4, "1^main", "hello") 82 traceCoroutine("world") { 83 expect(5, "1^main", "hello", "world") 84 delay(1) 85 expect(6, "1^main", "hello", "world") 86 } 87 expect(7, "1^main", "hello") 88 delay(1) 89 expect(8, "1^main", "hello") 90 } 91 expect(9, "1^main") 92 delay(1) 93 expect(10, "1^main") 94 } 95 96 @Test simpleLaunchnull97 fun simpleLaunch() { 98 val barrier = CompletableDeferred<Unit>() 99 runTest(finalEvent = 7) { 100 expect(1, "1^main") 101 delay(1) 102 expect(2, "1^main") 103 traceCoroutine("hello") { 104 expect(3, "1^main", "hello") 105 delay(1) 106 expect(4, "1^main", "hello") 107 launch { 108 expect(5, "1^main:1^") 109 delay(1) 110 // "hello" is not passed to child scope 111 expect(6, "1^main:1^") 112 barrier.complete(Unit) 113 } 114 } 115 barrier.await() 116 expect(7, "1^main") 117 } 118 } 119 120 @Test launchWithSuspendingLambdanull121 fun launchWithSuspendingLambda() = 122 runTest(finalEvent = 5) { 123 val fetchData: suspend () -> String = { 124 expect(3, "1^main:1^span-for-launch") 125 delay(1L) 126 traceCoroutine("span-for-fetchData") { 127 expect(4, "1^main:1^span-for-launch", "span-for-fetchData") 128 } 129 "stuff" 130 } 131 expect(1, "1^main") 132 launchTraced("span-for-launch") { 133 assertEquals("stuff", fetchData()) 134 expect(5, "1^main:1^span-for-launch") 135 } 136 expect(2, "1^main") 137 } 138 139 @Test stressTestContextSwitchesnull140 fun stressTestContextSwitches() = 141 runTest(totalEvents = 800) { 142 repeat(200) { 143 listOf(bgThread1, bgThread2, bgThread3, bgThread4).forEach { 144 launch(it) { 145 traceCoroutine("a") { 146 delay(1) 147 expectEndsWith("a") 148 } 149 } 150 } 151 } 152 } 153 154 @Test stressTestContextSwitches_depthnull155 fun stressTestContextSwitches_depth() { 156 fun CoroutineScope.recursivelyLaunch(n: Int) { 157 if (n == 0) return 158 launchTraced("launch#$n", start = CoroutineStart.UNDISPATCHED) { 159 traceCoroutine("a") { 160 recursivelyLaunch(n - 1) 161 delay(1) 162 expectEndsWith("a") 163 } 164 } 165 } 166 runTest(totalEvents = 400) { recursivelyLaunch(400) } 167 } 168 169 @Test withContext_incorrectUsagenull170 fun withContext_incorrectUsage() = 171 runTest(finalEvent = 4) { 172 assertTrue(coroutineContext[CoroutineTraceName] is TraceContextElement) 173 expect(1, "1^main") 174 withContext(CoroutineTraceName("inside-withContext")) { // <-- BAD, DON'T DO THIS 175 // This is why CoroutineTraceName() should not be used this way, it overwrites the 176 // TraceContextElement. Because it is not a CopyableThreadContextElement, it is 177 // not given opportunity to merge with the parent trace context. 178 // While we could make CoroutineTraceName a CopyableThreadContextElement, it would 179 // add too much overhead to tracing, especially for flows where operation fusion 180 // is common. 181 assertTrue(coroutineContext[CoroutineTraceName] is CoroutineTraceName) 182 183 // The result of replacing the `TraceContextElement` with `CoroutineTraceName` is 184 // that 185 // tracing doesn't happen: 186 expect(2, "1^main") // <-- Trace section from before withContext is open until the 187 // first suspension 188 delay(1) 189 expect(3) 190 } 191 expect(4, "1^main") 192 } 193 194 @Test withContext_correctUsagenull195 fun withContext_correctUsage() = 196 runTest(finalEvent = 4) { 197 expect(1, "1^main") 198 withContextTraced("inside-withContext", EmptyCoroutineContext) { 199 assertTrue(coroutineContext[CoroutineTraceName] is TraceContextElement) 200 expect(2, "1^main", "inside-withContext") 201 delay(1) 202 expect(3, "1^main", "inside-withContext") 203 } 204 expect(4, "1^main") 205 } 206 207 @Test <lambda>null208 fun launchInCoroutineScope() = runTest { 209 launchTraced("launch#0") { 210 expect("1^main:1^launch#0") 211 delay(1) 212 expect("1^main:1^launch#0") 213 } 214 coroutineScopeTraced("span-for-coroutineScope-1") { 215 launchTraced("launch#1") { 216 expect("1^main:2^launch#1") 217 delay(1) 218 expect("1^main:2^launch#1") 219 } 220 launchTraced("launch#2") { 221 expect("1^main:3^launch#2") 222 delay(1) 223 expect("1^main:3^launch#2") 224 } 225 coroutineScopeTraced("span-for-coroutineScope-2") { 226 launchTraced("launch#3") { 227 expect("1^main:4^launch#3") 228 delay(1) 229 expect("1^main:4^launch#3") 230 } 231 launchTraced("launch#4") { 232 expect("1^main:5^launch#4") 233 delay(1) 234 expect("1^main:5^launch#4") 235 } 236 } 237 } 238 launchTraced("launch#5") { 239 expect("1^main:6^launch#5") 240 delay(1) 241 expect("1^main:6^launch#5") 242 } 243 } 244 245 @Test <lambda>null246 fun namedScopeMerging() = runTest { 247 // to avoid race conditions in the test leading to flakes, avoid calling expectD() or 248 // delaying before launching (e.g. only call expectD() in leaf blocks) 249 expect("1^main") 250 launchTraced("A") { 251 expect("1^main:1^A") 252 traceCoroutine("span") { expectD("1^main:1^A", "span") } 253 launchTraced("B") { expectD("1^main:1^A:1^B") } 254 launchTraced("C") { 255 expect("1^main:1^A:2^C") 256 launch { expectD("1^main:1^A:2^C:1^") } 257 launchTraced("D") { expectD("1^main:1^A:2^C:2^D") } 258 launchTraced("E") { 259 expect("1^main:1^A:2^C:3^E") 260 launchTraced("F") { expectD("1^main:1^A:2^C:3^E:1^F") } 261 expect("1^main:1^A:2^C:3^E") 262 } 263 } 264 launchTraced("G") { expectD("1^main:1^A:3^G") } 265 } 266 launch { launch { launch { expectD("1^main:2^:1^:1^") } } } 267 delay(2) 268 launchTraced("H") { launch { launch { expectD("1^main:3^H:1^:1^") } } } 269 delay(2) 270 launch { 271 launch { 272 launch { 273 launch { launch { launchTraced("I") { expectD("1^main:4^:1^:1^:1^:1^:1^I") } } } 274 } 275 } 276 } 277 delay(2) 278 launchTraced("J") { 279 launchTraced("K") { launch { launch { expectD("1^main:5^J:1^K:1^:1^") } } } 280 } 281 delay(2) 282 launchTraced("L") { 283 launchTraced("M") { launch { launch { expectD("1^main:6^L:1^M:1^:1^") } } } 284 } 285 delay(2) 286 launchTraced("N") { 287 launchTraced("O") { launch { launchTraced("D") { expectD("1^main:7^N:1^O:1^:1^D") } } } 288 } 289 delay(2) 290 launchTraced("P") { 291 launchTraced("Q") { launch { launchTraced("R") { expectD("1^main:8^P:1^Q:1^:1^R") } } } 292 } 293 delay(2) 294 launchTraced("S") { launchTraced("T") { launch { expectD("1^main:9^S:1^T:1^") } } } 295 delay(2) 296 launchTraced("U") { launchTraced("V") { launch { expectD("1^main:10^U:1^V:1^") } } } 297 delay(2) 298 expectD("1^main") 299 } 300 301 @Test launchIntoSelfnull302 fun launchIntoSelf() = 303 runTest(finalEvent = 11) { 304 expect(1, "1^main") 305 delay(1) 306 expect(2, "1^main") 307 val reusedNameContext = CoroutineTraceName("my-coroutine") 308 launch(reusedNameContext) { 309 expect(3, "1^main:1^my-coroutine") 310 delay(1) 311 expect(4, "1^main:1^my-coroutine") 312 launch(reusedNameContext) { 313 expect(5, "1^main:1^my-coroutine:1^my-coroutine") 314 delay(5) 315 expect(8, "1^main:1^my-coroutine:1^my-coroutine") 316 } 317 delay(1) 318 expect(6, "1^main:1^my-coroutine") 319 launch(reusedNameContext) { 320 expect(7, "1^main:1^my-coroutine:2^my-coroutine") 321 delay(7) 322 expect(9, "1^main:1^my-coroutine:2^my-coroutine") 323 } 324 delay(10) 325 expect(10, "1^main:1^my-coroutine") 326 } 327 launch(reusedNameContext) { 328 delay(20) 329 expect(11, "1^main:2^my-coroutine") 330 } 331 } 332 333 @Test undispatchedLaunchnull334 fun undispatchedLaunch() = 335 runTest(totalEvents = 4) { 336 launchTraced("AAA", start = CoroutineStart.UNDISPATCHED) { 337 expect("1^main", "1^main:1^AAA") 338 launchTraced("BBB", start = CoroutineStart.UNDISPATCHED) { 339 traceCoroutine("delay-5") { 340 expect("1^main", "1^main:1^AAA", "1^main:1^AAA:1^BBB", "delay-5") 341 delay(5) 342 expect("1^main:1^AAA:1^BBB", "delay-5") 343 } 344 } 345 } 346 expect("1^main") 347 } 348 349 @Test undispatchedLaunch_cancellednull350 fun undispatchedLaunch_cancelled() = 351 runTest(totalEvents = 11) { 352 traceCoroutine("hello") { expect("1^main", "hello") } 353 val job = 354 launchTraced("AAA", start = CoroutineStart.UNDISPATCHED) { 355 expect("1^main", "1^main:1^AAA") 356 traceCoroutine("delay-50") { 357 expect("1^main", "1^main:1^AAA", "delay-50") 358 launchTraced("BBB", start = CoroutineStart.UNDISPATCHED) { 359 traceCoroutine("BBB:delay-25") { 360 expect( 361 "1^main", 362 "1^main:1^AAA", 363 "delay-50", 364 "1^main:1^AAA:1^BBB", 365 "BBB:delay-25", 366 ) 367 delay(25) 368 expect("1^main:1^AAA:1^BBB", "BBB:delay-25") 369 } 370 } 371 .join() 372 expect("1^main:1^AAA", "delay-50") 373 delay(25) 374 } 375 } 376 launchTraced("CCC") { 377 traceCoroutine("delay-35") { 378 expect("1^main:2^CCC", "delay-35") 379 delay(35) 380 expect("1^main:2^CCC", "delay-35") 381 } 382 job.cancelChildren() 383 expect("1^main:2^CCC") 384 job.join() 385 expect("1^main:2^CCC") 386 } 387 expect("1^main") 388 } 389 } 390