feat(observability): fix bugs found from product review + negative cases #2158

odeke-em · 2024-10-12T09:25:49Z

This change adds recording of retry span annotations, catching cases in which exceptions where thrown but spans were not ended while testing out and visually confirming the results.

src/transaction.ts

alkatrivedi · 2024-10-17T05:18:31Z

src/database.ts

- if (err) {
- setSpanError(span, err!);
- }
+ await runner.run().then(release, async err => {


we are already doing .then() on runner.run(), why do we then need to await here?

@odeke-em it will work even if we don't await on runner.run(). please check and remove the await

alkatrivedi · 2024-10-17T06:25:09Z

src/database.ts

 this.pool_.release(session!);
 };

 const runner = new TransactionRunner(
 session!,
 transaction!,
- (err, resp) => {
+ async (err, resp) => {
 if (err) {
 setSpanError(span, err!);


Suggested change

setSpanError(span, err!);

setSpanError(span, err);

we already are using if condition

surbhigarg92 · 2024-10-14T05:06:54Z

src/transaction.ts

@@ -754,9 +755,11 @@ export class Snapshot extends EventEmitter {
 (err as grpc.ServiceError).code === grpc.status.ABORTED
 )
 ) {
+ span.addEvent('Transaction Aborted, retrying begin', {


This code block is for the non Aborted errors. Change Transaction threw error, retrying with explicit begin

surbhigarg92 · 2024-10-17T12:58:03Z

src/database.ts

@@ -3222,14 +3223,14 @@ class Database extends common.GrpcServiceObject {
 span.addEvent('No session available', {
 'session.id': session?.id,
 });
- this.runTransaction(options, runFn!);
+ await this.runTransaction(options, runFn!);


Why have we added await on this.runTransaction. This does not return a promise nor its a async method.

surbhigarg92 · 2024-10-17T12:58:22Z

src/database.ts

 span.end();
 return;
 }

 if (err) {
+ await runFn!(err as grpc.ServiceError);


same here ?

surbhigarg92 · 2024-10-17T12:59:36Z

src/database.ts


 if (isSessionNotFoundError(err)) {
 span.addEvent('No session available', {
 'session.id': session?.id,
 });
 release();
- this.runTransaction(options, runFn!);
+ await this.runTransaction(options, runFn!);


again why async here?

surbhigarg92 · 2024-10-17T13:02:06Z

src/database.ts

+
+ try {
+ const result = await runner.run();
+ span.end();


span.end() should be done in finally block.

Not really, on an exception this code retries in the while loop above so that's not correct to end it in the finally block. It should be ended only on success.

surbhigarg92 · 2024-10-17T13:36:40Z

src/transaction.ts

 const traceConfig = {
 tableName: table,
 opts: this._observabilityOptions,
 dbName: this._dbName!,
 };
 return startTrace('Snapshot.createReadStream', traceConfig, span => {
+ let attempt = 0;


remove the attempt

@surbhigarg92 why? The feature docs ask that we record the attempt number for streams.

surbhigarg92 · 2024-10-17T13:39:44Z

src/transaction.ts

@@ -754,9 +764,16 @@ export class Snapshot extends EventEmitter {
 (err as grpc.ServiceError).code === grpc.status.ABORTED
 )
 ) {
- this.begin();
+ span.addEvent('Stream broken. Safe to retry', {


remove these two spans for stream broken. We are not retrying broken stream here , that is happening in partial-result-stream class. https:/googleapis/nodejs-spanner/blob/main/src/partial-result-stream.ts#L558-L586
Maybe lets skip these two spans for now and move on.

surbhigarg92 · 2024-10-17T13:41:42Z

src/transaction.ts

+ if (!resumeToken) {
+ if (attempt === 0) {
+ span.addEvent('Starting stream');
+ } else {
+ span.addEvent('Re-attempting start stream', {attempt: attempt});
+ }
+ } else {
+ span.addEvent('Resuming stream', {
+ resume_token: resumeToken!.toString(),
+ attempt: attempt,
+ });
+ }


Keep a simple span like we have done in other method without attempt

if (resumeToken) { span.addEvent('Resuming stream', { resume_token: resumeToken!.toString(),\ }); } ```

I don't follow what you mean here @surbhigarg92. When do we record the beginning attempt or the re-attempts?

surbhigarg92 · 2024-10-17T13:42:17Z

src/transaction.ts

@@ -1330,8 +1364,16 @@ export class Snapshot extends EventEmitter {
 (err as grpc.ServiceError).code === grpc.status.ABORTED
 )
 ) {
- this.begin();
+ span.addEvent('Stream broken. Safe to retry', {


same here. remove these events

surbhigarg92 · 2024-10-17T13:43:06Z

src/transaction.ts

- callback(err, resp);
- });
- }, callback);
+ try {


no change is required here. As we are doing ".then" on begin call.

Extracted out of PR googleapis#2158, this change traces Database.runTransactionAsync. However, testing isn't effective because of bugs such as googleapis#2166.

Extracted out of PR googleapis#2158, this change traces Database.runTransactionAsync. Updates googleapis#2079

This change adds recording of retry span annotations, catching cases in which exceptions where thrown but spans were not ended while testing out and visually confirming the results.

…ontext.active only in Spanner constructor

…turn before span.end()

…an.end

…ansaction*

… span

odeke-em requested review from a team as code owners October 12, 2024 09:25

product-auto-label bot added size: m Pull request size is medium. api: spanner Issues related to the googleapis/nodejs-spanner API. labels Oct 12, 2024

odeke-em force-pushed the trace-fix-bugs-from-product-review+negative-cases branch from 62bf905 to 1b7d8b6 Compare October 12, 2024 09:26

product-auto-label bot added size: l Pull request size is large. size: xl Pull request size is extra large. and removed size: m Pull request size is medium. size: l Pull request size is large. labels Oct 12, 2024

alkatrivedi reviewed Oct 16, 2024

View reviewed changes

src/transaction.ts Outdated Show resolved Hide resolved

alkatrivedi reviewed Oct 17, 2024

View reviewed changes

surbhigarg92 reviewed Oct 17, 2024

View reviewed changes

odeke-em force-pushed the trace-fix-bugs-from-product-review+negative-cases branch from 91c5281 to 508243f Compare October 18, 2024 06:06

alkatrivedi added kokoro:force-run Add this label to force Kokoro to re-run the tests. owlbot:run Add this label to trigger the Owlbot post processor. labels Oct 18, 2024

gcf-owl-bot bot removed the owlbot:run Add this label to trigger the Owlbot post processor. label Oct 18, 2024

yoshi-kokoro removed the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Oct 18, 2024

alkatrivedi added kokoro:force-run Add this label to force Kokoro to re-run the tests. owlbot:run Add this label to trigger the Owlbot post processor. labels Oct 18, 2024

gcf-owl-bot bot removed the owlbot:run Add this label to trigger the Owlbot post processor. label Oct 18, 2024

yoshi-kokoro removed the kokoro:force-run Add this label to force Kokoro to re-run the tests. label Oct 18, 2024

odeke-em force-pushed the trace-fix-bugs-from-product-review+negative-cases branch from 7bdc173 to a3589e5 Compare October 20, 2024 03:28

odeke-em mentioned this pull request Oct 21, 2024

feat: (observability): trace Database.runTransactionAsync #2167

Open

odeke-em added a commit to odeke-em/nodejs-spanner that referenced this pull request Oct 21, 2024

feat: (observability): trace Database.runTransactionAsync

4ecc6b4

Extracted out of PR googleapis#2158, this change traces Database.runTransactionAsync. Updates googleapis#2079

odeke-em added 3 commits October 21, 2024 03:30

feat(observability): fix bugs found from product review + negative cases

59b3d73

This change adds recording of retry span annotations, catching cases in which exceptions where thrown but spans were not ended while testing out and visually confirming the results.

Spin up observability-test negative tests

55f5baa

test: add callback+async/await for database('SELECT 1p')b

c8d4728

odeke-em added 14 commits October 21, 2024 03:30

test adjustments and reverts

bbba95e

Revert span.end() in transaction runner

0e1e20b

More context for the span name in patchSpanEndForDebugging

b51ad70

Ensure database.runTransaction async awaits on caller code + ensure c…

b356977

…ontext.active only in Spanner constructor

src: invoke await for operations inisde some traces to ensure they re…

6c0e4c2

…turn before span.end()

Add tests for more negative tests

54521dc

Add tests for stream retries+resumption and also add span events

b203cbc

Plumb more with await to ensure correct ending of callbacks before sp…

3f6e3db

…an.end

Adjustments to ensure correct order of operations with database.runTr…

e77c1f3

…ansaction*

Unconditionally add Transaction attempts

703b1af

Remove debugTraces

ed4a7d7

Extract Database.runTransaction logic for retry, then to properly end…

9180aed

… span

More span.end() checks

3db6a9c

Revert Database.runTransactionAsync changes to allow a spin-off PR

13bc9f5

odeke-em force-pushed the trace-fix-bugs-from-product-review+negative-cases branch from e0e31f5 to 13bc9f5 Compare October 21, 2024 10:52

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

feat(observability): fix bugs found from product review + negative cases #2158

feat(observability): fix bugs found from product review + negative cases #2158

odeke-em commented Oct 12, 2024

alkatrivedi Oct 17, 2024

alkatrivedi Oct 17, 2024

alkatrivedi Oct 17, 2024

surbhigarg92 Oct 14, 2024

surbhigarg92 Oct 17, 2024

surbhigarg92 Oct 17, 2024

surbhigarg92 Oct 17, 2024

surbhigarg92 Oct 17, 2024

odeke-em Oct 18, 2024

surbhigarg92 Oct 17, 2024

odeke-em Oct 21, 2024

surbhigarg92 Oct 17, 2024

surbhigarg92 Oct 17, 2024

odeke-em Oct 21, 2024

surbhigarg92 Oct 17, 2024

surbhigarg92 Oct 17, 2024

feat(observability): fix bugs found from product review + negative cases #2158

Are you sure you want to change the base?

feat(observability): fix bugs found from product review + negative cases #2158

Conversation

odeke-em commented Oct 12, 2024

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment