Skip to content
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.

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

fix(instrumentation-fetch): perf observer bugs #1868

Merged
merged 4 commits into from
Jan 30, 2021
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
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
16 changes: 9 additions & 7 deletions packages/opentelemetry-instrumentation-fetch/src/fetch.ts
Original file line number Diff line number Diff line change
Expand Up @@ -32,7 +32,7 @@ import { VERSION } from './version';
// hard to say how long it should really wait, seems like 300ms is
// safe enough
const OBSERVER_WAIT_TIME_MS = 300;

const urlNormalizingA = document.createElement('a');
/**
* FetchPlugin Config
*/
Expand Down Expand Up @@ -252,11 +252,10 @@ export class FetchInstrumentation extends InstrumentationBase<
response: FetchResponse
) {
const endTime = core.hrTime();
spanData.observer?.disconnect();

this._addFinalSpanAttributes(span, response);

setTimeout(() => {
spanData.observer?.disconnect();
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This was really subtle; thanks for catching it.

this._findResourceAndAddNetworkEvents(span, spanData, endTime);
this._tasksCount--;
this._clearResources();
Expand Down Expand Up @@ -352,15 +351,18 @@ export class FetchInstrumentation extends InstrumentationBase<
private _prepareSpanData(spanUrl: string): SpanData {
const startTime = core.hrTime();
const entries: PerformanceResourceTiming[] = [];

if (typeof window.PerformanceObserver === 'undefined') {
return { entries, startTime, spanUrl };
}

const observer: PerformanceObserver = new PerformanceObserver(list => {
const entries = list.getEntries() as PerformanceResourceTiming[];
entries.forEach(entry => {
if (entry.initiatorType === 'fetch' && entry.name === spanUrl) {
const perfObsEntries = list.getEntries() as PerformanceResourceTiming[];
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Feels like we should have a separate PR to turn on no-shadow for eslint. A quick trial of it shows 101 instances in this repo.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If you think that would avoid more bugs, could you open an issue so someone can handle it at some point ? (i could have opened it but i don't really understand whats shadowing exactly)

urlNormalizingA.href = spanUrl;
perfObsEntries.forEach(entry => {
if (
entry.initiatorType === 'fetch' &&
entry.name === urlNormalizingA.href
) {
entries.push(entry);
}
});
Expand Down
120 changes: 118 additions & 2 deletions packages/opentelemetry-instrumentation-fetch/test/fetch.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -96,6 +96,36 @@ function createMainResource(resource = {}): PerformanceResourceTiming {
return mainResource;
}

function createFakePerformanceObs(url: string) {
class FakePerfObs implements PerformanceObserver {
constructor(private readonly cb: PerformanceObserverCallback) {}
observe() {
const absoluteUrl = url.startsWith('http') ? url : location.origin + url;
const resources: PerformanceObserverEntryList = {
getEntries(): PerformanceEntryList {
return [
createResource({ name: absoluteUrl }) as any,
createMainResource({ name: absoluteUrl }) as any,
];
},
getEntriesByName(): PerformanceEntryList {
return [];
},
getEntriesByType(): PerformanceEntryList {
return [];
},
};
this.cb(resources, this);
}
disconnect() {}
takeRecords(): PerformanceEntryList {
return [];
}
}

return FakePerfObs;
}

describe('fetch', () => {
let sandbox: sinon.SinonSandbox;
let contextManager: ZoneContextManager;
Expand Down Expand Up @@ -169,7 +199,12 @@ describe('fetch', () => {

if (disablePerfObserver) {
sandbox.stub(window, 'PerformanceObserver').value(undefined);
} else {
sandbox
.stub(window, 'PerformanceObserver')
.value(createFakePerformanceObs(fileUrl));
}

if (disableGetEntries) {
sandbox.stub(performance, 'getEntriesByType').value(undefined);
} else {
Expand Down Expand Up @@ -597,6 +632,64 @@ describe('fetch', () => {
});
});

describe('when PerformanceObserver is used by default', () => {
beforeEach(done => {
// All above tests test it already but just in case
// lets explicitly turn getEntriesByType off so we can be sure
// that the perf entries come from the observer.
prepareData(done, url, {}, undefined, false, true);
});
afterEach(() => {
clearData();
});
it('should create both spans with network events', () => {
const span: tracing.ReadableSpan = exportSpy.args[0][0][0];
const events = span.events;

assert.strictEqual(
exportSpy.args.length,
2,
`Wrong number of spans: ${exportSpy.args.length}`
);

assert.strictEqual(events.length, 9, 'number of events is wrong');

assert.strictEqual(
events[6].name,
PTN.REQUEST_START,
`event ${PTN.REQUEST_START} is not defined`
);
});
});

describe('when fetching with relative url', () => {
beforeEach(done => {
prepareData(done, '/get', {}, undefined, false, true);
});
afterEach(() => {
clearData();
});
it('should create spans with network info', () => {
// no prefetch span because mock observer uses location.origin as url when relative
// and prefetch span finding compares url origins
const span: tracing.ReadableSpan = exportSpy.args[0][0][0];
const events = span.events;

assert.strictEqual(
exportSpy.args.length,
1,
`Wrong number of spans: ${exportSpy.args.length}`
);

assert.strictEqual(events.length, 9, 'number of events is wrong');
assert.strictEqual(
events[6].name,
PTN.REQUEST_START,
`event ${PTN.REQUEST_START} is not defined`
);
});
});

describe('when PerformanceObserver is undefined', () => {
beforeEach(done => {
prepareData(done, url, {}, undefined, true, false);
Expand All @@ -606,12 +699,21 @@ describe('fetch', () => {
clearData();
});

it('should still create spans', () => {
it('should fallback to getEntries', () => {
const span: tracing.ReadableSpan = exportSpy.args[0][0][0];
const events = span.events;

assert.strictEqual(
exportSpy.args.length,
2,
`Wrong number of spans: ${exportSpy.args.length}`
);
assert.strictEqual(events.length, 9, 'number of events is wrong');
assert.strictEqual(
events[6].name,
PTN.REQUEST_START,
`event ${PTN.REQUEST_START} is not defined`
);
});
});

Expand All @@ -622,7 +724,12 @@ describe('fetch', () => {
afterEach(() => {
clearData();
});
it('should capture fetch without preflight', () => {
it('should still capture fetch with basic attributes', () => {
const span: tracing.ReadableSpan = exportSpy.args[0][0][0];
const events = span.events;
const attributes = span.attributes;
const keys = Object.keys(attributes);

assert.strictEqual(
exportSpy.args.length,
1,
Expand All @@ -633,6 +740,15 @@ describe('fetch', () => {
'HTTP GET',
'wrong span captured'
);

assert.strictEqual(events.length, 0, 'Should not have any events');

// should still have basic attributes
assert.strictEqual(
attributes[keys[3]],
200,
`Missing basic attribute ${HttpAttribute.HTTP_STATUS_CODE}`
);
});
});
});