Skip to content

Commit

Permalink
ref(profiling): move sliceGPUData to timeseries code unit (#3872)
Browse files Browse the repository at this point in the history
  • Loading branch information
@armcknight
armcknight committed Apr 23, 2024
1 parent 1b314c5 commit 6e31b7c
Show file tree
Hide file tree
Showing 4 changed files with 72 additions and 58 deletions.
57 changes: 56 additions & 1 deletion Sources/Sentry/SentryProfileTimeseries.mm
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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.
Expand Down Expand Up @@ -39,7 +43,7 @@
firstSampleRelativeToTransactionStart, lastSampleRelativeToTransactionStart);
}

NSArray<SentrySample *> *_Nullable slicedProfileSamples(
NSArray<SentrySample *> *_Nullable sentry_slicedProfileSamples(
NSArray<SentrySample *> *samples, uint64_t startSystemTime, uint64_t endSystemTime)
{
if (samples.count == 0) {
Expand Down Expand Up @@ -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<SentrySerializedMetricEntry *> *
sentry_sliceGPUData(SentryFrameInfoTimeSeries *frameInfo, uint64_t startSystemTime,
uint64_t endSystemTime, BOOL useMostRecentRecording)
{
auto slicedGPUEntries = [NSMutableArray<SentrySerializedMetricEntry *> array];
__block NSNumber *nearestPredecessorValue;
[frameInfo enumerateObjectsUsingBlock:^(
NSDictionary<NSString *, NSNumber *> *_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
59 changes: 4 additions & 55 deletions Sources/Sentry/SentryProfiler.mm
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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<SentrySerializedMetricReading *> *
sliceGPUData(SentryFrameInfoTimeSeries *frameInfo, uint64_t startSystemTime, uint64_t endSystemTime,
BOOL useMostRecentRecording)
{
auto slicedGPUEntries = [NSMutableArray<SentrySerializedMetricEntry *> array];
__block NSNumber *nearestPredecessorValue;
[frameInfo enumerateObjectsUsingBlock:^(
NSDictionary<NSString *, NSNumber *> *_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<NSDictionary *> *
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -247,15 +196,15 @@
# if SENTRY_HAS_UIKIT
const auto mutableMetrics =
[NSMutableDictionary<NSString *, id> 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"] =
@ { @"unit" : @"nanosecond", @"values" : slowFrames };
}

const auto frozenFrames
= sliceGPUData(gpuData.frozenFrameTimestamps, startSystemTime, endSystemTime,
= sentry_sliceGPUData(gpuData.frozenFrameTimestamps, startSystemTime, endSystemTime,
/*useMostRecentRecording */ NO);
if (frozenFrames.count > 0) {
mutableMetrics[@"frozen_frame_renders"] =
Expand All @@ -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 };
Expand Down
12 changes: 11 additions & 1 deletion Sources/Sentry/include/SentryProfileTimeseries.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -5,14 +5,24 @@
# import "SentryDefines.h"
# import <Foundation/Foundation.h>

# if SENTRY_HAS_UIKIT
# import "SentryMetricProfiler.h"
# import "SentryScreenFrames.h"
# endif // SENTRY_HAS_UIKIT

@class SentrySample;
@class SentryTransaction;

NS_ASSUME_NONNULL_BEGIN

NSArray<SentrySample *> *_Nullable slicedProfileSamples(
NSArray<SentrySample *> *_Nullable sentry_slicedProfileSamples(
NSArray<SentrySample *> *samples, uint64_t startSystemTime, uint64_t endSystemTime);

# if SENTRY_HAS_UIKIT
NSArray<SentrySerializedMetricEntry *> *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
2 changes: 1 addition & 1 deletion Tests/SentryProfilerTests/SentryProfilerTests.mm
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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];
}];
};
Expand Down

0 comments on commit 6e31b7c

Please sign in to comment.