From 4a0c2822a7cd9f2ff56a4200af04533585b0a2cc Mon Sep 17 00:00:00 2001 From: Kevin Renskers Date: Mon, 3 Oct 2022 10:47:13 +0200 Subject: [PATCH] fix: Return SentryNoOpSpan when starting a child on a finished transaction (#2239) * fix: Starting a new span on a finished span results in a SentryNoOpSpan Closes #1624 * Add a test * Changelog * Fix test * Fix test * Move changelog (this is such an annoying manual thing to keep fixing) * Whoops * Fix tests (why does this work locally?) * Clean up * Use self.tracer.isFinished * Add testStartGrandChildOnFinishedSpan * Move logic to SentryTracer --- CHANGELOG.md | 6 +++ Sentry.xcodeproj/project.pbxproj | 4 ++ Sources/Sentry/SentrySpan.m | 1 + Sources/Sentry/SentryTracer.m | 7 ++++ Tests/SentryTests/Helper/SentryLogTests.swift | 9 ----- .../SentryBaseIntegrationTests.swift | 7 ---- .../Performance/SentryTracerObjCTests.m | 1 - .../Performance/SentryTracerTests.swift | 3 +- Tests/SentryTests/TestLogOutput.swift | 8 ++++ .../Transaction/SentrySpanTests.swift | 37 +++++++++++++++++-- 10 files changed, 62 insertions(+), 21 deletions(-) create mode 100644 Tests/SentryTests/TestLogOutput.swift diff --git a/CHANGELOG.md b/CHANGELOG.md index 8a6783d653e..0fab681a1ad 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,11 @@ # Changelog +## Unreleased + +### Fixes + +- Return SentryNoOpSpan when starting a child on a finished transaction (#2239) + ## 7.27.0 ### Features diff --git a/Sentry.xcodeproj/project.pbxproj b/Sentry.xcodeproj/project.pbxproj index 2f5b0137c77..51b3821838b 100644 --- a/Sentry.xcodeproj/project.pbxproj +++ b/Sentry.xcodeproj/project.pbxproj @@ -37,6 +37,7 @@ 03F84D3727DD4191008FE43F /* SentrySamplingProfiler.cpp in Sources */ = {isa = PBXBuildFile; fileRef = 03F84D3027DD4191008FE43F /* SentrySamplingProfiler.cpp */; }; 03F84D3827DD4191008FE43F /* SentryBacktrace.cpp in Sources */ = {isa = PBXBuildFile; fileRef = 03F84D3127DD4191008FE43F /* SentryBacktrace.cpp */; }; 03F9D37C2819A65C00602916 /* SentryProfilerTests.mm in Sources */ = {isa = PBXBuildFile; fileRef = 03F9D37B2819A65C00602916 /* SentryProfilerTests.mm */; }; + 0A1B497328E597DD00D7BFA3 /* TestLogOutput.swift in Sources */ = {isa = PBXBuildFile; fileRef = 0A1B497228E597DD00D7BFA3 /* TestLogOutput.swift */; }; 0A1C3592287D7107007D01E3 /* SentryMetaTests.swift in Sources */ = {isa = PBXBuildFile; fileRef = 0A1C3591287D7107007D01E3 /* SentryMetaTests.swift */; }; 0A2690B72885C2E000E4432D /* TestSentryPermissionsObserver.swift in Sources */ = {isa = PBXBuildFile; fileRef = 0AABE2EF2885C2120057ED69 /* TestSentryPermissionsObserver.swift */; }; 0A2D8D5B289815C0008720F6 /* SentryBaseIntegration.m in Sources */ = {isa = PBXBuildFile; fileRef = 0A2D8D5A289815C0008720F6 /* SentryBaseIntegration.m */; }; @@ -743,6 +744,7 @@ 03F84D3027DD4191008FE43F /* SentrySamplingProfiler.cpp */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.cpp.cpp; name = SentrySamplingProfiler.cpp; path = Sources/Sentry/SentrySamplingProfiler.cpp; sourceTree = SOURCE_ROOT; }; 03F84D3127DD4191008FE43F /* SentryBacktrace.cpp */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.cpp.cpp; name = SentryBacktrace.cpp; path = Sources/Sentry/SentryBacktrace.cpp; sourceTree = SOURCE_ROOT; }; 03F9D37B2819A65C00602916 /* SentryProfilerTests.mm */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.cpp.objcpp; path = SentryProfilerTests.mm; sourceTree = ""; }; + 0A1B497228E597DD00D7BFA3 /* TestLogOutput.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = TestLogOutput.swift; sourceTree = ""; }; 0A1C3591287D7107007D01E3 /* SentryMetaTests.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = SentryMetaTests.swift; sourceTree = ""; }; 0A2D8D5A289815C0008720F6 /* SentryBaseIntegration.m */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.objc; path = SentryBaseIntegration.m; sourceTree = ""; }; 0A2D8D5C289815EB008720F6 /* SentryBaseIntegration.h */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.h; name = SentryBaseIntegration.h; path = include/SentryBaseIntegration.h; sourceTree = ""; }; @@ -1885,6 +1887,7 @@ 7B6D1262265F7CC600C9BE4B /* PrivateSentrySDKOnlyTests.swift */, 8ED3D305264DFE700049393B /* SentryUIViewControllerSanitizerTests.swift */, D8918B212849FA6D00701F9A /* SentrySDKIntegrationTestsBase.swift */, + 0A1B497228E597DD00D7BFA3 /* TestLogOutput.swift */, ); path = SentryTests; sourceTree = ""; @@ -3653,6 +3656,7 @@ 7B68D93625FF5F1A0082D139 /* SentryAppState+Equality.m in Sources */, 7B5CAF7E27F5AD3500ED0DB6 /* TestNSURLRequestBuilder.m in Sources */, 8EAC7FF8265C8910005B44E5 /* SentryTracerTests.swift in Sources */, + 0A1B497328E597DD00D7BFA3 /* TestLogOutput.swift in Sources */, 7BA61CBD247BC6B900C130A8 /* TestSentryCrashBinaryImageProvider.swift in Sources */, 7BFA69F627E0840400233199 /* SentryANRTrackingIntegrationTests.swift in Sources */, 7BBD18B62451807600427C76 /* SentryDefaultRateLimitsTests.swift in Sources */, diff --git a/Sources/Sentry/SentrySpan.m b/Sources/Sentry/SentrySpan.m index 2238dd66259..2dab3697943 100644 --- a/Sources/Sentry/SentrySpan.m +++ b/Sources/Sentry/SentrySpan.m @@ -2,6 +2,7 @@ #import "NSDate+SentryExtras.h" #import "NSDictionary+SentrySanitize.h" #import "SentryCurrentDate.h" +#import "SentryLog.h" #import "SentryNoOpSpan.h" #import "SentryTraceHeader.h" #import "SentryTracer.h" diff --git a/Sources/Sentry/SentryTracer.m b/Sources/Sentry/SentryTracer.m index 97f9fcc701a..29baa07c68f 100644 --- a/Sources/Sentry/SentryTracer.m +++ b/Sources/Sentry/SentryTracer.m @@ -7,6 +7,7 @@ #import "SentryFramesTracker.h" #import "SentryHub+Private.h" #import "SentryLog.h" +#import "SentryNoOpSpan.h" #import "SentryProfiler.h" #import "SentryProfilesSampler.h" #import "SentryProfilingConditionals.h" @@ -261,6 +262,12 @@ - (void)cancelIdleTimeout { [self cancelIdleTimeout]; + if (self.isFinished) { + SENTRY_LOG_WARN( + @"Starting a child on a finished span is not supported; it won't be sent to Sentry."); + return [SentryNoOpSpan shared]; + } + SentrySpanContext *context = [[SentrySpanContext alloc] initWithTraceId:_rootSpan.context.traceId spanId:[[SentrySpanId alloc] init] diff --git a/Tests/SentryTests/Helper/SentryLogTests.swift b/Tests/SentryTests/Helper/SentryLogTests.swift index b1383a9f317..143c0f0a603 100644 --- a/Tests/SentryTests/Helper/SentryLogTests.swift +++ b/Tests/SentryTests/Helper/SentryLogTests.swift @@ -68,13 +68,4 @@ class SentryLogTests: XCTestCase { "Sentry - info:: 3", "Sentry - debug:: 4"], logOutput.loggedMessages) } - - class TestLogOutput: SentryLogOutput { - - var loggedMessages: [String] = [] - override func log(_ message: String) { - loggedMessages.append(message) - } - } - } diff --git a/Tests/SentryTests/Integrations/SentryBaseIntegrationTests.swift b/Tests/SentryTests/Integrations/SentryBaseIntegrationTests.swift index 573aebeeaab..3089f4976fd 100644 --- a/Tests/SentryTests/Integrations/SentryBaseIntegrationTests.swift +++ b/Tests/SentryTests/Integrations/SentryBaseIntegrationTests.swift @@ -48,11 +48,4 @@ class SentryBaseIntegrationTests: XCTestCase { XCTAssertFalse(result) XCTAssertEqual(["Sentry - debug:: Not going to enable SentryTests.MyTestIntegration because enableAutoSessionTracking is disabled."], logOutput.loggedMessages) } - - class TestLogOutput: SentryLogOutput { - var loggedMessages: [String] = [] - override func log(_ message: String) { - loggedMessages.append(message) - } - } } diff --git a/Tests/SentryTests/Performance/SentryTracerObjCTests.m b/Tests/SentryTests/Performance/SentryTracerObjCTests.m index d4f2f2f4538..b0d31cd6f7f 100644 --- a/Tests/SentryTests/Performance/SentryTracerObjCTests.m +++ b/Tests/SentryTests/Performance/SentryTracerObjCTests.m @@ -31,7 +31,6 @@ - (void)testSpanFinishesAfterTracerReleased_NoCrash_TracerIsNil } XCTAssertNotNil(child); - XCTAssertNil(child.tracer); [child finish]; } diff --git a/Tests/SentryTests/Performance/SentryTracerTests.swift b/Tests/SentryTests/Performance/SentryTracerTests.swift index 62d1e4b7d66..0bc3295d991 100644 --- a/Tests/SentryTests/Performance/SentryTracerTests.swift +++ b/Tests/SentryTests/Performance/SentryTracerTests.swift @@ -262,7 +262,8 @@ class SentryTracerTests: XCTestCase { child.finish() XCTAssertEqual(2, fixture.dispatchQueue.dispatchAfterInvocations.count) - + + // The grandchild is a NoOp span let grandChild = child.startChild(operation: fixture.transactionOperation) XCTAssertEqual(3, fixture.dispatchQueue.dispatchCancelInvocations.count) diff --git a/Tests/SentryTests/TestLogOutput.swift b/Tests/SentryTests/TestLogOutput.swift new file mode 100644 index 00000000000..84331fa4120 --- /dev/null +++ b/Tests/SentryTests/TestLogOutput.swift @@ -0,0 +1,8 @@ +import Foundation + +class TestLogOutput: SentryLogOutput { + var loggedMessages: [String] = [] + override func log(_ message: String) { + loggedMessages.append(message) + } +} diff --git a/Tests/SentryTests/Transaction/SentrySpanTests.swift b/Tests/SentryTests/Transaction/SentrySpanTests.swift index 6e86d33dd74..ed0b0ce1ab3 100644 --- a/Tests/SentryTests/Transaction/SentrySpanTests.swift +++ b/Tests/SentryTests/Transaction/SentrySpanTests.swift @@ -2,7 +2,9 @@ import Sentry import XCTest class SentrySpanTests: XCTestCase { - + private var logOutput: TestLogOutput! + private var fixture: Fixture! + private class Fixture { let someTransaction = "Some Transaction" let someOperation = "Some Operation" @@ -12,7 +14,7 @@ class SentrySpanTests: XCTestCase { let options: Options let currentDateProvider = TestCurrentDateProvider() let tracer = SentryTracer() - + init() { options = Options() options.tracesSampleRate = 1 @@ -32,9 +34,13 @@ class SentrySpanTests: XCTestCase { } - private var fixture: Fixture! override func setUp() { super.setUp() + + logOutput = TestLogOutput() + SentryLog.configure(true, diagnosticLevel: SentryLevel.debug) + SentryLog.setLogOutput(logOutput) + fixture = Fixture() CurrentDate.setCurrentDateProvider(fixture.currentDateProvider) } @@ -153,6 +159,31 @@ class SentrySpanTests: XCTestCase { XCTAssertEqual(childSpan.context.operation, fixture.someOperation) XCTAssertEqual(childSpan.context.spanDescription, fixture.someDescription) } + + func testStartChildOnFinishedSpan() { + let span = fixture.getSut() + span.finish() + + let childSpan = span.startChild(operation: fixture.someOperation, description: fixture.someDescription) + + XCTAssertNil(childSpan.context.parentSpanId) + XCTAssertEqual(childSpan.context.operation, "") + XCTAssertNil(childSpan.context.spanDescription) + XCTAssertTrue(logOutput.loggedMessages.contains("Sentry - warning:: Starting a child on a finished span is not supported; it won\'t be sent to Sentry.")) + } + + func testStartGrandChildOnFinishedSpan() { + let span = fixture.getSut() + let childSpan = span.startChild(operation: fixture.someOperation) + childSpan.finish() + span.finish() + + let grandChild = childSpan.startChild(operation: fixture.someOperation, description: fixture.someDescription) + XCTAssertNil(grandChild.context.parentSpanId) + XCTAssertEqual(grandChild.context.operation, "") + XCTAssertNil(grandChild.context.spanDescription) + XCTAssertTrue(logOutput.loggedMessages.contains("Sentry - warning:: Starting a child on a finished span is not supported; it won\'t be sent to Sentry.")) + } func testAddAndRemoveExtras() { let span = fixture.getSut()