Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
53 changes: 32 additions & 21 deletions platform/jvm/capture/src/main/kotlin/io/bitdrift/capture/Capture.kt
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@ package io.bitdrift.capture
import android.content.Context
import android.util.Log
import com.github.michaelbull.result.Err
import io.bitdrift.capture.common.IBackgroundThreadHandler
import io.bitdrift.capture.common.MainThreadHandler
import io.bitdrift.capture.events.span.Span
import io.bitdrift.capture.events.span.SpanResult
Expand All @@ -22,6 +23,7 @@ import io.bitdrift.capture.providers.SystemDateProvider
import io.bitdrift.capture.providers.session.SessionStrategy
import io.bitdrift.capture.reports.FatalIssueMechanism
import io.bitdrift.capture.reports.FatalIssueReporter
import io.bitdrift.capture.threading.CaptureDispatchers
import okhttp3.HttpUrl
import java.util.UUID
import java.util.concurrent.atomic.AtomicReference
Expand All @@ -35,14 +37,17 @@ internal sealed class LoggerState {

/**
* The logger is in the process of being started. Subsequent attempts to start the logger will be ignored.
* Any calls to Logger.log() meanwhile Logger.start() is in process will be cached in memory
*/
data object Starting : LoggerState()
class Starting(
val preInitInMemoryLogger: PreInitInMemoryLogger,
) : LoggerState()

/**
* The logger has been successfully started and is ready for use. Subsequent attempts to start the logger will be ignored.
*/
class Started(
val logger: LoggerImpl,
val loggerImpl: LoggerImpl,
) : LoggerState()

/**
Expand All @@ -58,6 +63,7 @@ object Capture {
internal const val LOG_TAG = "BitdriftCapture"
private val default: AtomicReference<LoggerState> = AtomicReference(LoggerState.NotStarted)
private val fatalIssueReporter = FatalIssueReporter()
private val preInitInMemoryLogger by lazy { PreInitInMemoryLogger() }

/**
* Returns a handle to the underlying logger instance, if Capture has been started.
Expand All @@ -67,8 +73,8 @@ object Capture {
fun logger(): ILogger? =
when (val state = default.get()) {
is LoggerState.NotStarted -> null
is LoggerState.Starting -> null
is LoggerState.Started -> state.logger
is LoggerState.Starting -> state.preInitInMemoryLogger
is LoggerState.Started -> state.loggerImpl
is LoggerState.StartFailure -> null
}

Expand Down Expand Up @@ -169,6 +175,7 @@ object Capture {
dateProvider: DateProvider? = null,
apiUrl: HttpUrl = defaultCaptureApiUrl,
bridge: IBridge,
backgroundThreadHandler: IBackgroundThreadHandler = CaptureDispatchers.CommonBackground,
) {
// Note that we need to use @Synchronized to prevent multiple loggers from being initialized,
// while subsequent logger access relies on volatile reads.
Expand All @@ -184,23 +191,27 @@ object Capture {
}

// Ideally we would use `getAndUpdate` in here but it's available for API 24 and up only.
if (default.compareAndSet(LoggerState.NotStarted, LoggerState.Starting)) {
try {
val logger =
LoggerImpl(
apiKey = apiKey,
apiUrl = apiUrl,
fieldProviders = fieldProviders,
dateProvider = dateProvider ?: SystemDateProvider(),
configuration = configuration,
sessionStrategy = sessionStrategy,
bridge = bridge,
fatalIssueReporter = fatalIssueReporter,
)
default.set(LoggerState.Started(logger))
} catch (e: Throwable) {
Log.w(LOG_TAG, "Failed to start Capture", e)
default.set(LoggerState.StartFailure)
if (default.compareAndSet(LoggerState.NotStarted, LoggerState.Starting(preInitInMemoryLogger))) {
backgroundThreadHandler.runAsync {
try {
val loggerImpl =
LoggerImpl(
apiKey = apiKey,
apiUrl = apiUrl,
fieldProviders = fieldProviders,
dateProvider = dateProvider ?: SystemDateProvider(),
configuration = configuration,
sessionStrategy = sessionStrategy,
bridge = bridge,
fatalIssueReporter = fatalIssueReporter,
preInitLogFlusher = preInitInMemoryLogger,
)
default.set(LoggerState.Started(loggerImpl))
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

From a concurrency perspective it seems like there might be a chance that logs are written to the in memory queue after it gets cleared but before we update the LoggerState, which seems like it could result in dropped logs?

I don't have a good solution for how to avoid this without making it significantly more complicated so maybe it's fine?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

yeah, probably ok i think the init time should be in order of ms (hundred of ms at most). One think to keep in mind is that the backing CommonBackground Thread io.bitdrift.capture.background-thread-worker is a single threaded one and everything within the backgroundThreadHandler.runAsync should be sequential

} catch (e: Throwable) {
Log.w(LOG_TAG, "Failed to start Capture", e)
preInitInMemoryLogger.clear()
default.set(LoggerState.StartFailure)
}
}
} else {
Log.w(LOG_TAG, "Multiple attempts to start Capture")
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,15 @@
// capture-sdk - bitdrift's client SDK
// Copyright Bitdrift, Inc. All rights reserved.
//
// Use of this source code is governed by a source available license that can be found in the
// LICENSE file or at:
// https://polyformproject.org/wp-content/uploads/2020/06/PolyForm-Shield-1.0.0.txt
package io.bitdrift.capture

/**
* Flushes the internal memory logging into the loggerImpl
*/
fun interface IPreInitLogFlusher {
/** Flush all in memory Logger calls into the Native `LoggerImpl` **/
fun flushToNative(loggerImpl: ILogger)
}
Original file line number Diff line number Diff line change
Expand Up @@ -85,6 +85,7 @@ internal class LoggerImpl(
private val eventListenerDispatcher: CaptureDispatchers.CommonBackground = CaptureDispatchers.CommonBackground,
windowManager: IWindowManager = WindowManager(errorHandler),
private val fatalIssueReporter: IFatalIssueReporter,
private val preInitLogFlusher: IPreInitLogFlusher,
) : ILogger {
private val metadataProvider: MetadataProvider
private val batteryMonitor = BatteryMonitor(context)
Expand Down Expand Up @@ -261,6 +262,8 @@ internal class LoggerImpl(
appExitLogger.installAppExitLogger()

CaptureJniLibrary.startLogger(this.loggerId)

preInitLogFlusher.flushToNative(this)
}

writeSdkStartLog(context, clientAttributes, initDuration = duration)
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,120 @@
// capture-sdk - bitdrift's client SDK
// Copyright Bitdrift, Inc. All rights reserved.
//
// Use of this source code is governed by a source available license that can be found in the
// LICENSE file or at:
// https://polyformproject.org/wp-content/uploads/2020/06/PolyForm-Shield-1.0.0.txt
package io.bitdrift.capture

import androidx.annotation.OpenForTesting
import io.bitdrift.capture.events.span.Span
import io.bitdrift.capture.network.HttpRequestInfo
import io.bitdrift.capture.network.HttpResponseInfo
import java.util.UUID
import java.util.concurrent.ConcurrentLinkedQueue
import kotlin.time.Duration

/**
*
* Given that Logger.start() runs on dedicated thread, will be caching any calls to Logger.log while
* start is in process of being initialized.
*
* When Logger.start() is completed will flush the in memory calls to the native layer
*/
internal class PreInitInMemoryLogger :
ILogger,
IPreInitLogFlusher {
private val _bufferedLoggerCalls = ConcurrentLinkedQueue<(ILogger) -> Unit>()

@get:OpenForTesting
val bufferedLoggerCalls: List<(ILogger) -> Unit>
get() = _bufferedLoggerCalls.toList()

override val sessionId: String = DEFAULT_NOT_SETUP_MESSAGE

override val sessionUrl: String = DEFAULT_NOT_SETUP_MESSAGE

override val deviceId: String = DEFAULT_NOT_SETUP_MESSAGE

/** Flush all in memory Logger calls into the Native `LoggerImpl` **/
override fun flushToNative(loggerImpl: ILogger) {
_bufferedLoggerCalls.forEach { it(loggerImpl) }
_bufferedLoggerCalls.clear()
}

override fun startNewSession() {
addLoggerCall { it.startNewSession() }
}

override fun createTemporaryDeviceCode(completion: (CaptureResult<String>) -> Unit) {
addLoggerCall { it.createTemporaryDeviceCode(completion) }
}

override fun addField(
key: String,
value: String,
) {
addLoggerCall { it.addField(key, value) }
}

override fun removeField(key: String) {
addLoggerCall { it.removeField(key) }
}

override fun log(
level: LogLevel,
fields: Map<String, String>?,
throwable: Throwable?,
message: () -> String,
) {
addLoggerCall { it.log(level, fields, throwable, message) }
}
Comment on lines +64 to +71
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

One potential issue with this is that the timestamp of the logs will be at the time that they were replayed, not the actual time they were logged? Maybe fine for now but something to keep in mind

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

yes i agree, it's not perfect as they will be called sequentially but not at the original timestamp. I will create follow up task

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

something that we could do is to evaluate the DateProvider eagerly when we receive a log and store the timestamp along with the log function call in the ConcurrentLinkedQueue, but of course this would need our rust logger to have a way to override timestamps

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

yup i thought something like that before but will need to tweak the rust layer


override fun logAppLaunchTTI(duration: Duration) {
addLoggerCall { it.logAppLaunchTTI(duration) }
}

override fun logScreenView(screenName: String) {
addLoggerCall { it.logScreenView(screenName) }
}

override fun startSpan(
name: String,
level: LogLevel,
fields: Map<String, String>?,
startTimeMs: Long?,
parentSpanId: UUID?,
): Span {
val span = Span(null, name, level, fields, startTimeMs, parentSpanId)
addLoggerCall {
span.setLoggerImpl(it as LoggerImpl)
it.startSpan(name, level, fields, startTimeMs, parentSpanId)
}
return span
}

override fun log(httpRequestInfo: HttpRequestInfo) {
addLoggerCall { it.log(httpRequestInfo) }
}

override fun log(httpResponseInfo: HttpResponseInfo) {
addLoggerCall { it.log(httpResponseInfo) }
}

/** Clear stored Logger calls **/
fun clear() {
_bufferedLoggerCalls.clear()
}

private fun addLoggerCall(logCall: (ILogger) -> Unit) {
if (_bufferedLoggerCalls.size >= MAX_LOG_CALL_SIZE) {
_bufferedLoggerCalls.poll()
}
_bufferedLoggerCalls.add(logCall)
}

private companion object {
private const val DEFAULT_NOT_SETUP_MESSAGE = "SDK starting"
private const val MAX_LOG_CALL_SIZE = 512 // Matching the pre-config buffer definition
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -130,4 +130,11 @@ class Span internal constructor(
}
logger = null
}

/**
* This is only needed during [io.bitdrift.capture.PreInitInMemoryLogger]
*/
internal fun setLoggerImpl(loggerImpl: LoggerImpl) {
this.logger = loggerImpl
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,7 @@ import com.nhaarman.mockitokotlin2.any
import com.nhaarman.mockitokotlin2.anyOrNull
import com.nhaarman.mockitokotlin2.mock
import com.nhaarman.mockitokotlin2.whenever
import io.bitdrift.capture.fakes.FakePreInitLogFlusher
import io.bitdrift.capture.providers.DateProvider
import io.bitdrift.capture.providers.session.SessionStrategy
import io.bitdrift.capture.reports.FatalIssueReporter
Expand Down Expand Up @@ -51,6 +52,7 @@ class CaptureLoggerSessionOverrideTest {
private lateinit var logger: LoggerImpl
private var testServerPort: Int? = null
private val fatalIssueReporter = FatalIssueReporter()
private val preInitLogFlusher = FakePreInitLogFlusher()

@Before
fun setUp() {
Expand Down Expand Up @@ -88,6 +90,7 @@ class CaptureLoggerSessionOverrideTest {
configuration = Configuration(),
preferences = preferences,
fatalIssueReporter = fatalIssueReporter,
preInitLogFlusher = preInitLogFlusher,
)

CaptureTestJniLibrary.stopTestApiServer()
Expand Down Expand Up @@ -121,8 +124,8 @@ class CaptureLoggerSessionOverrideTest {
preferences = preferences,
activityManager = activityManager,
fatalIssueReporter = fatalIssueReporter,
preInitLogFlusher = preInitLogFlusher,
)

val newStreamId = CaptureTestJniLibrary.awaitNextApiStream()
assertThat(newStreamId).isNotEqualTo(-1)

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,7 @@ import io.bitdrift.capture.attributes.DeviceAttributes
import io.bitdrift.capture.attributes.NetworkAttributes
import io.bitdrift.capture.common.RuntimeFeature
import io.bitdrift.capture.fakes.FakeFatalIssueReporter
import io.bitdrift.capture.fakes.FakePreInitLogFlusher
import io.bitdrift.capture.network.HttpRequestInfo
import io.bitdrift.capture.network.HttpResponse
import io.bitdrift.capture.network.HttpResponseInfo
Expand Down Expand Up @@ -63,6 +64,7 @@ class CaptureLoggerTest {
private lateinit var logger: LoggerImpl
private var testServerPort: Int? = null
private val fatalIssueReporter: IFatalIssueReporter = FakeFatalIssueReporter()
private val preInitLogFlusher = FakePreInitLogFlusher()

@Before
fun setUp() {
Expand All @@ -74,6 +76,7 @@ class CaptureLoggerTest {

testServerPort = CaptureTestJniLibrary.startTestApiServer(-1)

preInitLogFlusher.reset()
logger = buildLogger(dateProvider = systemDateProvider)
}

Expand Down Expand Up @@ -441,6 +444,7 @@ class CaptureLoggerTest {
)

assertThat(JniRuntime(logger.loggerId).isEnabled(RuntimeFeature.SESSION_REPLAY_COMPOSE)).isFalse
assertThat(preInitLogFlusher.wasFlushed).isTrue()
}

private fun testServerUrl(): HttpUrl =
Expand Down Expand Up @@ -469,6 +473,7 @@ class CaptureLoggerTest {
dateProvider = dateProvider,
configuration = Configuration(),
fatalIssueReporter = fatalIssueReporter,
preInitLogFlusher = preInitLogFlusher,
)
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,7 @@ import com.nhaarman.mockitokotlin2.mock
import com.nhaarman.mockitokotlin2.times
import com.nhaarman.mockitokotlin2.verify
import com.nhaarman.mockitokotlin2.whenever
import io.bitdrift.capture.fakes.FakeBackgroundThreadHandler
import io.bitdrift.capture.providers.session.SessionStrategy
import org.assertj.core.api.Assertions
import org.junit.After
Expand All @@ -24,6 +25,8 @@ import org.robolectric.annotation.Config
@RunWith(RobolectricTestRunner::class)
@Config(sdk = [21])
class ConfigurationTest {
private val fakeBackgroundThreadHandler = FakeBackgroundThreadHandler()

@Test
fun configurationFailure() {
val initializer = ContextHolder()
Expand Down Expand Up @@ -56,6 +59,7 @@ class ConfigurationTest {
sessionStrategy = SessionStrategy.Fixed(),
dateProvider = null,
bridge = bridge,
backgroundThreadHandler = fakeBackgroundThreadHandler,
)

// The configuration failed so the logger is still `null`.
Expand Down Expand Up @@ -85,6 +89,7 @@ class ConfigurationTest {
sessionStrategy = SessionStrategy.Fixed(),
dateProvider = null,
bridge = bridge,
backgroundThreadHandler = fakeBackgroundThreadHandler,
)

Assertions.assertThat(Capture.logger()).isNull()
Expand Down
Loading
Loading