pg: less sloppy logging

kwilteam · May 24, 2024 · d74a9cf · d74a9cf
1 parent 16eee7b
commit d74a9cf
Show file tree

Hide file tree

Showing 2 changed files with 24 additions and 4 deletions.
diff --git a/internal/sql/pg/conn.go b/internal/sql/pg/conn.go
@@ -11,6 +11,7 @@ import (
 	"strings"
 
 	"github.com/kwilteam/kwil-db/common/sql"
+	"github.com/kwilteam/kwil-db/core/log"
 
 	"github.com/jackc/pgx/v5"
 	"github.com/jackc/pgx/v5/pgconn"
@@ -109,11 +110,28 @@ func NewPool(ctx context.Context, cfg *PoolConfig) (*Pool, error) {
 	// NOTE: we can consider changing the default exec mode at construction e.g.:
 	// pCfg.ConnConfig.DefaultQueryExecMode = pgx.QueryExecModeSimpleProtocol
 	pCfg.ConnConfig.OnNotice = func(_ *pgconn.PgConn, n *pgconn.Notice) {
-		logger.Infof("%v [%v]: %v / %v", n.Severity, n.Code, n.Message, n.Detail)
+		level := log.InfoLevel
+		if n.Code == "42710" || strings.HasPrefix(n.Code, "42P") { // duplicate something ignored: https://www.postgresql.org/docs/16/errcodes-appendix.html
+			level = log.DebugLevel
+		}
+		if n.Detail == "" {
+			logger.Logf(level, "%v [%v]: %v", n.Severity, n.Code, n.Message)
+		} else {
+			logger.Logf(level, "%v [%v]: %v / %v", n.Severity, n.Code, n.Message, n.Detail)
+		}
 	}
 	defaultOnPgError := pCfg.ConnConfig.OnPgError
 	pCfg.ConnConfig.OnPgError = func(c *pgconn.PgConn, n *pgconn.PgError) bool {
-		logger.Warnf("%v [%v]: %v / %v", n.Severity, n.Code, n.Message, n.Detail)
+		level := log.WarnLevel
+		switch sev := strings.ToUpper(n.Severity); sev {
+		case "FATAL", "PANIC":
+			level = log.ErrorLevel
+		} // otherwise it would be "ERROR"
+		if n.Detail == "" {
+			logger.Logf(level, "%v [%v]: %v", n.Severity, n.Code, n.Message)
+		} else {
+			logger.Logf(level, "%v [%v]: %v / %v", n.Severity, n.Code, n.Message, n.Detail)
+		}
 		return defaultOnPgError(c, n) // automatically close any fatal errors (default we are overridding)
 	}
 	db, err := pgxpool.NewWithConfig(ctx, pCfg)

diff --git a/internal/sql/pg/sql.go b/internal/sql/pg/sql.go
@@ -131,7 +131,9 @@ func rollbackPreparedTxns(ctx context.Context, conn *pgx.Conn) (int, error) {
 	}
 	var closed int
 	connectedDB := conn.Config().Database
-	logger.Warnf("Found %d orphaned prepared transactions", len(preparedTxns))
+	if len(preparedTxns) > 0 {
+		logger.Warnf("Found %d orphaned prepared transactions", len(preparedTxns))
+	}
 	for _, ptx := range preparedTxns {
 		if connectedDB != ptx.Database {
 			logger.Infof(`Not rolling back prepared transaction %v on foreign database %v. `+
@@ -147,7 +149,7 @@ func rollbackPreparedTxns(ctx context.Context, conn *pgx.Conn) (int, error) {
 		}
 		closed++
 	}
-	return closed, err
+	return closed, nil
 }
 
 const (