diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml index 893431e8dd3..bf323ff03d4 100644 --- a/.github/workflows/test.yml +++ b/.github/workflows/test.yml @@ -26,14 +26,6 @@ on: - 'Samples/iOS-Swift/iOS-Swift.xcodeproj/xcshareddata/xcschemes/iOS-Swift.xcscheme' - 'Samples/macOS-Swift/macOS-Swift.xcodeproj/xcshareddata/xcschemes/macOS-Swift.xcscheme' - 'Samples/iOS-ObjectiveC/iOS-ObjectiveC.xcodeproj/xcshareddata/xcschemes/iOS-ObjectiveC.xcscheme' - - schedule: - # Run tests every hour to get some data on how long they take and how often they fail. - # We hypothesize that tests take longer and fail more often when the US is online. - # The plan is to remove this after a week or so, once we have enough data. - # We didn't choose 0 to minimize collisions with other workflows. - # Run every hour at 17 minutes past the hour. - - cron: '47 * * * *' jobs: build-test-server: diff --git a/.pre-commit-config.yaml b/.pre-commit-config.yaml index 19d4206ca97..e0158713b70 100644 --- a/.pre-commit-config.yaml +++ b/.pre-commit-config.yaml @@ -13,6 +13,13 @@ repos: - id: end-of-file-fixer - id: no-commit-to-branch + - repo: https://github.com/python-jsonschema/check-jsonschema + rev: 0.23.0 + hooks: + - id: check-github-actions + - id: check-github-workflows + args: [--verbose] + - repo: local hooks: - id: format-clang diff --git a/CHANGELOG.md b/CHANGELOG.md index ad8e1cb7304..e20f4c7be27 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,12 @@ # Changelog +## 8.7.2 + +### Fixed + +- Fix crashes in profiling serialization race condition (#3018, #3035) +- Fix a crash for user interaction transactions (#3036) + ## 8.7.1 ### Features diff --git a/Samples/iOS-Swift/iOS-Swift.xcodeproj/project.pbxproj b/Samples/iOS-Swift/iOS-Swift.xcodeproj/project.pbxproj index 48d9063fbe4..31f09b65e12 100644 --- a/Samples/iOS-Swift/iOS-Swift.xcodeproj/project.pbxproj +++ b/Samples/iOS-Swift/iOS-Swift.xcodeproj/project.pbxproj @@ -1190,7 +1190,7 @@ "$(inherited)", "@executable_path/Frameworks", ); - MARKETING_VERSION = 8.7.1; + MARKETING_VERSION = 8.7.2; PRODUCT_BUNDLE_IDENTIFIER = "io.sentry.sample.iOS-Swift"; PRODUCT_NAME = "$(TARGET_NAME)"; PROVISIONING_PROFILE_SPECIFIER = "match Development io.sentry.sample.iOS-Swift"; @@ -1219,7 +1219,7 @@ "$(inherited)", "@executable_path/Frameworks", ); - MARKETING_VERSION = 8.7.1; + MARKETING_VERSION = 8.7.2; PRODUCT_BUNDLE_IDENTIFIER = "io.sentry.sample.iOS-Swift"; PRODUCT_NAME = "$(TARGET_NAME)"; PROVISIONING_PROFILE_SPECIFIER = "match AppStore io.sentry.sample.iOS-Swift"; @@ -1864,7 +1864,7 @@ "$(inherited)", "@executable_path/Frameworks", ); - MARKETING_VERSION = 8.7.1; + MARKETING_VERSION = 8.7.2; PRODUCT_BUNDLE_IDENTIFIER = "io.sentry.sample.iOS-Swift.Clip"; PRODUCT_NAME = "$(TARGET_NAME)"; PROVISIONING_PROFILE_SPECIFIER = "match Development io.sentry.sample.iOS-Swift.Clip"; @@ -1899,7 +1899,7 @@ "$(inherited)", "@executable_path/Frameworks", ); - MARKETING_VERSION = 8.7.1; + MARKETING_VERSION = 8.7.2; PRODUCT_BUNDLE_IDENTIFIER = "io.sentry.sample.iOS-Swift.Clip"; PRODUCT_NAME = "$(TARGET_NAME)"; PROVISIONING_PROFILE_SPECIFIER = "match AppStore io.sentry.sample.iOS-Swift.Clip"; diff --git a/Sentry.podspec b/Sentry.podspec index 66b7e39f6fe..9455521b45d 100644 --- a/Sentry.podspec +++ b/Sentry.podspec @@ -1,6 +1,6 @@ Pod::Spec.new do |s| s.name = "Sentry" - s.version = "8.7.1" + s.version = "8.7.2" s.summary = "Sentry client for cocoa" s.homepage = "https://github.com/getsentry/sentry-cocoa" s.license = "mit" @@ -27,7 +27,7 @@ Pod::Spec.new do |s| } s.default_subspecs = ['Core'] - s.dependency "SentryPrivate", "8.7.1" + s.dependency "SentryPrivate", "8.7.2" s.subspec 'Core' do |sp| sp.source_files = "Sources/Sentry/**/*.{h,hpp,m,mm,c,cpp}", diff --git a/Sentry.xcodeproj/project.pbxproj b/Sentry.xcodeproj/project.pbxproj index b1e12416145..53fbd5ca682 100644 --- a/Sentry.xcodeproj/project.pbxproj +++ b/Sentry.xcodeproj/project.pbxproj @@ -7,6 +7,7 @@ objects = { /* Begin PBXBuildFile section */ + 0354A22B2A134D9C003C3A04 /* SentryProfiler+Private.h in Headers */ = {isa = PBXBuildFile; fileRef = 0354A22A2A134D9C003C3A04 /* SentryProfiler+Private.h */; }; 0356A570288B4612008BF593 /* SentryProfilesSampler.h in Headers */ = {isa = PBXBuildFile; fileRef = 0356A56E288B4612008BF593 /* SentryProfilesSampler.h */; }; 0356A571288B4612008BF593 /* SentryProfilesSampler.m in Sources */ = {isa = PBXBuildFile; fileRef = 0356A56F288B4612008BF593 /* SentryProfilesSampler.m */; }; 03BCC38A27E1BF49003232C7 /* SentryTime.h in Headers */ = {isa = PBXBuildFile; fileRef = 03BCC38927E1BF49003232C7 /* SentryTime.h */; }; @@ -861,6 +862,7 @@ /* End PBXContainerItemProxy section */ /* Begin PBXFileReference section */ + 0354A22A2A134D9C003C3A04 /* SentryProfiler+Private.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; name = "SentryProfiler+Private.h"; path = "Sources/Sentry/include/SentryProfiler+Private.h"; sourceTree = SOURCE_ROOT; }; 0356A56E288B4612008BF593 /* SentryProfilesSampler.h */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.h; name = SentryProfilesSampler.h; path = Sources/Sentry/include/SentryProfilesSampler.h; sourceTree = SOURCE_ROOT; }; 0356A56F288B4612008BF593 /* SentryProfilesSampler.m */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.objc; name = SentryProfilesSampler.m; path = Sources/Sentry/SentryProfilesSampler.m; sourceTree = SOURCE_ROOT; }; 035E73C727D56757005EEB11 /* SentryBacktraceTests.mm */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.cpp.objcpp; path = SentryBacktraceTests.mm; sourceTree = ""; }; @@ -3064,6 +3066,7 @@ 03F84D1127DD414C008FE43F /* SentryProfiler.h */, 844EDD6B2949387000C86F34 /* SentryMetricProfiler.h */, 8454CF8B293EAF9A006AC140 /* SentryMetricProfiler.mm */, + 0354A22A2A134D9C003C3A04 /* SentryProfiler+Private.h */, 84A888FC28D9B11700C51DFD /* SentryProfiler+Test.h */, 844EDC7B2942843400C86F34 /* SentryProfiler+SwiftTest.h */, 03F84D2B27DD4191008FE43F /* SentryProfiler.mm */, @@ -3515,6 +3518,7 @@ 7BC8522F24581096005A70F0 /* SentryFileContents.h in Headers */, 7B30B67C26527886006B2752 /* SentryDisplayLinkWrapper.h in Headers */, 7BD86ECF264A7C77005439DB /* SentryAppStartMeasurement.h in Headers */, + 0354A22B2A134D9C003C3A04 /* SentryProfiler+Private.h in Headers */, 7DC8310A2398283C0043DD9A /* SentryCrashIntegration.h in Headers */, 63FE718320DA4C1100CDBAE8 /* SentryCrashReportFixer.h in Headers */, 03F84D2027DD414C008FE43F /* SentryStackBounds.hpp in Headers */, diff --git a/SentryPrivate.podspec b/SentryPrivate.podspec index 7255a2baa45..b5c261cb869 100644 --- a/SentryPrivate.podspec +++ b/SentryPrivate.podspec @@ -1,6 +1,6 @@ Pod::Spec.new do |s| s.name = "SentryPrivate" - s.version = "8.7.1" + s.version = "8.7.2" s.summary = "Sentry Private Library." s.homepage = "https://github.com/getsentry/sentry-cocoa" s.license = "mit" diff --git a/SentrySwiftUI.podspec b/SentrySwiftUI.podspec index 90412866435..bbdb7d4e004 100644 --- a/SentrySwiftUI.podspec +++ b/SentrySwiftUI.podspec @@ -1,6 +1,6 @@ Pod::Spec.new do |s| s.name = "SentrySwiftUI" - s.version = "8.7.1" + s.version = "8.7.2" s.summary = "Sentry client for SwiftUI" s.homepage = "https://github.com/getsentry/sentry-cocoa" s.license = "mit" @@ -19,5 +19,5 @@ Pod::Spec.new do |s| s.watchos.framework = 'WatchKit' s.source_files = "Sources/SentrySwiftUI/**/*.{swift,h,m}" - s.dependency 'Sentry', "8.7.1" + s.dependency 'Sentry', "8.7.2" end diff --git a/Sources/Configuration/Sentry.xcconfig b/Sources/Configuration/Sentry.xcconfig index f29f5448755..3da08b62d4b 100644 --- a/Sources/Configuration/Sentry.xcconfig +++ b/Sources/Configuration/Sentry.xcconfig @@ -2,6 +2,6 @@ PRODUCT_NAME = Sentry INFOPLIST_FILE = Sources/Sentry/Info.plist PRODUCT_BUNDLE_IDENTIFIER = io.sentry.Sentry -CURRENT_PROJECT_VERSION = 8.7.1 +CURRENT_PROJECT_VERSION = 8.7.2 MODULEMAP_FILE = $(SRCROOT)/Sources/Sentry/Sentry.modulemap diff --git a/Sources/Configuration/SentryPrivate.xcconfig b/Sources/Configuration/SentryPrivate.xcconfig index b842e017630..1c0da4f6c44 100644 --- a/Sources/Configuration/SentryPrivate.xcconfig +++ b/Sources/Configuration/SentryPrivate.xcconfig @@ -1,3 +1,3 @@ PRODUCT_NAME = SentryPrivate MACH_O_TYPE = staticlib -CURRENT_PROJECT_VERSION = 8.7.1 +CURRENT_PROJECT_VERSION = 8.7.2 diff --git a/Sources/Sentry/SentryMeta.m b/Sources/Sentry/SentryMeta.m index 967396b0594..80d4dfed622 100644 --- a/Sources/Sentry/SentryMeta.m +++ b/Sources/Sentry/SentryMeta.m @@ -5,7 +5,7 @@ @implementation SentryMeta // Don't remove the static keyword. If you do the compiler adds the constant name to the global // symbol table and it might clash with other constants. When keeping the static keyword the // compiler replaces all occurrences with the value. -static NSString *versionString = @"8.7.1"; +static NSString *versionString = @"8.7.2"; static NSString *sdkName = @"sentry.cocoa"; + (NSString *)versionString diff --git a/Sources/Sentry/SentryProfileTimeseries.mm b/Sources/Sentry/SentryProfileTimeseries.mm index df4e6327c18..bd1d01c83bc 100644 --- a/Sources/Sentry/SentryProfileTimeseries.mm +++ b/Sources/Sentry/SentryProfileTimeseries.mm @@ -7,8 +7,6 @@ # import "SentryLog.h" # import "SentryTransaction.h" -std::mutex _gSamplesArrayLock; - /** * Print a debug log to help diagnose slicing errors. * @param start @c YES if this is an attempt to find the start of the sliced data based on the @@ -44,27 +42,21 @@ NSArray *_Nullable slicedProfileSamples( NSArray *samples, SentryTransaction *transaction) { - NSArray *samplesCopy; - { - std::lock_guard l(_gSamplesArrayLock); - samplesCopy = [samples copy]; - } - - if (samplesCopy.count == 0) { + if (samples.count == 0) { return nil; } const auto transactionStart = transaction.startSystemTime; const auto firstIndex = - [samplesCopy indexOfObjectWithOptions:NSEnumerationConcurrent - passingTest:^BOOL(SentrySample *_Nonnull sample, NSUInteger idx, - BOOL *_Nonnull stop) { - *stop = sample.absoluteTimestamp >= transactionStart; - return *stop; - }]; + [samples indexOfObjectWithOptions:NSEnumerationConcurrent + passingTest:^BOOL(SentrySample *_Nonnull sample, NSUInteger idx, + BOOL *_Nonnull stop) { + *stop = sample.absoluteTimestamp >= transactionStart; + return *stop; + }]; if (firstIndex == NSNotFound) { - logSlicingFailureWithArray(samplesCopy, transaction, /*start*/ YES); + logSlicingFailureWithArray(samples, transaction, /*start*/ YES); return nil; } else { SENTRY_LOG_DEBUG(@"Found first slice sample at index %lu", firstIndex); @@ -72,15 +64,15 @@ const auto transactionEnd = transaction.endSystemTime; const auto lastIndex = - [samplesCopy indexOfObjectWithOptions:NSEnumerationConcurrent | NSEnumerationReverse - passingTest:^BOOL(SentrySample *_Nonnull sample, NSUInteger idx, - BOOL *_Nonnull stop) { - *stop = sample.absoluteTimestamp <= transactionEnd; - return *stop; - }]; + [samples indexOfObjectWithOptions:NSEnumerationConcurrent | NSEnumerationReverse + passingTest:^BOOL(SentrySample *_Nonnull sample, NSUInteger idx, + BOOL *_Nonnull stop) { + *stop = sample.absoluteTimestamp <= transactionEnd; + return *stop; + }]; if (lastIndex == NSNotFound) { - logSlicingFailureWithArray(samplesCopy, transaction, /*start*/ NO); + logSlicingFailureWithArray(samples, transaction, /*start*/ NO); return nil; } else { SENTRY_LOG_DEBUG(@"Found last slice sample at index %lu", lastIndex); @@ -88,7 +80,7 @@ const auto range = NSMakeRange(firstIndex, (lastIndex - firstIndex) + 1); const auto indices = [NSIndexSet indexSetWithIndexesInRange:range]; - return [samplesCopy objectsAtIndexes:indices]; + return [samples objectsAtIndexes:indices]; } @implementation SentrySample diff --git a/Sources/Sentry/SentryProfiler.mm b/Sources/Sentry/SentryProfiler.mm index 21e011d8a95..09923cc5c37 100644 --- a/Sources/Sentry/SentryProfiler.mm +++ b/Sources/Sentry/SentryProfiler.mm @@ -1,3 +1,4 @@ +#import "SentryProfiler+Private.h" #import "SentryProfiler+Test.h" #if SENTRY_TARGET_PROFILING_SUPPORTED @@ -49,7 +50,6 @@ # endif const int kSentryProfilerFrequencyHz = 101; -NSString *const kTestStringConst = @"test"; NSTimeInterval kSentryProfilerTimeoutInterval = 30; NSString *const kSentryProfilerSerializationKeySlowFrameRenders = @"slow_frame_renders"; @@ -79,87 +79,6 @@ return [symbolNSStr substringWithRange:[match rangeAtIndex:1]]; } -void -processBacktrace(const Backtrace &backtrace, - NSMutableDictionary *threadMetadata, - NSMutableDictionary *queueMetadata, - NSMutableArray *samples, NSMutableArray *> *stacks, - NSMutableArray *> *frames, - NSMutableDictionary *frameIndexLookup, - NSMutableDictionary *stackIndexLookup) -{ - const auto threadID = sentry_stringForUInt64(backtrace.threadMetadata.threadID); - - NSString *queueAddress = nil; - if (backtrace.queueMetadata.address != 0) { - queueAddress = sentry_formatHexAddressUInt64(backtrace.queueMetadata.address); - } - NSMutableDictionary *metadata = threadMetadata[threadID]; - if (metadata == nil) { - metadata = [NSMutableDictionary dictionary]; - threadMetadata[threadID] = metadata; - } - if (!backtrace.threadMetadata.name.empty() && metadata[@"name"] == nil) { - metadata[@"name"] = [NSString stringWithUTF8String:backtrace.threadMetadata.name.c_str()]; - } - if (backtrace.threadMetadata.priority != -1 && metadata[@"priority"] == nil) { - metadata[@"priority"] = @(backtrace.threadMetadata.priority); - } - if (queueAddress != nil && queueMetadata[queueAddress] == nil - && backtrace.queueMetadata.label != nullptr) { - queueMetadata[queueAddress] = - @ { @"label" : [NSString stringWithUTF8String:backtrace.queueMetadata.label->c_str()] }; - } -# if defined(DEBUG) - const auto symbols - = backtrace_symbols(reinterpret_cast(backtrace.addresses.data()), - static_cast(backtrace.addresses.size())); -# endif - - const auto stack = [NSMutableArray array]; - for (std::vector::size_type backtraceAddressIdx = 0; - backtraceAddressIdx < backtrace.addresses.size(); backtraceAddressIdx++) { - const auto instructionAddress - = sentry_formatHexAddressUInt64(backtrace.addresses[backtraceAddressIdx]); - - const auto frameIndex = frameIndexLookup[instructionAddress]; - if (frameIndex == nil) { - const auto frame = [NSMutableDictionary dictionary]; - frame[@"instruction_addr"] = instructionAddress; -# if defined(DEBUG) - frame[@"function"] = parseBacktraceSymbolsFunctionName(symbols[backtraceAddressIdx]); -# endif - [stack addObject:@(frames.count)]; - frameIndexLookup[instructionAddress] = @(frames.count); - [frames addObject:frame]; - } else { - [stack addObject:frameIndex]; - } - } - - const auto sample = [[SentrySample alloc] init]; - sample.absoluteTimestamp = backtrace.absoluteTimestamp; - sample.threadID = backtrace.threadMetadata.threadID; - if (queueAddress != nil) { - sample.queueAddress = queueAddress; - } - const auto stackKey = [stack componentsJoinedByString:@"|"]; - const auto stackIndex = stackIndexLookup[stackKey]; - if (stackIndex) { - sample.stackIndex = stackIndex; - } else { - const auto nextStackIndex = @(stacks.count); - sample.stackIndex = nextStackIndex; - stackIndexLookup[stackKey] = nextStackIndex; - [stacks addObject:stack]; - } - - { - std::lock_guard l(_gSamplesArrayLock); - [samples addObject:sample]; - } -} - std::mutex _gProfilerLock; SentryProfiler *_Nullable _gCurrentProfiler; SentryNSProcessInfoWrapper *_gCurrentProcessInfoWrapper; @@ -264,12 +183,266 @@ return result; } +NSDictionary * +serializedProfileData(NSDictionary *profileData, SentryTransaction *transaction, + SentryId *profileID, NSString *truncationReason, NSString *environment, NSString *release, + NSDictionary *serializedMetrics, NSArray *debugMeta) +{ + NSMutableArray *const samples = profileData[@"profile"][@"samples"]; + // We need at least two samples to be able to draw a stack frame for any given function: one + // sample for the start of the frame and another for the end. Otherwise we would only have a + // stack frame with 0 duration, which wouldn't make sense. + if ([samples count] < 2) { + SENTRY_LOG_DEBUG(@"Not enough samples in profile"); + return nil; + } + + // slice the profile data to only include the samples/metrics within the transaction + const auto slicedSamples = slicedProfileSamples(samples, transaction); + if (slicedSamples.count < 2) { + SENTRY_LOG_DEBUG(@"Not enough samples in profile during the transaction"); + return nil; + } + const auto payload = [NSMutableDictionary dictionary]; + NSMutableDictionary *const profile = [profileData[@"profile"] mutableCopy]; + profile[@"samples"] = serializedSamplesWithRelativeTimestamps(slicedSamples, transaction); + payload[@"profile"] = profile; + + payload[@"version"] = @"1"; + const auto debugImages = [NSMutableArray *> new]; + for (SentryDebugMeta *debugImage in debugMeta) { + [debugImages addObject:[debugImage serialize]]; + } + if (debugImages.count > 0) { + payload[@"debug_meta"] = @ { @"images" : debugImages }; + } + + payload[@"os"] = @ { + @"name" : sentry_getOSName(), + @"version" : sentry_getOSVersion(), + @"build_number" : sentry_getOSBuildNumber() + }; + + const auto isEmulated = sentry_isSimulatorBuild(); + payload[@"device"] = @{ + @"architecture" : sentry_getCPUArchitecture(), + @"is_emulator" : @(isEmulated), + @"locale" : NSLocale.currentLocale.localeIdentifier, + @"manufacturer" : @"Apple", + @"model" : isEmulated ? sentry_getSimulatorDeviceModel() : sentry_getDeviceModel() + }; + + payload[@"profile_id"] = profileID.sentryIdString; + payload[@"truncation_reason"] = truncationReason; + payload[@"platform"] = transaction.platform; + payload[@"environment"] = environment; + + const auto timestamp = transaction.trace.originalStartTimestamp; + if (UNLIKELY(timestamp == nil)) { + SENTRY_LOG_WARN(@"There was no start timestamp on the provided transaction. Falling back " + @"to old behavior of using the current time."); + payload[@"timestamp"] = [[SentryCurrentDate date] sentry_toIso8601String]; + } else { + payload[@"timestamp"] = [timestamp sentry_toIso8601String]; + } + + payload[@"release"] = release; + payload[@"transaction"] = @ { + @"id" : transaction.eventId.sentryIdString, + @"trace_id" : transaction.trace.traceId.sentryIdString, + @"name" : transaction.transaction, + @"active_thread_id" : [transaction.trace.transactionContext sentry_threadInfo].threadId + }; + + // add the gathered metrics + auto metrics = serializedMetrics; + +# if SENTRY_HAS_UIKIT + const auto mutableMetrics = + [NSMutableDictionary dictionaryWithDictionary:metrics]; + const auto slowFrames = sliceGPUData(_gCurrentFramesTracker.currentFrames.slowFrameTimestamps, + transaction, /*useMostRecentRecording */ NO); + if (slowFrames.count > 0) { + mutableMetrics[@"slow_frame_renders"] = + @ { @"unit" : @"nanosecond", @"values" : slowFrames }; + } + + const auto frozenFrames + = sliceGPUData(_gCurrentFramesTracker.currentFrames.frozenFrameTimestamps, transaction, + /*useMostRecentRecording */ NO); + if (frozenFrames.count > 0) { + mutableMetrics[@"frozen_frame_renders"] = + @ { @"unit" : @"nanosecond", @"values" : frozenFrames }; + } + + if (slowFrames.count > 0 || frozenFrames.count > 0) { + const auto frameRates + = sliceGPUData(_gCurrentFramesTracker.currentFrames.frameRateTimestamps, transaction, + /*useMostRecentRecording */ YES); + if (frameRates.count > 0) { + mutableMetrics[@"screen_frame_rates"] = @ { @"unit" : @"hz", @"values" : frameRates }; + } + } + metrics = mutableMetrics; +# endif // SENTRY_HAS_UIKIT + + if (metrics.count > 0) { + payload[@"measurements"] = metrics; + } + + return payload; +} + +@implementation SentryProfilingMutableState + +- (instancetype)init +{ + if (self = [super init]) { + _samples = [NSMutableArray array]; + _stacks = [NSMutableArray *> array]; + _frames = [NSMutableArray *> array]; + _threadMetadata = [NSMutableDictionary dictionary]; + _queueMetadata = [NSMutableDictionary dictionary]; + _frameIndexLookup = [NSMutableDictionary dictionary]; + _stackIndexLookup = [NSMutableDictionary dictionary]; + } + return self; +} + +@end + +@implementation SentryProfilingState { + SentryProfilingMutableState *_mutableState; + std::mutex _lock; +} + +- (instancetype)init +{ + if (self = [super init]) { + _mutableState = [[SentryProfilingMutableState alloc] init]; + } + return self; +} + +- (void)mutate:(void (^)(SentryProfilingMutableState *))block +{ + NSParameterAssert(block); + std::lock_guard l(_lock); + block(_mutableState); +} + +- (void)appendBacktrace:(const Backtrace &)backtrace +{ + [self mutate:^(SentryProfilingMutableState *state) { + const auto threadID = sentry_stringForUInt64(backtrace.threadMetadata.threadID); + + NSString *queueAddress = nil; + if (backtrace.queueMetadata.address != 0) { + queueAddress = sentry_formatHexAddressUInt64(backtrace.queueMetadata.address); + } + NSMutableDictionary *metadata = state.threadMetadata[threadID]; + if (metadata == nil) { + metadata = [NSMutableDictionary dictionary]; + state.threadMetadata[threadID] = metadata; + } + if (!backtrace.threadMetadata.name.empty() && metadata[@"name"] == nil) { + metadata[@"name"] = + [NSString stringWithUTF8String:backtrace.threadMetadata.name.c_str()]; + } + if (backtrace.threadMetadata.priority != -1 && metadata[@"priority"] == nil) { + metadata[@"priority"] = @(backtrace.threadMetadata.priority); + } + if (queueAddress != nil && state.queueMetadata[queueAddress] == nil + && backtrace.queueMetadata.label != nullptr) { + state.queueMetadata[queueAddress] = @ { + @"label" : [NSString stringWithUTF8String:backtrace.queueMetadata.label->c_str()] + }; + } +# if defined(DEBUG) + const auto symbols + = backtrace_symbols(reinterpret_cast(backtrace.addresses.data()), + static_cast(backtrace.addresses.size())); +# endif + + const auto stack = [NSMutableArray array]; + for (std::vector::size_type backtraceAddressIdx = 0; + backtraceAddressIdx < backtrace.addresses.size(); backtraceAddressIdx++) { + const auto instructionAddress + = sentry_formatHexAddressUInt64(backtrace.addresses[backtraceAddressIdx]); + + const auto frameIndex = state.frameIndexLookup[instructionAddress]; + if (frameIndex == nil) { + const auto frame = [NSMutableDictionary dictionary]; + frame[@"instruction_addr"] = instructionAddress; +# if defined(DEBUG) + frame[@"function"] + = parseBacktraceSymbolsFunctionName(symbols[backtraceAddressIdx]); +# endif + const auto newFrameIndex = @(state.frames.count); + [stack addObject:newFrameIndex]; + state.frameIndexLookup[instructionAddress] = newFrameIndex; + [state.frames addObject:frame]; + } else { + [stack addObject:frameIndex]; + } + } + + const auto sample = [[SentrySample alloc] init]; + sample.absoluteTimestamp = backtrace.absoluteTimestamp; + sample.threadID = backtrace.threadMetadata.threadID; + if (queueAddress != nil) { + sample.queueAddress = queueAddress; + } + + const auto stackKey = [stack componentsJoinedByString:@"|"]; + const auto stackIndex = state.stackIndexLookup[stackKey]; + if (stackIndex) { + sample.stackIndex = stackIndex; + } else { + const auto nextStackIndex = @(state.stacks.count); + sample.stackIndex = nextStackIndex; + state.stackIndexLookup[stackKey] = nextStackIndex; + [state.stacks addObject:stack]; + } + + [state.samples addObject:sample]; + }]; +} + +- (NSDictionary *)copyProfilingData +{ + std::lock_guard l(_lock); + + NSMutableArray *const samples = [_mutableState.samples copy]; + NSMutableArray *> *const stacks = [_mutableState.stacks copy]; + NSMutableArray *> *const frames = [_mutableState.frames copy]; + NSMutableDictionary *const queueMetadata = + [_mutableState.queueMetadata copy]; + + // thread metadata contains a mutable substructure, so it's not enough to perform a copy of + // the top-level dictionary, we need to go deeper to copy the mutable subdictionaries + const auto threadMetadata = [NSMutableDictionary dictionary]; + [_mutableState.threadMetadata enumerateKeysAndObjectsUsingBlock:^(NSString *_Nonnull key, + NSDictionary *_Nonnull obj, BOOL *_Nonnull stop) { threadMetadata[key] = [obj copy]; }]; + + return @{ + @"profile" : @ { + @"samples" : samples, + @"stacks" : stacks, + @"frames" : frames, + @"thread_metadata" : threadMetadata, + @"queue_metadata" : queueMetadata + } + }; +} + +@end + @implementation SentryProfiler { - NSMutableDictionary *_profileData; + SentryProfilingState *_state; std::shared_ptr _profiler; SentryMetricProfiler *_metricProfiler; SentryDebugImageProvider *_debugImageProvider; - thread::TIDType _mainThreadID; SentryProfilerTruncationReason _truncationReason; NSTimer *_timeoutTimer; @@ -285,7 +458,6 @@ - (instancetype)initWithHub:(SentryHub *)hub SENTRY_LOG_DEBUG(@"Initialized new SentryProfiler %@", self); _debugImageProvider = [SentryDependencyContainer sharedInstance].debugImageProvider; _hub = hub; - _mainThreadID = ThreadHandle::current()->tid(); return self; } @@ -353,78 +525,8 @@ + (BOOL)isRunning + (SentryEnvelopeItem *)createProfilingEnvelopeItemForTransaction:(SentryTransaction *)transaction { - std::lock_guard l(_gProfilerLock); - - if (_gCurrentProfiler == nil) { - SENTRY_LOG_DEBUG(@"No profiler from which to receive data."); - return nil; - } - - const auto payload = [NSMutableDictionary dictionary]; - - NSArray *samples = _gCurrentProfiler->_profileData[@"profile"][@"samples"]; - - // We need at least two samples to be able to draw a stack frame for any given function: one - // sample for the start of the frame and another for the end. Otherwise we would only have a - // stack frame with 0 duration, which wouldn't make sense. - if ([samples count] < 2) { - SENTRY_LOG_DEBUG(@"Not enough samples in profile"); - return nil; - } - - // slice the profile data to only include the samples/metrics within the transaction - const auto slicedSamples = slicedProfileSamples(samples, transaction); - if (slicedSamples.count < 2) { - SENTRY_LOG_DEBUG(@"Not enough samples in profile during the transaction"); - return nil; - } - - payload[@"profile"] = @{ - @"samples" : serializedSamplesWithRelativeTimestamps(slicedSamples, transaction), - @"stacks" : _gCurrentProfiler->_profileData[@"profile"][@"stacks"], - @"frames" : _gCurrentProfiler->_profileData[@"profile"][@"frames"], - @"thread_metadata" : _gCurrentProfiler->_profileData[@"profile"][@"thread_metadata"], - @"queue_metadata" : _gCurrentProfiler->_profileData[@"profile"][@"queue_metadata"], - }; - - // add the serialized info for the associated transaction - const auto transactionInfo = [self serializeInfoForTransaction:transaction]; - if (!transactionInfo) { - SENTRY_LOG_WARN(@"Could not find any associated transaction for the profile."); - return nil; - } - payload[@"transaction"] = transactionInfo; - - // add the gathered metrics - const auto metrics = [_gCurrentProfiler->_metricProfiler serializeForTransaction:transaction]; - -# if SENTRY_HAS_UIKIT - const auto slowFrames = sliceGPUData(_gCurrentFramesTracker.currentFrames.slowFrameTimestamps, - transaction, /*useMostRecentRecording */ NO); - if (slowFrames.count > 0) { - metrics[@"slow_frame_renders"] = @{ @"unit" : @"nanosecond", @"values" : slowFrames }; - } - - const auto frozenFrames - = sliceGPUData(_gCurrentFramesTracker.currentFrames.frozenFrameTimestamps, transaction, - /*useMostRecentRecording */ NO); - if (frozenFrames.count > 0) { - metrics[@"frozen_frame_renders"] = @{ @"unit" : @"nanosecond", @"values" : frozenFrames }; - } - - if (slowFrames.count > 0 || frozenFrames.count > 0) { - const auto frameRates - = sliceGPUData(_gCurrentFramesTracker.currentFrames.frameRateTimestamps, transaction, - /*useMostRecentRecording */ YES); - if (frameRates.count > 0) { - metrics[@"screen_frame_rates"] = @{ @"unit" : @"hz", @"values" : frameRates }; - } - } -# endif // SENTRY_HAS_UIKIT - - if (metrics.count > 0) { - payload[@"measurements"] = metrics; - } + const auto profileID = [[SentryId alloc] init]; + const auto payload = [self serializeForTransaction:transaction profileID:profileID]; # if defined(TEST) || defined(TESTCI) [NSNotificationCenter.defaultCenter postNotificationName:@"SentryProfileCompleteNotification" @@ -432,10 +534,6 @@ + (SentryEnvelopeItem *)createProfilingEnvelopeItemForTransaction:(SentryTransac userInfo:payload]; # endif // defined(TEST) || defined(TESTCI) - // add the remaining basic metadata for the profile - const auto profileID = [[SentryId alloc] init]; - [self serializeBasicProfileInfo:payload profileID:profileID transaction:transaction]; - return [self envelopeItemForProfileData:payload profileID:profileID]; } @@ -475,6 +573,25 @@ + (void)useFramesTracker:(SentryFramesTracker *)framesTracker # pragma mark - Private ++ (NSDictionary *)serializeForTransaction:(SentryTransaction *)transaction + profileID:(SentryId *)profileID +{ + std::lock_guard l(_gProfilerLock); + + if (_gCurrentProfiler == nil) { + SENTRY_LOG_DEBUG(@"No profiler from which to receive data."); + return nil; + } + + return serializedProfileData([_gCurrentProfiler->_state copyProfilingData], transaction, + profileID, profilerTruncationReasonName(_gCurrentProfiler->_truncationReason), + _gCurrentProfiler -> _hub.scope.environmentString + ?: _gCurrentProfiler->_hub.getClient.options.environment, + _gCurrentProfiler->_hub.getClient.options.releaseName, + [_gCurrentProfiler->_metricProfiler serializeForTransaction:transaction], + [_gCurrentProfiler->_debugImageProvider getDebugImages]); +} + + (void)timeoutAbort { std::lock_guard l(_gProfilerLock); @@ -576,80 +693,20 @@ - (void)start SENTRY_LOG_DEBUG(@"Starting profiler."); - _profileData = [NSMutableDictionary dictionary]; - const auto sampledProfile = [NSMutableDictionary dictionary]; - - /* - * Maintain an index of unique frames to avoid duplicating large amounts of data. Every - * unique frame is stored in an array, and every time a stack trace is captured for a - * sample, the stack is stored as an array of integers indexing into the array of frames. - * Stacks are thusly also stored as unique elements in their own index, an array of arrays - * of frame indices, and each sample references a stack by index, to deduplicate common - * stacks between samples, such as when the same deep function call runs across multiple - * samples. - * - * E.g. if we have the following samples in the following function call stacks: - * - * v sample1 v sample2 v sample3 v sample4 - * |-foo--------|------------|-----| |-abc--------|------------|-----| - * |-bar-----|------------|--| |-def-----|------------|--| - * |-baz---|------------|-| |-ghi---|------------|-| - * - * Then we'd wind up with the following structures: - * - * frames: [ - * { function: foo, instruction_addr: ... }, - * { function: bar, instruction_addr: ... }, - * { function: baz, instruction_addr: ... }, - * { function: abc, instruction_addr: ... }, - * { function: def, instruction_addr: ... }, - * { function: ghi, instruction_addr: ... } - * ] - * stacks: [ [0, 1, 2], [3, 4, 5] ] - * samples: [ - * { stack_id: 0, ... }, - * { stack_id: 0, ... }, - * { stack_id: 1, ... }, - * { stack_id: 1, ... } - * ] - */ - const auto samples = [NSMutableArray array]; - const auto stacks = [NSMutableArray *> array]; - const auto frames = [NSMutableArray *> array]; - const auto frameIndexLookup = [NSMutableDictionary dictionary]; - const auto stackIndexLookup = [NSMutableDictionary dictionary]; - sampledProfile[@"samples"] = samples; - sampledProfile[@"stacks"] = stacks; - sampledProfile[@"frames"] = frames; - - const auto threadMetadata = [NSMutableDictionary dictionary]; - const auto queueMetadata = [NSMutableDictionary dictionary]; - sampledProfile[@"thread_metadata"] = threadMetadata; - sampledProfile[@"queue_metadata"] = queueMetadata; - _profileData[@"profile"] = sampledProfile; - - __weak const auto weakSelf = self; + SentryProfilingState *const state = [[SentryProfilingState alloc] init]; + _state = state; _profiler = std::make_shared( - [weakSelf, threadMetadata, queueMetadata, samples, mainThreadID = _mainThreadID, frames, - frameIndexLookup, stacks, stackIndexLookup](auto &backtrace) { - const auto strongSelf = weakSelf; - if (strongSelf == nil) { - SENTRY_LOG_WARN(@"Profiler instance no longer exists, cannot process next sample."); - return; - } - - // in test, we'll overwrite the sample's timestamp to one mocked by SentryCurrentDate etal. - // Doing this in a unified way between tests and production required extensive changes to - // the C++ layer, so we opted for this solution to avoid any potential breakages or - // performance hits there. + [state](auto &backtrace) { + // in test, we'll overwrite the sample's timestamp to one mocked by SentryCurrentDate + // etal. Doing this in a unified way between tests and production required extensive + // changes to the C++ layer, so we opted for this solution to avoid any potential + // breakages or performance hits there. # if defined(TEST) || defined(TESTCI) Backtrace backtraceCopy = backtrace; backtraceCopy.absoluteTimestamp = SentryCurrentDate.systemTime; - processBacktrace(backtraceCopy, threadMetadata, queueMetadata, samples, stacks, frames, - frameIndexLookup, stackIndexLookup); + [state appendBacktrace:backtraceCopy]; # else - processBacktrace(backtrace, threadMetadata, queueMetadata, samples, stacks, frames, - frameIndexLookup, stackIndexLookup); + [state appendBacktrace:backtrace]; # endif // defined(TEST) || defined(TESTCI) }, kSentryProfilerFrequencyHz); @@ -674,66 +731,7 @@ - (void)stop SENTRY_LOG_DEBUG(@"Stopped profiler %@.", self); } -+ (void)serializeBasicProfileInfo:(NSMutableDictionary *)profile - profileID:(SentryId *const &)profileID - transaction:(SentryTransaction *)transaction -{ - profile[@"version"] = @"1"; - const auto debugImages = [NSMutableArray *> new]; - const auto debugMeta = [_gCurrentProfiler->_debugImageProvider getDebugImages]; - for (SentryDebugMeta *debugImage in debugMeta) { - [debugImages addObject:[debugImage serialize]]; - } - if (debugImages.count > 0) { - profile[@"debug_meta"] = @{ @"images" : debugImages }; - } - - profile[@"os"] = @{ - @"name" : sentry_getOSName(), - @"version" : sentry_getOSVersion(), - @"build_number" : sentry_getOSBuildNumber() - }; - - const auto isEmulated = sentry_isSimulatorBuild(); - profile[@"device"] = @{ - @"architecture" : sentry_getCPUArchitecture(), - @"is_emulator" : @(isEmulated), - @"locale" : NSLocale.currentLocale.localeIdentifier, - @"manufacturer" : @"Apple", - @"model" : isEmulated ? sentry_getSimulatorDeviceModel() : sentry_getDeviceModel() - }; - - profile[@"profile_id"] = profileID.sentryIdString; - profile[@"truncation_reason"] - = profilerTruncationReasonName(_gCurrentProfiler->_truncationReason); - profile[@"platform"] = transaction.platform; - profile[@"environment"] = _gCurrentProfiler->_hub.scope.environmentString - ?: _gCurrentProfiler->_hub.getClient.options.environment; - - const auto timestamp = transaction.trace.originalStartTimestamp; - if (UNLIKELY(timestamp == nil)) { - SENTRY_LOG_WARN(@"There was no start timestamp on the provided transaction. Falling back " - @"to old behavior of using the current time."); - profile[@"timestamp"] = [[SentryCurrentDate date] sentry_toIso8601String]; - } else { - profile[@"timestamp"] = [timestamp sentry_toIso8601String]; - } - - profile[@"release"] = _gCurrentProfiler->_hub.getClient.options.releaseName; -} - -/** @return serialize info corresponding to the specified transaction. */ -+ (NSDictionary *)serializeInfoForTransaction:(SentryTransaction *)transaction -{ - return @{ - @"id" : transaction.eventId.sentryIdString, - @"trace_id" : transaction.trace.traceId.sentryIdString, - @"name" : transaction.transaction, - @"active_thread_id" : [transaction.trace.transactionContext sentry_threadInfo].threadId - }; -} - -+ (SentryEnvelopeItem *)envelopeItemForProfileData:(NSMutableDictionary *)profile ++ (SentryEnvelopeItem *)envelopeItemForProfileData:(NSDictionary *)profile profileID:(SentryId *)profileID { const auto JSONData = [SentrySerialization dataWithJSONObject:profile]; diff --git a/Sources/Sentry/SentryTracer.m b/Sources/Sentry/SentryTracer.m index a9388aefa2c..cfe62b28a81 100644 --- a/Sources/Sentry/SentryTracer.m +++ b/Sources/Sentry/SentryTracer.m @@ -75,6 +75,7 @@ @implementation SentryTracer { NSMutableArray> *_children; BOOL _startTimeChanged; NSDate *_originalStartTimestamp; + NSObject *_idleTimeoutLock; #if SENTRY_HAS_UIKIT NSUInteger initTotalFrames; @@ -125,6 +126,7 @@ - (instancetype)initWithTransactionContext:(SentryTransactionContext *)transacti appStartMeasurement = [self getAppStartMeasurement]; + _idleTimeoutLock = [[NSObject alloc] init]; if ([self hasIdleTimeout]) { [self dispatchIdleTimeout]; } @@ -164,26 +166,28 @@ - (nullable SentryTracer *)tracer - (void)dispatchIdleTimeout { - if (_idleTimeoutBlock != nil) { - [_configuration.dispatchQueueWrapper dispatchCancel:_idleTimeoutBlock]; - } - __weak SentryTracer *weakSelf = self; - _idleTimeoutBlock = [_configuration.dispatchQueueWrapper createDispatchBlock:^{ - if (weakSelf == nil) { - SENTRY_LOG_DEBUG(@"WeakSelf is nil. Not doing anything."); - return; + @synchronized(_idleTimeoutLock) { + if (_idleTimeoutBlock != NULL) { + [_configuration.dispatchQueueWrapper dispatchCancel:_idleTimeoutBlock]; + } + __weak SentryTracer *weakSelf = self; + _idleTimeoutBlock = [_configuration.dispatchQueueWrapper createDispatchBlock:^{ + if (weakSelf == nil) { + SENTRY_LOG_DEBUG(@"WeakSelf is nil. Not doing anything."); + return; + } + [weakSelf finishInternal]; + }]; + + if (_idleTimeoutBlock == NULL) { + SENTRY_LOG_WARN(@"Couldn't create idle time out block. Can't schedule idle timeout. " + @"Finishing transaction"); + // If the transaction has no children, the SDK will discard it. + [self finishInternal]; + } else { + [_configuration.dispatchQueueWrapper dispatchAfter:_configuration.idleTimeout + block:_idleTimeoutBlock]; } - [weakSelf finishInternal]; - }]; - - if (_idleTimeoutBlock == NULL) { - SENTRY_LOG_WARN(@"Couldn't create idle time out block. Can't schedule idle timeout. " - @"Finishing transaction"); - // If the transaction has no children, the SDK will discard it. - [self finishInternal]; - } else { - [_configuration.dispatchQueueWrapper dispatchAfter:_configuration.idleTimeout - block:_idleTimeoutBlock]; } } @@ -199,8 +203,10 @@ - (BOOL)isAutoGeneratedTransaction - (void)cancelIdleTimeout { - if ([self hasIdleTimeout]) { - [_configuration.dispatchQueueWrapper dispatchCancel:_idleTimeoutBlock]; + @synchronized(_idleTimeoutLock) { + if ([self hasIdleTimeout]) { + [_configuration.dispatchQueueWrapper dispatchCancel:_idleTimeoutBlock]; + } } } diff --git a/Sources/Sentry/SentryTransactionContext.mm b/Sources/Sentry/SentryTransactionContext.mm index 73bec3d3589..d0b94b9fe66 100644 --- a/Sources/Sentry/SentryTransactionContext.mm +++ b/Sources/Sentry/SentryTransactionContext.mm @@ -11,15 +11,6 @@ static const auto kSentryDefaultSamplingDecision = kSentrySampleDecisionUndecided; -@interface -SentryTransactionContext () - -#if SENTRY_TARGET_PROFILING_SUPPORTED -@property (nonatomic, strong) SentryThread *threadInfo; -#endif - -@end - @implementation SentryTransactionContext #pragma mark - Public diff --git a/Sources/Sentry/include/SentryProfileTimeseries.h b/Sources/Sentry/include/SentryProfileTimeseries.h index cac370d2324..a8d2203df5f 100644 --- a/Sources/Sentry/include/SentryProfileTimeseries.h +++ b/Sources/Sentry/include/SentryProfileTimeseries.h @@ -8,13 +8,6 @@ @class SentryTransaction; -/** - * Synchronizes reads and writes to the samples array; otherwise there will be a data race between - * when the sampling profiler tries to insert a new sample, and when we iterate over the sample - * array with fast enumeration to extract only those samples needed for a given transaction. - */ -SENTRY_EXTERN std::mutex _gSamplesArrayLock; - NS_ASSUME_NONNULL_BEGIN /** A storage class to hold the data associated with a single profiler sample. */ diff --git a/Sources/Sentry/include/SentryProfiler+Private.h b/Sources/Sentry/include/SentryProfiler+Private.h new file mode 100644 index 00000000000..8ba1a27e6f5 --- /dev/null +++ b/Sources/Sentry/include/SentryProfiler+Private.h @@ -0,0 +1,69 @@ +#import "SentryBacktrace.hpp" +#import "SentryProfilingConditionals.h" +#import + +#if SENTRY_TARGET_PROFILING_SUPPORTED + +NS_ASSUME_NONNULL_BEGIN + +@class SentrySample; + +@interface SentryProfilingMutableState : NSObject +@property (nonatomic, strong, readonly) NSMutableArray *samples; +@property (nonatomic, strong, readonly) NSMutableArray *> *stacks; +@property (nonatomic, strong, readonly) NSMutableArray *> *frames; +@property (nonatomic, strong, readonly) + NSMutableDictionary *threadMetadata; +@property (nonatomic, strong, readonly) + NSMutableDictionary *queueMetadata; + +/* + * Maintain an index of unique frames to avoid duplicating large amounts of data. Every + * unique frame is stored in an array, and every time a stack trace is captured for a + * sample, the stack is stored as an array of integers indexing into the array of frames. + * Stacks are thusly also stored as unique elements in their own index, an array of arrays + * of frame indices, and each sample references a stack by index, to deduplicate common + * stacks between samples, such as when the same deep function call runs across multiple + * samples. + * + * E.g. if we have the following samples in the following function call stacks: + * + * v sample1 v sample2 v sample3 v sample4 + * |-foo--------|------------|-----| |-abc--------|------------|-----| + * |-bar-----|------------|--| |-def-----|------------|--| + * |-baz---|------------|-| |-ghi---|------------|-| + * + * Then we'd wind up with the following structures: + * + * frames: [ + * { function: foo, instruction_addr: ... }, + * { function: bar, instruction_addr: ... }, + * { function: baz, instruction_addr: ... }, + * { function: abc, instruction_addr: ... }, + * { function: def, instruction_addr: ... }, + * { function: ghi, instruction_addr: ... } + * ] + * stacks: [ [0, 1, 2], [3, 4, 5] ] + * samples: [ + * { stack_id: 0, ... }, + * { stack_id: 0, ... }, + * { stack_id: 1, ... }, + * { stack_id: 1, ... } + * ] + */ +@property (nonatomic, strong, readonly) + NSMutableDictionary *frameIndexLookup; +@property (nonatomic, strong, readonly) + NSMutableDictionary *stackIndexLookup; +@end + +@interface SentryProfilingState : NSObject +// All functions are safe to call from multiple threads concurrently +- (void)mutate:(void (^)(SentryProfilingMutableState *))block; +- (void)appendBacktrace:(const sentry::profiling::Backtrace &)backtrace; +- (NSDictionary *)copyProfilingData; +@end + +NS_ASSUME_NONNULL_END + +#endif diff --git a/Sources/Sentry/include/SentryProfiler+Test.h b/Sources/Sentry/include/SentryProfiler+Test.h index 958c10a5008..ee07199123e 100644 --- a/Sources/Sentry/include/SentryProfiler+Test.h +++ b/Sources/Sentry/include/SentryProfiler+Test.h @@ -1,20 +1,21 @@ #include "SentryBacktrace.hpp" +#import "SentryProfiler+Private.h" #import "SentryProfiler.h" #import "SentryProfilingConditionals.h" #if SENTRY_TARGET_PROFILING_SUPPORTED +@class SentryDebugMeta; +@class SentryId; @class SentrySample; +@class SentryTransaction; NS_ASSUME_NONNULL_BEGIN -void processBacktrace(const sentry::profiling::Backtrace &backtrace, - NSMutableDictionary *threadMetadata, - NSMutableDictionary *queueMetadata, - NSMutableArray *samples, NSMutableArray *> *stacks, - NSMutableArray *> *frames, - NSMutableDictionary *frameIndexLookup, - NSMutableDictionary *stackIndexLookup); +NSDictionary *serializedProfileData(NSDictionary *profileData, + SentryTransaction *transaction, SentryId *profileID, NSString *truncationReason, + NSString *environment, NSString *release, NSDictionary *serializedMetrics, + NSArray *debugMeta); NS_ASSUME_NONNULL_END diff --git a/Sources/Sentry/include/SentryProfiler.h b/Sources/Sentry/include/SentryProfiler.h index 2bfa6d16f26..2fa99f8331c 100644 --- a/Sources/Sentry/include/SentryProfiler.h +++ b/Sources/Sentry/include/SentryProfiler.h @@ -21,7 +21,6 @@ typedef NS_ENUM(NSUInteger, SentryProfilerTruncationReason) { NS_ASSUME_NONNULL_BEGIN SENTRY_EXTERN const int kSentryProfilerFrequencyHz; -SENTRY_EXTERN NSString *const kTestStringConst; SENTRY_EXTERN NSString *const kSentryProfilerSerializationKeySlowFrameRenders; SENTRY_EXTERN NSString *const kSentryProfilerSerializationKeyFrozenFrameRenders; diff --git a/Sources/Sentry/include/SentryTransactionContext+Private.h b/Sources/Sentry/include/SentryTransactionContext+Private.h index 14f3061e771..92a572c5dfb 100644 --- a/Sources/Sentry/include/SentryTransactionContext+Private.h +++ b/Sources/Sentry/include/SentryTransactionContext+Private.h @@ -4,7 +4,7 @@ NS_ASSUME_NONNULL_BEGIN @interface -SentryTransactionContext (Private) +SentryTransactionContext () - (instancetype)initWithName:(NSString *)name nameSource:(SentryTransactionNameSource)source @@ -37,6 +37,10 @@ SentryTransactionContext (Private) parentSampled:(SentrySampleDecision)parentSampled; #if SENTRY_TARGET_PROFILING_SUPPORTED +// This is currently only exposed for testing purposes, see -[SentryProfilerTests +// testProfilerMutationDuringSerialization] +@property (nonatomic, strong) SentryThread *threadInfo; + - (SentryThread *)sentry_threadInfo; #endif diff --git a/Tests/SentryProfilerTests/SentryProfilerTests.mm b/Tests/SentryProfilerTests/SentryProfilerTests.mm index b947c6bedb1..2ab454a1e4c 100644 --- a/Tests/SentryProfilerTests/SentryProfilerTests.mm +++ b/Tests/SentryProfilerTests/SentryProfilerTests.mm @@ -1,8 +1,11 @@ #import "SentryEvent+Private.h" +#import "SentryId.h" #import "SentryProfileTimeseries.h" #import "SentryProfiler+Test.h" #import "SentryProfilingConditionals.h" +#import "SentryThread.h" #import "SentryTransaction.h" +#import "SentryTransactionContext+Private.h" #if SENTRY_TARGET_PROFILING_SUPPORTED @@ -57,15 +60,7 @@ - (void)testProfilerCanBeInitializedOffMainThread - (void)testProfilerMutationDuringSlicing { - const auto resolvedThreadMetadata = - [NSMutableDictionary dictionary]; - const auto resolvedQueueMetadata = [NSMutableDictionary dictionary]; - const auto resolvedStacks = [NSMutableArray *> array]; - const auto resolvedSamples = [NSMutableArray array]; - const auto resolvedFrames = [NSMutableArray *> array]; - const auto frameIndexLookup = [NSMutableDictionary dictionary]; - const auto stackIndexLookup = [NSMutableDictionary dictionary]; - + SentryProfilingState *state = [[SentryProfilingState alloc] init]; // generate a large timeseries of simulated data const auto threads = 5; @@ -97,9 +92,7 @@ - (void)testProfilerMutationDuringSlicing for (auto sample = 0; sample < samplesPerThread; sample++) { backtrace.absoluteTimestamp = sampleIdx; // simulate 1 sample per nanosecond - processBacktrace(backtrace, resolvedThreadMetadata, resolvedQueueMetadata, - resolvedSamples, resolvedStacks, resolvedFrames, frameIndexLookup, - stackIndexLookup); + [state appendBacktrace:backtrace]; ++sampleIdx; } } @@ -124,8 +117,10 @@ - (void)testProfilerMutationDuringSlicing sliceExpectation.expectedFulfillmentCount = operations; void (^sliceBlock)(void) = ^(void) { - __unused const auto slice = slicedProfileSamples(resolvedSamples, transaction); - [sliceExpectation fulfill]; + [state mutate:^(SentryProfilingMutableState *mutableState) { + __unused const auto slice = slicedProfileSamples(mutableState.samples, transaction); + [sliceExpectation fulfill]; + }]; }; ThreadMetadata threadMetadata; @@ -150,9 +145,8 @@ - (void)testProfilerMutationDuringSlicing mutateExpectation.expectedFulfillmentCount = operations; void (^mutateBlock)(void) = ^(void) { - processBacktrace(backtrace, resolvedThreadMetadata, resolvedQueueMetadata, resolvedSamples, - resolvedStacks, resolvedFrames, frameIndexLookup, stackIndexLookup); - [mutateExpectation fulfill]; + [state mutate:^( + __unused SentryProfilingMutableState *mutableState) { [mutateExpectation fulfill]; }]; }; const auto sliceOperations = [[NSOperationQueue alloc] init]; // concurrent queue @@ -168,16 +162,132 @@ - (void)testProfilerMutationDuringSlicing [self waitForExpectationsWithTimeout:1 handler:nil]; } +/** + * We received reports of crashes happening during serialization, which turned out to be caused by a + * data race in the collections we use to store profiler information, which are block-enumerated by + * NSJSONSerialization, which is not a thread-safe operation. So when the backtrace profiler + * modified the same collection from another thread while the block enumeration was in progress, a + * crash occurred. The solution is twofold: + * 1. copy the data structures so that serialization works with a new instance that will never be + * modified by the backtrace sampler thread + * 2. force exclusive access to the data structures so that they are never modified during any + * other operation, even the copy + */ +- (void)testProfilerMutationDuringSerialization +{ + SentryProfilingState *state = [[SentryProfilingState alloc] init]; + // initialize the data structures with some simulated data + { + ThreadMetadata threadMetadata; + // leave thread name as nil so it can be overwritten later + threadMetadata.threadID = 1; + threadMetadata.priority = 2; + + QueueMetadata queueMetadata; + queueMetadata.address = 3; + queueMetadata.label = std::make_shared("testQueue-1"); + + Backtrace backtrace; + backtrace.threadMetadata = threadMetadata; + backtrace.queueMetadata = queueMetadata; + backtrace.addresses = std::vector({ 0x4, 0x5, 0x6 }); + + backtrace.absoluteTimestamp = 1; + [state appendBacktrace:backtrace]; + + backtrace.absoluteTimestamp = 2; + [state appendBacktrace:backtrace]; + } + + // serialize the data as if it were captured in a transaction envelope + const auto profileData = [state copyProfilingData]; + + const auto context = [[SentrySpanContext alloc] initWithOperation:@"test trace"]; + const auto trace = [[SentryTracer alloc] initWithContext:context]; + const auto transaction = [[SentryTransaction alloc] initWithTrace:trace children:@[]]; + transaction.transaction = @"someTransaction"; + transaction.trace.transactionContext = + [[SentryTransactionContext alloc] initWithName:@"someTransaction" + operation:@"someOperation"]; + transaction.trace.transactionContext.threadInfo = [[SentryThread alloc] initWithThreadId:@1]; + transaction.startSystemTime = 1; + transaction.endSystemTime = 2; + + const auto profileID = [[SentryId alloc] init]; + const auto serialization = serializedProfileData(profileData, transaction, profileID, + profilerTruncationReasonName(SentryProfilerTruncationReasonNormal), @"test", @"someRelease", + @{}, @[]); + + // cause the data structures to be modified again: add new addresses + { + ThreadMetadata threadMetadata; + threadMetadata.name = "newThread-2"; + threadMetadata.threadID = 12345568910; + threadMetadata.priority = 666; + + QueueMetadata queueMetadata; + queueMetadata.address = 9876543210; + queueMetadata.label = std::make_shared("newQueue-2"); + + Backtrace backtrace; + backtrace.threadMetadata = threadMetadata; + backtrace.queueMetadata = queueMetadata; + backtrace.absoluteTimestamp = 5; + backtrace.addresses = std::vector({ 0x777, 0x888, 0x999 }); + + [state appendBacktrace:backtrace]; + } + + // cause the data structures to be modified again: overwrite previous thread metadata + // subdictionary contents + { + ThreadMetadata threadMetadata; + threadMetadata.name = "testThread-1"; + threadMetadata.threadID = 1; + threadMetadata.priority = 2; + + QueueMetadata queueMetadata; + queueMetadata.address = 3; + queueMetadata.label = std::make_shared("testQueue-1"); + + Backtrace backtrace; + backtrace.threadMetadata = threadMetadata; + backtrace.queueMetadata = queueMetadata; + backtrace.absoluteTimestamp = 6; + backtrace.addresses = std::vector({ 0x4, 0x5, 0x6 }); + + [state appendBacktrace:backtrace]; + } + + // ensure the serialization's copied data structures don't contain the new addresses + NSArray *> *frames = serialization[@"profile"][@"frames"]; + XCTAssertEqual(frames.count, 3UL, + @"New frames appeared in the data structure that should have been copied for serialization " + @"and should no longer be modifiable from the backtrace sampler thread."); + + const auto index = + [frames indexOfObjectPassingTest:^BOOL(NSDictionary *_Nonnull obj, + __unused NSUInteger idx, __unused BOOL *_Nonnull stop) { + NSString *address = obj[@"instruction_addr"]; + const auto unexpected = + @[ @"0x0000000000000777", @"0x0000000000000888", @"0x0000000000000999" ]; + return [unexpected containsObject:address]; + }]; + XCTAssertEqual(index, NSNotFound, + @"The data structures copied for serialization should not be modified with subsequent " + @"calls from the backtrace sampler. The new backtrace addresses should not appear in the " + @"copies of the profiling data structures after calling the serialization function."); + + // ensure the serialization's copied data structures don't get the updated thread info + XCTAssertNil(serialization[@"profile"][@"thread_metadata"][@"1"][@"name"], + @"Thread metadata had a nil thread name at time of serialization, but modification " + @"overwrote it later and that change propagated to the serialization copy of the profiling " + @"data structure."); +} + - (void)testProfilerPayload { - const auto resolvedThreadMetadata = - [NSMutableDictionary dictionary]; - const auto resolvedQueueMetadata = [NSMutableDictionary dictionary]; - const auto resolvedStacks = [NSMutableArray *> array]; - const auto resolvedSamples = [NSMutableArray array]; - const auto resolvedFrames = [NSMutableArray *> array]; - const auto frameIndexLookup = [NSMutableDictionary dictionary]; - const auto stackIndexLookup = [NSMutableDictionary dictionary]; + SentryProfilingState *state = [[SentryProfilingState alloc] init]; // record an initial backtrace @@ -190,7 +300,7 @@ - (void)testProfilerPayload queueMetadata1.address = 9876543210; queueMetadata1.label = std::make_shared("testQueue"); - const auto addresses1 = std::vector({ 123, 456, 789 }); + const auto addresses1 = std::vector({ 0x123, 0x456, 0x789 }); Backtrace backtrace1; backtrace1.threadMetadata = threadMetadata1; @@ -198,8 +308,7 @@ - (void)testProfilerPayload backtrace1.absoluteTimestamp = 5; backtrace1.addresses = addresses1; - processBacktrace(backtrace1, resolvedThreadMetadata, resolvedQueueMetadata, resolvedSamples, - resolvedStacks, resolvedFrames, frameIndexLookup, stackIndexLookup); + [state appendBacktrace:backtrace1]; // record a second backtrace with some common addresses to test frame deduplication @@ -212,7 +321,7 @@ - (void)testProfilerPayload queueMetadata2.address = 9876543210; queueMetadata2.label = std::make_shared("testQueue"); - const auto addresses2 = std::vector({ 777, 888, 789 }); + const auto addresses2 = std::vector({ 0x777, 0x888, 0x789 }); Backtrace backtrace2; backtrace2.threadMetadata = threadMetadata2; @@ -220,17 +329,27 @@ - (void)testProfilerPayload backtrace2.absoluteTimestamp = 5; backtrace2.addresses = addresses2; - processBacktrace(backtrace2, resolvedThreadMetadata, resolvedQueueMetadata, resolvedSamples, - resolvedStacks, resolvedFrames, frameIndexLookup, stackIndexLookup); + [state appendBacktrace:backtrace2]; + + // record a third backtrace that's identical to the second to test stack/frame deduplication - // record a third backtrace that's identical to the second to test stack deduplication + [state appendBacktrace:backtrace2]; - processBacktrace(backtrace2, resolvedThreadMetadata, resolvedQueueMetadata, resolvedSamples, - resolvedStacks, resolvedFrames, frameIndexLookup, stackIndexLookup); + [state mutate:^(SentryProfilingMutableState *mutableState) { + XCTAssertEqual(mutableState.frames.count, 5UL); + const auto expectedOrdered = @[ + @"0x0000000000000123", @"0x0000000000000456", @"0x0000000000000789", + @"0x0000000000000777", @"0x0000000000000888" + ]; + [mutableState.frames + enumerateObjectsUsingBlock:^(NSDictionary *_Nonnull actualFrame, + NSUInteger idx, __unused BOOL *_Nonnull stop) { + XCTAssert([actualFrame[@"instruction_addr"] isEqualToString:expectedOrdered[idx]]); + }]; - XCTAssertEqual(resolvedFrames.count, 5UL); - XCTAssertEqual(resolvedStacks.count, 2UL); - XCTAssertEqual(resolvedSamples.count, 3UL); + XCTAssertEqual(mutableState.stacks.count, 2UL); + XCTAssertEqual(mutableState.samples.count, 3UL); + }]; } @end diff --git a/Tests/SentryTests/Transaction/SentryTracerTests.swift b/Tests/SentryTests/Transaction/SentryTracerTests.swift index d5c86020dfa..8487135e718 100644 --- a/Tests/SentryTests/Transaction/SentryTracerTests.swift +++ b/Tests/SentryTests/Transaction/SentryTracerTests.swift @@ -211,6 +211,15 @@ class SentryTracerTests: XCTestCase { XCTAssertFalse(fixture.timerWrapper.overrides.timer.isValid) } + + func testDeadlineTimer_MultipleSpansFinishedInParallel() { + let sut = fixture.getSut(idleTimeout: 0.01, dispatchQueueWrapper: SentryDispatchQueueWrapper()) + + testConcurrentModifications(writeWork: { _ in + let child = sut.startChild(operation: self.fixture.transactionOperation) + child.finish() + }) + } func testFinish_CheckDefaultStatus() { let sut = fixture.getSut()