Merge pull request #7382 from ethereum-optimism/indexer.database.logging

feat(indexer) database logging

indexer/cmd/indexer/cli.go

@@ -35,7 +35,7 @@ func runIndexer(ctx *cli.Context) error {
 		return err
 	}
 
-	db, err := database.NewDB(cfg.DB)
+	db, err := database.NewDB(log, cfg.DB)
 	if err != nil {
 		log.Error("failed to connect to database", "err", err)
 		return err
@@ -59,7 +59,7 @@ func runApi(ctx *cli.Context) error {
 		return err
 	}
 
-	db, err := database.NewDB(cfg.DB)
+	db, err := database.NewDB(log, cfg.DB)
 	if err != nil {
 		log.Error("failed to connect to database", "err", err)
 		return err
@@ -79,7 +79,7 @@ func runMigrations(ctx *cli.Context) error {
 		return err
 	}
 
-	db, err := database.NewDB(cfg.DB)
+	db, err := database.NewDB(log, cfg.DB)
 	if err != nil {
 		log.Error("failed to connect to database", "err", err)
 		return err

indexer/database/db.go

@@ -12,9 +12,10 @@ import (
 	"github.com/ethereum-optimism/optimism/op-service/retry"
 	"github.com/pkg/errors"
 
+	"github.com/ethereum/go-ethereum/log"
+
 	"gorm.io/driver/postgres"
 	"gorm.io/gorm"
-	"gorm.io/gorm/logger"
 )
 
 var (
@@ -35,7 +36,7 @@ type DB struct {
 	BridgeTransactions BridgeTransactionsDB
 }
 
-func NewDB(dbConfig config.DBConfig) (*DB, error) {
+func NewDB(log log.Logger, dbConfig config.DBConfig) (*DB, error) {
 	retryStrategy := &retry.ExponentialStrategy{Min: 1000, Max: 20_000, MaxJitter: 250}
 
 	dsn := fmt.Sprintf("host=%s dbname=%s sslmode=disable", dbConfig.Host, dbConfig.Name)
@@ -52,21 +53,22 @@ func NewDB(dbConfig config.DBConfig) (*DB, error) {
 	gormConfig := gorm.Config{
 		// The indexer will explicitly manage the transactions
 		SkipDefaultTransaction: true,
-		Logger:                 logger.Default.LogMode(logger.Silent),
+		Logger:                 newLogger(log),
 	}
 
 	gorm, err := retry.Do[*gorm.DB](context.Background(), 10, retryStrategy, func() (*gorm.DB, error) {
 		gorm, err := gorm.Open(postgres.Open(dsn), &gormConfig)
-
 		if err != nil {
-			return nil, errors.Wrap(err, "failed to connect to database")
+			return nil, fmt.Errorf("failed to connect to database: %w", err)
 		}
+
 		return gorm, nil
 	})
 
 	if err != nil {
-		return nil, errors.Wrap(err, "failed to connect to database after multiple retries")
+		return nil, fmt.Errorf("failed to connect to database after multiple retries: %w", err)
 	}
+
 	db := &DB{
 		gorm:               gorm,
 		Blocks:             newBlocksDB(gorm),
@@ -75,6 +77,7 @@ func NewDB(dbConfig config.DBConfig) (*DB, error) {
 		BridgeMessages:     newBridgeMessagesDB(gorm),
 		BridgeTransactions: newBridgeTransactionsDB(gorm),
 	}
+
 	return db, nil
 }
 

indexer/database/logger.go

+package database
+
+import (
+	"context"
+	"fmt"
+	"strings"
+	"time"
+
+	"github.com/ethereum/go-ethereum/log"
+
+	"gorm.io/gorm/logger"
+)
+
+var (
+	_ logger.Interface = Logger{}
+
+	SlowThresholdMilliseconds = 200
+)
+
+type Logger struct {
+	log log.Logger
+}
+
+func newLogger(log log.Logger) Logger {
+	return Logger{log.New("module", "db")}
+}
+
+func (l Logger) LogMode(lvl logger.LogLevel) logger.Interface {
+	return l
+}
+
+func (l Logger) Info(ctx context.Context, msg string, data ...interface{}) {
+	l.log.Info(fmt.Sprintf(msg, data...))
+}
+
+func (l Logger) Warn(ctx context.Context, msg string, data ...interface{}) {
+	l.log.Warn(fmt.Sprintf(msg, data...))
+}
+
+func (l Logger) Error(ctx context.Context, msg string, data ...interface{}) {
+	l.log.Error(fmt.Sprintf(msg, data...))
+}
+
+func (l Logger) Trace(ctx context.Context, begin time.Time, fc func() (sql string, rowsAffected int64), err error) {
+	elapsedMs := time.Since(begin).Milliseconds()
+
+	// omit any values for batch inserts as they can be very long
+	sql, rows := fc()
+	if i := strings.Index(strings.ToLower(sql), "values"); i > 0 {
+		sql = fmt.Sprintf("%sVALUES (...)", sql[:i])
+	}
+
+	if elapsedMs < 200 {
+		l.log.Debug("database operation", "duration_ms", elapsedMs, "rows_affected", rows, "sql", sql)
+	} else {
+		l.log.Warn("database operation", "duration_ms", elapsedMs, "rows_affected", rows, "sql", sql)
+	}
+}

indexer/e2e_tests/setup.go

@@ -86,7 +86,8 @@ func createE2ETestSuite(t *testing.T) E2ETestSuite {
 		MetricsServer: config.ServerConfig{Host: "127.0.0.1", Port: 0},
 	}
 
-	db, err := database.NewDB(indexerCfg.DB)
+	// Emit debug log levels
+	db, err := database.NewDB(testlog.Logger(t, log.LvlDebug).New("role", "db"), indexerCfg.DB)
 	require.NoError(t, err)
 	t.Cleanup(func() { db.Close() })
 
@@ -138,9 +139,13 @@ func setupTestDatabase(t *testing.T) string {
 		Password: "",
 	}
 	// NewDB will create the database schema
-	db, err := database.NewDB(dbConfig)
+
+	silentLog := log.New()
+	silentLog.SetHandler(log.DiscardHandler())
+	db, err := database.NewDB(silentLog, dbConfig)
 	require.NoError(t, err)
 	defer db.Close()
+
 	err = db.ExecuteSQLMigration("../migrations")
 	require.NoError(t, err)
 

indexer/indexer.toml

 # Chain configures l1 chain addresses
-# Can configure them manually or use a preset l2 ChainId for known chains including OP Mainnet, OP Goerli, Base, Base Goerli, Zora, and Zora goerli
+# Can configure them manually or use a preset L2 ChainId for known chains
+#  - i.e OP Mainnet, OP Goerli, Base, Base Goerli, Zora, Zora Goerli, etc
 [chain]
-
 preset = $INDEXER_CHAIN_PRESET
 
 # L1 Config
@@ -15,17 +15,12 @@ l2-polling-interval = 0
 l2-header-buffer-size = 0
 l2-confirmation-depth = 0
 
-
 [rpcs]
 l1-rpc = "${INDEXER_RPC_URL_L1}"
 l2-rpc = "${INDEXER_RPC_URL_L2}"
 
 [db]
 host = "$INDEXER_DB_HOST"
-# this port may be problematic once we depoly
-# the DATABASE_URL looks like this for previous services and didn't include a port
-# DATABASE_URL="postgresql://${INDEXER_DB_USER}:${INDEXER_DB_PASS}@localhost/${INDEXER_DB_NAME}?host=${INDEXER_DB_HOST}"
-# If not problematic delete these comments
 port = $INDEXER_DB_PORT
 user = "$INDEXER_DB_USER"
 password = "$INDEXER_DB_PASS"