From 7c65503505616351d1b89e695b29c679296dee7b Mon Sep 17 00:00:00 2001
From: Kamil Holubicki <kamil.holubicki@percona.com>
Date: Wed, 7 Jun 2023 13:05:38 +0200
Subject: [PATCH] Problem: Some error logs indicate only the error returned by
 the server without the information about the server identity itself. On the
 other hand there are also logs which display the server identity together
 with the returned error.

Cause:
There is an utility layer implemented by golib/sqlutils which intercepts
database queries. Some queries done by orchestrator go through this
layer and some don't.
sqlutils layer in case of query error prints out the query to the stdout

Solution:
golib/sqlutils layer is not aware of the server identity it operates on.
It proxies creation of sql.DB object and then uses this object for
queries execution.

Logger interface has been introduced. golib/sqlutils client can register
its own logger which will be used instead of internal logging when the
error occurs during usage of the related sql.DB object.
---
 go/db/db.go          | 12 ++++++++----
 go/db/tls.go         | 21 ++++++++++++++++++++-
 go/raft/rel_store.go |  2 +-
 3 files changed, 29 insertions(+), 6 deletions(-)

diff --git a/go/db/db.go b/go/db/db.go
index 4080875af..2d7a1e33f 100644
--- a/go/db/db.go
+++ b/go/db/db.go
@@ -21,6 +21,7 @@ import (
 	"errors"
 	"fmt"
 	"regexp"
+	"strconv"
 	"strings"
 	"sync"
 	"time"
@@ -100,7 +101,8 @@ func openTopology(host string, port int, readTimeout int) (db *sql.DB, err error
 			return nil, err
 		}
 	}
-	if db, _, err = sqlutils.GetDB(mysql_uri); err != nil {
+	sqlUtilsLogger := SqlUtilsLogger{client_context: host + ":" + strconv.Itoa(port)}
+	if db, _, err = sqlutils.GetDB(mysql_uri, sqlUtilsLogger); err != nil {
 		return nil, err
 	}
 	if config.Config.MySQLConnectionLifetimeSeconds > 0 {
@@ -123,7 +125,8 @@ func openOrchestratorMySQLGeneric() (db *sql.DB, fromCache bool, err error) {
 	if config.Config.MySQLOrchestratorUseMutualTLS {
 		uri, _ = SetupMySQLOrchestratorTLS(uri)
 	}
-	return sqlutils.GetDB(uri)
+	sqlUtilsLogger := SqlUtilsLogger{client_context: config.Config.MySQLOrchestratorHost + ":" + config.Config.MySQLOrchestratorHost}
+	return sqlutils.GetDB(uri, sqlUtilsLogger)
 }
 
 func IsSQLite() bool {
@@ -174,7 +177,7 @@ func safeMySQLURI(dsn string) string {
 func OpenOrchestrator() (db *sql.DB, err error) {
 	var fromCache bool
 	if IsSQLite() {
-		db, fromCache, err = sqlutils.GetSQLiteDB(config.Config.SQLite3DataFile)
+		db, fromCache, err = sqlutils.GetSQLiteDB(config.Config.SQLite3DataFile, nil)
 		if err == nil && !fromCache {
 			log.Debugf("Connected to orchestrator backend: sqlite on %v", config.Config.SQLite3DataFile)
 		}
@@ -191,7 +194,8 @@ func OpenOrchestrator() (db *sql.DB, err error) {
 			}
 		}
 		dsn := getMySQLURI()
-		db, fromCache, err = sqlutils.GetDB(dsn)
+		sqlUtilsLogger := SqlUtilsLogger{client_context: dsn}
+		db, fromCache, err = sqlutils.GetDB(dsn, sqlUtilsLogger)
 		if err == nil && !fromCache {
 			log.Debugf("Connected to orchestrator backend: %v", safeMySQLURI(dsn))
 
diff --git a/go/db/tls.go b/go/db/tls.go
index 5804dad25..fe9b0f928 100644
--- a/go/db/tls.go
+++ b/go/db/tls.go
@@ -19,6 +19,7 @@ package db
 import (
 	"crypto/tls"
 	"fmt"
+	"strconv"
 	"strings"
 	"time"
 
@@ -55,6 +56,23 @@ func init() {
 	metrics.Register("instance_tls.write_cache", writeInstanceTLSCacheCounter)
 }
 
+type SqlUtilsLogger struct {
+	client_context string
+}
+
+func (logger SqlUtilsLogger) OnError(caller_context string, query string, err error) error {
+	query = strings.Join(strings.Fields(query), " ")  // trim whitespaces
+	query = strings.Replace(query, "%", "%%", -1)  // escape %
+
+	msg := fmt.Sprintf("%+v(%+v) %+v: %+v",
+						caller_context,
+						logger.client_context,
+						query,
+						err)
+
+	return log.Errorf(msg)
+}
+
 func requiresTLS(host string, port int, mysql_uri string) bool {
 	cacheKey := fmt.Sprintf("%s:%d", host, port)
 
@@ -64,7 +82,8 @@ func requiresTLS(host string, port int, mysql_uri string) bool {
 	}
 
 	required := false
-	db, _, _ := sqlutils.GetDB(mysql_uri)
+	sqlUtilsLogger := SqlUtilsLogger{client_context: host + ":" + strconv.Itoa(port)}
+	db, _, _ := sqlutils.GetDB(mysql_uri, sqlUtilsLogger)
 	if err := db.Ping(); err != nil && (strings.Contains(err.Error(), Error3159) || strings.Contains(err.Error(), Error1045)) {
 		required = true
 	}
diff --git a/go/raft/rel_store.go b/go/raft/rel_store.go
index 12fe77fd3..ac32237a0 100644
--- a/go/raft/rel_store.go
+++ b/go/raft/rel_store.go
@@ -75,7 +75,7 @@ func (relStore *RelationalStore) openDB() (*sql.DB, error) {
 
 	if relStore.backend == nil {
 		relStoreFile := filepath.Join(relStore.dataDir, raftStoreFile)
-		sqliteDB, _, err := sqlutils.GetSQLiteDB(relStoreFile)
+		sqliteDB, _, err := sqlutils.GetSQLiteDB(relStoreFile, nil)
 		if err != nil {
 			return nil, err
 		}