diff --git a/CHANGELOG.md b/CHANGELOG.md index 09622493a2..4a8db73b3d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,11 @@ # Changelog +## Unreleased + +### Internal + +- Measure the hostname cache TTL and the 30 second performance-collection budget on a monotonic ticker, so that a device time change no longer shortens or extends either ([#6099](https://github.com/getsentry/sentry-java/pull/6099)) + ## 8.56.0 ### Behavioral Changes diff --git a/sentry-test-support/src/main/kotlin/io/sentry/time/TestMonotonicTicker.kt b/sentry-test-support/src/main/kotlin/io/sentry/time/TestMonotonicTicker.kt index 2471a1bc8d..e799d7520e 100644 --- a/sentry-test-support/src/main/kotlin/io/sentry/time/TestMonotonicTicker.kt +++ b/sentry-test-support/src/main/kotlin/io/sentry/time/TestMonotonicTicker.kt @@ -9,7 +9,7 @@ import java.util.concurrent.TimeUnit * nanosecond ticker is off by a factor of a million and still compiles, whereas `advance(1001, * MILLISECONDS)` cannot be. */ -class TestMonotonicTicker(private var nanos: Long = 0) : MonotonicTicker { +class TestMonotonicTicker(@Volatile private var nanos: Long = 0) : MonotonicTicker { override fun tickNanos(): Long = nanos fun advance(amount: Long, unit: TimeUnit) { diff --git a/sentry/src/main/java/io/sentry/DefaultCompositePerformanceCollector.java b/sentry/src/main/java/io/sentry/DefaultCompositePerformanceCollector.java index 2b5a386300..8e8de23109 100644 --- a/sentry/src/main/java/io/sentry/DefaultCompositePerformanceCollector.java +++ b/sentry/src/main/java/io/sentry/DefaultCompositePerformanceCollector.java @@ -1,5 +1,7 @@ package io.sentry; +import io.sentry.time.Deadline; +import io.sentry.time.MonotonicTicker; import io.sentry.util.AutoClosableReentrantLock; import io.sentry.util.Objects; import java.util.ArrayList; @@ -26,10 +28,19 @@ public final class DefaultCompositePerformanceCollector implements CompositePerf private final boolean hasNoCollectors; private final @NotNull SentryOptions options; + private final @NotNull MonotonicTicker ticker; private final @NotNull AtomicBoolean isStarted = new AtomicBoolean(false); public DefaultCompositePerformanceCollector(final @NotNull SentryOptions options) { + this( + Objects.requireNonNull(options, "The options object is required."), + options.getMonotonicTicker()); + } + + DefaultCompositePerformanceCollector( + final @NotNull SentryOptions options, final @NotNull MonotonicTicker ticker) { this.options = Objects.requireNonNull(options, "The options object is required."); + this.ticker = Objects.requireNonNull(ticker, "The ticker is required."); this.snapshotCollectors = new ArrayList<>(); this.continuousCollectors = new ArrayList<>(); @@ -124,7 +135,7 @@ public void run() { // Add the enriched tempData to all transactions/profiles/objects that collect data. // Then Check if that object timed out. for (CompositeData data : compositeDataMap.values()) { - if (data.addDataAndCheckTimeout(tempData, tempData.getNanoTimestamp())) { + if (data.addDataAndCheckTimeout(tempData)) { // timed out if (data.transaction != null) { timedOutTransactions.add(data.transaction); @@ -212,33 +223,30 @@ public void close() { private class CompositeData { private final @NotNull List dataList; private final @Nullable ITransaction transaction; - private final long startTimestamp; + private final @NotNull Deadline collectUntil; private CompositeData(final @Nullable ITransaction transaction) { this.dataList = new ArrayList<>(); this.transaction = transaction; - this.startTimestamp = options.getDateProvider().now().nanoTimestamp(); + // On a ticker rather than the date provider: this is how long we have been collecting, and + // a device time change must not end a collection early or keep a finished one going. + this.collectUntil = + Deadline.after(ticker, TRANSACTION_COLLECTION_TIMEOUT_MILLIS, TimeUnit.MILLISECONDS); } /** * Adds the data to the internal list of PerformanceCollectionData. Then it checks if data * collection timed out (for transactions only). * - * @param nowNanos the timestamp of the current collection, passed in so a single clock reading - * is shared by every transaction in this collection round. * @return true if data collection timed out (for transactions only). */ - boolean addDataAndCheckTimeout( - final @NotNull PerformanceCollectionData data, final long nowNanos) { + boolean addDataAndCheckTimeout(final @NotNull PerformanceCollectionData data) { // stop() hands dataList out while this timer thread may still be writing to it, so consumers // synchronize on the list while iterating. We must hold the same monitor here. synchronized (dataList) { dataList.add(data); } - return transaction != null - && nowNanos - > startTimestamp - + TimeUnit.MILLISECONDS.toNanos(TRANSACTION_COLLECTION_TIMEOUT_MILLIS); + return transaction != null && collectUntil.hasPassed(); } } } diff --git a/sentry/src/main/java/io/sentry/HostnameCache.java b/sentry/src/main/java/io/sentry/HostnameCache.java index 56cc0c2e84..427b90d16d 100644 --- a/sentry/src/main/java/io/sentry/HostnameCache.java +++ b/sentry/src/main/java/io/sentry/HostnameCache.java @@ -1,5 +1,8 @@ package io.sentry; +import io.sentry.time.Deadline; +import io.sentry.time.JavaMonotonicTicker; +import io.sentry.time.MonotonicTicker; import io.sentry.util.AutoClosableReentrantLock; import io.sentry.util.Objects; import java.net.InetAddress; @@ -42,14 +45,16 @@ public final class HostnameCache { private static final @NotNull AutoClosableReentrantLock staticLock = new AutoClosableReentrantLock(); - /** Time for which the cache is kept. */ - private final long cacheDuration; + /** Time for which the cache is kept, in milliseconds. */ + private final long cacheDurationMillis; + + private final @NotNull MonotonicTicker ticker; /** Current value for hostname (might change over time). */ @Nullable private volatile String hostname; - /** Time at which the cache should expire. */ - private volatile long expirationTimestamp; + /** When the cached hostname goes stale. */ + private volatile @NotNull Deadline cacheFreshUntil; /** Whether a cache update thread is currently running or not. */ private final @NotNull AtomicBoolean updateRunning = new AtomicBoolean(false); @@ -74,22 +79,34 @@ private HostnameCache() { this(HOSTNAME_CACHE_DURATION); } - HostnameCache(long cacheDuration) { + HostnameCache(long cacheDurationMillis) { // avoid method refs on Android due to some issues with older AGP setups // noinspection Convert2MethodRef - this(cacheDuration, () -> InetAddress.getLocalHost()); + this(cacheDurationMillis, () -> InetAddress.getLocalHost()); + } + + HostnameCache(long cacheDurationMillis, final @NotNull Callable getLocalhost) { + this(cacheDurationMillis, getLocalhost, JavaMonotonicTicker.getInstance()); } /** * Sets up a cache for the hostname. * - * @param cacheDuration cache duration in milliseconds. + * @param cacheDurationMillis cache duration in milliseconds. * @param getLocalhost a callback to obtain the localhost address - this is mostly here because of * testability + * @param ticker the ticker the cache lifetime is measured on */ - HostnameCache(long cacheDuration, final @NotNull Callable getLocalhost) { - this.cacheDuration = cacheDuration; + HostnameCache( + long cacheDurationMillis, + final @NotNull Callable getLocalhost, + final @NotNull MonotonicTicker ticker) { + this.cacheDurationMillis = cacheDurationMillis; this.getLocalhost = Objects.requireNonNull(getLocalhost, "getLocalhost is required"); + this.ticker = Objects.requireNonNull(ticker, "ticker is required"); + // Nothing resolved yet, so the cache is stale rather than fresh until updateCache says + // otherwise. + this.cacheFreshUntil = Deadline.passed(ticker); // A single thread executor whose worker thread times out while idle, so no thread is kept // alive between the infrequent cache refreshes. final @NotNull ThreadPoolExecutor executor = @@ -122,8 +139,7 @@ boolean isClosed() { */ @Nullable public String getHostname() { - if (expirationTimestamp < System.currentTimeMillis() - && updateRunning.compareAndSet(false, true)) { + if (cacheFreshUntil.hasPassed() && updateRunning.compareAndSet(false, true)) { updateCache(); } @@ -136,7 +152,7 @@ private void updateCache() { () -> { try { hostname = getLocalhost.call().getCanonicalHostName(); - expirationTimestamp = System.currentTimeMillis() + cacheDuration; + cacheFreshUntil = Deadline.after(ticker, cacheDurationMillis, TimeUnit.MILLISECONDS); } finally { updateRunning.set(false); } @@ -156,7 +172,7 @@ private void updateCache() { } private void handleCacheUpdateFailure() { - expirationTimestamp = System.currentTimeMillis() + TimeUnit.SECONDS.toMillis(1); + cacheFreshUntil = Deadline.after(ticker, 1, TimeUnit.SECONDS); } private static final class HostnameCacheThreadFactory implements ThreadFactory { diff --git a/sentry/src/test/java/io/sentry/DefaultCompositePerformanceCollectorTest.kt b/sentry/src/test/java/io/sentry/DefaultCompositePerformanceCollectorTest.kt index d259100853..46f9ca51a0 100644 --- a/sentry/src/test/java/io/sentry/DefaultCompositePerformanceCollectorTest.kt +++ b/sentry/src/test/java/io/sentry/DefaultCompositePerformanceCollectorTest.kt @@ -3,6 +3,7 @@ package io.sentry import io.sentry.test.getCtor import io.sentry.test.getProperty import io.sentry.test.injectForField +import io.sentry.time.TestMonotonicTicker import io.sentry.util.thread.ThreadChecker import java.util.Timer import java.util.concurrent.TimeUnit @@ -34,6 +35,7 @@ class DefaultCompositePerformanceCollectorTest { val id1 = "id1" val scopes: IScopes = mock() val options = SentryOptions() + val ticker = TestMonotonicTicker() var mockTimer: Timer? = null val mockCpuCollector: IPerformanceSnapshotCollector = @@ -65,7 +67,7 @@ class DefaultCompositePerformanceCollectorTest { optionsConfiguration.configure(options) transaction1 = SentryTracer(TransactionContext("", ""), scopes) transaction2 = SentryTracer(TransactionContext("", ""), scopes) - val collector = DefaultCompositePerformanceCollector(options) + val collector = DefaultCompositePerformanceCollector(options, ticker) val timer: Timer = collector.getProperty("timer") ?: Timer(true) mockTimer = spy(timer) collector.injectForField("timer", mockTimer) @@ -183,26 +185,19 @@ class DefaultCompositePerformanceCollectorTest { @Test fun `collector times out after 30 seconds`() { - val mockDateProvider = mock() val mockCollector = mock() - val dates = - listOf( - SentryNanotimeDate(TimeUnit.SECONDS.toMillis(100), TimeUnit.SECONDS.toNanos(100)), - SentryNanotimeDate(TimeUnit.SECONDS.toMillis(131), TimeUnit.SECONDS.toNanos(131)), - ) - whenever(mockDateProvider.now()).thenReturn(dates[0], dates[0], dates[0], dates[1]) - val collector = fixture.getSut { - it.dateProvider = mockDateProvider - it.addPerformanceCollector(mockCollector) - } + val collector = fixture.getSut { it.addPerformanceCollector(mockCollector) } collector.start(fixture.transaction1) verify(fixture.mockTimer, never())!!.cancel() + // 31 seconds of collecting have gone by + fixture.ticker.advance(31, TimeUnit.SECONDS) + // Let's sleep to make the collector get values Thread.sleep(300) - // When the collector gets the values, it checks the current date, set 31 seconds after the - // begin. This means it should stop itself + // When the collector gets the values, it checks how long it has been collecting for, which is + // now past the 30 second budget. This means it should stop itself verify(fixture.mockTimer)!!.cancel() // When the collector times out, the data collection for spans is stopped, too @@ -214,23 +209,18 @@ class DefaultCompositePerformanceCollectorTest { } @Test - fun `collector collects for 30 seconds`() { - val mockDateProvider = mock() - val dates = - listOf( - SentryNanotimeDate(TimeUnit.SECONDS.toMillis(100), TimeUnit.SECONDS.toNanos(100)), - SentryNanotimeDate(TimeUnit.SECONDS.toMillis(130), TimeUnit.SECONDS.toNanos(130)), - ) - whenever(mockDateProvider.now()).thenReturn(dates[0], dates[0], dates[0], dates[1]) - val collector = fixture.getSut { it.dateProvider = mockDateProvider } + fun `collector keeps collecting while inside the 30 second budget`() { + val collector = fixture.getSut() collector.start(fixture.transaction1) verify(fixture.mockTimer, never())!!.cancel() + // 29 seconds of collecting have gone by + fixture.ticker.advance(29, TimeUnit.SECONDS) + // Let's sleep to make the collector get values Thread.sleep(300) - // When the collector gets the values, it checks the current date, set 30 seconds after the - // begin. This means it should continue without being cancelled + // Still inside the 30 second budget, so it should continue without being cancelled verify(fixture.mockTimer, never())!!.cancel() // Data is deleted after the collector times out diff --git a/sentry/src/test/java/io/sentry/HostnameCacheTest.kt b/sentry/src/test/java/io/sentry/HostnameCacheTest.kt index 3cc3a52aa2..9d38b592e6 100644 --- a/sentry/src/test/java/io/sentry/HostnameCacheTest.kt +++ b/sentry/src/test/java/io/sentry/HostnameCacheTest.kt @@ -2,6 +2,7 @@ package io.sentry import com.google.common.truth.Truth.assertThat import io.sentry.test.getProperty +import io.sentry.time.TestMonotonicTicker import java.net.InetAddress import java.util.concurrent.ThreadPoolExecutor import java.util.concurrent.TimeUnit @@ -23,6 +24,22 @@ class HostnameCacheTest { assertThat(cache.hostname).isEqualTo("myhost") } + @Test + fun `hostname is re-resolved only once the cache duration has elapsed`() { + val ticker = TestMonotonicTicker() + val address = mock() + whenever(address.canonicalHostName).thenReturn("first", "second") + val cache = HostnameCache(TimeUnit.HOURS.toMillis(5), { address }, ticker) + + assertThat(cache.hostname).isEqualTo("first") + + ticker.advance(4, TimeUnit.HOURS) + assertThat(cache.hostname).isEqualTo("first") + + ticker.advance(1, TimeUnit.HOURS) + assertThat(cache.hostname).isEqualTo("second") + } + @Test fun `worker thread times out while idle instead of staying alive`() { val cache = getSut()