ui: transaction time reporting extremely large number

[THardy98]

The console has been seen to report extremely large numbers for a transaction's time on the transactions tab page. Here is an example:

This was seen looking at the transaction times on one of Twitter’s clusters. Auto-commit for transactions was enabled, and these transactions are implicit transactions. The cluster is question was self-hosted, running v22.1.0.

Jira issue: CRDB-16714

[rafiss]

I have a way to reproduce the large UI time.

1. Start a fresh v22.1.2 cluster. (I used single-node insecure.)
2. Run the following program.

package main

import (
        "context"
        "fmt"
        // Import driver
        "github.com/jackc/pgx/v4"
)

func main() {
    ctx := context.Background()

    c, err := pgx.Connect(ctx, "postgresql://root@localhost:26257/defaultdb?sslmode=disable")
    fmt.Println(err)

    var i int
    err = c.QueryRow(ctx, "SELECT $1::INT8", 1).Scan(&i)
    fmt.Println(i, err)

}

3. Go to the Transactions page: http://localhost:8081/#/sql-activity?tab=Transactions

---

It seems specific to the extended protocol. I changed the last bit to

    var i int
    err = c.QueryRow(ctx, "SELECT 1::INT8",  pgx.QuerySimpleProtocol(true)).Scan(&i)
    fmt.Println(i, err)

and could not reproduce.

---

I wonder if after #76792 went in, it’s no longer correct to unconditionally call statsCollector.Reset during each phase of the extended protocol (e.g. prepare and bind). All of these phases normally (but not always) happen in the same implicit transaction

[rafiss]

After discussion on Slack, I think we want this fix:

diff --git a/pkg/sql/conn_executor_exec.go b/pkg/sql/conn_executor_exec.go
index be845b3231..34d3af3992 100644
--- a/pkg/sql/conn_executor_exec.go
+++ b/pkg/sql/conn_executor_exec.go
@@ -2168,8 +2168,7 @@ func (ex *connExecutor) recordTransactionStart(txnID uuid.UUID) {

     // Transaction received time is the time at which the statement that prompted
     // the creation of this transaction was received.
-    ex.phaseTimes.SetSessionPhaseTime(sessionphase.SessionTransactionReceived,
-        ex.phaseTimes.GetSessionPhaseTime(sessionphase.SessionQueryReceived))
+    ex.phaseTimes.SetSessionPhaseTime(sessionphase.SessionTransactionReceived, txnStart)
     ex.phaseTimes.SetSessionPhaseTime(sessionphase.SessionFirstStartExecTransaction, timeutil.Now())
     ex.phaseTimes.SetSessionPhaseTime(sessionphase.SessionMostRecentStartExecTransaction,
         ex.phaseTimes.GetSessionPhaseTime(sessionphase.SessionFirstStartExecTransaction))

The reason is that now, the implicit transaction starts before SessionQueryReceived is populated. Luckily, we already had the txnStart time available here, and this is the correct time to use anyway.