From 6e31b7c796f20edaf39ba795667596e7bf876c43 Mon Sep 17 00:00:00 2001 From: Andrew McKnight Date: Tue, 23 Apr 2024 10:09:05 -0800 Subject: [PATCH] ref(profiling): move sliceGPUData to timeseries code unit (#3872) --- Sources/Sentry/SentryProfileTimeseries.mm | 57 +++++++++++++++++- Sources/Sentry/SentryProfiler.mm | 59 ++----------------- .../Sentry/include/SentryProfileTimeseries.h | 12 +++- .../SentryProfilerTests.mm | 2 +- 4 files changed, 72 insertions(+), 58 deletions(-) diff --git a/Sources/Sentry/SentryProfileTimeseries.mm b/Sources/Sentry/SentryProfileTimeseries.mm index f058c99009b..0abaf648d03 100644 --- a/Sources/Sentry/SentryProfileTimeseries.mm +++ b/Sources/Sentry/SentryProfileTimeseries.mm @@ -7,6 +7,10 @@ # import "SentryLog.h" # import "SentrySample.h" # import "SentryTransaction.h" +# if SENTRY_HAS_UIKIT +# import "SentryFormatter.h" +# import "SentryTime.h" +# endif // SENTRY_HAS_UIKIT /** * Print a debug log to help diagnose slicing errors. @@ -39,7 +43,7 @@ firstSampleRelativeToTransactionStart, lastSampleRelativeToTransactionStart); } -NSArray *_Nullable slicedProfileSamples( +NSArray *_Nullable sentry_slicedProfileSamples( NSArray *samples, uint64_t startSystemTime, uint64_t endSystemTime) { if (samples.count == 0) { @@ -81,4 +85,55 @@ return [samples objectsAtIndexes:indices]; } +# if SENTRY_HAS_UIKIT +/** + * Convert the data structure that records timestamps for GPU frame render info from + * SentryFramesTracker to the structure expected for profiling metrics, and throw out any that + * didn't occur within the profile time. + * @param useMostRecentRecording @c SentryFramesTracker doesn't stop running once it starts. + * Although we reset the profiling timestamps each time the profiler stops and starts, concurrent + * transactions that start after the first one won't have a screen frame rate recorded within their + * timeframe, because it will have already been recorded for the first transaction and isn't + * recorded again unless the system changes it. In these cases, use the most recently recorded data + * for it. + */ +NSArray * +sentry_sliceGPUData(SentryFrameInfoTimeSeries *frameInfo, uint64_t startSystemTime, + uint64_t endSystemTime, BOOL useMostRecentRecording) +{ + auto slicedGPUEntries = [NSMutableArray array]; + __block NSNumber *nearestPredecessorValue; + [frameInfo enumerateObjectsUsingBlock:^( + NSDictionary *_Nonnull obj, NSUInteger idx, BOOL *_Nonnull stop) { + const auto timestamp = obj[@"timestamp"].unsignedLongLongValue; + + if (!orderedChronologically(startSystemTime, timestamp)) { + SENTRY_LOG_DEBUG(@"GPU info recorded (%llu) before transaction start (%llu), " + @"will not report it.", + timestamp, startSystemTime); + nearestPredecessorValue = obj[@"value"]; + return; + } + + if (!orderedChronologically(timestamp, endSystemTime)) { + SENTRY_LOG_DEBUG(@"GPU info recorded after transaction finished, won't record."); + return; + } + const auto relativeTimestamp = getDurationNs(startSystemTime, timestamp); + + [slicedGPUEntries addObject:@ { + @"elapsed_since_start_ns" : sentry_stringForUInt64(relativeTimestamp), + @"value" : obj[@"value"], + }]; + }]; + if (useMostRecentRecording && slicedGPUEntries.count == 0 && nearestPredecessorValue != nil) { + [slicedGPUEntries addObject:@ { + @"elapsed_since_start_ns" : @"0", + @"value" : nearestPredecessorValue, + }]; + } + return slicedGPUEntries; +} +# endif // SENTRY_HAS_UIKIT + #endif // SENTRY_TARGET_PROFILING_SUPPORTED diff --git a/Sources/Sentry/SentryProfiler.mm b/Sources/Sentry/SentryProfiler.mm index 7fa4e95544d..5d428129268 100644 --- a/Sources/Sentry/SentryProfiler.mm +++ b/Sources/Sentry/SentryProfiler.mm @@ -97,57 +97,6 @@ } } -# if SENTRY_HAS_UIKIT -/** - * Convert the data structure that records timestamps for GPU frame render info from - * SentryFramesTracker to the structure expected for profiling metrics, and throw out any that - * didn't occur within the profile time. - * @param useMostRecentRecording @c SentryFramesTracker doesn't stop running once it starts. - * Although we reset the profiling timestamps each time the profiler stops and starts, concurrent - * transactions that start after the first one won't have a screen frame rate recorded within their - * timeframe, because it will have already been recorded for the first transaction and isn't - * recorded again unless the system changes it. In these cases, use the most recently recorded data - * for it. - */ -NSArray * -sliceGPUData(SentryFrameInfoTimeSeries *frameInfo, uint64_t startSystemTime, uint64_t endSystemTime, - BOOL useMostRecentRecording) -{ - auto slicedGPUEntries = [NSMutableArray array]; - __block NSNumber *nearestPredecessorValue; - [frameInfo enumerateObjectsUsingBlock:^( - NSDictionary *_Nonnull obj, NSUInteger idx, BOOL *_Nonnull stop) { - const auto timestamp = obj[@"timestamp"].unsignedLongLongValue; - - if (!orderedChronologically(startSystemTime, timestamp)) { - SENTRY_LOG_DEBUG(@"GPU info recorded (%llu) before transaction start (%llu), " - @"will not report it.", - timestamp, startSystemTime); - nearestPredecessorValue = obj[@"value"]; - return; - } - - if (!orderedChronologically(timestamp, endSystemTime)) { - SENTRY_LOG_DEBUG(@"GPU info recorded after transaction finished, won't record."); - return; - } - const auto relativeTimestamp = getDurationNs(startSystemTime, timestamp); - - [slicedGPUEntries addObject:@ { - @"elapsed_since_start_ns" : sentry_stringForUInt64(relativeTimestamp), - @"value" : obj[@"value"], - }]; - }]; - if (useMostRecentRecording && slicedGPUEntries.count == 0 && nearestPredecessorValue != nil) { - [slicedGPUEntries addObject:@ { - @"elapsed_since_start_ns" : @"0", - @"value" : nearestPredecessorValue, - }]; - } - return slicedGPUEntries; -} -# endif // SENTRY_HAS_UIKIT - /** Given an array of samples with absolute timestamps, return the serialized JSON mapping with * their data, with timestamps normalized relative to the provided transaction's start time. */ NSArray * @@ -200,7 +149,7 @@ } // slice the profile data to only include the samples/metrics within the transaction - const auto slicedSamples = slicedProfileSamples(samples, startSystemTime, endSystemTime); + const auto slicedSamples = sentry_slicedProfileSamples(samples, startSystemTime, endSystemTime); if (slicedSamples.count < 2) { SENTRY_LOG_DEBUG(@"Not enough samples in profile during the transaction"); [hub.getClient recordLostEvent:kSentryDataCategoryProfile @@ -247,7 +196,7 @@ # if SENTRY_HAS_UIKIT const auto mutableMetrics = [NSMutableDictionary dictionaryWithDictionary:metrics]; - const auto slowFrames = sliceGPUData(gpuData.slowFrameTimestamps, startSystemTime, + const auto slowFrames = sentry_sliceGPUData(gpuData.slowFrameTimestamps, startSystemTime, endSystemTime, /*useMostRecentRecording */ NO); if (slowFrames.count > 0) { mutableMetrics[@"slow_frame_renders"] = @@ -255,7 +204,7 @@ } const auto frozenFrames - = sliceGPUData(gpuData.frozenFrameTimestamps, startSystemTime, endSystemTime, + = sentry_sliceGPUData(gpuData.frozenFrameTimestamps, startSystemTime, endSystemTime, /*useMostRecentRecording */ NO); if (frozenFrames.count > 0) { mutableMetrics[@"frozen_frame_renders"] = @@ -264,7 +213,7 @@ if (slowFrames.count > 0 || frozenFrames.count > 0) { const auto frameRates - = sliceGPUData(gpuData.frameRateTimestamps, startSystemTime, endSystemTime, + = sentry_sliceGPUData(gpuData.frameRateTimestamps, startSystemTime, endSystemTime, /*useMostRecentRecording */ YES); if (frameRates.count > 0) { mutableMetrics[@"screen_frame_rates"] = @ { @"unit" : @"hz", @"values" : frameRates }; diff --git a/Sources/Sentry/include/SentryProfileTimeseries.h b/Sources/Sentry/include/SentryProfileTimeseries.h index 7aac0ef438f..bfa1b138320 100644 --- a/Sources/Sentry/include/SentryProfileTimeseries.h +++ b/Sources/Sentry/include/SentryProfileTimeseries.h @@ -5,14 +5,24 @@ # import "SentryDefines.h" # import +# if SENTRY_HAS_UIKIT +# import "SentryMetricProfiler.h" +# import "SentryScreenFrames.h" +# endif // SENTRY_HAS_UIKIT + @class SentrySample; @class SentryTransaction; NS_ASSUME_NONNULL_BEGIN -NSArray *_Nullable slicedProfileSamples( +NSArray *_Nullable sentry_slicedProfileSamples( NSArray *samples, uint64_t startSystemTime, uint64_t endSystemTime); +# if SENTRY_HAS_UIKIT +NSArray *sentry_sliceGPUData(SentryFrameInfoTimeSeries *frameInfo, + uint64_t startSystemTime, uint64_t endSystemTime, BOOL useMostRecentRecording); +# endif // SENTRY_HAS_UIKIT + NS_ASSUME_NONNULL_END #endif // SENTRY_TARGET_PROFILING_SUPPORTED diff --git a/Tests/SentryProfilerTests/SentryProfilerTests.mm b/Tests/SentryProfilerTests/SentryProfilerTests.mm index 40ee42289eb..a0da151c13f 100644 --- a/Tests/SentryProfilerTests/SentryProfilerTests.mm +++ b/Tests/SentryProfilerTests/SentryProfilerTests.mm @@ -109,7 +109,7 @@ - (void)testProfilerMutationDuringSlicing void (^sliceBlock)(void) = ^(void) { [state mutate:^(SentryProfilerMutableState *mutableState) { __unused const auto slice - = slicedProfileSamples(mutableState.samples, startSystemTime, endSystemTime); + = sentry_slicedProfileSamples(mutableState.samples, startSystemTime, endSystemTime); [sliceExpectation fulfill]; }]; };