Skip to content

Commit ac8b6e0

Browse files
odeke-emodeke-em
committed
feat(observability): trace Transaction
This change adds observability tracing for Transaction along with tests. Alsoo while here, added SessionPool.createSessions span. Updates googleapis#2079 Built from PR googleapis#2087 Updates googleapis#2114
1 parent 5237e11 commit ac8b6e0

File tree

7 files changed

+1343
-382
lines changed

7 files changed

+1343
-382
lines changed

‎observability-test/spanner.ts

Lines changed: 286 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -112,6 +112,61 @@ async function setup(
112112
}
113113

114114
describe('EndToEnd', () => {
115+
const selectSql = 'SELECT 1';
116+
const updateSql = 'UPDATE FOO SET BAR=1 WHERE BAZ=2';
117+
118+
let server: grpc.Server;
119+
let spanner: Spanner;
120+
let database: Database;
121+
let spannerMock: mock.MockSpanner;
122+
let traceExporter: typeof InMemorySpanExporter;
123+
124+
const contextManager = new AsyncHooksContextManager();
125+
setGlobalContextManager(contextManager);
126+
127+
afterEach(() => {
128+
disableContextAndManager(contextManager);
129+
});
130+
131+
beforeEach(async () => {
132+
const setupResult = await setup();
133+
spanner = setupResult.spanner;
134+
server = setupResult.server;
135+
spannerMock = setupResult.spannerMock;
136+
137+
spannerMock.putStatementResult(
138+
selectSql,
139+
mock.StatementResult.resultSet(createSelect1ResultSet())
140+
);
141+
spannerMock.putStatementResult(
142+
updateSql,
143+
mock.StatementResult.updateCount(1)
144+
);
145+
146+
traceExporter = new InMemorySpanExporter();
147+
const sampler = new AlwaysOnSampler();
148+
149+
const provider = new NodeTracerProvider({
150+
sampler: sampler,
151+
exporter: traceExporter,
152+
});
153+
provider.addSpanProcessor(new SimpleSpanProcessor(traceExporter));
154+
155+
const instance = spanner.instance('instance');
156+
database = instance.database('database');
157+
database._observabilityOptions = {
158+
tracerProvider: provider,
159+
enableExtendedTracing: false,
160+
};
161+
});
162+
163+
afterEach(() => {
164+
traceExporter.reset();
165+
spannerMock.resetRequests();
166+
spanner.close();
167+
server.tryShutdown(() => {});
168+
});
169+
115170
describe('Database', () => {
116171
let server: grpc.Server;
117172
let spanner: Spanner;
@@ -205,7 +260,7 @@ describe('EndToEnd', () => {
205260

206261
traceExporter.forceFlush();
207262
const spans = traceExporter.getFinishedSpans();
208-
assert.strictEqual(spans.length, 1, 'Exactly 1 span expected');
263+
assert.strictEqual(spans.length, 4);
209264

210265
const actualSpanNames: string[] = [];
211266
const actualEventNames: string[] = [];
@@ -216,14 +271,19 @@ describe('EndToEnd', () => {
216271
});
217272
});
218273

219-
const expectedSpanNames = ['CloudSpanner.Database.getSnapshot'];
274+
const expectedSpanNames = [
275+
'CloudSpanner.Snapshot.begin',
276+
'CloudSpanner.Database.getSnapshot',
277+
'CloudSpanner.Snapshot.runStream',
278+
'CloudSpanner.Snapshot.run',
279+
];
220280
assert.deepStrictEqual(
221281
actualSpanNames,
222282
expectedSpanNames,
223283
`span names mismatch:\n\tGot: ${actualSpanNames}\n\tWant: ${expectedSpanNames}`
224284
);
225285

226-
const expectedEventNames = [];
286+
const expectedEventNames = ['Begin Transaction'];
227287
assert.deepStrictEqual(
228288
actualEventNames,
229289
expectedEventNames,
@@ -279,7 +339,7 @@ describe('EndToEnd', () => {
279339
.on('end', () => {
280340
traceExporter.forceFlush();
281341
const spans = traceExporter.getFinishedSpans();
282-
assert.strictEqual(spans.length, 1, 'Exactly 1 span expected');
342+
assert.strictEqual(spans.length, 2);
283343

284344
const actualSpanNames: string[] = [];
285345
const actualEventNames: string[] = [];
@@ -290,7 +350,10 @@ describe('EndToEnd', () => {
290350
});
291351
});
292352

293-
const expectedSpanNames = ['CloudSpanner.Database.runStream'];
353+
const expectedSpanNames = [
354+
'CloudSpanner.Snapshot.runStream',
355+
'CloudSpanner.Database.runStream',
356+
];
294357
assert.deepStrictEqual(
295358
actualSpanNames,
296359
expectedSpanNames,
@@ -313,7 +376,7 @@ describe('EndToEnd', () => {
313376

314377
traceExporter.forceFlush();
315378
const spans = traceExporter.getFinishedSpans();
316-
assert.strictEqual(spans.length, 2, 'Exactly 2 spans expected');
379+
assert.strictEqual(spans.length, 3, 'Exactly 2 spans expected');
317380

318381
// Sort the spans by duration.
319382
spans.sort((spanA, spanB) => {
@@ -330,6 +393,7 @@ describe('EndToEnd', () => {
330393
});
331394

332395
const expectedSpanNames = [
396+
'CloudSpanner.Snapshot.runStream',
333397
'CloudSpanner.Database.runStream',
334398
'CloudSpanner.Database.run',
335399
];
@@ -375,7 +439,7 @@ describe('EndToEnd', () => {
375439

376440
traceExporter.forceFlush();
377441
const spans = traceExporter.getFinishedSpans();
378-
assert.strictEqual(spans.length, 1, 'Exactly 1 span expected');
442+
assert.strictEqual(spans.length, 3);
379443

380444
const actualEventNames: string[] = [];
381445
const actualSpanNames: string[] = [];
@@ -386,7 +450,11 @@ describe('EndToEnd', () => {
386450
});
387451
});
388452

389-
const expectedSpanNames = ['CloudSpanner.Database.runTransaction'];
453+
const expectedSpanNames = [
454+
'CloudSpanner.Database.runTransaction',
455+
'CloudSpanner.Snapshot.runStream',
456+
'CloudSpanner.Snapshot.run',
457+
];
390458
assert.deepStrictEqual(
391459
actualSpanNames,
392460
expectedSpanNames,
@@ -413,7 +481,7 @@ describe('EndToEnd', () => {
413481

414482
traceExporter.forceFlush();
415483
const spans = traceExporter.getFinishedSpans();
416-
assert.strictEqual(spans.length, 1, 'Exactly 1 span expected');
484+
assert.strictEqual(spans.length, 2, 'Exactly 1 span expected');
417485

418486
const actualEventNames: string[] = [];
419487
const actualSpanNames: string[] = [];
@@ -424,14 +492,21 @@ describe('EndToEnd', () => {
424492
});
425493
});
426494

427-
const expectedSpanNames = ['CloudSpanner.Database.writeAtLeastOnce'];
495+
const expectedSpanNames = [
496+
'CloudSpanner.Transaction.commit',
497+
'CloudSpanner.Database.writeAtLeastOnce',
498+
];
428499
assert.deepStrictEqual(
429500
actualSpanNames,
430501
expectedSpanNames,
431502
`span names mismatch:\n\tGot: ${actualSpanNames}\n\tWant: ${expectedSpanNames}`
432503
);
433504

434-
const expectedEventNames = ['Using Session'];
505+
const expectedEventNames = [
506+
'Starting Commit',
507+
'Commit Done',
508+
'Using Session',
509+
];
435510
assert.deepStrictEqual(
436511
actualEventNames,
437512
expectedEventNames,
@@ -442,6 +517,206 @@ describe('EndToEnd', () => {
442517
});
443518
});
444519
});
520+
521+
describe('Transaction', () => {
522+
it('run', done => {
523+
database.getTransaction((err, tx) => {
524+
assert.ifError(err);
525+
526+
tx!.run('SELECT 1', (err, rows) => {
527+
traceExporter.forceFlush();
528+
529+
const spans = traceExporter.getFinishedSpans();
530+
assert.strictEqual(spans.length, 3);
531+
532+
const actualSpanNames: string[] = [];
533+
const actualEventNames: string[] = [];
534+
spans.forEach(span => {
535+
actualSpanNames.push(span.name);
536+
span.events.forEach(event => {
537+
actualEventNames.push(event.name);
538+
});
539+
});
540+
541+
const expectedSpanNames = [
542+
'CloudSpanner.Database.getTransaction',
543+
'CloudSpanner.Snapshot.runStream',
544+
'CloudSpanner.Snapshot.run',
545+
];
546+
assert.deepStrictEqual(
547+
actualSpanNames,
548+
expectedSpanNames,
549+
`span names mismatch:\n\tGot: ${actualSpanNames}\n\tWant: ${expectedSpanNames}`
550+
);
551+
552+
const expectedEventNames = ['Using Session'];
553+
assert.strictEqual(
554+
actualEventNames.every(value => expectedEventNames.includes(value)),
555+
true,
556+
`Unexpected events:\n\tGot: ${actualEventNames}\n\tWant: ${expectedEventNames}`
557+
);
558+
559+
done();
560+
});
561+
});
562+
});
563+
564+
it('Transaction.begin+Dml.runUpdate', done => {
565+
database.getTransaction((err, tx) => {
566+
assert.ifError(err);
567+
568+
// Firstly erase the prior spans so that we can have only Transaction spans.
569+
traceExporter.reset();
570+
571+
tx!.begin();
572+
tx!.runUpdate(updateSql, (err, rowCount) => {
573+
assert.ifError(err);
574+
575+
traceExporter.forceFlush();
576+
577+
const spans = traceExporter.getFinishedSpans();
578+
assert.strictEqual(spans.length, 4);
579+
580+
const actualSpanNames: string[] = [];
581+
const actualEventNames: string[] = [];
582+
spans.forEach(span => {
583+
actualSpanNames.push(span.name);
584+
span.events.forEach(event => {
585+
actualEventNames.push(event.name);
586+
});
587+
});
588+
589+
const expectedSpanNames = [
590+
'CloudSpanner.Snapshot.begin',
591+
'CloudSpanner.Snapshot.runStream',
592+
'CloudSpanner.Snapshot.run',
593+
'CloudSpanner.Dml.runUpdate',
594+
];
595+
assert.deepStrictEqual(
596+
actualSpanNames,
597+
expectedSpanNames,
598+
`span names mismatch:\n\tGot: ${actualSpanNames}\n\tWant: ${expectedSpanNames}`
599+
);
600+
601+
const expectedEventNames = [
602+
'Begin Transaction',
603+
'Transaction Creation Done',
604+
];
605+
assert.strictEqual(
606+
actualEventNames.every(value => expectedEventNames.includes(value)),
607+
true,
608+
`Unexpected events:\n\tGot: ${actualEventNames}\n\tWant: ${expectedEventNames}`
609+
);
610+
611+
done();
612+
});
613+
});
614+
});
615+
616+
it('runStream', done => {
617+
let rowCount = 0;
618+
database.getTransaction((err, tx) => {
619+
assert.ifError(err);
620+
tx!
621+
.runStream(selectSql)
622+
.on('data', () => rowCount++)
623+
.on('error', assert.ifError)
624+
.on('stats', _stats => {})
625+
.on('end', () => {
626+
tx!.end();
627+
628+
traceExporter.forceFlush();
629+
630+
const spans = traceExporter.getFinishedSpans();
631+
assert.strictEqual(spans.length, 2);
632+
633+
const actualSpanNames: string[] = [];
634+
const actualEventNames: string[] = [];
635+
spans.forEach(span => {
636+
actualSpanNames.push(span.name);
637+
span.events.forEach(event => {
638+
actualEventNames.push(event.name);
639+
});
640+
});
641+
642+
const expectedSpanNames = [
643+
'CloudSpanner.Database.getTransaction',
644+
'CloudSpanner.Snapshot.runStream',
645+
];
646+
assert.deepStrictEqual(
647+
actualSpanNames,
648+
expectedSpanNames,
649+
`span names mismatch:\n\tGot: ${actualSpanNames}\n\tWant: ${expectedSpanNames}`
650+
);
651+
652+
const expectedEventNames = ['Using Session'];
653+
assert.deepStrictEqual(
654+
actualEventNames,
655+
expectedEventNames,
656+
`Unexpected events:\n\tGot: ${actualEventNames}\n\tWant: ${expectedEventNames}`
657+
);
658+
659+
done();
660+
});
661+
});
662+
});
663+
664+
it('rollback', done => {
665+
database.getTransaction((err, tx) => {
666+
assert.ifError(err);
667+
668+
// Firstly erase the prior spans so that we can have only Transaction spans.
669+
traceExporter.reset();
670+
671+
tx!.begin();
672+
673+
tx!.runUpdate(updateSql, async (err, rowCount) => {
674+
assert.ifError(err);
675+
tx!.rollback(err => {
676+
traceExporter.forceFlush();
677+
678+
const spans = traceExporter.getFinishedSpans();
679+
680+
const actualSpanNames: string[] = [];
681+
const actualEventNames: string[] = [];
682+
spans.forEach(span => {
683+
actualSpanNames.push(span.name);
684+
span.events.forEach(event => {
685+
actualEventNames.push(event.name);
686+
});
687+
});
688+
689+
const expectedSpanNames = [
690+
'CloudSpanner.Snapshot.begin',
691+
'CloudSpanner.Snapshot.runStream',
692+
'CloudSpanner.Snapshot.run',
693+
'CloudSpanner.Dml.runUpdate',
694+
'CloudSpanner.Transaction.rollback',
695+
];
696+
assert.deepStrictEqual(
697+
actualSpanNames,
698+
expectedSpanNames,
699+
`span names mismatch:\n\tGot: ${actualSpanNames}\n\tWant: ${expectedSpanNames}`
700+
);
701+
702+
const expectedEventNames = [
703+
'Begin Transaction',
704+
'Transaction Creation Done',
705+
];
706+
assert.strictEqual(
707+
actualEventNames.every(value =>
708+
expectedEventNames.includes(value)
709+
),
710+
true,
711+
`Unexpected events:\n\tGot: ${actualEventNames}\n\tWant: ${expectedEventNames}`
712+
);
713+
714+
done();
715+
});
716+
});
717+
});
718+
});
719+
});
445720
});
446721

447722
describe('ObservabilityOptions injection and propagation', async () => {

0 commit comments

Comments
 (0)