Commit
This commit does not belong to any branch on this repository, and may belong to a fork outside of the repository.
Feature: Android profiling traces (#1897)
* Added a transaction profiler (noOp on java sdk) that starts/stops android profiling when a transaction starts or is finished * Added a new envelope item type "profile", generated using android trace file. Its payload is a json represented by ProfilingTraceData * SentryExecutorService now uses a ScheduledExecutorService to allow the schedule() method * Added "profilingTracesDirPath" and "profilingTracesIntervalMillis" to SentryAndroidOptions * Added "profilingEnabled", "maxTraceFileSize" and "transactionProfiler" to SentryOptions * Added io.sentry.traces.profiling.enable to manifest options * Profiling is disabled by default * Profiling traces directory's content is deleted in the background when the options are initialized
- Loading branch information
1 parent
af80ce7
commit 4f4a194
Showing
41 changed files
with
1,238 additions
and
135 deletions.
There are no files selected for viewing
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -2,6 +2,8 @@ | |
|
|
||
| ## Unreleased | ||
|
|
||
| * Feat: Add Android profiling traces #1897 | ||
|
|
||
| ## 5.6.2 | ||
|
|
||
| ### Various fixes & improvements | ||
|
|
||
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
256 changes: 256 additions & 0 deletions
256
sentry-android-core/src/main/java/io/sentry/android/core/AndroidTransactionProfiler.java
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,256 @@ | ||
| package io.sentry.android.core; | ||
|
|
||
| import static android.content.Context.ACTIVITY_SERVICE; | ||
| import static java.util.concurrent.TimeUnit.MILLISECONDS; | ||
|
|
||
| import android.annotation.SuppressLint; | ||
| import android.app.ActivityManager; | ||
| import android.content.Context; | ||
| import android.content.pm.PackageInfo; | ||
| import android.os.Build; | ||
| import android.os.Debug; | ||
| import android.os.SystemClock; | ||
| import io.sentry.ITransaction; | ||
| import io.sentry.ITransactionProfiler; | ||
| import io.sentry.ProfilingTraceData; | ||
| import io.sentry.SentryLevel; | ||
| import io.sentry.android.core.internal.util.CpuInfoUtils; | ||
| import io.sentry.util.Objects; | ||
| import java.io.File; | ||
| import java.util.UUID; | ||
| import java.util.concurrent.Future; | ||
| import org.jetbrains.annotations.NotNull; | ||
| import org.jetbrains.annotations.Nullable; | ||
|
|
||
| final class AndroidTransactionProfiler implements ITransactionProfiler { | ||
|
|
||
| /** | ||
| * This appears to correspond to the buffer size of the data part of the file, excluding the key | ||
| * part. Once the buffer is full, new records are ignored, but the resulting trace file will be | ||
| * valid. | ||
| * | ||
| * <p>30 second traces can require a buffer of a few MB. 8MB is the default buffer size for | ||
| * [Debug.startMethodTracingSampling], but 3 should be enough for most cases. We can adjust this | ||
| * in the future if we notice that traces are being truncated in some applications. | ||
| */ | ||
| private static final int BUFFER_SIZE_BYTES = 3_000_000; | ||
|
|
||
| private static final int PROFILING_TIMEOUT_MILLIS = 30_000; | ||
|
|
||
| private int intervalUs; | ||
| private @Nullable File traceFile = null; | ||
| private @Nullable File traceFilesDir = null; | ||
| private @Nullable Future<?> scheduledFinish = null; | ||
| private volatile @Nullable ITransaction activeTransaction = null; | ||
| private volatile @Nullable ProfilingTraceData timedOutProfilingData = null; | ||
| private final @NotNull Context context; | ||
| private final @NotNull SentryAndroidOptions options; | ||
| private final @NotNull IBuildInfoProvider buildInfoProvider; | ||
| private final @Nullable PackageInfo packageInfo; | ||
| private long transactionStartNanos = 0; | ||
|
|
||
| public AndroidTransactionProfiler( | ||
| final @NotNull Context context, | ||
| final @NotNull SentryAndroidOptions sentryAndroidOptions, | ||
| final @NotNull IBuildInfoProvider buildInfoProvider) { | ||
| this.context = Objects.requireNonNull(context, "The application context is required"); | ||
| this.options = Objects.requireNonNull(sentryAndroidOptions, "SentryAndroidOptions is required"); | ||
| this.buildInfoProvider = | ||
| Objects.requireNonNull(buildInfoProvider, "The BuildInfoProvider is required."); | ||
| this.packageInfo = ContextUtils.getPackageInfo(context, options.getLogger()); | ||
| final String tracesFilesDirPath = options.getProfilingTracesDirPath(); | ||
| if (tracesFilesDirPath == null || tracesFilesDirPath.isEmpty()) { | ||
| options | ||
| .getLogger() | ||
| .log( | ||
| SentryLevel.WARNING, | ||
| "Disabling profiling because no profiling traces dir path is defined in options."); | ||
| return; | ||
| } | ||
| long intervalMillis = options.getProfilingTracesIntervalMillis(); | ||
| if (intervalMillis <= 0) { | ||
| options | ||
| .getLogger() | ||
| .log( | ||
| SentryLevel.WARNING, | ||
| "Disabling profiling because trace interval is set to %d milliseconds", | ||
| intervalMillis); | ||
| return; | ||
| } | ||
| intervalUs = (int) MILLISECONDS.toMicros(intervalMillis); | ||
| traceFilesDir = new File(tracesFilesDirPath); | ||
| } | ||
|
|
||
| @SuppressLint("NewApi") | ||
| @Override | ||
| public synchronized void onTransactionStart(@NotNull ITransaction transaction) { | ||
|
|
||
| // Debug.startMethodTracingSampling() is only available since Lollipop | ||
| if (buildInfoProvider.getSdkInfoVersion() < Build.VERSION_CODES.LOLLIPOP) return; | ||
|
|
||
| // traceFilesDir is null or intervalUs is 0 only if there was a problem in the constructor, but | ||
| // we already logged that | ||
| if (traceFilesDir == null || intervalUs == 0) { | ||
| return; | ||
| } | ||
|
|
||
| // If a transaction is currently being profiled, we ignore this call | ||
| if (activeTransaction != null) { | ||
| options | ||
| .getLogger() | ||
| .log( | ||
| SentryLevel.WARNING, | ||
| "Profiling is already active and was started by transaction %s", | ||
| activeTransaction.getSpanContext().getTraceId().toString()); | ||
| return; | ||
| } | ||
|
|
||
| traceFile = new File(traceFilesDir, UUID.randomUUID() + ".trace"); | ||
|
|
||
| if (traceFile.exists()) { | ||
| options | ||
| .getLogger() | ||
| .log(SentryLevel.DEBUG, "Trace file already exists: %s", traceFile.getPath()); | ||
| return; | ||
| } | ||
| activeTransaction = transaction; | ||
|
|
||
| // We stop the trace after 30 seconds, since such a long trace is very probably a trace | ||
| // that will never end due to an error | ||
| scheduledFinish = | ||
| options | ||
| .getExecutorService() | ||
| .schedule( | ||
| () -> timedOutProfilingData = onTransactionFinish(transaction), | ||
| PROFILING_TIMEOUT_MILLIS); | ||
|
|
||
| transactionStartNanos = SystemClock.elapsedRealtimeNanos(); | ||
| Debug.startMethodTracingSampling(traceFile.getPath(), BUFFER_SIZE_BYTES, intervalUs); | ||
| } | ||
|
|
||
| @SuppressLint("NewApi") | ||
| @Override | ||
| public synchronized @Nullable ProfilingTraceData onTransactionFinish( | ||
| @NotNull ITransaction transaction) { | ||
|
|
||
| // onTransactionStart() is only available since Lollipop | ||
| // and SystemClock.elapsedRealtimeNanos() since Jelly Bean | ||
| if (buildInfoProvider.getSdkInfoVersion() < Build.VERSION_CODES.LOLLIPOP) return null; | ||
|
|
||
| final ITransaction finalActiveTransaction = activeTransaction; | ||
| final ProfilingTraceData profilingData = timedOutProfilingData; | ||
|
|
||
| // Profiling finished, but we check if we cached last profiling data due to a timeout | ||
| if (finalActiveTransaction == null) { | ||
| // If the cached timed out profiling data refers to the transaction that started it we return | ||
| // it back, otherwise we would simply lose it | ||
| if (profilingData != null) { | ||
| // The timed out transaction is finishing | ||
| if (profilingData | ||
| .getTraceId() | ||
| .equals(transaction.getSpanContext().getTraceId().toString())) { | ||
| timedOutProfilingData = null; | ||
| return profilingData; | ||
| } else { | ||
| // Another transaction is finishing before the timed out one | ||
| options | ||
| .getLogger() | ||
| .log( | ||
| SentryLevel.ERROR, | ||
| "Profiling data with id %s exists but doesn't match the closing transaction %s", | ||
| profilingData.getTraceId(), | ||
| transaction.getSpanContext().getTraceId().toString()); | ||
| return null; | ||
| } | ||
| } | ||
| // A transaction is finishing, but profiling didn't start. Maybe it was started by another one | ||
| options | ||
| .getLogger() | ||
| .log( | ||
| SentryLevel.INFO, | ||
| "Transaction %s finished, but profiling never started for it. Skipping", | ||
| transaction.getSpanContext().getTraceId().toString()); | ||
| return null; | ||
| } | ||
|
|
||
| if (finalActiveTransaction != transaction) { | ||
| options | ||
| .getLogger() | ||
| .log( | ||
| SentryLevel.DEBUG, | ||
| "Transaction %s finished, but profiling was started by transaction %s. Skipping", | ||
| transaction.getSpanContext().getTraceId().toString(), | ||
| finalActiveTransaction.getSpanContext().getTraceId().toString()); | ||
| return null; | ||
| } | ||
|
|
||
| Debug.stopMethodTracing(); | ||
| long transactionDurationNanos = SystemClock.elapsedRealtimeNanos() - transactionStartNanos; | ||
|
|
||
| activeTransaction = null; | ||
|
|
||
| if (scheduledFinish != null) { | ||
| scheduledFinish.cancel(true); | ||
| scheduledFinish = null; | ||
| } | ||
|
|
||
| if (traceFile == null || !traceFile.exists()) { | ||
| options | ||
| .getLogger() | ||
| .log( | ||
| SentryLevel.ERROR, | ||
| "Trace file %s does not exists", | ||
| traceFile == null ? "null" : traceFile.getPath()); | ||
| return null; | ||
| } | ||
|
|
||
| String versionName = ""; | ||
| String versionCode = ""; | ||
| String totalMem = "0"; | ||
| ActivityManager.MemoryInfo memInfo = getMemInfo(); | ||
| if (packageInfo != null) { | ||
| versionName = ContextUtils.getVersionName(packageInfo); | ||
| versionCode = ContextUtils.getVersionCode(packageInfo); | ||
| } | ||
| if (memInfo != null) { | ||
| totalMem = Long.toString(memInfo.totalMem); | ||
| } | ||
|
|
||
| return new ProfilingTraceData( | ||
| traceFile, | ||
| transaction, | ||
| Long.toString(transactionDurationNanos), | ||
| buildInfoProvider.getSdkInfoVersion(), | ||
| buildInfoProvider.getManufacturer(), | ||
| buildInfoProvider.getModel(), | ||
| buildInfoProvider.getVersionRelease(), | ||
| buildInfoProvider.isEmulator(), | ||
| CpuInfoUtils.readMaxFrequencies(), | ||
| totalMem, | ||
| options.getProguardUuid(), | ||
| versionName, | ||
| versionCode, | ||
| options.getEnvironment()); | ||
| } | ||
|
|
||
| /** | ||
| * Get MemoryInfo object representing the memory state of the application. | ||
| * | ||
| * @return MemoryInfo object representing the memory state of the application | ||
| */ | ||
| private @Nullable ActivityManager.MemoryInfo getMemInfo() { | ||
| try { | ||
| ActivityManager actManager = (ActivityManager) context.getSystemService(ACTIVITY_SERVICE); | ||
| ActivityManager.MemoryInfo memInfo = new ActivityManager.MemoryInfo(); | ||
| if (actManager != null) { | ||
| actManager.getMemoryInfo(memInfo); | ||
| return memInfo; | ||
| } | ||
| options.getLogger().log(SentryLevel.INFO, "Error getting MemoryInfo."); | ||
| return null; | ||
| } catch (Throwable e) { | ||
| options.getLogger().log(SentryLevel.ERROR, "Error getting MemoryInfo.", e); | ||
| return null; | ||
| } | ||
| } | ||
| } |
Oops, something went wrong.