Skip to content

Commit 4ecc6b4

Browse files
odeke-emodeke-em
committed
feat: (observability): trace Database.runTransactionAsync
Extracted out of PR #2158, this change traces Database.runTransactionAsync. Updates #2079
1 parent 51bc8a7 commit 4ecc6b4

File tree

3 files changed

+225
-38
lines changed

3 files changed

+225
-38
lines changed

‎observability-test/database.ts‎

Lines changed: 131 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1565,6 +1565,137 @@ describe('Database', () => {
15651565
});
15661566
});
15671567

1568+
describe('runTransactionAsync', () => {
1569+
const SESSION = new FakeSession();
1570+
const TRANSACTION = new FakeTransaction(
1571+
{} as google.spanner.v1.TransactionOptions.ReadWrite
1572+
);
1573+
1574+
let pool: FakeSessionPool;
1575+
1576+
beforeEach(() => {
1577+
pool = database.pool_;
1578+
(sandbox.stub(pool, 'getSession') as sinon.SinonStub).callsFake(
1579+
callback => {
1580+
callback(null, SESSION, TRANSACTION);
1581+
}
1582+
);
1583+
});
1584+
1585+
it('with no error', async () => {
1586+
const fakeValue = {};
1587+
1588+
sandbox
1589+
.stub(FakeAsyncTransactionRunner.prototype, 'run')
1590+
.resolves(fakeValue);
1591+
1592+
const value = await database.runTransactionAsync(async txn => {
1593+
const result = await txn.run('SELECT 1');
1594+
await txn.commit();
1595+
return result;
1596+
});
1597+
1598+
assert.strictEqual(value, fakeValue);
1599+
1600+
await provider.forceFlush();
1601+
await traceExporter.forceFlush();
1602+
const spans = traceExporter.getFinishedSpans();
1603+
withAllSpansHaveDBName(spans);
1604+
1605+
const actualSpanNames: string[] = [];
1606+
const actualEventNames: string[] = [];
1607+
spans.forEach(span => {
1608+
actualSpanNames.push(span.name);
1609+
span.events.forEach(event => {
1610+
actualEventNames.push(event.name);
1611+
});
1612+
});
1613+
1614+
const expectedSpanNames = ['CloudSpanner.Database.runTransactionAsync'];
1615+
assert.deepStrictEqual(
1616+
actualSpanNames,
1617+
expectedSpanNames,
1618+
`span names mismatch:\n\tGot: ${actualSpanNames}\n\tWant: ${expectedSpanNames}`
1619+
);
1620+
1621+
// Ensure that the span actually produced an error that was recorded.
1622+
const firstSpan = spans[0];
1623+
assert.strictEqual(
1624+
SpanStatusCode.UNSET,
1625+
firstSpan.status.code,
1626+
'Unexpected span status'
1627+
);
1628+
assert.strictEqual(
1629+
undefined,
1630+
firstSpan.status.message,
1631+
'Unexpected span status message'
1632+
);
1633+
1634+
const expectedEventNames = ['Using Session'];
1635+
assert.deepStrictEqual(
1636+
actualEventNames,
1637+
expectedEventNames,
1638+
`Unexpected events:\n\tGot: ${actualEventNames}\n\tWant: ${expectedEventNames}`
1639+
);
1640+
});
1641+
1642+
it('with error', async () => {
1643+
const ourException = new Error('our thrown error');
1644+
sandbox
1645+
.stub(FakeAsyncTransactionRunner.prototype, 'run')
1646+
.throws(ourException);
1647+
1648+
assert.rejects(async () => {
1649+
const value = await database.runTransactionAsync(async txn => {
1650+
const result = await txn.run('SELECT 1');
1651+
await txn.commit();
1652+
return result;
1653+
});
1654+
}, ourException);
1655+
1656+
await provider.forceFlush();
1657+
await traceExporter.forceFlush();
1658+
const spans = traceExporter.getFinishedSpans();
1659+
withAllSpansHaveDBName(spans);
1660+
1661+
const actualSpanNames: string[] = [];
1662+
const actualEventNames: string[] = [];
1663+
spans.forEach(span => {
1664+
actualSpanNames.push(span.name);
1665+
span.events.forEach(event => {
1666+
actualEventNames.push(event.name);
1667+
});
1668+
});
1669+
1670+
const expectedSpanNames = ['CloudSpanner.Database.runTransactionAsync'];
1671+
assert.deepStrictEqual(
1672+
actualSpanNames,
1673+
expectedSpanNames,
1674+
`span names mismatch:\n\tGot: ${actualSpanNames}\n\tWant: ${expectedSpanNames}`
1675+
);
1676+
1677+
// Ensure that the span actually produced an error that was recorded.
1678+
const firstSpan = spans[0];
1679+
assert.strictEqual(
1680+
firstSpan.status.code,
1681+
SpanStatusCode.ERROR,
1682+
'Unexpected span status'
1683+
);
1684+
assert.strictEqual(
1685+
firstSpan.status.message,
1686+
ourException.message,
1687+
'Unexpected span status message'
1688+
);
1689+
1690+
const expectedEventNames = ['Using Session'];
1691+
assert.deepStrictEqual(
1692+
actualEventNames,
1693+
expectedEventNames,
1694+
`Unexpected events:\n\tGot: ${actualEventNames}\n\tWant: ${expectedEventNames}`
1695+
);
1696+
});
1697+
});
1698+
15681699
describe('runStream', () => {
15691700
const QUERY = {
15701701
sql: 'SELECT * FROM table',

‎observability-test/spanner.ts‎

Lines changed: 46 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -468,6 +468,52 @@ describe('EndToEnd', () => {
468468
});
469469
});
470470

471+
it('runTransactionAsync', async () => {
472+
const withAllSpansHaveDBName = generateWithAllSpansHaveDBName(
473+
database.formattedName_
474+
);
475+
await database.runTransactionAsync(async transaction => {
476+
const [rows] = await transaction!.run('SELECT 1');
477+
});
478+
479+
traceExporter.forceFlush();
480+
const spans = traceExporter.getFinishedSpans();
481+
withAllSpansHaveDBName(spans);
482+
483+
const actualEventNames: string[] = [];
484+
const actualSpanNames: string[] = [];
485+
spans.forEach(span => {
486+
actualSpanNames.push(span.name);
487+
span.events.forEach(event => {
488+
actualEventNames.push(event.name);
489+
});
490+
});
491+
492+
const expectedSpanNames = [
493+
'CloudSpanner.Snapshot.runStream',
494+
'CloudSpanner.Snapshot.run',
495+
'CloudSpanner.Database.runTransactionAsync',
496+
];
497+
assert.deepStrictEqual(
498+
actualSpanNames,
499+
expectedSpanNames,
500+
`span names mismatch:\n\tGot: ${actualSpanNames}\n\tWant: ${expectedSpanNames}`
501+
);
502+
503+
const expectedEventNames = [
504+
'Transaction Creation Done',
505+
'Acquiring session',
506+
'Cache hit: has usable session',
507+
'Acquired session',
508+
'Using Session',
509+
];
510+
assert.deepStrictEqual(
511+
actualEventNames,
512+
expectedEventNames,
513+
`Unexpected events:\n\tGot: ${actualEventNames}\n\tWant: ${expectedEventNames}`
514+
);
515+
});
516+
471517
it('writeAtLeastOnce', done => {
472518
const withAllSpansHaveDBName = generateWithAllSpansHaveDBName(
473519
database.formattedName_

‎src/database.ts‎

Lines changed: 48 additions & 38 deletions
Original file line numberDiff line numberDiff line change
@@ -3363,46 +3363,56 @@ class Database extends common.GrpcServiceObject {
33633363

33643364
let sessionId = '';
33653365
const getSession = this.pool_.getSession.bind(this.pool_);
3366-
const span = getActiveOrNoopSpan();
3367-
// Loop to retry 'Session not found' errors.
3368-
// (and yes, we like while (true) more than for (;;) here)
3369-
// eslint-disable-next-line no-constant-condition
3370-
while (true) {
3371-
try {
3372-
const [session, transaction] = await promisify(getSession)();
3373-
transaction.requestOptions = Object.assign(
3374-
transaction.requestOptions || {},
3375-
options.requestOptions
3376-
);
3377-
if (options.optimisticLock) {
3378-
transaction.useOptimisticLock();
3379-
}
3380-
if (options.excludeTxnFromChangeStreams) {
3381-
transaction.excludeTxnFromChangeStreams();
3382-
}
3383-
sessionId = session?.id;
3384-
span.addEvent('Using Session', {'session.id': sessionId});
3385-
const runner = new AsyncTransactionRunner<T>(
3386-
session,
3387-
transaction,
3388-
runFn,
3389-
options
3390-
);
3391-
3392-
try {
3393-
return await runner.run();
3394-
} finally {
3395-
this.pool_.release(session);
3396-
}
3397-
} catch (e) {
3398-
if (!isSessionNotFoundError(e as ServiceError)) {
3399-
span.addEvent('No session available', {
3400-
'session.id': sessionId,
3401-
});
3402-
throw e;
3366+
return startTrace(
3367+
'Database.runTransactionAsync',
3368+
this._traceConfig,
3369+
async span => {
3370+
// Loop to retry 'Session not found' errors.
3371+
// (and yes, we like while (true) more than for (;;) here)
3372+
// eslint-disable-next-line no-constant-condition
3373+
while (true) {
3374+
try {
3375+
const [session, transaction] = await promisify(getSession)();
3376+
transaction.requestOptions = Object.assign(
3377+
transaction.requestOptions || {},
3378+
options.requestOptions
3379+
);
3380+
if (options.optimisticLock) {
3381+
transaction.useOptimisticLock();
3382+
}
3383+
if (options.excludeTxnFromChangeStreams) {
3384+
transaction.excludeTxnFromChangeStreams();
3385+
}
3386+
sessionId = session?.id;
3387+
span.addEvent('Using Session', {'session.id': sessionId});
3388+
const runner = new AsyncTransactionRunner<T>(
3389+
session,
3390+
transaction,
3391+
runFn,
3392+
options
3393+
);
3394+
3395+
try {
3396+
return await runner.run();
3397+
} catch (e) {
3398+
setSpanError(span, e as Error);
3399+
throw e;
3400+
} finally {
3401+
span.end();
3402+
this.pool_.release(session);
3403+
}
3404+
} catch (e) {
3405+
if (!isSessionNotFoundError(e as ServiceError)) {
3406+
span.addEvent('No session available', {
3407+
'session.id': sessionId,
3408+
});
3409+
span.end();
3410+
throw e;
3411+
}
3412+
}
34033413
}
34043414
}
3405-
}
3415+
);
34063416
}
34073417

34083418
/**

0 commit comments

Comments
 (0)