diff --git a/CHANGELOG.md b/CHANGELOG.md index d4138889120..44bff4d10aa 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,7 +4,7 @@ ### Fixes -- Fix issue with invalid profiles uploading (#2358) +- Fix issue with invalid profiles uploading (#2358 and #2359) ## 7.30.0 diff --git a/Sources/Sentry/SentryProfiler.mm b/Sources/Sentry/SentryProfiler.mm index cb2fcdb801a..70b4cd1358c 100644 --- a/Sources/Sentry/SentryProfiler.mm +++ b/Sources/Sentry/SentryProfiler.mm @@ -574,19 +574,38 @@ - (void)captureEnvelope // populate info from all transactions that occurred while profiler was running auto transactionsInfo = [NSMutableArray array]; + SENTRY_LOG_DEBUG(@"Profile start timestamp: %@ absolute time: %llu", _startDate, + (unsigned long long)_startTimestamp); + SENTRY_LOG_DEBUG(@"Profile end timestamp: %@ absolute time: %llu", _endDate, + (unsigned long long)_endTimestamp); for (SentryTransaction *transaction in _transactions) { + SENTRY_LOG_DEBUG(@"Transaction %@ start timestamp: %@", transaction.trace.context.traceId, + transaction.startTimestamp); + SENTRY_LOG_DEBUG(@"Transaction %@ end timestamp: %@", transaction.trace.context.traceId, + transaction.timestamp); const auto relativeStart = [NSString stringWithFormat:@"%llu", [transaction.startTimestamp compare:_startDate] == NSOrderedAscending ? 0 : (unsigned long long)( [transaction.startTimestamp timeIntervalSinceDate:_startDate] * 1e9)]; - const auto relativeEnd = - [NSString stringWithFormat:@"%llu", - [transaction.timestamp compare:_endDate] == NSOrderedDescending - ? profileDuration - : (unsigned long long)( - [transaction.timestamp timeIntervalSinceDate:_startDate] * 1e9)]; + + NSString *relativeEnd; + if ([transaction.timestamp compare:_endDate] == NSOrderedDescending) { + relativeEnd = [NSString stringWithFormat:@"%llu", profileDuration]; + } else { + const auto profileStartToTransactionEnd_ns = + [transaction.timestamp timeIntervalSinceDate:_startDate] * 1e9; + if (profileStartToTransactionEnd_ns < 0) { + SENTRY_LOG_DEBUG(@"Transaction %@ ended before the profiler started, won't " + @"associate it with this profile.", + transaction.trace.context.traceId.sentryIdString); + continue; + } else { + relativeEnd = [NSString + stringWithFormat:@"%llu", (unsigned long long)profileStartToTransactionEnd_ns]; + } + } [transactionsInfo addObject:@{ @"id" : transaction.eventId.sentryIdString, @"trace_id" : transaction.trace.context.traceId.sentryIdString, @@ -596,6 +615,11 @@ - (void)captureEnvelope @"active_thread_id" : [transaction.trace.transactionContext sentry_threadInfo].threadId }]; } + + if (transactionsInfo.count == 0) { + SENTRY_LOG_DEBUG(@"No transactions to associate with this profile, will not upload."); + return; + } profile[@"transactions"] = transactionsInfo; NSError *error = nil; @@ -610,6 +634,8 @@ - (void)captureEnvelope const auto item = [[SentryEnvelopeItem alloc] initWithHeader:header data:JSONData]; const auto envelopeHeader = [[SentryEnvelopeHeader alloc] initWithId:profileID]; const auto envelope = [[SentryEnvelope alloc] initWithHeader:envelopeHeader singleItem:item]; + + SENTRY_LOG_DEBUG(@"Capturing profile envelope."); [_hub captureEnvelope:envelope]; } diff --git a/Sources/Sentry/SentrySpan.m b/Sources/Sentry/SentrySpan.m index 17c60188777..766a94af0a2 100644 --- a/Sources/Sentry/SentrySpan.m +++ b/Sources/Sentry/SentrySpan.m @@ -25,8 +25,8 @@ @implementation SentrySpan { - (instancetype)initWithTracer:(SentryTracer *)tracer context:(SentrySpanContext *)context { if (self = [super init]) { - SENTRY_LOG_DEBUG( - @"Starting span %@ with tracer %@", context.spanId.sentrySpanIdString, tracer); + SENTRY_LOG_DEBUG(@"Created span %@ for trace ID %@", context.spanId.sentrySpanIdString, + tracer.context.traceId); _tracer = tracer; _context = context; self.startTimestamp = [SentryCurrentDate date]; @@ -128,6 +128,8 @@ - (void)finishWithStatus:(SentrySpanStatus)status _isFinished = YES; if (self.timestamp == nil) { self.timestamp = [SentryCurrentDate date]; + SENTRY_LOG_DEBUG(@"Setting span timestamp: %@ at system time %llu", self.timestamp, + (unsigned long long)getAbsoluteTime()); } if (self.tracer != nil) { [self.tracer spanFinished:self]; diff --git a/Sources/Sentry/SentryTracer.m b/Sources/Sentry/SentryTracer.m index 8ce9a43fccf..b87578b68fd 100644 --- a/Sources/Sentry/SentryTracer.m +++ b/Sources/Sentry/SentryTracer.m @@ -143,6 +143,8 @@ - (instancetype)initWithTransactionContext:(SentryTransactionContext *)transacti dispatchQueueWrapper:(nullable SentryDispatchQueueWrapper *)dispatchQueueWrapper { if (self = [super init]) { + SENTRY_LOG_DEBUG( + @"Starting transaction at system time %llu", (unsigned long long)getAbsoluteTime()); self.rootSpan = [[SentrySpan alloc] initWithTracer:self context:transactionContext]; self.transactionContext = transactionContext; _children = [[NSMutableArray alloc] init]; @@ -399,6 +401,8 @@ - (SentryTraceHeader *)toTraceHeader - (void)finish { + SENTRY_LOG_DEBUG( + @"-[SentryTracer finish] for trace ID %@", _traceContext.traceId.sentryIdString); [self finishWithStatus:kSentrySpanStatusOk]; } diff --git a/Tests/SentryTests/Profiling/SentryProfilerSwiftTests.swift b/Tests/SentryTests/Profiling/SentryProfilerSwiftTests.swift index a99a0eec51a..6d794e96acc 100644 --- a/Tests/SentryTests/Profiling/SentryProfilerSwiftTests.swift +++ b/Tests/SentryTests/Profiling/SentryProfilerSwiftTests.swift @@ -327,7 +327,7 @@ private extension SentryProfilerSwiftTests { } XCTAssertNotNil(transaction["trace_id"]) XCTAssertNotNil(transaction["relative_start_ns"]) - XCTAssertNotNil(transaction["relative_end_ns"]) + XCTAssertFalse((transaction["relative_end_ns"] as! NSString).isEqual(to: "0")) XCTAssertNotNil(transaction["active_thread_id"]) }