-
-
Notifications
You must be signed in to change notification settings - Fork 458
[ANR] Reduced AndroidTransactionProfiler lock #4817
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
base: main
Are you sure you want to change the base?
Changes from all commits
cb58df3
5ea152d
9bf4a81
f7d8315
8ad8925
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -354,4 +354,8 @@ private void putPerformanceCollectionDataInMeasurements( | |
| } | ||
| } | ||
| } | ||
|
|
||
| boolean isRunning() { | ||
| return isRunning; | ||
| } | ||
| } | ||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -5,8 +5,6 @@ | |
| import android.annotation.SuppressLint; | ||
| import android.content.Context; | ||
| import android.os.Build; | ||
| import android.os.Process; | ||
| import android.os.SystemClock; | ||
| import io.sentry.DateUtils; | ||
| import io.sentry.ILogger; | ||
| import io.sentry.ISentryExecutorService; | ||
|
|
@@ -26,9 +24,9 @@ | |
| import java.util.ArrayList; | ||
| import java.util.Date; | ||
| import java.util.List; | ||
| import java.util.concurrent.atomic.AtomicBoolean; | ||
| import org.jetbrains.annotations.NotNull; | ||
| import org.jetbrains.annotations.Nullable; | ||
| import org.jetbrains.annotations.TestOnly; | ||
|
|
||
| final class AndroidTransactionProfiler implements ITransactionProfiler { | ||
| private final @NotNull Context context; | ||
|
|
@@ -39,10 +37,16 @@ final class AndroidTransactionProfiler implements ITransactionProfiler { | |
| private final @NotNull ISentryExecutorService executorService; | ||
| private final @NotNull BuildInfoProvider buildInfoProvider; | ||
| private boolean isInitialized = false; | ||
| private int transactionsCounter = 0; | ||
| private final @NotNull AtomicBoolean isRunning = new AtomicBoolean(false); | ||
| private final @NotNull SentryFrameMetricsCollector frameMetricsCollector; | ||
| private @Nullable ProfilingTransactionData currentProfilingTransactionData; | ||
|
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. should this be volatile? There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. we access it only inside the lock, except in |
||
| private @Nullable AndroidProfiler profiler = null; | ||
|
|
||
| /** | ||
| * The underlying profiler instance. It is thread safe to call it after checking if it's not null, | ||
| * because we never nullify it after instantiation. | ||
| */ | ||
| private volatile @Nullable AndroidProfiler profiler = null; | ||
stefanosiano marked this conversation as resolved.
Show resolved
Hide resolved
|
||
|
|
||
| private long profileStartNanos; | ||
| private long profileStartCpuMillis; | ||
| private @NotNull Date profileStartTimestamp; | ||
|
|
@@ -95,6 +99,7 @@ private void init() { | |
| return; | ||
| } | ||
| isInitialized = true; | ||
|
|
||
| if (!isProfilingEnabled) { | ||
| logger.log(SentryLevel.INFO, "Profiling is disabled in options."); | ||
| return; | ||
|
|
@@ -124,22 +129,30 @@ private void init() { | |
|
|
||
| @Override | ||
| public void start() { | ||
| try (final @NotNull ISentryLifecycleToken ignored = lock.acquire()) { | ||
| // Debug.startMethodTracingSampling() is only available since Lollipop, but Android Profiler | ||
| // causes crashes on api 21 -> https://github.com/getsentry/sentry-java/issues/3392 | ||
| if (buildInfoProvider.getSdkInfoVersion() < Build.VERSION_CODES.LOLLIPOP_MR1) return; | ||
| // Debug.startMethodTracingSampling() is only available since Lollipop, but Android Profiler | ||
| // causes crashes on api 21 -> https://github.com/getsentry/sentry-java/issues/3392 | ||
| if (buildInfoProvider.getSdkInfoVersion() < Build.VERSION_CODES.LOLLIPOP_MR1) return; | ||
|
|
||
| // When the first transaction is starting, we can start profiling | ||
| if (!isRunning.getAndSet(true)) { | ||
| // Let's initialize trace folder and profiling interval | ||
| init(); | ||
|
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I guess we still need to wrap profiler instantiation into a synchronized lock? And also where we're checking There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. profiler instantiation is guarded by |
||
|
|
||
| transactionsCounter++; | ||
| // When the first transaction is starting, we can start profiling | ||
| if (transactionsCounter == 1 && onFirstStart()) { | ||
| if (onFirstStart()) { | ||
| logger.log(SentryLevel.DEBUG, "Profiler started."); | ||
| } else { | ||
| transactionsCounter--; | ||
| logger.log( | ||
| SentryLevel.WARNING, "A profile is already running. This profile will be ignored."); | ||
| // If profiler is not null and is running, it means that a profile is already running | ||
| if (profiler != null && profiler.isRunning()) { | ||
| logger.log( | ||
| SentryLevel.WARNING, "A profile is already running. This profile will be ignored."); | ||
| } else { | ||
| try (final @NotNull ISentryLifecycleToken ignored = lock.acquire()) { | ||
| // Ensure we unbind any transaction data, just in case of concurrent starts | ||
| currentProfilingTransactionData = null; | ||
| } | ||
| // Otherwise we update the flag, because it means the profiler is not running | ||
| isRunning.set(false); | ||
| } | ||
stefanosiano marked this conversation as resolved.
Show resolved
Hide resolved
|
||
| } | ||
| } | ||
| } | ||
|
|
@@ -164,11 +177,14 @@ private boolean onFirstStart() { | |
|
|
||
| @Override | ||
| public void bindTransaction(final @NotNull ITransaction transaction) { | ||
| try (final @NotNull ISentryLifecycleToken ignored = lock.acquire()) { | ||
| // If the profiler is running, but no profilingTransactionData is set, we bind it here | ||
| if (transactionsCounter > 0 && currentProfilingTransactionData == null) { | ||
| currentProfilingTransactionData = | ||
| new ProfilingTransactionData(transaction, profileStartNanos, profileStartCpuMillis); | ||
| // If the profiler is running, but no profilingTransactionData is set, we bind it here | ||
| if (isRunning.get() && currentProfilingTransactionData == null) { | ||
| try (final @NotNull ISentryLifecycleToken ignored = lock.acquire()) { | ||
| // If the profiler is running, but no profilingTransactionData is set, we bind it here | ||
| if (isRunning.get() && currentProfilingTransactionData == null) { | ||
| currentProfilingTransactionData = | ||
| new ProfilingTransactionData(transaction, profileStartNanos, profileStartCpuMillis); | ||
| } | ||
stefanosiano marked this conversation as resolved.
Show resolved
Hide resolved
|
||
| } | ||
| } | ||
| } | ||
|
|
@@ -178,15 +194,13 @@ public void bindTransaction(final @NotNull ITransaction transaction) { | |
| final @NotNull ITransaction transaction, | ||
| final @Nullable List<PerformanceCollectionData> performanceCollectionData, | ||
| final @NotNull SentryOptions options) { | ||
| try (final @NotNull ISentryLifecycleToken ignored = lock.acquire()) { | ||
| return onTransactionFinish( | ||
| transaction.getName(), | ||
| transaction.getEventId().toString(), | ||
| transaction.getSpanContext().getTraceId().toString(), | ||
| false, | ||
| performanceCollectionData, | ||
| options); | ||
| } | ||
| return onTransactionFinish( | ||
| transaction.getName(), | ||
| transaction.getEventId().toString(), | ||
| transaction.getSpanContext().getTraceId().toString(), | ||
| false, | ||
| performanceCollectionData, | ||
| options); | ||
| } | ||
|
|
||
| @SuppressLint("NewApi") | ||
|
|
@@ -197,20 +211,23 @@ public void bindTransaction(final @NotNull ITransaction transaction) { | |
| final boolean isTimeout, | ||
| final @Nullable List<PerformanceCollectionData> performanceCollectionData, | ||
| final @NotNull SentryOptions options) { | ||
| try (final @NotNull ISentryLifecycleToken ignored = lock.acquire()) { | ||
| // check if profiler was created | ||
| if (profiler == null) { | ||
| return null; | ||
| } | ||
|
|
||
| // onTransactionStart() is only available since Lollipop_MR1 | ||
| // and SystemClock.elapsedRealtimeNanos() since Jelly Bean | ||
| // and SUPPORTED_ABIS since KITKAT | ||
| if (buildInfoProvider.getSdkInfoVersion() < Build.VERSION_CODES.LOLLIPOP_MR1) return null; | ||
| // onTransactionStart() is only available since Lollipop_MR1 | ||
| // and SystemClock.elapsedRealtimeNanos() since Jelly Bean | ||
| // and SUPPORTED_ABIS since KITKAT | ||
| if (buildInfoProvider.getSdkInfoVersion() < Build.VERSION_CODES.LOLLIPOP_MR1) return null; | ||
|
|
||
| // check if profiler was created | ||
| if (profiler == null) { | ||
| return null; | ||
| } | ||
|
|
||
| final ProfilingTransactionData txData; | ||
| try (final @NotNull ISentryLifecycleToken ignored = lock.acquire()) { | ||
| txData = currentProfilingTransactionData; | ||
|
|
||
| // Transaction finished, but it's not in the current profile | ||
| if (currentProfilingTransactionData == null | ||
| || !currentProfilingTransactionData.getId().equals(transactionId)) { | ||
| if (txData == null || !txData.getId().equals(transactionId)) { | ||
| // A transaction is finishing, but it's not profiled. We can skip it | ||
| logger.log( | ||
| SentryLevel.INFO, | ||
|
|
@@ -219,118 +236,90 @@ public void bindTransaction(final @NotNull ITransaction transaction) { | |
| traceId); | ||
| return null; | ||
| } | ||
| currentProfilingTransactionData = null; | ||
| } | ||
|
|
||
| if (transactionsCounter > 0) { | ||
| transactionsCounter--; | ||
| } | ||
| logger.log(SentryLevel.DEBUG, "Transaction %s (%s) finished.", transactionName, traceId); | ||
|
|
||
| logger.log(SentryLevel.DEBUG, "Transaction %s (%s) finished.", transactionName, traceId); | ||
| final AndroidProfiler.ProfileEndData endData = | ||
| profiler.endAndCollect(false, performanceCollectionData); | ||
|
|
||
| if (transactionsCounter != 0) { | ||
| // We notify the data referring to this transaction that it finished | ||
| if (currentProfilingTransactionData != null) { | ||
| currentProfilingTransactionData.notifyFinish( | ||
| SystemClock.elapsedRealtimeNanos(), | ||
| profileStartNanos, | ||
| Process.getElapsedCpuTime(), | ||
| profileStartCpuMillis); | ||
| } | ||
| return null; | ||
| } | ||
|
|
||
| final AndroidProfiler.ProfileEndData endData = | ||
| profiler.endAndCollect(false, performanceCollectionData); | ||
| // check if profiler end successfully | ||
| if (endData == null) { | ||
| return null; | ||
| } | ||
| isRunning.set(false); | ||
|
|
||
| long transactionDurationNanos = endData.endNanos - profileStartNanos; | ||
| // check if profiler end successfully | ||
| if (endData == null) { | ||
| return null; | ||
| } | ||
|
|
||
| List<ProfilingTransactionData> transactionList = new ArrayList<>(1); | ||
| final ProfilingTransactionData txData = currentProfilingTransactionData; | ||
| if (txData != null) { | ||
| transactionList.add(txData); | ||
| } | ||
| currentProfilingTransactionData = null; | ||
| // We clear the counter in case of a timeout | ||
| transactionsCounter = 0; | ||
|
|
||
| String totalMem = "0"; | ||
| final @Nullable Long memory = | ||
| (options instanceof SentryAndroidOptions) | ||
| ? DeviceInfoUtil.getInstance(context, (SentryAndroidOptions) options).getTotalMemory() | ||
| : null; | ||
| if (memory != null) { | ||
| totalMem = Long.toString(memory); | ||
| } | ||
| String[] abis = Build.SUPPORTED_ABIS; | ||
| long transactionDurationNanos = endData.endNanos - profileStartNanos; | ||
|
|
||
| // We notify all transactions data that all transactions finished. | ||
| // Some may not have been really finished, in case of a timeout | ||
| for (ProfilingTransactionData t : transactionList) { | ||
| t.notifyFinish( | ||
| endData.endNanos, profileStartNanos, endData.endCpuMillis, profileStartCpuMillis); | ||
| } | ||
| final @NotNull List<ProfilingTransactionData> transactionList = new ArrayList<>(1); | ||
| transactionList.add(txData); | ||
| txData.notifyFinish( | ||
| endData.endNanos, profileStartNanos, endData.endCpuMillis, profileStartCpuMillis); | ||
|
|
||
| // cpu max frequencies are read with a lambda because reading files is involved, so it will be | ||
| // done in the background when the trace file is read | ||
| return new ProfilingTraceData( | ||
| endData.traceFile, | ||
| profileStartTimestamp, | ||
| transactionList, | ||
| transactionName, | ||
| transactionId, | ||
| traceId, | ||
| Long.toString(transactionDurationNanos), | ||
| buildInfoProvider.getSdkInfoVersion(), | ||
| abis != null && abis.length > 0 ? abis[0] : "", | ||
| () -> CpuInfoUtils.getInstance().readMaxFrequencies(), | ||
| buildInfoProvider.getManufacturer(), | ||
| buildInfoProvider.getModel(), | ||
| buildInfoProvider.getVersionRelease(), | ||
| buildInfoProvider.isEmulator(), | ||
| totalMem, | ||
| options.getProguardUuid(), | ||
| options.getRelease(), | ||
| options.getEnvironment(), | ||
| (endData.didTimeout || isTimeout) | ||
| ? ProfilingTraceData.TRUNCATION_REASON_TIMEOUT | ||
| : ProfilingTraceData.TRUNCATION_REASON_NORMAL, | ||
| endData.measurementsMap); | ||
| String totalMem = "0"; | ||
| final @Nullable Long memory = | ||
| (options instanceof SentryAndroidOptions) | ||
| ? DeviceInfoUtil.getInstance(context, (SentryAndroidOptions) options).getTotalMemory() | ||
| : null; | ||
| if (memory != null) { | ||
| totalMem = Long.toString(memory); | ||
| } | ||
| final String[] abis = Build.SUPPORTED_ABIS; | ||
|
|
||
| // cpu max frequencies are read with a lambda because reading files is involved, so it will be | ||
| // done in the background when the trace file is read | ||
| return new ProfilingTraceData( | ||
| endData.traceFile, | ||
| profileStartTimestamp, | ||
| transactionList, | ||
| transactionName, | ||
| transactionId, | ||
| traceId, | ||
| Long.toString(transactionDurationNanos), | ||
| buildInfoProvider.getSdkInfoVersion(), | ||
| abis != null && abis.length > 0 ? abis[0] : "", | ||
| () -> CpuInfoUtils.getInstance().readMaxFrequencies(), | ||
| buildInfoProvider.getManufacturer(), | ||
| buildInfoProvider.getModel(), | ||
| buildInfoProvider.getVersionRelease(), | ||
| buildInfoProvider.isEmulator(), | ||
| totalMem, | ||
| options.getProguardUuid(), | ||
| options.getRelease(), | ||
| options.getEnvironment(), | ||
| (endData.didTimeout || isTimeout) | ||
| ? ProfilingTraceData.TRUNCATION_REASON_TIMEOUT | ||
| : ProfilingTraceData.TRUNCATION_REASON_NORMAL, | ||
| endData.measurementsMap); | ||
stefanosiano marked this conversation as resolved.
Show resolved
Hide resolved
|
||
| } | ||
|
|
||
| @Override | ||
| public boolean isRunning() { | ||
| return transactionsCounter != 0; | ||
| return isRunning.get(); | ||
| } | ||
|
|
||
| @Override | ||
| public void close() { | ||
| final @Nullable ProfilingTransactionData txData = currentProfilingTransactionData; | ||
| // we stop profiling | ||
| if (currentProfilingTransactionData != null) { | ||
| if (txData != null) { | ||
| onTransactionFinish( | ||
| currentProfilingTransactionData.getName(), | ||
| currentProfilingTransactionData.getId(), | ||
| currentProfilingTransactionData.getTraceId(), | ||
| txData.getName(), | ||
| txData.getId(), | ||
| txData.getTraceId(), | ||
| true, | ||
| null, | ||
| ScopesAdapter.getInstance().getOptions()); | ||
| } else if (transactionsCounter != 0) { | ||
| // in case the app start profiling is running, and it's not bound to a transaction, we still | ||
| // stop profiling, but we also have to manually update the counter. | ||
| transactionsCounter--; | ||
| } | ||
| // in case the app start profiling is running, and it's not bound to a transaction, we still | ||
| // stop profiling, but we also have to manually update the flag. | ||
| isRunning.set(false); | ||
|
|
||
| // we have to first stop profiling otherwise we would lost the last profile | ||
| if (profiler != null) { | ||
| profiler.close(); | ||
| } | ||
| } | ||
|
|
||
| @TestOnly | ||
| int getTransactionsCounter() { | ||
| return transactionsCounter; | ||
| } | ||
| } | ||
Uh oh!
There was an error while loading. Please reload this page.