1717import io .sentry .ITransactionProfiler ;
1818import io .sentry .ProfilingTraceData ;
1919import io .sentry .ProfilingTransactionData ;
20- import io .sentry .SentryEnvelope ;
2120import io .sentry .SentryLevel ;
2221import io .sentry .android .core .internal .util .CpuInfoUtils ;
2322import io .sentry .android .core .internal .util .SentryFrameMetricsCollector ;
24- import io .sentry .exception .SentryEnvelopeException ;
2523import io .sentry .profilemeasurements .ProfileMeasurement ;
2624import io .sentry .profilemeasurements .ProfileMeasurementValue ;
2725import io .sentry .util .Objects ;
3230import java .util .List ;
3331import java .util .Map ;
3432import java .util .UUID ;
33+ import java .util .concurrent .ExecutionException ;
3534import java .util .concurrent .Future ;
3635import java .util .concurrent .TimeUnit ;
3736import org .jetbrains .annotations .NotNull ;
@@ -56,6 +55,7 @@ final class AndroidTransactionProfiler implements ITransactionProfiler {
5655 private @ Nullable File traceFile = null ;
5756 private @ Nullable File traceFilesDir = null ;
5857 private @ Nullable Future <?> scheduledFinish = null ;
58+ private volatile @ Nullable ProfilingTraceData timedOutProfilingData = null ;
5959 private final @ NotNull Context context ;
6060 private final @ NotNull SentryAndroidOptions options ;
6161 private final @ NotNull IHub hub ;
@@ -66,7 +66,7 @@ final class AndroidTransactionProfiler implements ITransactionProfiler {
6666 private int transactionsCounter = 0 ;
6767 private @ Nullable String frameMetricsCollectorId ;
6868 private final @ NotNull SentryFrameMetricsCollector frameMetricsCollector ;
69- private final @ NotNull Map < String , ProfilingTransactionData > transactionMap = new HashMap <>() ;
69+ private @ Nullable ProfilingTransactionData currentProfilingTransactionData ;
7070 private final @ NotNull ArrayDeque <ProfileMeasurementValue > screenFrameRateMeasurements =
7171 new ArrayDeque <>();
7272 private final @ NotNull ArrayDeque <ProfileMeasurementValue > slowFrameRenderMeasurements =
@@ -160,20 +160,23 @@ private void onTransactionStartSafe(final @NotNull ITransaction transaction) {
160160 // When the first transaction is starting, we can start profiling
161161 if (transactionsCounter == 1 ) {
162162 onFirstTransactionStarted (transaction );
163+ options
164+ .getLogger ()
165+ .log (
166+ SentryLevel .DEBUG ,
167+ "Transaction %s (%s) started and being profiled." ,
168+ transaction .getName (),
169+ transaction .getSpanContext ().getTraceId ().toString ());
163170 } else {
164- ProfilingTransactionData transactionData =
165- new ProfilingTransactionData (
166- transaction , SystemClock .elapsedRealtimeNanos (), Process .getElapsedCpuTime ());
167- transactionMap .put (transaction .getEventId ().toString (), transactionData );
171+ transactionsCounter --;
172+ options
173+ .getLogger ()
174+ .log (
175+ SentryLevel .WARNING ,
176+ "A transaction is already being profiled. Transaction %s (%s) will be ignored." ,
177+ transaction .getName (),
178+ transaction .getSpanContext ().getTraceId ().toString ());
168179 }
169- options
170- .getLogger ()
171- .log (
172- SentryLevel .DEBUG ,
173- "Transaction %s (%s) started. Transactions being profiled: %d" ,
174- transaction .getName (),
175- transaction .getSpanContext ().getTraceId ().toString (),
176- transactionsCounter );
177180 }
178181
179182 @ SuppressLint ("NewApi" )
@@ -229,41 +232,75 @@ public void onFrameMetricCollected(
229232 scheduledFinish =
230233 options
231234 .getExecutorService ()
232- .schedule (() -> onTransactionFinish (transaction , true ), PROFILING_TIMEOUT_MILLIS );
235+ .schedule (
236+ () -> timedOutProfilingData = onTransactionFinish (transaction , true ),
237+ PROFILING_TIMEOUT_MILLIS );
233238
234239 transactionStartNanos = SystemClock .elapsedRealtimeNanos ();
235240 profileStartCpuMillis = Process .getElapsedCpuTime ();
236241
237- ProfilingTransactionData transactionData =
242+ currentProfilingTransactionData =
238243 new ProfilingTransactionData (transaction , transactionStartNanos , profileStartCpuMillis );
239- transactionMap .put (transaction .getEventId ().toString (), transactionData );
240244
241245 Debug .startMethodTracingSampling (traceFile .getPath (), BUFFER_SIZE_BYTES , intervalUs );
242246 }
243247
244248 @ Override
245- public synchronized void onTransactionFinish (final @ NotNull ITransaction transaction ) {
246- options .getExecutorService ().submit (() -> onTransactionFinish (transaction , false ));
249+ public @ Nullable synchronized ProfilingTraceData onTransactionFinish (
250+ final @ NotNull ITransaction transaction ) {
251+ try {
252+ return options
253+ .getExecutorService ()
254+ .submit (() -> onTransactionFinish (transaction , false ))
255+ .get ();
256+ } catch (ExecutionException e ) {
257+ options .getLogger ().log (SentryLevel .ERROR , "Error finishing profiling: " , e );
258+ } catch (InterruptedException e ) {
259+ options .getLogger ().log (SentryLevel .ERROR , "Error finishing profiling: " , e );
260+ }
261+ return null ;
247262 }
248263
249264 @ SuppressLint ("NewApi" )
250- private void onTransactionFinish (
265+ private @ Nullable ProfilingTraceData onTransactionFinish (
251266 final @ NotNull ITransaction transaction , final boolean isTimeout ) {
252267
253268 // onTransactionStart() is only available since Lollipop
254269 // and SystemClock.elapsedRealtimeNanos() since Jelly Bean
255- if (buildInfoProvider .getSdkInfoVersion () < Build .VERSION_CODES .LOLLIPOP ) return ;
256-
257- // Transaction finished, but it's not in the current profile. We can skip it
258- if (!transactionMap .containsKey (transaction .getEventId ().toString ())) {
270+ if (buildInfoProvider .getSdkInfoVersion () < Build .VERSION_CODES .LOLLIPOP ) return null ;
271+
272+ final ProfilingTraceData profilingData = timedOutProfilingData ;
273+
274+ // Transaction finished, but it's not in the current profile
275+ if (currentProfilingTransactionData == null
276+ || !currentProfilingTransactionData .getId ().equals (transaction .getEventId ().toString ())) {
277+ // We check if we cached a profiling data due to a timeout with this profile in it
278+ // If so, we return it back, otherwise we would simply lose it
279+ if (profilingData != null ) {
280+ if (profilingData .getTransactionId ().equals (transaction .getEventId ().toString ())) {
281+ timedOutProfilingData = null ;
282+ return profilingData ;
283+ } else {
284+ // Another transaction is finishing before the timed out one
285+ options
286+ .getLogger ()
287+ .log (
288+ SentryLevel .INFO ,
289+ "A timed out profiling data exists, but the finishing transaction %s (%s) is not part of it" ,
290+ transaction .getName (),
291+ transaction .getSpanContext ().getTraceId ().toString ());
292+ return null ;
293+ }
294+ }
295+ // A transaction is finishing, but it's not profiled. We can skip it
259296 options
260297 .getLogger ()
261298 .log (
262299 SentryLevel .INFO ,
263300 "Transaction %s (%s) finished, but was not currently being profiled. Skipping" ,
264301 transaction .getName (),
265302 transaction .getSpanContext ().getTraceId ().toString ());
266- return ;
303+ return null ;
267304 }
268305
269306 if (transactionsCounter > 0 ) {
@@ -274,38 +311,32 @@ private void onTransactionFinish(
274311 .getLogger ()
275312 .log (
276313 SentryLevel .DEBUG ,
277- "Transaction %s (%s) finished. Transactions to be profiled: %d " ,
314+ "Transaction %s (%s) finished." ,
278315 transaction .getName (),
279- transaction .getSpanContext ().getTraceId ().toString (),
280- transactionsCounter );
316+ transaction .getSpanContext ().getTraceId ().toString ());
281317
282318 if (transactionsCounter != 0 && !isTimeout ) {
283319 // We notify the data referring to this transaction that it finished
284- ProfilingTransactionData transactionData =
285- transactionMap .get (transaction .getEventId ().toString ());
286- if (transactionData != null ) {
287- transactionData .notifyFinish (
320+ if (currentProfilingTransactionData != null ) {
321+ currentProfilingTransactionData .notifyFinish (
288322 SystemClock .elapsedRealtimeNanos (),
289323 transactionStartNanos ,
290324 Process .getElapsedCpuTime (),
291325 profileStartCpuMillis );
292326 }
293- return ;
327+ return null ;
294328 }
295- onLastTransactionFinished (transaction , isTimeout );
296- }
297329
298- @ SuppressLint ("NewApi" )
299- private void onLastTransactionFinished (final ITransaction transaction , final boolean isTimeout ) {
300330 Debug .stopMethodTracing ();
301331 frameMetricsCollector .stopCollection (frameMetricsCollectorId );
302332
303333 long transactionEndNanos = SystemClock .elapsedRealtimeNanos ();
304334 long transactionEndCpuMillis = Process .getElapsedCpuTime ();
305335 long transactionDurationNanos = transactionEndNanos - transactionStartNanos ;
306336
307- List <ProfilingTransactionData > transactionList = new ArrayList <>(transactionMap .values ());
308- transactionMap .clear ();
337+ List <ProfilingTransactionData > transactionList = new ArrayList <>(1 );
338+ transactionList .add (currentProfilingTransactionData );
339+ currentProfilingTransactionData = null ;
309340 // We clear the counter in case of a timeout
310341 transactionsCounter = 0 ;
311342
@@ -316,7 +347,7 @@ private void onLastTransactionFinished(final ITransaction transaction, final boo
316347
317348 if (traceFile == null ) {
318349 options .getLogger ().log (SentryLevel .ERROR , "Trace file does not exists" );
319- return ;
350+ return null ;
320351 }
321352
322353 String totalMem = "0" ;
@@ -355,42 +386,26 @@ private void onLastTransactionFinished(final ITransaction transaction, final boo
355386
356387 // cpu max frequencies are read with a lambda because reading files is involved, so it will be
357388 // done in the background when the trace file is read
358- ProfilingTraceData profilingTraceData =
359- new ProfilingTraceData (
360- traceFile ,
361- transactionList ,
362- transaction ,
363- Long .toString (transactionDurationNanos ),
364- buildInfoProvider .getSdkInfoVersion (),
365- abis != null && abis .length > 0 ? abis [0 ] : "" ,
366- () -> CpuInfoUtils .getInstance ().readMaxFrequencies (),
367- buildInfoProvider .getManufacturer (),
368- buildInfoProvider .getModel (),
369- buildInfoProvider .getVersionRelease (),
370- buildInfoProvider .isEmulator (),
371- totalMem ,
372- options .getProguardUuid (),
373- options .getRelease (),
374- options .getEnvironment (),
375- isTimeout
376- ? ProfilingTraceData .TRUNCATION_REASON_TIMEOUT
377- : ProfilingTraceData .TRUNCATION_REASON_NORMAL ,
378- measurementsMap );
379-
380- SentryEnvelope envelope ;
381- try {
382- envelope =
383- SentryEnvelope .from (
384- options .getSerializer (),
385- profilingTraceData ,
386- options .getMaxTraceFileSize (),
387- options .getSdkVersion ());
388- } catch (SentryEnvelopeException e ) {
389- options .getLogger ().log (SentryLevel .ERROR , "Failed to capture profile." , e );
390- return ;
391- }
392-
393- hub .captureEnvelope (envelope );
389+ return new ProfilingTraceData (
390+ traceFile ,
391+ transactionList ,
392+ transaction ,
393+ Long .toString (transactionDurationNanos ),
394+ buildInfoProvider .getSdkInfoVersion (),
395+ abis != null && abis .length > 0 ? abis [0 ] : "" ,
396+ () -> CpuInfoUtils .getInstance ().readMaxFrequencies (),
397+ buildInfoProvider .getManufacturer (),
398+ buildInfoProvider .getModel (),
399+ buildInfoProvider .getVersionRelease (),
400+ buildInfoProvider .isEmulator (),
401+ totalMem ,
402+ options .getProguardUuid (),
403+ options .getRelease (),
404+ options .getEnvironment (),
405+ isTimeout
406+ ? ProfilingTraceData .TRUNCATION_REASON_TIMEOUT
407+ : ProfilingTraceData .TRUNCATION_REASON_NORMAL ,
408+ measurementsMap );
394409 }
395410
396411 /**
0 commit comments