Skip to content

Commit

Permalink
Don't wait on main thread when SDK restarts (#3200)
Browse files Browse the repository at this point in the history
* added new methods to close instances with isRestarting flag:
- IHub.close(Boolean)
- ISentryClient.close(Boolean)
- ITransport.close(Boolean)
* when the SDK restarts, the executor service is now closed in the background, and current network connections are dropped
* AsyncHttpTransport now stores the current runnable in a variable and runs it in the rejectedExecutionHandler on close
  • Loading branch information
stefanosiano authored Feb 16, 2024
1 parent ceb541b commit f33a11d
Show file tree
Hide file tree
Showing 30 changed files with 385 additions and 27 deletions.
3 changes: 2 additions & 1 deletion CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -7,8 +7,9 @@
- Add new threshold parameters to monitor config ([#3181](https://github.com/getsentry/sentry-java/pull/3181))
- Report process init time as a span for app start performance ([#3159](https://github.com/getsentry/sentry-java/pull/3159))

## Fixes
### Fixes

- Don't wait on main thread when SDK restarts ([#3200](https://github.com/getsentry/sentry-java/pull/3200))
- Fix Jetpack Compose widgets are not being correctly identified for user interaction tracing ([#3209](https://github.com/getsentry/sentry-java/pull/3209))

## 7.3.0
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -54,6 +54,10 @@ class InternalSentrySdkTest {
options.dsn = "https://key@host/proj"
options.setTransportFactory { _, _ ->
object : ITransport {
override fun close(isRestarting: Boolean) {
// no-op
}

override fun close() {
// no-op
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -133,6 +133,10 @@ class SessionTrackingIntegrationTest {
TODO("Not yet implemented")
}

override fun close(isRestarting: Boolean) {
TODO("Not yet implemented")
}

override fun close() {
TODO("Not yet implemented")
}
Expand Down
Original file line number Diff line number Diff line change
@@ -1,6 +1,5 @@
package io.sentry.uitest.android

import android.util.Log
import androidx.lifecycle.Lifecycle
import androidx.test.core.app.launchActivity
import androidx.test.espresso.Espresso
Expand Down Expand Up @@ -199,7 +198,6 @@ class EnvelopeTests : BaseUiTest() {

relay.assert {
findEnvelope {
Log.e("ITEMS", it.items.joinToString { item -> item.header.type.itemType })
assertEnvelopeTransaction(it.items.toList(), AndroidLogger()).transaction == "timedOutProfile"
}.assert {
val transactionItem: SentryTransaction = it.assertTransaction()
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,7 @@ import io.sentry.protocol.SentryTransaction
import org.junit.runner.RunWith
import kotlin.test.Test
import kotlin.test.assertEquals
import kotlin.test.assertTrue

@RunWith(AndroidJUnit4::class)
class SdkInitTests : BaseUiTest() {
Expand Down Expand Up @@ -74,4 +75,83 @@ class SdkInitTests : BaseUiTest() {
assertNoOtherEnvelopes()
}
}

@Test
fun doubleInitDoesNotWait() {
relayIdlingResource.increment()
// Let's make the first request timeout
relay.addTimeoutResponse()

initSentry(true) { options: SentryAndroidOptions ->
options.tracesSampleRate = 1.0
}

Sentry.startTransaction("beforeRestart", "emptyTransaction").finish()

// We want the SDK to start sending the event. If we don't wait, it's possible we don't send anything before the SDK is restarted
waitUntilIdle()

relayIdlingResource.increment()
relayIdlingResource.increment()

val beforeRestart = System.currentTimeMillis()
// We restart the SDK. This shouldn't block the main thread, but new options (e.g. profiling) should work
initSentry(true) { options: SentryAndroidOptions ->
options.tracesSampleRate = 1.0
options.profilesSampleRate = 1.0
}
val afterRestart = System.currentTimeMillis()
val restartMs = afterRestart - beforeRestart

Sentry.startTransaction("afterRestart", "emptyTransaction").finish()
// We assert for less than 1 second just to account for slow devices in saucelabs or headless emulator
assertTrue(restartMs < 1000, "Expected less than 1000 ms for SDK restart. Got $restartMs ms")

relay.assert {
findEnvelope {
assertEnvelopeTransaction(it.items.toList()).transaction == "beforeRestart"
}.assert {
it.assertTransaction()
// No profiling item, as in the first init it was not enabled
it.assertNoOtherItems()
}
findEnvelope {
assertEnvelopeTransaction(it.items.toList()).transaction == "afterRestart"
}.assert {
it.assertTransaction()
// There is a profiling item, as in the second init it was enabled
it.assertProfile()
it.assertNoOtherItems()
}
assertNoOtherEnvelopes()
}
}

@Test
fun initCloseInitWaits() {
relayIdlingResource.increment()
// Let's make the first request timeout
relay.addTimeoutResponse()

initSentry(true) { options: SentryAndroidOptions ->
options.tracesSampleRate = 1.0
options.flushTimeoutMillis = 3000
}

Sentry.startTransaction("beforeRestart", "emptyTransaction").finish()

// We want the SDK to start sending the event. If we don't wait, it's possible we don't send anything before the SDK is restarted
waitUntilIdle()

val beforeRestart = System.currentTimeMillis()
Sentry.close()
// We stop the SDK. This should block the main thread. Then we start it again with new options
initSentry(true) { options: SentryAndroidOptions ->
options.tracesSampleRate = 1.0
options.profilesSampleRate = 1.0
}
val afterRestart = System.currentTimeMillis()
val restartMs = afterRestart - beforeRestart
assertTrue(restartMs > 3000, "Expected more than 3000 ms for SDK close and restart. Got $restartMs ms")
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@ import okhttp3.mockwebserver.Dispatcher
import okhttp3.mockwebserver.MockResponse
import okhttp3.mockwebserver.MockWebServer
import okhttp3.mockwebserver.RecordedRequest
import okhttp3.mockwebserver.SocketPolicy
import kotlin.test.assertNotNull

/** Mocks a relay server. */
Expand All @@ -32,24 +33,24 @@ class MockRelay(
init {
relay.dispatcher = object : Dispatcher() {
override fun dispatch(request: RecordedRequest): MockResponse {
// If a request with a body size of 0 is received, we drop it.
// This shouldn't happen in reality, but it rarely happens in tests.
if (request.bodySize == 0L || request.failure != null) {
return MockResponse()
}
// We check if there is any custom response previously set to return to this request,
// otherwise we return a successful MockResponse.
val response = responses.asSequence()
.mapNotNull { it(request) }
.firstOrNull()
?: MockResponse()
val response = responses.removeFirstOrNull()?.let { it(request) } ?: MockResponse()

// We should receive only envelopes on this path.
if (request.path == envelopePath) {
val relayResponse = RelayAsserter.RelayResponse(request, response)
// If we reply with NO_RESPONSE, we can ignore the request, so we can return here
if (relayResponse.envelope == null || response.socketPolicy == SocketPolicy.NO_RESPONSE) {
// If we are waiting for requests to be received, we decrement the associated counter.
if (waitForRequests) {
relayIdlingResource.decrement()
}
return response
}
assertNotNull(relayResponse.envelope)
val envelopeId: String = relayResponse.envelope!!.header.eventId!!.toString()
// If we already received the envelope (e.g. retrying mechanism) we drop it
// If we already received the envelope (e.g. retrying mechanism) we ignore it
if (receivedEnvelopes.contains(envelopeId)) {
return MockResponse()
}
Expand Down Expand Up @@ -90,6 +91,13 @@ class MockRelay(
responses.add(0, response)
}

/** Add a custom response to be returned at the next request received. */
fun addTimeoutResponse() {
addResponse {
MockResponse().setSocketPolicy(SocketPolicy.NO_RESPONSE)
}
}

/** Add a custom response to be returned at the next request received, if it satisfies the [filter]. */
fun addResponse(
filter: (RecordedRequest) -> Boolean,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -40,7 +40,13 @@ class RelayAsserter(
filter: (envelope: SentryEnvelope) -> Boolean = { true }
): RelayResponse {
val relayResponseIndex = unassertedEnvelopes.indexOfFirst { it.envelope?.let(filter) ?: false }
if (relayResponseIndex == -1) throw AssertionError("No envelope request found with specified filter")
if (relayResponseIndex == -1) {
throw AssertionError(
"No envelope request found with specified filter.\n" +
"There was a total of ${originalUnassertedEnvelopes.size} envelopes: " +
originalUnassertedEnvelopes.joinToString { describeEnvelope(it.envelope!!) }
)
}
return unassertedEnvelopes.removeAt(relayResponseIndex)
}

Expand Down
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
public final class io/sentry/transport/apache/ApacheHttpClientTransport : io/sentry/transport/ITransport {
public fun <init> (Lio/sentry/SentryOptions;Lio/sentry/RequestDetails;Lorg/apache/hc/client5/http/impl/async/CloseableHttpAsyncClient;Lio/sentry/transport/RateLimiter;)V
public fun close ()V
public fun close (Z)V
public fun flush (J)V
public fun getRateLimiter ()Lio/sentry/transport/RateLimiter;
public fun send (Lio/sentry/SentryEnvelope;Lio/sentry/Hint;)V
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -196,9 +196,14 @@ public void flush(long timeoutMillis) {

@Override
public void close() throws IOException {
close(false);
}

@Override
public void close(final boolean isRestarting) throws IOException {
options.getLogger().log(DEBUG, "Shutting down");
try {
httpclient.awaitShutdown(TimeValue.ofSeconds(1));
httpclient.awaitShutdown(TimeValue.ofSeconds(isRestarting ? 0 : 1));
} catch (InterruptedException e) {
options.getLogger().log(DEBUG, "Thread interrupted while closing the connection.");
Thread.currentThread().interrupt();
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -31,6 +31,7 @@ import java.util.concurrent.Executors
import kotlin.test.AfterTest
import kotlin.test.Test
import kotlin.test.assertEquals
import kotlin.test.assertNotEquals

class ApacheHttpClientTransportTest {

Expand Down Expand Up @@ -116,7 +117,21 @@ class ApacheHttpClientTransportTest {
fun `close waits for shutdown`() {
val sut = fixture.getSut()
sut.close()
verify(fixture.client).awaitShutdown(any())
verify(fixture.client).awaitShutdown(check { assertNotEquals(0L, it.duration) })
}

@Test
fun `close with isRestarting false waits for shutdown`() {
val sut = fixture.getSut()
sut.close(false)
verify(fixture.client).awaitShutdown(check { assertNotEquals(0L, it.duration) })
}

@Test
fun `close with isRestarting true does not wait for shutdown`() {
val sut = fixture.getSut()
sut.close(true)
verify(fixture.client).awaitShutdown(check { assertEquals(0L, it.duration) })
}

@Test
Expand Down
10 changes: 10 additions & 0 deletions sentry/api/sentry.api
Original file line number Diff line number Diff line change
Expand Up @@ -427,6 +427,7 @@ public final class io/sentry/Hub : io/sentry/IHub {
public fun clone ()Lio/sentry/IHub;
public synthetic fun clone ()Ljava/lang/Object;
public fun close ()V
public fun close (Z)V
public fun configureScope (Lio/sentry/ScopeCallback;)V
public fun continueTrace (Ljava/lang/String;Ljava/util/List;)Lio/sentry/TransactionContext;
public fun endSession ()V
Expand Down Expand Up @@ -477,6 +478,7 @@ public final class io/sentry/HubAdapter : io/sentry/IHub {
public fun clone ()Lio/sentry/IHub;
public synthetic fun clone ()Ljava/lang/Object;
public fun close ()V
public fun close (Z)V
public fun configureScope (Lio/sentry/ScopeCallback;)V
public fun continueTrace (Ljava/lang/String;Ljava/util/List;)Lio/sentry/TransactionContext;
public fun endSession ()V
Expand Down Expand Up @@ -567,6 +569,7 @@ public abstract interface class io/sentry/IHub {
public abstract fun clearBreadcrumbs ()V
public abstract fun clone ()Lio/sentry/IHub;
public abstract fun close ()V
public abstract fun close (Z)V
public abstract fun configureScope (Lio/sentry/ScopeCallback;)V
public abstract fun continueTrace (Ljava/lang/String;Ljava/util/List;)Lio/sentry/TransactionContext;
public abstract fun endSession ()V
Expand Down Expand Up @@ -732,6 +735,7 @@ public abstract interface class io/sentry/ISentryClient {
public abstract fun captureTransaction (Lio/sentry/protocol/SentryTransaction;Lio/sentry/TraceContext;Lio/sentry/IScope;Lio/sentry/Hint;Lio/sentry/ProfilingTraceData;)Lio/sentry/protocol/SentryId;
public abstract fun captureUserFeedback (Lio/sentry/UserFeedback;)V
public abstract fun close ()V
public abstract fun close (Z)V
public abstract fun flush (J)V
public abstract fun getRateLimiter ()Lio/sentry/transport/RateLimiter;
public abstract fun isEnabled ()Z
Expand Down Expand Up @@ -1131,6 +1135,7 @@ public final class io/sentry/NoOpHub : io/sentry/IHub {
public fun clone ()Lio/sentry/IHub;
public synthetic fun clone ()Ljava/lang/Object;
public fun close ()V
public fun close (Z)V
public fun configureScope (Lio/sentry/ScopeCallback;)V
public fun continueTrace (Ljava/lang/String;Ljava/util/List;)Lio/sentry/TransactionContext;
public fun endSession ()V
Expand Down Expand Up @@ -1849,6 +1854,7 @@ public final class io/sentry/SentryClient : io/sentry/ISentryClient {
public fun captureTransaction (Lio/sentry/protocol/SentryTransaction;Lio/sentry/TraceContext;Lio/sentry/IScope;Lio/sentry/Hint;Lio/sentry/ProfilingTraceData;)Lio/sentry/protocol/SentryId;
public fun captureUserFeedback (Lio/sentry/UserFeedback;)V
public fun close ()V
public fun close (Z)V
public fun flush (J)V
public fun getRateLimiter ()Lio/sentry/transport/RateLimiter;
public fun isEnabled ()Z
Expand Down Expand Up @@ -4536,6 +4542,7 @@ public final class io/sentry/transport/AsyncHttpTransport : io/sentry/transport/
public fun <init> (Lio/sentry/SentryOptions;Lio/sentry/transport/RateLimiter;Lio/sentry/transport/ITransportGate;Lio/sentry/RequestDetails;)V
public fun <init> (Lio/sentry/transport/QueuedThreadPoolExecutor;Lio/sentry/SentryOptions;Lio/sentry/transport/RateLimiter;Lio/sentry/transport/ITransportGate;Lio/sentry/transport/HttpConnection;)V
public fun close ()V
public fun close (Z)V
public fun flush (J)V
public fun getRateLimiter ()Lio/sentry/transport/RateLimiter;
public fun isHealthy ()Z
Expand All @@ -4552,6 +4559,7 @@ public abstract interface class io/sentry/transport/ICurrentDateProvider {
}

public abstract interface class io/sentry/transport/ITransport : java/io/Closeable {
public abstract fun close (Z)V
public abstract fun flush (J)V
public abstract fun getRateLimiter ()Lio/sentry/transport/RateLimiter;
public fun isHealthy ()Z
Expand All @@ -4573,6 +4581,7 @@ public final class io/sentry/transport/NoOpEnvelopeCache : io/sentry/cache/IEnve

public final class io/sentry/transport/NoOpTransport : io/sentry/transport/ITransport {
public fun close ()V
public fun close (Z)V
public fun flush (J)V
public static fun getInstance ()Lio/sentry/transport/NoOpTransport;
public fun getRateLimiter ()Lio/sentry/transport/RateLimiter;
Expand Down Expand Up @@ -4606,6 +4615,7 @@ public final class io/sentry/transport/ReusableCountLatch {
public final class io/sentry/transport/StdoutTransport : io/sentry/transport/ITransport {
public fun <init> (Lio/sentry/ISerializer;)V
public fun close ()V
public fun close (Z)V
public fun flush (J)V
public fun getRateLimiter ()Lio/sentry/transport/RateLimiter;
public fun send (Lio/sentry/SentryEnvelope;Lio/sentry/Hint;)V
Expand Down
15 changes: 13 additions & 2 deletions sentry/src/main/java/io/sentry/Hub.java
Original file line number Diff line number Diff line change
Expand Up @@ -331,6 +331,12 @@ public void endSession() {

@Override
public void close() {
close(false);
}

@Override
@SuppressWarnings("FutureReturnValueIgnored")
public void close(final boolean isRestarting) {
if (!isEnabled()) {
options
.getLogger()
Expand All @@ -352,12 +358,17 @@ public void close() {
configureScope(scope -> scope.clear());
options.getTransactionProfiler().close();
options.getTransactionPerformanceCollector().close();
options.getExecutorService().close(options.getShutdownTimeoutMillis());
final @NotNull ISentryExecutorService executorService = options.getExecutorService();
if (isRestarting) {
executorService.submit(() -> executorService.close(options.getShutdownTimeoutMillis()));
} else {
executorService.close(options.getShutdownTimeoutMillis());
}

// Close the top-most client
final StackItem item = stack.peek();
// TODO: should we end session before closing client?
item.getClient().close();
item.getClient().close(isRestarting);
} catch (Throwable e) {
options.getLogger().log(SentryLevel.ERROR, "Error while closing the Hub.", e);
}
Expand Down
5 changes: 5 additions & 0 deletions sentry/src/main/java/io/sentry/HubAdapter.java
Original file line number Diff line number Diff line change
Expand Up @@ -78,6 +78,11 @@ public void endSession() {
Sentry.endSession();
}

@Override
public void close(final boolean isRestarting) {
Sentry.close();
}

@Override
public void close() {
Sentry.close();
Expand Down
Loading

0 comments on commit f33a11d

Please sign in to comment.