release-23.1: sql: add extra information to protocol errors in bind

pkg/acceptance/testdata/node/base-test.js

@@ -40,7 +40,7 @@ describe('error cases', () => {
   const cases = [{
     name: 'not enough params',
     query: { text: 'SELECT 3', values: ['foo'] },
-    msg: "bind message supplies 1 parameters, but prepared statement \"\" requires 0",
+    msg: "bind message supplies 1 parameters, but requires 0",
     code: '08P01',
   }, {
     name: 'invalid utf8',

pkg/sql/conn_executor_prepare.go

@@ -329,14 +329,26 @@ func (ex *connExecutor) populatePrepared(
 func (ex *connExecutor) execBind(
 	ctx context.Context, bindCmd BindStmt,
 ) (fsm.Event, fsm.EventPayload) {
+	var ps *PreparedStatement
 	retErr := func(err error) (fsm.Event, fsm.EventPayload) {
+		if bindCmd.PreparedStatementName != "" {
+			err = errors.WithDetailf(err, "statement name %q", bindCmd.PreparedStatementName)
+		}
+		if bindCmd.PortalName != "" {
+			err = errors.WithDetailf(err, "portal name %q", bindCmd.PortalName)
+		}
+		if ps != nil && ps.StatementSummary != "" {
+			err = errors.WithDetailf(err, "statement summary %q", ps.StatementSummary)
+		}
 		return eventNonRetriableErr{IsCommit: fsm.False}, eventNonRetriableErrPayload{err: err}
 	}
 
-	ps, ok := ex.extraTxnState.prepStmtsNamespace.prepStmts[bindCmd.PreparedStatementName]
+	var ok bool
+	ps, ok = ex.extraTxnState.prepStmtsNamespace.prepStmts[bindCmd.PreparedStatementName]
 	if !ok {
 		return retErr(newPreparedStmtDNEError(ex.sessionData(), bindCmd.PreparedStatementName))
 	}
+
 	ex.extraTxnState.prepStmtsNamespace.touchLRUEntry(bindCmd.PreparedStatementName)
 
 	// We need to make sure type resolution happens within a transaction.
@@ -422,7 +434,7 @@ func (ex *connExecutor) execBind(
 		if len(bindCmd.Args) != int(numQArgs) {
 			return retErr(
 				pgwirebase.NewProtocolViolationErrorf(
-					"bind message supplies %d parameters, but prepared statement \"%s\" requires %d", len(bindCmd.Args), bindCmd.PreparedStatementName, numQArgs))
+					"bind message supplies %d parameters, but requires %d", len(bindCmd.Args), numQArgs))
 		}
 
 		resolve := func(ctx context.Context, txn *kv.Txn) (err error) {
@@ -482,9 +494,14 @@ func (ex *connExecutor) execBind(
 
 	numCols := len(ps.Columns)
 	if (len(bindCmd.OutFormats) > 1) && (len(bindCmd.OutFormats) != numCols) {
-		return retErr(pgwirebase.NewProtocolViolationErrorf(
+		err := pgwirebase.NewProtocolViolationErrorf(
 			"expected 1 or %d for number of format codes, got %d",
-			numCols, len(bindCmd.OutFormats)))
+			numCols, len(bindCmd.OutFormats))
+		// A user is hitting this error unexpectedly and rarely, dump extra info,
+		// should be okay since this should be a very rare error.
+		log.Infof(ctx, "%s outformats: %v, AST: %T, prepared statements: %s", err.Error(),
+			bindCmd.OutFormats, ps.AST, ex.extraTxnState.prepStmtsNamespace.String())
+		return retErr(err)
 	}
 
 	columnFormatCodes := bindCmd.OutFormats

pkg/sql/pgwire/pgwire_test.go

@@ -451,9 +451,9 @@ func TestPGPreparedQuery(t *testing.T) {
 		{"SELECT $1 > 0", []preparedQueryTest{
 			baseTest.SetArgs(1).Results(true),
 			baseTest.SetArgs("1").Results(true),
-			baseTest.SetArgs(1.1).Error(`pq: error in argument for $1: could not parse "1.1" as type int: strconv.ParseInt: parsing "1.1": invalid syntax`).Results(true),
-			baseTest.SetArgs("1.0").Error(`pq: error in argument for $1: could not parse "1.0" as type int: strconv.ParseInt: parsing "1.0": invalid syntax`),
-			baseTest.SetArgs(true).Error(`pq: error in argument for $1: could not parse "true" as type int: strconv.ParseInt: parsing "true": invalid syntax`),
+			baseTest.SetArgs(1.1).Error(`error in argument for \$1: could not parse "1.1" as type int: strconv.ParseInt: parsing "1.1": invalid syntax`).Results(true),
+			baseTest.SetArgs("1.0").Error(`error in argument for \$1: could not parse "1.0" as type int: strconv.ParseInt: parsing "1.0": invalid syntax`),
+			baseTest.SetArgs(true).Error(`error in argument for \$1: could not parse "true" as type int: strconv.ParseInt: parsing "true": invalid syntax`),
 		}},
 		{"SELECT ($1) > 0", []preparedQueryTest{
 			baseTest.SetArgs(1).Results(true),
@@ -467,7 +467,7 @@ func TestPGPreparedQuery(t *testing.T) {
 			baseTest.SetArgs(true).Results(true),
 			baseTest.SetArgs(false).Results(false),
 			baseTest.SetArgs(1).Results(true),
-			baseTest.SetArgs("").Error(`pq: error in argument for $1: could not parse "" as type bool: strconv.ParseBool: parsing "": invalid syntax`),
+			baseTest.SetArgs("").Error(`error in argument for \$1: could not parse "" as type bool: strconv.ParseBool: parsing "": invalid syntax`),
 			// Make sure we can run another after a failure.
 			baseTest.SetArgs(true).Results(true),
 		}},
@@ -476,14 +476,12 @@ func TestPGPreparedQuery(t *testing.T) {
 			baseTest.SetArgs("true").Results(true),
 			baseTest.SetArgs("false").Results(false),
 			baseTest.SetArgs("1").Results(true),
-			baseTest.SetArgs(2).Error(`pq: error in argument for $1: could not parse "2" as type bool: strconv.ParseBool: parsing "2": invalid syntax`),
-			baseTest.SetArgs(3.1).Error(`pq: error in argument for $1: could not parse "3.1" as type bool: strconv.ParseBool: parsing "3.1": invalid syntax`),
-			baseTest.SetArgs("").Error(`pq: error in argument for $1: could not parse "" as type bool: strconv.ParseBool: parsing "": invalid syntax`),
+			baseTest.SetArgs(2).Error(`error in argument for \$1: could not parse "2" as type bool: strconv.ParseBool: parsing "2": invalid syntax`),
+			baseTest.SetArgs(3.1).Error(`error in argument for \$1: could not parse "3.1" as type bool: strconv.ParseBool: parsing "3.1": invalid syntax`),
+			baseTest.SetArgs("").Error(`error in argument for \$1: could not parse "" as type bool: strconv.ParseBool: parsing "": invalid syntax`),
 		}},
 		{"SELECT CASE 40+2 WHEN 42 THEN 51 ELSE $1::INT END", []preparedQueryTest{
-			baseTest.Error(
-				"pq: no value provided for placeholder: $1",
-			).PreparedError(
+			baseTest.Error(`no value provided for placeholder: \$1`).PreparedError(
 				wrongArgCountString(1, 0),
 			),
 		}},
@@ -492,14 +490,14 @@ func TestPGPreparedQuery(t *testing.T) {
 			baseTest.SetArgs("2", 1).Results(true),
 			baseTest.SetArgs(1, "2").Results(false),
 			baseTest.SetArgs("2", "1.0").Results(true),
-			baseTest.SetArgs("2.0", "1").Error(`pq: error in argument for $1: could not parse "2.0" as type int: strconv.ParseInt: parsing "2.0": invalid syntax`),
-			baseTest.SetArgs(2.1, 1).Error(`pq: error in argument for $1: could not parse "2.1" as type int: strconv.ParseInt: parsing "2.1": invalid syntax`),
+			baseTest.SetArgs("2.0", "1").Error(`error in argument for \$1: could not parse "2.0" as type int: strconv.ParseInt: parsing "2.0": invalid syntax`),
+			baseTest.SetArgs(2.1, 1).Error(`error in argument for \$1: could not parse "2.1" as type int: strconv.ParseInt: parsing "2.1": invalid syntax`),
 		}},
 		{"SELECT greatest($1, 0, $2), $2", []preparedQueryTest{
 			baseTest.SetArgs(1, -1).Results(1, -1),
 			baseTest.SetArgs(-1, 10).Results(10, 10),
 			baseTest.SetArgs("-2", "-1").Results(0, -1),
-			baseTest.SetArgs(1, 2.1).Error(`pq: error in argument for $2: could not parse "2.1" as type int: strconv.ParseInt: parsing "2.1": invalid syntax`),
+			baseTest.SetArgs(1, 2.1).Error(`error in argument for \$2: could not parse "2.1" as type int: strconv.ParseInt: parsing "2.1": invalid syntax`),
 		}},
 		{"SELECT $1::int, $1::float", []preparedQueryTest{
 			baseTest.SetArgs(1).Results(1, 1.0),
@@ -508,7 +506,7 @@ func TestPGPreparedQuery(t *testing.T) {
 		{"SELECT 3 + $1, $1 + $2", []preparedQueryTest{
 			baseTest.SetArgs("1", "2").Results(4, 3),
 			baseTest.SetArgs(3, "4").Results(6, 7),
-			baseTest.SetArgs(0, "a").Error(`pq: error in argument for $2: could not parse "a" as type int: strconv.ParseInt: parsing "a": invalid syntax`),
+			baseTest.SetArgs(0, "a").Error(`error in argument for \$2: could not parse "a" as type int: strconv.ParseInt: parsing "a": invalid syntax`),
 		}},
 		// Check for name resolution.
 		{"SELECT count(*)", []preparedQueryTest{
@@ -522,7 +520,7 @@ func TestPGPreparedQuery(t *testing.T) {
 		{"SELECT CASE 1 WHEN $1 THEN $2 ELSE 2 END", []preparedQueryTest{
 			baseTest.SetArgs(1, 3).Results(3),
 			baseTest.SetArgs(2, 3).Results(2),
-			baseTest.SetArgs(true, 0).Error(`pq: error in argument for $1: could not parse "true" as type int: strconv.ParseInt: parsing "true": invalid syntax`),
+			baseTest.SetArgs(true, 0).Error(`error in argument for \$1: could not parse "true" as type int: strconv.ParseInt: parsing "true": invalid syntax`),
 		}},
 		{"SELECT $1[2] LIKE 'b'", []preparedQueryTest{
 			baseTest.SetArgs(pq.Array([]string{"a", "b", "c"})).Results(true),
@@ -892,7 +890,7 @@ func TestPGPreparedQuery(t *testing.T) {
 						if prepared && test.preparedError != "" {
 							expectedErr = test.preparedError
 						}
-						if err.Error() != expectedErr {
+						if !testutils.IsError(err, expectedErr) {
 							t.Errorf("%s: %v: expected error: %s, got %s", query, test.qargs, expectedErr, err)
 						}
 					}
@@ -1094,7 +1092,7 @@ func TestPGPreparedExec(t *testing.T) {
 			"INSERT INTO d.public.t VALUES ($1, $2, $3)",
 			[]preparedExecTest{
 				baseTest.SetArgs(1, "one", 2).RowsAffected(1),
-				baseTest.SetArgs("two", 2, 2).Error(`pq: error in argument for $1: could not parse "two" as type int: strconv.ParseInt: parsing "two": invalid syntax`),
+				baseTest.SetArgs("two", 2, 2).Error(`error in argument for \$1: could not parse "two" as type int: strconv.ParseInt: parsing "two": invalid syntax`),
 			},
 		},
 		{
@@ -1294,7 +1292,7 @@ func TestPGPreparedExec(t *testing.T) {
 				if result, err := execFunc(test.qargs...); err != nil {
 					if test.error == "" {
 						t.Errorf("%s: %v: unexpected error: %s", query, test.qargs, err)
-					} else if err.Error() != test.error {
+					} else if !testutils.IsError(err, test.error) {
 						t.Errorf("%s: %v: expected error: %s, got %s", query, test.qargs, test.error, err)
 					}
 				} else {

pkg/sql/pgwire/pgwirebase/encoding.go

@@ -15,7 +15,6 @@ import (
 	"bytes"
 	"context"
 	"encoding/binary"
-	"fmt"
 	"io"
 	"math"
 	"strconv"
@@ -1002,20 +1001,17 @@ func decodeBinaryTuple(ctx context.Context, evalCtx *eval.Context, b []byte) (tr
 
 	bufferLength := len(b)
 	if bufferLength < tupleHeaderSize {
-		return nil, pgerror.Newf(
-			pgcode.Syntax,
-			"tuple requires a %d byte header for binary format. bufferLength=%d",
-			tupleHeaderSize, bufferLength)
+		return nil, errors.WithDetailf(
+			pgerror.Newf(pgcode.Syntax, "tuple requires a %d byte header for binary format", tupleHeaderSize),
+			"bufferLength=%d", bufferLength)
 	}
 
 	bufferStartIdx := 0
 	bufferEndIdx := bufferStartIdx + tupleHeaderSize
 	numberOfElements := int32(binary.BigEndian.Uint32(b[bufferStartIdx:bufferEndIdx]))
 	if numberOfElements < 0 {
-		return nil, pgerror.Newf(
-			pgcode.Syntax,
-			"tuple must have non-negative number of elements. numberOfElements=%d",
-			numberOfElements)
+		return nil, errors.WithDetailf(pgerror.New(pgcode.Syntax, "tuple must have non-negative number of elements"),
+			"numberOfElements=%d", numberOfElements)
 	}
 	bufferStartIdx = bufferEndIdx
 
@@ -1024,39 +1020,38 @@ func decodeBinaryTuple(ctx context.Context, evalCtx *eval.Context, b []byte) (tr
 
 	elementIdx := int32(0)
 
-	// getStateString is used to output current state in error messages
-	getSyntaxError := func(message string, args ...interface{}) error {
-		formattedMessage := fmt.Sprintf(message, args...)
-		return pgerror.Newf(
-			pgcode.Syntax,
-			"%s elementIdx=%d bufferLength=%d bufferStartIdx=%d bufferEndIdx=%d",
-			formattedMessage, elementIdx, bufferLength, bufferStartIdx, bufferEndIdx)
+	// decorateSyntaxError is used to output the current state in error messages.
+	decorateSyntaxError := func(err error) error {
+		return errors.WithDetailf(
+			err,
+			"elementIdx=%d bufferLength=%d bufferStartIdx=%d bufferEndIdx=%d",
+			elementIdx, bufferLength, bufferStartIdx, bufferEndIdx)
 	}
 
 	for elementIdx < numberOfElements {
 
 		bufferEndIdx = bufferStartIdx + oidSize
 		if bufferEndIdx < bufferStartIdx {
-			return nil, getSyntaxError("integer overflow reading element OID for binary format. ")
+			return nil, decorateSyntaxError(pgerror.New(pgcode.Syntax, "integer overflow reading element OID for binary format"))
 		}
 		if bufferLength < bufferEndIdx {
-			return nil, getSyntaxError("insufficient bytes reading element OID for binary format. ")
+			return nil, decorateSyntaxError(pgerror.New(pgcode.Syntax, "insufficient bytes reading element OID for binary format"))
 		}
 
 		elementOID := int32(binary.BigEndian.Uint32(b[bufferStartIdx:bufferEndIdx]))
 		elementType, ok := types.OidToType[oid.Oid(elementOID)]
 		if !ok {
-			return nil, getSyntaxError("element type not found for OID %d. ", elementOID)
+			return nil, decorateSyntaxError(pgerror.Newf(pgcode.Syntax, "element type not found for OID %d", elementOID))
 		}
 		typs[elementIdx] = elementType
 		bufferStartIdx = bufferEndIdx
 
 		bufferEndIdx = bufferStartIdx + elementSize
 		if bufferEndIdx < bufferStartIdx {
-			return nil, getSyntaxError("integer overflow reading element size for binary format. ")
+			return nil, decorateSyntaxError(pgerror.New(pgcode.Syntax, "integer overflow reading element size for binary format"))
 		}
 		if bufferLength < bufferEndIdx {
-			return nil, getSyntaxError("insufficient bytes reading element size for binary format. ")
+			return nil, decorateSyntaxError(pgerror.New(pgcode.Syntax, "insufficient bytes reading element size for binary format"))
 		}
 
 		bytesToRead := binary.BigEndian.Uint32(b[bufferStartIdx:bufferEndIdx])
@@ -1066,10 +1061,10 @@ func decodeBinaryTuple(ctx context.Context, evalCtx *eval.Context, b []byte) (tr
 		} else {
 			bufferEndIdx = bufferStartIdx + int(bytesToRead)
 			if bufferEndIdx < bufferStartIdx {
-				return nil, getSyntaxError("integer overflow reading element for binary format. ")
+				return nil, decorateSyntaxError(pgerror.New(pgcode.Syntax, "integer overflow reading element for binary format"))
 			}
 			if bufferLength < bufferEndIdx {
-				return nil, getSyntaxError("insufficient bytes reading element for binary format. ")
+				return nil, decorateSyntaxError(pgerror.New(pgcode.Syntax, "insufficient bytes reading element for binary format"))
 			}
 
 			colDatum, err := DecodeDatum(ctx, evalCtx, elementType, FormatBinary, b[bufferStartIdx:bufferEndIdx])

pkg/sql/pgwire/testdata/pgtest/aborted_txn

@@ -102,7 +102,7 @@ until
 ErrorResponse
 ReadyForQuery
 ----
-{"Type":"ErrorResponse","Code":"25P02"}
+{"Type":"ErrorResponse","Code":"25P02","Detail":"statement name \"s1\"\n--\nstatement summary \"SELECT * FROM drop_cols\""}
 {"Type":"ReadyForQuery","TxStatus":"E"}
 
 # Rollback the transaction, and make sure prepared statement works.
@@ -300,7 +300,7 @@ ReadyForQuery
 {"Type":"CommandComplete","CommandTag":"SAVEPOINT"}
 {"Type":"ReadyForQuery","TxStatus":"T"}
 {"Type":"BindComplete"}
-{"Type":"ErrorResponse","Code":"23505","ConstraintName":"t103936_j_key"}
+{"Type":"ErrorResponse","Code":"23505","ConstraintName":"t103936_j_key","Detail":"Key (j)=(2) already exists."}
 {"Type":"ReadyForQuery","TxStatus":"E"}
 
 # Get back to a good state.

pkg/sql/pgwire/testdata/pgtest/array

@@ -10,7 +10,7 @@ ErrorResponse
 ReadyForQuery
 ----
 {"Type":"ParseComplete"}
-{"Type":"ErrorResponse","Code":"08P01"}
+{"Type":"ErrorResponse","Code":"08P01","Detail":"statement summary \"SELECT $1::INTERVAL[]\""}
 {"Type":"ReadyForQuery","TxStatus":"I"}
 
 send

pkg/sql/pgwire/testdata/pgtest/copy

@@ -1078,7 +1078,7 @@ ErrorResponse
 ReadyForQuery
 ----
 {"Type":"ParseComplete"}
-{"Type":"ErrorResponse","Code":"08P01","Message":"bind message supplies 1 parameters, but prepared statement \"\" requires 0"}
+{"Type":"ErrorResponse","Code":"08P01","Message":"bind message supplies 1 parameters, but requires 0","Detail":"statement summary \"COPY (SELECT) TO STDOUT\""}
 {"Type":"ReadyForQuery","TxStatus":"I"}
 
 # And it's also an error to _not_ bind a placeholder.

pkg/sql/pgwire/testdata/pgtest/errors

@@ -50,7 +50,7 @@ until
 ErrorResponse
 ReadyForQuery
 ----
-{"Type":"ErrorResponse","Code":"23503","ConstraintName":"fk_p_ref_parent"}
+{"Type":"ErrorResponse","Code":"23503","ConstraintName":"fk_p_ref_parent","Detail":"Key (p)=(1) is not present in table \"parent\"."}
 {"Type":"ReadyForQuery","TxStatus":"I"}
 
 send
@@ -82,5 +82,20 @@ until
 ErrorResponse
 ReadyForQuery
 ----
-{"Type":"ErrorResponse","Code":"23503","ConstraintName":"foo bar"}
+{"Type":"ErrorResponse","Code":"23503","ConstraintName":"foo bar","Detail":"Key (p)=(1) is not present in table \"parent\"."}
+{"Type":"ReadyForQuery","TxStatus":"I"}
+
+send
+Parse {"Name": "s0", "Query": "select $1,$2,$3", "ParameterOIDs":[1043, 1043, 1043]}
+Bind {"DestinationPortal": "p0", "PreparedStatement": "s0", "ParameterFormatCodes": [0], "ResultFormatCodes": [0,1,2,3,4,5], "Parameters": [{"text":"whitebear"}, {"text":"blackbear"}, {"text":"brownbear"}]}
+Execute {"Portal": "p0"}
+Sync
+----
+
+until
+ErrorResponse
+ReadyForQuery
+----
+{"Type":"ParseComplete"}
+{"Type":"ErrorResponse","Code":"08P01","Detail":"statement name \"s0\"\n--\nportal name \"p0\"\n--\nstatement summary \"SELECT $1, $1, $1\""}
 {"Type":"ReadyForQuery","TxStatus":"I"}

pkg/sql/pgwire/testdata/pgtest/inet

@@ -10,7 +10,7 @@ ErrorResponse
 ReadyForQuery
 ----
 {"Type":"ParseComplete"}
-{"Type":"ErrorResponse","Code":"08P01"}
+{"Type":"ErrorResponse","Code":"08P01","Detail":"statement summary \"SELECT $1::INET\""}
 {"Type":"ReadyForQuery","TxStatus":"I"}
 
 # IPv4family
@@ -23,7 +23,7 @@ until
 ErrorResponse
 ReadyForQuery
 ----
-{"Type":"ErrorResponse","Code":"22P03"}
+{"Type":"ErrorResponse","Code":"22P03","Detail":"statement summary \"SELECT $1::INET\""}
 {"Type":"ReadyForQuery","TxStatus":"I"}
 
 # IPv6family
@@ -36,7 +36,7 @@ until
 ErrorResponse
 ReadyForQuery
 ----
-{"Type":"ErrorResponse","Code":"22P03"}
+{"Type":"ErrorResponse","Code":"22P03","Detail":"statement summary \"SELECT $1::INET\""}
 {"Type":"ReadyForQuery","TxStatus":"I"}
 
 # Unknown family
@@ -49,5 +49,5 @@ until
 ErrorResponse
 ReadyForQuery
 ----
-{"Type":"ErrorResponse","Code":"22P03"}
+{"Type":"ErrorResponse","Code":"22P03","Detail":"statement summary \"SELECT $1::INET\""}
 {"Type":"ReadyForQuery","TxStatus":"I"}

pkg/sql/pgwire/testdata/pgtest/json

@@ -10,7 +10,7 @@ ErrorResponse
 ReadyForQuery
 ----
 {"Type":"ParseComplete"}
-{"Type":"ErrorResponse","Code":"08P01"}
+{"Type":"ErrorResponse","Code":"08P01","Detail":"statement summary \"SELECT $1::JSONB\""}
 {"Type":"ReadyForQuery","TxStatus":"I"}
 
 # JSONB version 2 followed by two double quotes (ASCII 0x22). This is a
@@ -25,7 +25,7 @@ until mapError=(XX000, 08P01)
 ErrorResponse
 ReadyForQuery
 ----
-{"Type":"ErrorResponse","Code":"08P01"}
+{"Type":"ErrorResponse","Code":"08P01","Detail":"statement summary \"SELECT $1::JSONB\""}
 {"Type":"ReadyForQuery","TxStatus":"I"}
 
 # Test binary output encoding for JSONB.