Unconditionally add Transaction attempts

Author: odeke-em

observability-test/spanner.ts

@@ -467,6 +467,7 @@ describe('EndToEnd', () => {
         'Cache hit: has usable session',
         'Acquired session',
         'Using Session',
+        'Transaction Attempt Succeeded',
       ];
       assert.deepStrictEqual(
         actualEventNames,
@@ -1610,6 +1611,7 @@ SELECT 1p
       'Transaction Attempt Failed',
       'Transaction Attempt Aborted',
       'exception',
+      'exception',
     ];
     assert.deepStrictEqual(
       actualEventNames,
@@ -1641,7 +1643,6 @@ SELECT 1p
       );
     }
 
-    console.log('flushing now');
     provider.forceFlush();
     assertDatabaseRunPlusAwaitTransactionForAlreadyExistentData();
   });
@@ -1793,8 +1794,6 @@ describe('Traces for ExecuteStream broken stream retries', () => {
         });
         await database.close();
 
-        console.log('done here');
-
         const requests = spannerMock
           .getRequests()
           .filter(val => (val as v1.ExecuteSqlRequest).sql)
@@ -2101,8 +2100,8 @@ describe('Traces for ExecuteStream broken stream retries', () => {
       const [updateCount] = await tx!.runUpdate(insertSql);
       assert.strictEqual(updateCount, 1);
       await tx!.commit();
-      await database.close();
     });
+    await database.close();
 
     // The span for a successful invocation of database.runTransaction
     // can only be ended after the calling function is completed.
@@ -2120,13 +2119,13 @@ describe('Traces for ExecuteStream broken stream retries', () => {
     const expectedSpanNames = [
       'CloudSpanner.Database.batchCreateSessions',
       'CloudSpanner.SessionPool.createSessions',
-      'CloudSpanner.Database.runTransaction',
       'CloudSpanner.Snapshot.runStream',
       'CloudSpanner.Snapshot.run',
       'CloudSpanner.Dml.runUpdate',
       'CloudSpanner.Snapshot.begin',
       'CloudSpanner.Transaction.commit',
       'CloudSpanner.Transaction.commit',
+      'CloudSpanner.Database.runTransactionAsync',
     ];
     assert.deepStrictEqual(
       actualSpanNames,
@@ -2148,6 +2147,8 @@ describe('Traces for ExecuteStream broken stream retries', () => {
       'Acquiring session',
       'Waiting for a session to become available',
       'Acquired session',
+      'Using Session',
+      'Transaction Attempt Succeeded',
     ];
     assert.deepStrictEqual(
       actualEventNames,
@@ -2223,6 +2224,7 @@ describe('Traces for ExecuteStream broken stream retries', () => {
       'Waiting for a session to become available',
       'Acquired session',
       'Using Session',
+      'Transaction Attempt Succeeded',
     ];
     assert.deepStrictEqual(
       actualEventNames,

src/database.ts

@@ -3399,9 +3399,10 @@ class Database extends common.GrpcServiceObject {
             );
 
             try {
-              return await runner.run();
-            } finally {
+              const result = await runner.run();
               span.end();
+              return result;
+            } finally {
               this.pool_.release(session);
             }
           } catch (e) {

src/transaction-runner.ts

@@ -234,18 +234,20 @@ export abstract class Runner<T> {
     while (this.attempts === 0 || Date.now() - start < timeout) {
       const transaction = await this.getTransaction();
 
+      // this.attempts refers to the number of retries, not while loop iterations
+      // hence without a +1, reading a span entry that says attempt=0 makes no
+      // sence to a user.
+      const countableAttempts = this.attempts + 1;
+
       try {
         const result = await this._run(transaction);
-        if (this.attempts > 0) {
-          // No add to annotate if the transaction wasn't retried.
-          span.addEvent('Transaction Attempt Succeeded', {
-            attempt: this.attempts + 1,
-          });
-        }
+        span.addEvent('Transaction Attempt Succeeded', {
+          attempt: countableAttempts,
+        });
         return result;
       } catch (e) {
         span.addEvent('Transaction Attempt Failed', {
-          attempt: this.attempts + 1,
+          attempt: countableAttempts,
         });
         this.session.lastError = e as grpc.ServiceError;
         lastError = e as grpc.ServiceError;
@@ -268,7 +270,7 @@ export abstract class Runner<T> {
       this.attempts += 1;
 
       const delay = this.getNextDelay(lastError!);
-      span.addEvent('Backing off', {delay: delay, attempt: this.attempts});
+      span.addEvent('Backing off', {delay: delay, attempt: countableAttempts});
       await new Promise(resolve => setTimeout(resolve, delay));
     }