Skip to content

temp(assets-controller): sentry subspan tracing decorators. #9689

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Draft
Prithpal-Sooriya wants to merge 1 commit into
base: main
Choose a base branch
from
Draft

temp(assets-controller): sentry subspan tracing decorators. #9689

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
7 changes: 7 additions & 0 deletions packages/assets-controller/CHANGELOG.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -13,12 +13,19 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0

### Changed

- Nest the Sentry spans emitted while fetching assets under one root span per pipeline, so that a fetch costs a single Sentry transaction instead of one per measurement ([#9672](https://github.com/MetaMask/core/pull/9672))
- `AssetsFullFetch`, `AssetsControllerFirstInitFetch`, `AssetsDataSourceTiming` and `AssetsDataSourceError` are now recorded as subspans of `AssetsFetchPipeline` (fast lane) or `AssetsBackgroundFetch` (background lane), and `AssetsUpdatePipeline` as a subspan of `AssetsUpdateEnrichment`.
- Pipeline spans are emitted only on the unlock (first-init) fetch of a session. Later polls, force updates and subscription-driven enrichment no longer emit them. `AssetsFullFetch` previously fired on every force update.
- `AssetsFullFetch.duration_ms` now measures middleware execution only, and no longer includes building the data request or committing the result to state.
- Dashboard-facing spans copy numeric span data into tags and backdate `startTime`, so Sentry records them as measurements that Spans widgets charting `p95(duration_ms)` can read.
- `calculateBalanceForAllWallets` emits a single `AggregatedBalanceSelector` subspan under an `AggregatedBalance` parent, instead of one root span per account group.
- Bump `@metamask/keyring-api` from `^23.5.0` to `^23.7.0` ([#9676](https://github.com/MetaMask/core/pull/9676))
- Bump `@metamask/keyring-internal-api` from `^11.0.1` to `^11.0.2` ([#9676](https://github.com/MetaMask/core/pull/9676))
- Bump `@metamask/keyring-snap-client` from `^9.2.0` to `^9.2.1` ([#9676](https://github.com/MetaMask/core/pull/9676))

### Fixed

- A rejected `trace` promise can no longer fail a full fetch or `handleAssetsUpdate` enrichment; tracing is now best-effort throughout, and the underlying work still runs exactly once ([#9672](https://github.com/MetaMask/core/pull/9672))
- `SnapDataSource` now delivers snap-sourced balance updates directly to `AssetsController` via a constructor-supplied `onAssetsUpdate` callback instead of fanning out to `activeSubscriptions`, so updates (e.g. Tron energy/bandwidth) are no longer dropped when no active subscription is tracked for the chain in the SnapDataSource ([#9656](https://github.com/MetaMask/core/pull/9656))

## [11.2.1]
Expand Down
249 changes: 248 additions & 1 deletion packages/assets-controller/src/AssetsController.test.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1395,6 +1395,98 @@ describe('AssetsController', () => {
});

describe('handleAssetsUpdate', () => {
it('nests the update pipeline record under an AssetsUpdateEnrichment root', async () => {
const enrichmentContext = { id: 'assets-update-enrichment' };
const traceMock = jest
.fn()
.mockImplementation(
async (
request: TraceRequest,
fn?: (context?: unknown) => unknown,
) => {
return fn?.(
request.parentContext === undefined
? enrichmentContext
: undefined,
);
},
);
const trace = traceMock as unknown as TraceCallback;

await withController(
{ controllerOptions: { trace } },
async ({ controller }) => {
await controller.handleAssetsUpdate(
{
updateMode: 'merge',
assetsBalance: {
[MOCK_ACCOUNT_ID]: { [MOCK_ASSET_ID]: { amount: '1' } },
},
},
'test-source',
);

const requests = traceMock.mock.calls.map(
([request]) => request as TraceRequest,
);
const byName = (name: string): TraceRequest[] =>
requests.filter((request) => request.name === name);

expect(byName('AssetsUpdateEnrichment')).toMatchObject([
{ parentContext: undefined },
]);
expect(byName('AssetsUpdatePipeline')).toMatchObject([
{
parentContext: enrichmentContext,
data: expect.objectContaining({
source: 'test-source',
duration_ms: expect.any(Number),
has_balance: true,
}),
startTime: expect.any(Number),
},
]);
},
);
});

it('does not fail when the tracer rejects after enrichment completes', async () => {
const trace = jest
.fn()
.mockImplementation(
async (
_request: TraceRequest,
fn?: (context?: unknown) => unknown,
) => {
if (fn) {
await fn({ id: 'parent' });
throw new Error('telemetry failed');
}
return undefined;
},
) as unknown as TraceCallback;

await withController(
{ controllerOptions: { trace } },
async ({ controller }) => {
expect(
await controller.handleAssetsUpdate(
{
updateMode: 'merge',
assetsBalance: {
[MOCK_ACCOUNT_ID]: { [MOCK_ASSET_ID]: { amount: '1' } },
},
},
'test-source',
),
).toBeUndefined();
expect(
controller.state.assetsBalance[MOCK_ACCOUNT_ID]?.[MOCK_ASSET_ID],
).toStrictEqual({ amount: '1' });
},
);
});

it('preserves existing rich metadata when the API response has empty symbol and name', async () => {
const richMetadata: FungibleAssetMetadata = {
type: 'erc20',
Expand Down Expand Up @@ -2519,7 +2611,13 @@ describe('AssetsController', () => {
duration_ms: expect.any(Number),
chain_ids: expect.any(String),
}),
tags: { controller: 'AssetsController' },
// Numeric data is mirrored into tags so the Sentry adapter records
// it as a measurement, and the span is backdated to match.
tags: expect.objectContaining({
controller: 'AssetsController',
duration_ms: expect.any(Number),
}),
startTime: expect.any(Number),
});
const {
duration_ms: durationMs,
Expand All @@ -2533,6 +2631,112 @@ describe('AssetsController', () => {
);
});

it('nests fetch spans under a single AssetsFetchPipeline root on unlock', async () => {
const pipelineContext = { id: 'assets-fetch-pipeline' };
const traceMock = jest
.fn()
.mockImplementation(
async (
request: TraceRequest,
fn?: (context?: unknown) => unknown,
) => {
// Only the root span (no parent of its own) hands out a context.
return fn?.(
request.parentContext === undefined ? pipelineContext : undefined,
);
},
);
const trace = traceMock as unknown as TraceCallback;

await withController(
{
clientControllerState: { isUiOpen: true },
controllerOptions: { trace },
},
async ({ messenger }) => {
(
messenger as unknown as {
publish: (topic: string, payload?: unknown) => void;
}
).publish('ClientController:stateChange', { isUiOpen: true });
messenger.publish('KeyringController:unlock');
await new Promise((resolve) => setTimeout(resolve, 100));

const requests = traceMock.mock.calls.map(
([request]) => request as TraceRequest,
);
const byName = (name: string): TraceRequest[] =>
requests.filter((request) => request.name === name);

expect(byName('AssetsFetchPipeline')).toHaveLength(1);
expect(byName('AssetsFetchPipeline')[0]).toMatchObject({
parentContext: undefined,
tags: { controller: 'AssetsController' },
});

for (const name of [
'AssetsFullFetch',
'AssetsControllerFirstInitFetch',
'AssetsDataSourceTiming',
]) {
const nested = byName(name);
expect(nested.length).toBeGreaterThan(0);
for (const request of nested) {
expect(request.parentContext).toBe(pipelineContext);
}
}
},
);
});

it('does not fail a force update when the tracer rejects after the work completes', async () => {
const trace = jest
.fn()
.mockImplementation(
async (
_request: TraceRequest,
fn?: (context?: unknown) => unknown,
) => {
if (fn) {
await fn({ id: 'parent' });
// Simulate a Sentry adapter failing once the span closes.
throw new Error('telemetry failed');
}
return undefined;
},
) as unknown as TraceCallback;

await withController(
{ controllerOptions: { trace } },
async ({ controller }) => {
expect(
await controller.getAssets([createMockInternalAccount()], {
forceUpdate: true,
}),
).toBeDefined();
},
);
});

it('still runs a force update when the tracer rejects before invoking the work', async () => {
const trace = jest
.fn()
.mockRejectedValue(
new Error('telemetry failed'),
) as unknown as TraceCallback;

await withController(
{ controllerOptions: { trace } },
async ({ controller }) => {
expect(
await controller.getAssets([createMockInternalAccount()], {
forceUpdate: true,
}),
).toBeDefined();
},
);
});

it('replaces pre-lock balances on unlock via merge with covered-chain replacement', async () => {
const fetchV5MultiAccountBalances = jest.fn().mockResolvedValue({
balances: [
Expand Down Expand Up @@ -2627,6 +2831,49 @@ describe('AssetsController', () => {
},
);
});

it('stops emitting pipeline spans once the first-init fetch has reported', async () => {
const traceMock = jest
.fn()
.mockImplementation(
async (_request: TraceRequest, fn?: (context?: unknown) => unknown) =>
fn?.(),
);
const trace = traceMock as unknown as TraceCallback;

await withController(
{
clientControllerState: { isUiOpen: true },
controllerOptions: { trace },
},
async ({ controller, messenger }) => {
(
messenger as unknown as {
publish: (topic: string, payload?: unknown) => void;
}
).publish('ClientController:stateChange', { isUiOpen: true });
messenger.publish('KeyringController:unlock');
await new Promise((resolve) => setTimeout(resolve, 100));

const countSpans = (): Record<string, number> => {
const counts: Record<string, number> = {};
for (const [request] of traceMock.mock.calls) {
const { name } = request as TraceRequest;
counts[name] = (counts[name] ?? 0) + 1;
}
return counts;
};
const before = countSpans();

// Steady-state polling must not keep paying for spans.
await controller.getAssets([createMockInternalAccount()], {
forceUpdate: true,
});

expect(countSpans()).toStrictEqual(before);
},
);
});
});

describe('subscribeAssetsPrice', () => {
Expand Down
Loading
Loading