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

feat: add sqlcommenter comment with trace context to queries in pg instrumentation #1286

Merged
merged 19 commits into from
Nov 24, 2022
Merged
Show file tree
Hide file tree
Changes from 8 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
2 changes: 2 additions & 0 deletions plugins/node/opentelemetry-instrumentation-pg/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -48,6 +48,8 @@ PostgreSQL instrumentation has few options available to choose from. You can set
| ------- | ---- | ----------- |
| [`enhancedDatabaseReporting`](./src/types.ts#L30) | `boolean` | If true, additional information about query parameters and results will be attached (as `attributes`) to spans representing database operations |
| `responseHook` | `PgInstrumentationExecutionResponseHook` (function) | Function for adding custom attributes from db response |
| `requireParentSpan` | `boolean` | If true, requires a parent span to create new spans (default false) |
Copy link
Contributor Author

Choose a reason for hiding this comment

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

This was previously added, but README was out of date.

| `addSqlCommenterCommentToQueries` | `boolean` | If true, adds [sqlcommenter](https://github.com/open-telemetry/opentelemetry-sqlcommenter) specification compliant comment to queries with tracing context |

## Useful links

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -72,6 +72,7 @@
"typescript": "4.3.5"
},
"dependencies": {
"@opentelemetry/core": "^1.8.0",
"@opentelemetry/instrumentation": "^0.34.0",
"@opentelemetry/semantic-conventions": "^1.0.0",
"@types/pg": "8.6.1",
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -178,6 +178,7 @@ export class PgInstrumentation extends InstrumentationBase {
// Handle different client.query(...) signatures
if (typeof args[0] === 'string') {
const query = args[0];

if (args.length > 1 && args[1] instanceof Array) {
const params = args[1];
span = utils.handleParameterizedQuery.call(
Expand All @@ -195,14 +196,29 @@ export class PgInstrumentation extends InstrumentationBase {
query
);
}

if (plugin.getConfig().addSqlCommenterCommentToQueries) {
// Modify the query with a tracing comment
args[0] = utils.addSqlCommenterComment(span, args[0]);
}
} else if (typeof args[0] === 'object') {
const queryConfig = args[0] as NormalizedQueryConfig;

span = utils.handleConfigQuery.call(
this,
plugin.tracer,
plugin.getConfig(),
queryConfig
);

if (plugin.getConfig().addSqlCommenterCommentToQueries) {
// Copy the query config instead of writing to args[0].text so that we don't modify user's
// original query config reference
args[0] = {
...queryConfig,
text: utils.addSqlCommenterComment(span, queryConfig.text),
};
}
} else {
return utils.handleInvalidQuery.call(
this,
Expand Down
6 changes: 6 additions & 0 deletions plugins/node/opentelemetry-instrumentation-pg/src/types.ts
Original file line number Diff line number Diff line change
Expand Up @@ -46,4 +46,10 @@ export interface PgInstrumentationConfig extends InstrumentationConfig {
* @default false
*/
requireParentSpan?: boolean;

/**
* If true, queries are modified to also include a comment with
* the tracing context, following the {@link https://github.com/open-telemetry/opentelemetry-sqlcommenter sqlcommenter} format
*/
addSqlCommenterCommentToQueries?: boolean;
}
56 changes: 56 additions & 0 deletions plugins/node/opentelemetry-instrumentation-pg/src/utils.ts
Original file line number Diff line number Diff line change
Expand Up @@ -24,7 +24,10 @@ import {
diag,
INVALID_SPAN_CONTEXT,
Attributes,
defaultTextMapSetter,
ROOT_CONTEXT,
} from '@opentelemetry/api';
import { W3CTraceContextPropagator } from '@opentelemetry/core';
import { AttributeNames } from './enums/AttributeNames';
import {
SemanticAttributes,
Expand Down Expand Up @@ -289,3 +292,56 @@ export function patchClientConnectCallback(
cb.call(this, err);
};
}

function hasValidSqlComment(query: string): boolean {
const indexOpeningDashDashComment = query.indexOf('--');
Copy link

Choose a reason for hiding this comment

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

The query might contain "--" as part of parameter. In that case, this method will return true that the query contains a comment.

For Ex:

SELECT c1 FROM t1 WHERE c2 = '--<search_text>';

I am not sure how to detect correctly that a query contains a comment without using a parser.
Should we add a comment at-least for now that this may not be completely correct and revisit once we have a proper solution or a change in the spec ?

Copy link
Contributor Author

@henrinormak henrinormak Nov 24, 2022

Choose a reason for hiding this comment

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

Does the same also apply for the block comment? i.e if it is inside of a string literal, it is not a comment? I took the current code almost verbatim from the existing sqlcommenter Node implementation (the knex one for example), so the fault is present there as well.

Adding a parser would not really be a problem, I think, although not sure what the overhead would be for each query execution, perhaps a comment in the source code + a OpenTelemetry diagnostic log line for queries that are ignored is a nice starting point?

Copy link

Choose a reason for hiding this comment

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

Yes, it might affect a block comment also. I agree the issue originates in the original SQLCommenter libraries. That's why i am inclined towards adding a comment regarding this issue here (and if possible callout in docs).

Adding a parser might affect the performance as well as will be an additional dependency in this library (which databases are anyway doing).

We are thinking if the specs regarding "do not add a comment if there is already a comment" could be modified. Should it just be "add a new comment at the end of the statement" ?.
But, for that we need to understand whether different databases (at-least the supported ones Postgres, MySQL, SQLite, etc) have any constraints on comments and whether any popular "hint"(Ex pg_hint_plan, MySQL query hints) features will get affected if multiple comment sections are present.

So, maybe till that is finalised, we can add a comment and tech debt maybe ?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Added a comment and a short note to the README for the flag.

if (indexOpeningDashDashComment >= 0) {
return true;
}

const indexOpeningSlashComment = query.indexOf('/*');
if (indexOpeningSlashComment < 0) {
return false;
}

const indexClosingSlashComment = query.indexOf('*/');
return indexOpeningDashDashComment < indexClosingSlashComment;
}

export function addSqlCommenterComment(span: Span, query: string): string {
if (query.length === 0 || typeof query !== 'string') {
henrinormak marked this conversation as resolved.
Show resolved Hide resolved
return query;
}

// As per sqlcommenter spec we shall not add a comment if there already is a comment
// in the query
if (hasValidSqlComment(query)) {
return query;
}

const propagator = new W3CTraceContextPropagator();
const headers: { [key: string]: string } = {};
propagator.inject(
trace.setSpan(ROOT_CONTEXT, span),
headers,
defaultTextMapSetter
Flarna marked this conversation as resolved.
Show resolved Hide resolved
);

// sqlcommenter spec requires keys in the comment to be sorted lexicographically
const sortedKeys = Object.keys(headers).sort();

if (sortedKeys.length === 0) {
return query;
}

const commentString = sortedKeys
.map((key) => {
const escapedValue = headers[key].replace(/([^\\])(')/g, (_, prefix) => {
henrinormak marked this conversation as resolved.
Show resolved Hide resolved
blumamir marked this conversation as resolved.
Show resolved Hide resolved
henrinormak marked this conversation as resolved.
Show resolved Hide resolved
return `${prefix}\\'`;
});
return `${key}='${escapedValue}'`;
})
.join(",");
henrinormak marked this conversation as resolved.
Show resolved Hide resolved

return `${query} /*${commentString}*/`;
}
118 changes: 118 additions & 0 deletions plugins/node/opentelemetry-instrumentation-pg/test/pg.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -44,6 +44,7 @@ import {
DbSystemValues,
} from '@opentelemetry/semantic-conventions';
import { isSupported } from './utils';
import { addSqlCommenterComment } from '../src/utils';

const pgVersion = require('pg/package.json').version;
const nodeVersion = process.versions.node;
Expand Down Expand Up @@ -99,6 +100,7 @@ describe('pg', () => {
instrumentation.enable();
}

let executedQueries: (pg.Query & { text?: string })[];
let postgres: typeof pg;
let client: pg.Client;
let instrumentation: PgInstrumentation;
Expand Down Expand Up @@ -141,8 +143,21 @@ describe('pg', () => {
context.setGlobalContextManager(contextManager);
instrumentation.setTracerProvider(provider);

executedQueries = [];
postgres = require('pg');
client = new postgres.Client(CONFIG);

// We need to track the actual queries that get executed to assert
// that the sqlcommenter logic works
const privateClient: {
queryQueue: (pg.Query & { text?: string })[];
} = client as any;
const originalPush = privateClient.queryQueue.push;
privateClient.queryQueue.push = (...items) => {
executedQueries.push(...items);
return originalPush.apply(privateClient.queryQueue, items);
};

henrinormak marked this conversation as resolved.
Show resolved Hide resolved
await client.connect();
});

Expand All @@ -161,6 +176,7 @@ describe('pg', () => {
afterEach(() => {
memoryExporter.reset();
context.disable();
executedQueries.splice(0, executedQueries.length);
});

it('should return an instrumentation', () => {
Expand Down Expand Up @@ -649,6 +665,108 @@ describe('pg', () => {
});
});

it('should not add sqlcommenter comment when flag is not specified', async () => {
const span = tracer.startSpan('test span');
await context.with(trace.setSpan(context.active(), span), async () => {
try {
const query = 'SELECT NOW()';
const resPromise = await client.query(query);
assert.ok(resPromise);

const [span] = memoryExporter.getFinishedSpans();
assert.ok(span);

const commentedQuery = addSqlCommenterComment(
trace.wrapSpanContext(span.spanContext()),
query
);
assert.equal(executedQueries.length, 1);
assert.equal(executedQueries[0].text, query);
assert.notEqual(query, commentedQuery);
} catch (e) {
assert.ok(false, e.message);
}
});
});

it('should not add sqlcommenter comment with client.query({text, callback}) when flag is not specified', done => {
const span = tracer.startSpan('test span');
context.with(trace.setSpan(context.active(), span), () => {
const query = 'SELECT NOW()';
client.query({
text: query,
callback: (err: Error, res: pg.QueryResult) => {
assert.strictEqual(err, null);
assert.ok(res);

const [span] = memoryExporter.getFinishedSpans();
const commentedQuery = addSqlCommenterComment(
trace.wrapSpanContext(span.spanContext()),
query
);
assert.equal(executedQueries.length, 1);
assert.equal(executedQueries[0].text, query);
assert.notEqual(query, commentedQuery);
done();
},
} as pg.QueryConfig);
});
});

it('should add sqlcommenter comment when addSqlCommenterCommentToQueries=true is specified', async () => {
instrumentation.setConfig({
addSqlCommenterCommentToQueries: true,
});

const span = tracer.startSpan('test span');
await context.with(trace.setSpan(context.active(), span), async () => {
try {
const query = 'SELECT NOW()';
const resPromise = await client.query(query);
assert.ok(resPromise);

const [span] = memoryExporter.getFinishedSpans();
const commentedQuery = addSqlCommenterComment(
Flarna marked this conversation as resolved.
Show resolved Hide resolved
trace.wrapSpanContext(span.spanContext()),
query
);
assert.equal(executedQueries.length, 1);
assert.equal(executedQueries[0].text, commentedQuery);
assert.notEqual(query, commentedQuery);
} catch (e) {
assert.ok(false, e.message);
}
});
});

it('should add sqlcommenter comment when addSqlCommenterCommentToQueries=true is specified with client.query({text, callback})', done => {
instrumentation.setConfig({
addSqlCommenterCommentToQueries: true,
});

const span = tracer.startSpan('test span');
context.with(trace.setSpan(context.active(), span), () => {
const query = 'SELECT NOW()';
client.query({
text: query,
callback: (err: Error, res: pg.QueryResult) => {
assert.strictEqual(err, null);
assert.ok(res);

const [span] = memoryExporter.getFinishedSpans();
const commentedQuery = addSqlCommenterComment(
trace.wrapSpanContext(span.spanContext()),
query
);
assert.equal(executedQueries.length, 1);
assert.equal(executedQueries[0].text, commentedQuery);
assert.notEqual(query, commentedQuery);
done();
},
} as pg.QueryConfig);
});
});

it('should not generate traces for client.query() when requireParentSpan=true is specified', done => {
instrumentation.setConfig({
requireParentSpan: true,
Expand Down
Loading