From 7d25f48497ebd3f3f0107b44391ec6d82868eb6d Mon Sep 17 00:00:00 2001 From: Yousif <74918474+yousif-bugsnag@users.noreply.github.com> Date: Tue, 7 Jan 2025 13:58:43 +0000 Subject: [PATCH] feat(react-native): delegate first class spans to native SDK when attached (#556) * feat(react-native): add turbo module initialise method avoid repeated calls to the native module by calling initialise once on module load and getting all of the native settings at once * feat(react-native): delegate first class spans to native SDK * feat(react-native): run onSpanEnd callbacks when processing native spans * test(react-native): add span factory unit tests * refactor: move onSpanEndCallback logic out of batch processor * revert: undo initialise method This partially reverts commit 0820748db7d981e87e08b2b3f6eaeb8899bec9c2. * test(react-native): update native integration e2e test * fix(react-native): preserve sampling attribute for native Android spans * refactor(core): configure span factory as early as possible and move early spans logic into span factory * test(react-native): test custom attributes on native spans * refactor(react-native): always use discard end time when discarding spans * fix(react-native): fix platform check --- packages/core/lib/attributes.ts | 4 + packages/core/lib/batch-processor.ts | 41 +--- packages/core/lib/config.ts | 5 +- packages/core/lib/core.ts | 16 +- packages/core/lib/span-factory.ts | 39 ++-- packages/core/lib/span.ts | 32 +++ packages/core/lib/validation.ts | 3 +- .../react-native/__mocks__/react-native.ts | 64 +++--- .../NativeBugsnagPerformanceImpl.java | 2 +- .../react-native/lib/platform-extensions.tsx | 8 +- .../react-native/lib/span-factory.ts | 49 ++++- .../react-native/tests/client.test.ts | 76 +++---- .../react-native/tests/span-factory.test.ts | 197 ++++++++++++++++++ .../ScenarioLauncherImpl.java | 1 + .../scenario-launcher/ios/ScenarioLauncher.mm | 1 + .../scenarios/NativeIntegrationScenario.js | 20 +- .../features/native-integration.feature | 68 +++++- 17 files changed, 483 insertions(+), 143 deletions(-) create mode 100644 packages/platforms/react-native/tests/span-factory.test.ts diff --git a/packages/core/lib/attributes.ts b/packages/core/lib/attributes.ts index 00c16daae..7c11b514b 100644 --- a/packages/core/lib/attributes.ts +++ b/packages/core/lib/attributes.ts @@ -113,6 +113,10 @@ export class SpanAttributes { Array.from(this.attributes).forEach(([key, value]) => { this.validateAttribute(key, value) }) return Array.from(this.attributes).map(([key, value]) => attributeToJson(key, value)) } + + toObject () { + return Object.fromEntries(this.attributes) + } } export class ResourceAttributes extends SpanAttributes { diff --git a/packages/core/lib/batch-processor.ts b/packages/core/lib/batch-processor.ts index 6bab209b0..e5372dec8 100644 --- a/packages/core/lib/batch-processor.ts +++ b/packages/core/lib/batch-processor.ts @@ -4,13 +4,9 @@ import type ProbabilityManager from './probability-manager' import type { Processor } from './processor' import type { RetryQueue } from './retry-queue' import type { ReadonlySampler } from './sampler' -import type { Span, SpanEnded } from './span' +import type { SpanEnded } from './span' -import { millisecondsToNanoseconds } from './clock' -import { spanEndedToSpan } from './span' - -export type OnSpanEndCallback = (span: Span) => boolean | Promise -export type OnSpanEndCallbacks = OnSpanEndCallback[] +import { runSpanEndCallbacks } from './span' type MinimalProbabilityManager = Pick @@ -114,37 +110,6 @@ export class BatchProcessor implements Processor { await this.flushQueue } - private async runCallbacks (span: Span): Promise { - if (this.configuration.onSpanEnd) { - const callbackStartTime = performance.now() - let continueToBatch = true - for (const callback of this.configuration.onSpanEnd) { - try { - let result = callback(span) - - // @ts-expect-error result may or may not be a promise - if (typeof result.then === 'function') { - result = await result - } - - if (result === false) { - continueToBatch = false - break - } - } catch (err) { - this.configuration.logger.error('Error in onSpanEnd callback: ' + err) - } - } - if (continueToBatch) { - const duration = millisecondsToNanoseconds(performance.now() - callbackStartTime) - span.setAttribute('bugsnag.span.callbacks_duration', duration) - } - return continueToBatch - } else { - return true - } - } - private async prepareBatch (): Promise { if (this.spans.length === 0) { return @@ -165,7 +130,7 @@ export class BatchProcessor implements Processor { if (this.sampler.sample(span)) { // Run any callbacks that have been registered before batching // as callbacks could cause the span to be discarded - const shouldAddToBatch = await this.runCallbacks(spanEndedToSpan(span)) + const shouldAddToBatch = await runSpanEndCallbacks(span, this.configuration.logger, this.configuration.onSpanEnd) if (shouldAddToBatch) batch.push(span) } } diff --git a/packages/core/lib/config.ts b/packages/core/lib/config.ts index ebf3abca7..2fe1e913f 100644 --- a/packages/core/lib/config.ts +++ b/packages/core/lib/config.ts @@ -1,4 +1,3 @@ -import type { OnSpanEndCallbacks } from './batch-processor' import { ATTRIBUTE_ARRAY_LENGTH_LIMIT_DEFAULT, ATTRIBUTE_COUNT_LIMIT_DEFAULT, @@ -8,6 +7,7 @@ import { ATTRIBUTE_STRING_VALUE_LIMIT_MAX } from './custom-attribute-limits' import type { Plugin } from './plugin' +import type { Span } from './span' import { isLogger, isNumber, isObject, isOnSpanEndCallbacks, isPluginArray, isString, isStringArray, isStringWithLength } from './validation' type SetTraceCorrelation = (traceId: string, spanId: string) => void @@ -39,6 +39,9 @@ export interface Logger { error: (message: string) => void } +export type OnSpanEndCallback = (span: Span) => boolean | Promise +export type OnSpanEndCallbacks = OnSpanEndCallback[] + export interface Configuration { apiKey: string endpoint?: string diff --git a/packages/core/lib/core.ts b/packages/core/lib/core.ts index 83f53a486..d07dc4868 100644 --- a/packages/core/lib/core.ts +++ b/packages/core/lib/core.ts @@ -14,7 +14,6 @@ import type { Persistence } from './persistence' import type { Plugin } from './plugin' import ProbabilityFetcher from './probability-fetcher' import ProbabilityManager from './probability-manager' -import type { Processor } from './processor' import { BufferingProcessor } from './processor' import type { RetryQueueFactory } from './retry-queue' import Sampler from './sampler' @@ -55,7 +54,6 @@ export type BugsnagPerformance = Client & T export function createClient (options: ClientOptions): BugsnagPerformance { const bufferingProcessor = new BufferingProcessor() - let processor: Processor = bufferingProcessor const spanContextStorage = options.spanContextStorage || new DefaultSpanContextStorage(options.backgroundingListener) let logger = options.schema.logger.defaultValue const sampler = new Sampler(1.0) @@ -63,7 +61,7 @@ export function createClient ( const SpanFactoryClass = options.spanFactory || SpanFactory const spanFactory = new SpanFactoryClass( - processor, + bufferingProcessor, sampler, options.idGenerator, options.spanAttributesSource, @@ -101,6 +99,8 @@ export function createClient ( options.spanAttributesSource.configure(configuration) + spanFactory.configure(configuration) + const probabilityManagerPromise = configuration.samplingProbability === undefined ? ProbabilityManager.create( options.persistence, @@ -110,7 +110,7 @@ export function createClient ( : FixedProbabilityManager.create(sampler, configuration.samplingProbability) probabilityManagerPromise.then((manager: ProbabilityManager | FixedProbabilityManager) => { - processor = new BatchProcessor( + const batchProcessor = new BatchProcessor( delivery, configuration, options.retryQueueFactory(delivery, configuration.retryQueueMaxSize), @@ -119,17 +119,14 @@ export function createClient ( new TracePayloadEncoder(options.clock, configuration, options.resourceAttributesSource) ) - // ensure all spans started before .start() are added to the batch - for (const span of bufferingProcessor.spans) { - processor.add(span) - } + spanFactory.reprocessEarlySpans(batchProcessor) // register with the backgrounding listener - we do this in 'start' as // there's nothing to do if we're backgrounded before start is called // e.g. we can't trigger delivery until we have the apiKey and endpoint // from configuration options.backgroundingListener.onStateChange(state => { - (processor as BatchProcessor).flush() + batchProcessor.flush() // ensure we have a fresh probability value when returning to the // foreground @@ -139,7 +136,6 @@ export function createClient ( }) logger = configuration.logger - spanFactory.configure(processor, configuration) }) for (const plugin of configuration.plugins) { diff --git a/packages/core/lib/span-factory.ts b/packages/core/lib/span-factory.ts index 73b9039fc..a5c99b434 100644 --- a/packages/core/lib/span-factory.ts +++ b/packages/core/lib/span-factory.ts @@ -2,11 +2,11 @@ import type { SpanAttribute, SpanAttributesLimits, SpanAttributesSource } from ' import { SpanAttributes } from './attributes' import type { BackgroundingListener, BackgroundingListenerState } from './backgrounding-listener' import type { Clock } from './clock' -import type { Configuration, InternalConfiguration, Logger } from './config' +import type { Configuration, InternalConfiguration, Logger, OnSpanEndCallbacks } from './config' import { defaultSpanAttributeLimits } from './custom-attribute-limits' import type { IdGenerator } from './id-generator' import type { NetworkSpanOptions } from './network-span' -import type { Processor } from './processor' +import type { BufferingProcessor, Processor } from './processor' import type { ReadonlySampler } from './sampler' import type { InternalSpanOptions, ParentContext, Span, SpanOptionSchema, SpanOptions } from './span' import { SpanInternal, coreSpanOptionSchema } from './span' @@ -27,8 +27,9 @@ export class SpanFactory { private readonly spanAttributesSource: SpanAttributesSource protected readonly clock: Clock private readonly spanContextStorage: SpanContextStorage - private logger: Logger + protected logger: Logger private spanAttributeLimits: SpanAttributesLimits = defaultSpanAttributeLimits + protected onSpanEndCallbacks?: OnSpanEndCallbacks private openSpans: WeakSet = new WeakSet() private isInForeground: boolean = true @@ -73,6 +74,9 @@ export class SpanFactory { : this.spanContextStorage.current const attributes = new SpanAttributes(new Map(), this.spanAttributeLimits, name, this.logger) + if (typeof options.isFirstClass === 'boolean') { + attributes.set('bugsnag.span.first_class', options.isFirstClass) + } const span = this.createSpanInternal(name, safeStartTime, parentContext, options.isFirstClass, attributes) @@ -98,10 +102,6 @@ export class SpanFactory { const parentSpanId = parentContext ? parentContext.id : undefined const traceId = parentContext ? parentContext.traceId : this.idGenerator.generate(128) - if (typeof isFirstClass === 'boolean') { - attributes.set('bugsnag.span.first_class', isFirstClass) - } - return new SpanInternal(spanId, traceId, name, startTime, attributes, this.clock, parentSpanId) } @@ -117,14 +117,23 @@ export class SpanFactory { return spanInternal } - configure (processor: Processor, configuration: InternalConfiguration) { - this.processor = processor + configure (configuration: InternalConfiguration) { this.logger = configuration.logger this.spanAttributeLimits = { attributeArrayLengthLimit: configuration.attributeArrayLengthLimit, attributeCountLimit: configuration.attributeCountLimit, attributeStringValueLimit: configuration.attributeStringValueLimit } + this.onSpanEndCallbacks = configuration.onSpanEnd + } + + reprocessEarlySpans (batchProcessor: Processor) { + // ensure all spans in the buffering processor are added to the batch + for (const span of (this.processor as BufferingProcessor).spans) { + batchProcessor.add(span) + } + + this.processor = batchProcessor } endSpan ( @@ -148,8 +157,7 @@ export class SpanFactory { // - they are already invalid // - they have an explicit discard end time if (untracked || !isValidSpan || endTime === DISCARD_END_TIME) { - // we still call end on the span so that it is no longer considered valid - span.end(endTime, this.sampler.spanProbability) + this.discardSpan(span) return } @@ -159,9 +167,16 @@ export class SpanFactory { } this.spanAttributesSource.requestAttributes(span) + this.sendForProcessing(span, endTime) + } - const spanEnded = span.end(endTime, this.sampler.spanProbability) + protected discardSpan (span: SpanInternal) { + // we still call end on the span so that it is no longer considered valid + span.end(DISCARD_END_TIME, this.sampler.spanProbability) + } + protected sendForProcessing (span: SpanInternal, endTime: number) { + const spanEnded = span.end(endTime, this.sampler.spanProbability) if (this.sampler.sample(spanEnded)) { this.processor.add(spanEnded) } diff --git a/packages/core/lib/span.ts b/packages/core/lib/span.ts index a93ab3586..ff4f2497c 100644 --- a/packages/core/lib/span.ts +++ b/packages/core/lib/span.ts @@ -1,5 +1,7 @@ import type { SpanAttribute, SpanAttributes } from './attributes' +import { millisecondsToNanoseconds } from './clock' import type { Clock } from './clock' +import type { Logger, OnSpanEndCallbacks } from './config' import type { DeliverySpan } from './delivery' import { SpanEvents } from './events' import type { SpanContext } from './span-context' @@ -86,6 +88,36 @@ export function spanEndedToSpan (span: SpanEnded): Span { } } +export async function runSpanEndCallbacks (spanEnded: SpanEnded, logger: Logger, callbacks?: OnSpanEndCallbacks) { + if (!callbacks) return true + + const span = spanEndedToSpan(spanEnded) + const callbackStartTime = performance.now() + let shouldSample = true + for (const callback of callbacks) { + try { + let result = callback(span) + + // @ts-expect-error result may or may not be a promise + if (typeof result.then === 'function') { + result = await result + } + + if (result === false) { + shouldSample = false + break + } + } catch (err) { + logger.error('Error in onSpanEnd callback: ' + err) + } + } + if (shouldSample) { + const duration = millisecondsToNanoseconds(performance.now() - callbackStartTime) + span.setAttribute('bugsnag.span.callbacks_duration', duration) + } + return shouldSample +} + export class SpanInternal implements SpanContext { readonly id: string readonly traceId: string diff --git a/packages/core/lib/validation.ts b/packages/core/lib/validation.ts index f858d8624..2949aacb8 100644 --- a/packages/core/lib/validation.ts +++ b/packages/core/lib/validation.ts @@ -1,5 +1,4 @@ -import type { OnSpanEndCallback } from './batch-processor' -import type { Configuration, Logger } from './config' +import type { Configuration, Logger, OnSpanEndCallback } from './config' import type { PersistedProbability } from './persistence' import type { Plugin } from './plugin' import type { ParentContext } from './span' diff --git a/packages/platforms/react-native/__mocks__/react-native.ts b/packages/platforms/react-native/__mocks__/react-native.ts index 55864341f..1f5b4c9d6 100644 --- a/packages/platforms/react-native/__mocks__/react-native.ts +++ b/packages/platforms/react-native/__mocks__/react-native.ts @@ -4,6 +4,8 @@ type PlatformConstants = { Manufacturer: string, Model: string, Release: string } | Record +const VALID_API_KEY = 'a1b2c3d4e5f6a7b8c9d0e1f2a3b4c5d6' + export const Platform = new class { private os: Os = 'ios' @@ -105,29 +107,31 @@ const createPool = () => { return '0123456789abcdef'.repeat(128) } -const BugsnagReactNativePerformance = { - getDeviceInfo (): DeviceInfo { - switch (Platform.OS) { - case 'ios': - return { - arch: 'arm64', - model: 'iPhone14,1', - bundleVersion: '12345', - bundleIdentifier: 'my.cool.app' - } - - case 'android': - return { - arch: 'x86', - model: 'TheGoodPhone1', - versionCode: '6789', - bundleIdentifier: 'my.cool.app' - } +const getDevice = (): DeviceInfo => { + switch (Platform.OS) { + case 'ios': + return { + arch: 'arm64', + model: 'iPhone14,1', + bundleVersion: '12345', + bundleIdentifier: 'my.cool.app' + } + + case 'android': + return { + arch: 'x86', + model: 'TheGoodPhone1', + versionCode: '6789', + bundleIdentifier: 'my.cool.app' + } + + case 'other': + return {} + } +} - case 'other': - return {} - } - }, +const BugsnagReactNativePerformance = { + getDeviceInfo: jest.fn(getDevice), requestEntropy: jest.fn(() => { return createPool() }), @@ -135,16 +139,26 @@ const BugsnagReactNativePerformance = { return Promise.resolve(createPool()) }), isNativePerformanceAvailable: jest.fn(() => { - return false + return true }), getNativeConfiguration: jest.fn(() => { - return null + return { + apiKey: VALID_API_KEY, + endpoint: '/traces', + appVersion: '1.2.3', + releaseStage: 'test', + enabledReleaseStages: ['test', 'production'], + serviceName: 'com.native.performance.test', + attributeCountLimit: 128, + attributeStringValueLimit: 1024, + attributeArrayLengthLimit: 1000 + } }), startNativeSpan: jest.fn((name, options) => { return { name, id: 'native-span-id', - traceId: 'native-trace-id', + traceId: options.parentContext?.traceId || 'native-trace-id', startTime: options.startTime, parentSpanId: options.parentContext?.id || undefined } diff --git a/packages/platforms/react-native/android/src/main/java/com/bugsnag/android/performance/NativeBugsnagPerformanceImpl.java b/packages/platforms/react-native/android/src/main/java/com/bugsnag/android/performance/NativeBugsnagPerformanceImpl.java index 6c9c6de78..c55a689e0 100644 --- a/packages/platforms/react-native/android/src/main/java/com/bugsnag/android/performance/NativeBugsnagPerformanceImpl.java +++ b/packages/platforms/react-native/android/src/main/java/com/bugsnag/android/performance/NativeBugsnagPerformanceImpl.java @@ -156,7 +156,7 @@ public WritableMap startNativeSpan(String name, ReadableMap options) { SpanFactory spanFactory = BugsnagPerformance.INSTANCE.getInstrumentedAppState$internal().getSpanFactory(); SpanImpl nativeSpan = spanFactory.createCustomSpan(name, spanOptions); - nativeSpan.getAttributes().getEntries$internal().clear(); + nativeSpan.getAttributes().getEntries$internal().removeIf(entry -> !entry.getKey().equals("bugsnag.sampling.p")); String spanKey = EncodingUtils.toHexString(nativeSpan.getSpanId()) + EncodingUtils.toHexString(nativeSpan.getTraceId()); openSpans.put(spanKey, nativeSpan); diff --git a/packages/platforms/react-native/lib/platform-extensions.tsx b/packages/platforms/react-native/lib/platform-extensions.tsx index 1f7b0c419..f9e1bc829 100644 --- a/packages/platforms/react-native/lib/platform-extensions.tsx +++ b/packages/platforms/react-native/lib/platform-extensions.tsx @@ -31,15 +31,16 @@ export const platformExtensions = (appStartTime: number, clock: Clock, schema: R }, attach: function (config?: ReactNativeAttachConfiguration) { const logger = schema.logger.validate(config?.logger) ? config.logger : schema.logger.defaultValue - const isNativePerformanceAvailable = NativeBugsnagPerformance !== null && NativeBugsnagPerformance.isNativePerformanceAvailable() + const platform = Platform.OS === 'ios' ? 'Cocoa' : 'Android' + const isNativePerformanceAvailable = NativeBugsnagPerformance?.isNativePerformanceAvailable() if (!isNativePerformanceAvailable) { - logger.warn(`Could not attach to native SDK. No compatible version of Bugsnag ${Platform.OS} performance was found`) + logger.warn(`Could not attach to native SDK. No compatible version of Bugsnag ${platform} Performance was found.`) return } const nativeConfig = NativeBugsnagPerformance?.getNativeConfiguration() if (!nativeConfig) { - logger.warn(`Could not attach to native SDK. Bugsnag ${Platform.OS} performance has not been started`) + logger.warn(`Could not attach to native SDK. Bugsnag ${platform} Performance has not been started.`) return } @@ -48,6 +49,7 @@ export const platformExtensions = (appStartTime: number, clock: Clock, schema: R ...nativeConfig } + spanFactory.onAttach() const client = this as unknown as Client client.start(finalConfig) } diff --git a/packages/platforms/react-native/lib/span-factory.ts b/packages/platforms/react-native/lib/span-factory.ts index be3c2fefc..3cd8a2161 100644 --- a/packages/platforms/react-native/lib/span-factory.ts +++ b/packages/platforms/react-native/lib/span-factory.ts @@ -1,9 +1,54 @@ -import { SpanFactory } from '@bugsnag/core-performance' +import { runSpanEndCallbacks, SpanFactory, SpanInternal } from '@bugsnag/core-performance' import type { SpanAttributes, ParentContext } from '@bugsnag/core-performance' import type { ReactNativeConfiguration } from './config' +import NativeBugsnagPerformance from './native' +import type { ReactNativeClock } from './clock' + +class NativeSpanInternal extends SpanInternal { + public readonly isNativeSpan: boolean = true +} export class ReactNativeSpanFactory extends SpanFactory { + private attachedToNative = false + + onAttach () { + this.attachedToNative = true + } + protected createSpanInternal (name: string, startTime: number, parentContext: ParentContext | null | undefined, isFirstClass: boolean | undefined, attributes: SpanAttributes) { - return super.createSpanInternal(name, startTime, parentContext, isFirstClass, attributes) + if (!NativeBugsnagPerformance || !this.attachedToNative || isFirstClass !== true) { + return super.createSpanInternal(name, startTime, parentContext, isFirstClass, attributes) + } + + const unixStartTimeNanos = (this.clock as ReactNativeClock).toUnixNanoseconds(startTime) + const nativeParentContext = parentContext ? { id: parentContext.id, traceId: parentContext.traceId } : undefined + const nativeSpan = NativeBugsnagPerformance.startNativeSpan(name, { startTime: unixStartTimeNanos, parentContext: nativeParentContext }) + return new NativeSpanInternal(nativeSpan.id, nativeSpan.traceId, name, startTime, attributes, this.clock, nativeSpan.parentSpanId) + } + + protected discardSpan (span: NativeSpanInternal) { + if (span.isNativeSpan) { + NativeBugsnagPerformance?.discardNativeSpan(span.id, span.traceId) + } + + super.discardSpan(span) + } + + protected sendForProcessing (span: NativeSpanInternal, endTime: number) { + span.isNativeSpan ? this.processNativeSpan(span, endTime) : super.sendForProcessing(span, endTime) + } + + private async processNativeSpan (span: NativeSpanInternal, endTime: number) { + const spanEnded = span.end(endTime, this.sampler.spanProbability) + const shouldSend = await runSpanEndCallbacks(spanEnded, this.logger, this.onSpanEndCallbacks) + + if (shouldSend) { + const unixEndTimeNanos = (this.clock as ReactNativeClock).toUnixNanoseconds(endTime) + const attributes = spanEnded.attributes.toObject() + delete attributes['bugsnag.sampling.p'] + NativeBugsnagPerformance?.endNativeSpan(spanEnded.id, spanEnded.traceId, unixEndTimeNanos, attributes) + } else { + NativeBugsnagPerformance?.discardNativeSpan(spanEnded.id, spanEnded.traceId) + } } } diff --git a/packages/platforms/react-native/tests/client.test.ts b/packages/platforms/react-native/tests/client.test.ts index 8457518d6..e381f9c89 100644 --- a/packages/platforms/react-native/tests/client.test.ts +++ b/packages/platforms/react-native/tests/client.test.ts @@ -1,10 +1,14 @@ /* eslint-disable @typescript-eslint/no-var-requires */ - +/* eslint-disable @typescript-eslint/no-non-null-assertion */ import type { ReactNativeConfiguration } from '../lib/config' import type { BugsnagPerformance } from '@bugsnag/core-performance' import type { PlatformExtensions } from '../lib/platform-extensions' import type { Spec } from '../lib/NativeBugsnagPerformance' +// trick the client in thinking it's not running in the remote debugger +// @ts-expect-error 'typeof globalThis' has no index signature +global.nativeCallSyncHook = () => {} + let client: BugsnagPerformance let turboModule: Spec const RESPONSE_TIME = 100 @@ -58,6 +62,7 @@ global.XMLHttpRequest = XMLHttpRequest as unknown as typeof globalThis.XMLHttpRe beforeEach(() => { jest.resetModules() + jest.clearAllMocks() mockFetch = createMockFetch() global.fetch = mockFetch turboModule = require('../lib/native').default @@ -66,36 +71,27 @@ beforeEach(() => { describe('React Native client tests', () => { describe('attach()', () => { it('logs a warning and noops if native performance is not available', () => { + turboModule.isNativePerformanceAvailable = jest.fn().mockReturnValue(false) + client = require('../lib/client').default const warnSpy = jest.spyOn(console, 'warn').mockImplementation(() => {}) client.attach({}) - expect(warnSpy).toHaveBeenCalledWith('Could not attach to native SDK. No compatible version of Bugsnag ios performance was found') + expect(warnSpy).toHaveBeenCalledWith('Could not attach to native SDK. No compatible version of Bugsnag Cocoa Performance was found.') }) it('logs a warning and noops if native performance has not been started', () => { - turboModule.isNativePerformanceAvailable = jest.fn().mockReturnValue(true) turboModule.getNativeConfiguration = jest.fn().mockReturnValue(null) client = require('../lib/client').default const warnSpy = jest.spyOn(console, 'warn').mockImplementation(() => {}) client.attach() - expect(warnSpy).toHaveBeenCalledWith('Could not attach to native SDK. Bugsnag ios performance has not been started') + expect(warnSpy).toHaveBeenCalledWith('Could not attach to native SDK. Bugsnag Cocoa Performance has not been started.') }) it('starts the client using the native configuration', () => { - turboModule.isNativePerformanceAvailable = jest.fn().mockReturnValue(true) - turboModule.getNativeConfiguration = jest.fn().mockReturnValue({ - apiKey: '1234567890abcdef1234567890abcdef12', - endpoint: '/traces', - releaseStage: 'production', - serviceName: 'unknown_service', - attributeCountLimit: 128, - attributeStringValueLimit: 1024, - attributeArrayLengthLimit: 1000 - }) - + const nativeConfig = turboModule.getNativeConfiguration() client = require('../lib/client').default const startSpy = jest.spyOn(client, 'start') @@ -108,35 +104,27 @@ describe('React Native client tests', () => { generateAnonymousId: true }) - expect(startSpy).toHaveBeenCalledWith(expect.objectContaining({ - apiKey: '1234567890abcdef1234567890abcdef12', - endpoint: '/traces', - releaseStage: 'production', - serviceName: 'unknown_service', - attributeCountLimit: 128, - attributeStringValueLimit: 1024, - attributeArrayLengthLimit: 1000, + expect(startSpy).toHaveBeenCalledWith({ + apiKey: nativeConfig!.apiKey, + endpoint: nativeConfig!.endpoint, + appVersion: nativeConfig!.appVersion, + releaseStage: nativeConfig!.releaseStage, + enabledReleaseStages: nativeConfig!.enabledReleaseStages, + serviceName: nativeConfig!.serviceName, + attributeCountLimit: nativeConfig!.attributeCountLimit, + attributeStringValueLimit: nativeConfig!.attributeStringValueLimit, + attributeArrayLengthLimit: nativeConfig!.attributeArrayLengthLimit, autoInstrumentAppStarts: false, autoInstrumentNetworkRequests: false, codeBundleId: '12345', logger: console, tracePropagationUrls: [/^https:\/\/example\.com/], generateAnonymousId: true - })) + }) }) it('does not overwrite native configuration with JS values', () => { - turboModule.isNativePerformanceAvailable = jest.fn().mockReturnValue(true) - turboModule.getNativeConfiguration = jest.fn().mockReturnValue({ - apiKey: '1234567890abcdef1234567890abcdef12', - endpoint: '/traces', - releaseStage: 'production', - serviceName: 'unknown_service', - attributeCountLimit: 128, - attributeStringValueLimit: 1024, - attributeArrayLengthLimit: 1000 - }) - + const nativeConfig = turboModule.getNativeConfiguration() client = require('../lib/client').default const startSpy = jest.spyOn(client, 'start') @@ -145,7 +133,9 @@ describe('React Native client tests', () => { apiKey: 'ignored', endpoint: 'ignored', releaseStage: 'ignored', + enabledReleaseStages: ['ignored'], serviceName: 'ignored', + appVersion: 'ignored', attributeCountLimit: 0, attributeStringValueLimit: 0, attributeArrayLengthLimit: 0, @@ -158,13 +148,15 @@ describe('React Native client tests', () => { }) expect(startSpy).toHaveBeenCalledWith(expect.objectContaining({ - apiKey: '1234567890abcdef1234567890abcdef12', - endpoint: '/traces', - releaseStage: 'production', - serviceName: 'unknown_service', - attributeCountLimit: 128, - attributeStringValueLimit: 1024, - attributeArrayLengthLimit: 1000, + apiKey: nativeConfig!.apiKey, + endpoint: nativeConfig!.endpoint, + appVersion: nativeConfig!.appVersion, + releaseStage: nativeConfig!.releaseStage, + enabledReleaseStages: nativeConfig!.enabledReleaseStages, + serviceName: nativeConfig!.serviceName, + attributeCountLimit: nativeConfig!.attributeCountLimit, + attributeStringValueLimit: nativeConfig!.attributeStringValueLimit, + attributeArrayLengthLimit: nativeConfig!.attributeArrayLengthLimit, autoInstrumentAppStarts: false, autoInstrumentNetworkRequests: false, codeBundleId: '12345', diff --git a/packages/platforms/react-native/tests/span-factory.test.ts b/packages/platforms/react-native/tests/span-factory.test.ts new file mode 100644 index 000000000..cffd13334 --- /dev/null +++ b/packages/platforms/react-native/tests/span-factory.test.ts @@ -0,0 +1,197 @@ +/* eslint-disable @typescript-eslint/no-non-null-assertion */ +import { ReactNativeSpanFactory } from '../lib/span-factory' +import NativeBugsnagPerformance from '../lib/native' +import { ControllableBackgroundingListener, InMemoryProcessor, spanAttributesSource, StableIdGenerator } from '@bugsnag/js-performance-test-utilities' +import { DefaultSpanContextStorage, Sampler, DISCARD_END_TIME } from '@bugsnag/core-performance' +import type { InternalConfiguration } from '@bugsnag/core-performance' +import createClock from '../lib/clock' +import type { ReactNativeClock } from '../lib/clock' +import type { ReactNativeConfiguration } from '../lib/config' + +let clock: ReactNativeClock +let spanFactory: ReactNativeSpanFactory +let processor: InMemoryProcessor +let contextStorage: DefaultSpanContextStorage +let backgroundingListener: ControllableBackgroundingListener + +beforeEach(() => { + jest.useFakeTimers() + jest.resetModules() + jest.clearAllMocks() + + clock = createClock(performance) + processor = new InMemoryProcessor() + backgroundingListener = new ControllableBackgroundingListener() + contextStorage = new DefaultSpanContextStorage(backgroundingListener) + spanFactory = new ReactNativeSpanFactory( + processor, + new Sampler(1.0), + new StableIdGenerator(), + spanAttributesSource, + clock, + backgroundingListener, + jestLogger, + contextStorage + ) +}) + +const jestLogger = { + debug: jest.fn(), + error: jest.fn(), + info: jest.fn(), + warn: jest.fn() +} + +describe('ReactNativeSpanFactory', () => { + describe('startSpan', () => { + it('starts a native span when isFirstClass is true', () => { + spanFactory.onAttach() + + const startTime = clock.now() + const nativeSpan = spanFactory.startSpan('native span', { startTime, isFirstClass: true }) + expect(NativeBugsnagPerformance!.startNativeSpan).toHaveBeenCalledWith('native span', expect.objectContaining({ startTime: clock.toUnixNanoseconds(startTime) })) + expect(contextStorage.current).toBe(nativeSpan) + }) + + it.each([false, undefined])('does not start a native span when isFirstClass is %p', isFirstClass => { + spanFactory.onAttach() + + const startTime = clock.now() + const span = spanFactory.startSpan('not first class', { startTime, isFirstClass }) + expect(NativeBugsnagPerformance!.startNativeSpan).not.toHaveBeenCalled() + expect(contextStorage.current).toBe(span) + }) + + it('does not start a native span when not attached to native', () => { + const startTime = clock.now() + const span = spanFactory.startSpan('first class', { startTime, isFirstClass: true }) + expect(NativeBugsnagPerformance!.startNativeSpan).not.toHaveBeenCalled() + expect(contextStorage.current).toBe(span) + }) + + it('sets the native parent context when parentContext is provided', () => { + spanFactory.onAttach() + + const startTime = clock.now() + const parentContext = spanFactory.startSpan('parent', { startTime, isFirstClass: false }) + const nativeSpan = spanFactory.startSpan('child', { startTime, isFirstClass: true, parentContext }) + expect(NativeBugsnagPerformance!.startNativeSpan).toHaveBeenCalledWith('child', expect.objectContaining({ parentContext: { id: parentContext.id, traceId: parentContext.traceId } })) + expect(nativeSpan.id).toBe('native-span-id') + expect(nativeSpan.traceId).toBe(parentContext.traceId) + expect(nativeSpan.parentSpanId).toBe(parentContext.id) + expect(contextStorage.current).toBe(nativeSpan) + }) + + it.each([null, undefined])('does not set the native parent context when parentContext is %p', parentContext => { + spanFactory.onAttach() + + const startTime = clock.now() + const nativeSpan = spanFactory.startSpan('child', { startTime, isFirstClass: true, parentContext }) + expect(NativeBugsnagPerformance!.startNativeSpan).toHaveBeenCalledWith('child', expect.objectContaining({ parentContext: undefined })) + expect(nativeSpan.id).toBe('native-span-id') + expect(nativeSpan.traceId).toBe('native-trace-id') + expect(contextStorage.current).toBe(nativeSpan) + }) + }) + + describe('endSpan', () => { + it('sends native spans to the native module', async () => { + spanFactory.onAttach() + + const startTime = clock.now() + const nativeSpan = spanFactory.startSpan('native span', { startTime, isFirstClass: true }) + expect(NativeBugsnagPerformance!.startNativeSpan).toHaveBeenCalledWith('native span', expect.objectContaining({ startTime: clock.toUnixNanoseconds(startTime) })) + expect(contextStorage.current).toBe(nativeSpan) + + const endTime = clock.now() + spanFactory.endSpan(nativeSpan, endTime, { 'additional.attribute': 'test' }) + await jest.runOnlyPendingTimersAsync() + + expect(contextStorage.current).toBeUndefined() + expect(processor.spans.length).toBe(0) + expect(NativeBugsnagPerformance!.endNativeSpan).toHaveBeenCalledWith( + nativeSpan.id, + nativeSpan.traceId, + clock.toUnixNanoseconds(endTime), + { 'bugsnag.span.first_class': true, 'additional.attribute': 'test' }) + }) + + it('sends non-native spans to the JS processor', async () => { + spanFactory.onAttach() + const startTime = clock.now() + const span = spanFactory.startSpan('not native', { startTime, isFirstClass: false }) + expect(NativeBugsnagPerformance!.startNativeSpan).not.toHaveBeenCalled() + expect(contextStorage.current).toBe(span) + + const endTime = clock.now() + spanFactory.endSpan(span, endTime) + await jest.runOnlyPendingTimersAsync() + + expect(NativeBugsnagPerformance!.endNativeSpan).not.toHaveBeenCalled() + expect(contextStorage.current).toBeUndefined() + expect(processor.spans.length).toBe(1) + }) + + it('runs onSpanEnd callbacks for native spans', async () => { + spanFactory.onAttach() + + const onSpanEndCallback = jest.fn((span) => { + return Promise.resolve(span.name === 'should send') + }) + + spanFactory.configure({ logger: jestLogger, onSpanEnd: [onSpanEndCallback] } as unknown as InternalConfiguration) + const startTime = clock.now() + const validSpan = spanFactory.startSpan('should send', { startTime, isFirstClass: true }) + expect(NativeBugsnagPerformance!.startNativeSpan).toHaveBeenCalledWith('should send', expect.objectContaining({ startTime: clock.toUnixNanoseconds(startTime) })) + expect(contextStorage.current).toBe(validSpan) + + const invalidSpan = spanFactory.startSpan('should discard', { startTime, isFirstClass: true }) + expect(NativeBugsnagPerformance!.startNativeSpan).toHaveBeenCalledWith('should discard', expect.objectContaining({ startTime: clock.toUnixNanoseconds(startTime) })) + expect(contextStorage.current).toBe(invalidSpan) + + const endTime = clock.now() + spanFactory.endSpan(invalidSpan, endTime) + await jest.runOnlyPendingTimersAsync() + + expect(onSpanEndCallback).toHaveBeenCalledTimes(1) + expect(NativeBugsnagPerformance!.endNativeSpan).not.toHaveBeenCalled() + expect(NativeBugsnagPerformance!.discardNativeSpan).toHaveBeenCalledTimes(1) + + spanFactory.endSpan(validSpan, endTime) + await jest.runOnlyPendingTimersAsync() + + expect(onSpanEndCallback).toHaveBeenCalledTimes(2) + expect(NativeBugsnagPerformance!.endNativeSpan).toHaveBeenCalledTimes(1) + expect(NativeBugsnagPerformance!.discardNativeSpan).toHaveBeenCalledTimes(1) + + expect(processor.spans.length).toBe(0) + }) + }) + + describe('discardSpan', () => { + it('calls discardNativeSpan for native spans', () => { + spanFactory.onAttach() + + const startTime = clock.now() + const nativeSpan = spanFactory.startSpan('native span', { startTime, isFirstClass: true }) + expect(NativeBugsnagPerformance!.startNativeSpan).toHaveBeenCalledWith('native span', expect.objectContaining({ startTime: clock.toUnixNanoseconds(startTime) })) + + spanFactory.endSpan(nativeSpan, DISCARD_END_TIME) + expect(NativeBugsnagPerformance!.endNativeSpan).not.toHaveBeenCalled() + expect(NativeBugsnagPerformance!.discardNativeSpan).toHaveBeenCalledWith(nativeSpan.id, nativeSpan.traceId) + }) + + it('does not call discardNativeSpan for non-native spans', () => { + spanFactory.onAttach() + + const startTime = clock.now() + const span = spanFactory.startSpan('not native', { startTime, isFirstClass: false }) + expect(NativeBugsnagPerformance!.startNativeSpan).not.toHaveBeenCalled() + + spanFactory.endSpan(span, DISCARD_END_TIME) + expect(NativeBugsnagPerformance!.discardNativeSpan).not.toHaveBeenCalled() + expect(NativeBugsnagPerformance!.endNativeSpan).not.toHaveBeenCalled() + expect(processor.spans.length).toBe(0) + }) + }) +}) diff --git a/test/react-native/features/fixtures/scenario-launcher/android/src/main/java/com/bugsnag/reactnative/scenariolauncher/ScenarioLauncherImpl.java b/test/react-native/features/fixtures/scenario-launcher/android/src/main/java/com/bugsnag/reactnative/scenariolauncher/ScenarioLauncherImpl.java index 5cec31a5b..b871ede5e 100644 --- a/test/react-native/features/fixtures/scenario-launcher/android/src/main/java/com/bugsnag/reactnative/scenariolauncher/ScenarioLauncherImpl.java +++ b/test/react-native/features/fixtures/scenario-launcher/android/src/main/java/com/bugsnag/reactnative/scenariolauncher/ScenarioLauncherImpl.java @@ -162,6 +162,7 @@ public void startNativePerformance(ReadableMap configuration, Promise promise) { config.setEndpoint(configuration.getString("endpoint")); config.setAutoInstrumentAppStarts(false); config.setAutoInstrumentActivities(AutoInstrument.OFF); + config.setAutoInstrumentRendering(true); BugsnagPerformance.start(config); Log.d(MODULE_NAME, "Started Android performance"); diff --git a/test/react-native/features/fixtures/scenario-launcher/ios/ScenarioLauncher.mm b/test/react-native/features/fixtures/scenario-launcher/ios/ScenarioLauncher.mm index dd246e420..277f6c74a 100644 --- a/test/react-native/features/fixtures/scenario-launcher/ios/ScenarioLauncher.mm +++ b/test/react-native/features/fixtures/scenario-launcher/ios/ScenarioLauncher.mm @@ -123,6 +123,7 @@ @implementation ScenarioLauncher config.autoInstrumentAppStarts = NO; config.autoInstrumentViewControllers = NO; config.autoInstrumentNetworkRequests = NO; + config.autoInstrumentRendering = YES; config.internal.autoTriggerExportOnBatchSize = 1; [BugsnagPerformance startWithConfiguration:config]; diff --git a/test/react-native/features/fixtures/scenario-launcher/scenarios/NativeIntegrationScenario.js b/test/react-native/features/fixtures/scenario-launcher/scenarios/NativeIntegrationScenario.js index 573f94177..f9cd7f8e2 100644 --- a/test/react-native/features/fixtures/scenario-launcher/scenarios/NativeIntegrationScenario.js +++ b/test/react-native/features/fixtures/scenario-launcher/scenarios/NativeIntegrationScenario.js @@ -11,14 +11,30 @@ export const initialise = async (config) => { endpoint: config.endpoint } + const onSpanEnd = [ + async (span) => { + span.setAttribute('custom.string.attribute', 'test') + span.setAttribute('custom.int.attribute', 12345) + span.setAttribute('custom.double.attribute', 123.45) + span.setAttribute('custom.boolean.attribute', true) + span.setAttribute('custom.stringarray.attribute', ['a', 'b', 'c']) + span.setAttribute('custom.intarray.attribute', [1, 2, 3]) + span.setAttribute('custom.doublearray.attribute', [1.1, 2.2, 3.3]) + return true + } + ] + await NativeScenarioLauncher.startNativePerformance(nativeConfig) - BugsnagPerformance.attach({ maximumBatchSize: 1, autoInstrumentAppStarts: false, autoInstrumentNetworkRequests: false }) + BugsnagPerformance.attach({ onSpanEnd, maximumBatchSize: 1, autoInstrumentAppStarts: false, autoInstrumentNetworkRequests: false }) } export const App = () => { useEffect(() => { - BugsnagPerformance.startSpan('NativeIntegration').end() + const parentSpan = BugsnagPerformance.startSpan('JS parent span') + const childSpan = BugsnagPerformance.startSpan('Native child span', { isFirstClass: true }) + childSpan.end() + parentSpan.end() }, []) return ( diff --git a/test/react-native/features/native-integration.feature b/test/react-native/features/native-integration.feature index 8bd1ed2f0..b4598d57a 100644 --- a/test/react-native/features/native-integration.feature +++ b/test/react-native/features/native-integration.feature @@ -1,10 +1,68 @@ @native_integration Feature: Native Integration - Scenario: Native Integration + Scenario: First class custom spans are delegated to the native SDK When I run 'NativeIntegrationScenario' - And I wait to receive 1 span - Then a span named "NativeIntegration" contains the attributes: - | attribute | type | value | - | bugsnag.span.category | stringValue | custom | + And I wait to receive 2 sampling requests + And I wait to receive 2 traces + # JS trace + And the trace payload field "resourceSpans.0.resource" string attribute "service.name" equals "com.bugsnag.fixtures.reactnative.performance" + And the trace payload field "resourceSpans.0.resource" string attribute "telemetry.sdk.name" equals "bugsnag.performance.reactnative" + + And the trace payload field "resourceSpans.0.scopeSpans.0.spans.0.name" equals "JS parent span" + And the trace payload field "resourceSpans.0.scopeSpans.0.spans.0" double attribute "bugsnag.sampling.p" equals 1.0 + And the trace payload field "resourceSpans.0.scopeSpans.0.spans.0" string attribute "bugsnag.span.category" equals "custom" + + And the trace payload field "resourceSpans.0.scopeSpans.0.spans.0" string attribute "custom.string.attribute" equals "test" + And the trace payload field "resourceSpans.0.scopeSpans.0.spans.0" integer attribute "custom.int.attribute" equals 12345 + And the trace payload field "resourceSpans.0.scopeSpans.0.spans.0" double attribute "custom.double.attribute" equals 123.45 + And the trace payload field "resourceSpans.0.scopeSpans.0.spans.0" boolean attribute "custom.boolean.attribute" is true + And the trace payload field "resourceSpans.0.scopeSpans.0.spans.0" string array attribute "custom.stringarray.attribute" equals the array: + | a | + | b | + | c | + And the trace payload field "resourceSpans.0.scopeSpans.0.spans.0" integer array attribute "custom.intarray.attribute" equals the array: + | 1 | + | 2 | + | 3 | + And the trace payload field "resourceSpans.0.scopeSpans.0.spans.0" double array attribute "custom.doublearray.attribute" equals the array: + | 1.1 | + | 2.2 | + | 3.3 | + + And the trace payload field "resourceSpans.0.scopeSpans.0.spans.0.spanId" is stored as the value "parentSpanId" + And the trace payload field "resourceSpans.0.scopeSpans.0.spans.0.traceId" is stored as the value "traceId" + + Then I discard the oldest trace + + # Native trace + And the trace payload field "resourceSpans.0.resource" string attribute "service.name" equals "com.bugsnag.fixtures.reactnative.performance" + And the trace payload field "resourceSpans.0.resource" string attribute "telemetry.sdk.name" equals the platform-dependent string: + | ios | bugsnag.performance.cocoa | + | android | bugsnag.performance.android | + + And the trace payload field "resourceSpans.0.scopeSpans.0.spans.0.name" equals "Native child span" + And the trace payload field "resourceSpans.0.scopeSpans.0.spans.0.parentSpanId" equals the stored value "parentSpanId" + And the trace payload field "resourceSpans.0.scopeSpans.0.spans.0.traceId" equals the stored value "traceId" + + And the trace payload field "resourceSpans.0.scopeSpans.0.spans.0" double attribute "bugsnag.sampling.p" equals 1.0 + And the trace payload field "resourceSpans.0.scopeSpans.0.spans.0" string attribute "bugsnag.span.category" equals "custom" + And the trace payload field "resourceSpans.0.scopeSpans.0.spans.0" boolean attribute "bugsnag.span.first_class" is true + + And the trace payload field "resourceSpans.0.scopeSpans.0.spans.0" string attribute "custom.string.attribute" equals "test" + And the trace payload field "resourceSpans.0.scopeSpans.0.spans.0" integer attribute "custom.int.attribute" equals 12345 + And the trace payload field "resourceSpans.0.scopeSpans.0.spans.0" double attribute "custom.double.attribute" equals 123.45 + And the trace payload field "resourceSpans.0.scopeSpans.0.spans.0" boolean attribute "custom.boolean.attribute" is true + And the trace payload field "resourceSpans.0.scopeSpans.0.spans.0" string array attribute "custom.stringarray.attribute" equals the array: + | a | + | b | + | c | + And the trace payload field "resourceSpans.0.scopeSpans.0.spans.0" integer array attribute "custom.intarray.attribute" equals the array: + | 1 | + | 2 | + | 3 | + And the trace payload field "resourceSpans.0.scopeSpans.0.spans.0" double array attribute "custom.doublearray.attribute" equals the array: + | 1.1 | + | 2.2 | + | 3.3 | \ No newline at end of file