Adding the debug bar logic in the server (#22410)

* Adding debugbar layer

* Adding sql debugbar info

* Make duration consistent across the debugbar lines

* Adding the debugbar/systeminfo endpoint

* Adding logs to the debugbar

* Improve the debugbar logger fields info

* Improving the debug bar architecture

* Allow to enable/disable debugbar in the backend

* Exposing the Debug Bar enable in the client config

* Adding more system information to the debugbar

* Adding params info to the store layer

* Organizing a bit the debugbar code in the server and adding some extra data to the system info api

* Adding debugbar email traces

* Changing the socket event name to 'debugbar'

* Adding explain support for the debugbar

* Adding missed file

* Omitting data related to the debugbar itself

* Removing unneeded functions

* Avoid arbitrary execution in explain api

* Moving debugbar inside the platform directory

* Replacing debugbar logger with a new logger Target

* Removed uneeded changes

* Fixing some linter errors

* Adding a debugbar log level to use it later for log events strictly related to the debug bar

* Fixing linter errors

* Fixing tests

* Adding i18n strings

store/sqlstore/sqlx_wrapper.go

@@ -64,15 +64,17 @@ var namedParamRegex = regexp.MustCompile(`:\w+`)
 
 type sqlxDBWrapper struct {
 	*sqlx.DB
-	queryTimeout time.Duration
-	trace        bool
+	queryTimeout    time.Duration
+	trace           bool
+	debugbarPublish func(string, float64, ...any)
 }
 
-func newSqlxDBWrapper(db *sqlx.DB, timeout time.Duration, trace bool) *sqlxDBWrapper {
+func newSqlxDBWrapper(db *sqlx.DB, timeout time.Duration, trace bool, debugbarPublish func(string, float64, ...any)) *sqlxDBWrapper {
 	return &sqlxDBWrapper{
-		DB:           db,
-		queryTimeout: timeout,
-		trace:        trace,
+		DB:              db,
+		queryTimeout:    timeout,
+		trace:           trace,
+		debugbarPublish: debugbarPublish,
 	}
 }
 
@@ -86,7 +88,7 @@ func (w *sqlxDBWrapper) Beginx() (*sqlxTxWrapper, error) {
 		return nil, err
 	}
 
-	return newSqlxTxWrapper(tx, w.queryTimeout, w.trace), nil
+	return newSqlxTxWrapper(tx, w.queryTimeout, w.trace, w.debugbarPublish), nil
 }
 
 func (w *sqlxDBWrapper) BeginXWithIsolation(opts *sql.TxOptions) (*sqlxTxWrapper, error) {
@@ -95,7 +97,7 @@ func (w *sqlxDBWrapper) BeginXWithIsolation(opts *sql.TxOptions) (*sqlxTxWrapper
 		return nil, err
 	}
 
-	return newSqlxTxWrapper(tx, w.queryTimeout, w.trace), nil
+	return newSqlxTxWrapper(tx, w.queryTimeout, w.trace, w.debugbarPublish), nil
 }
 
 func (w *sqlxDBWrapper) Get(dest any, query string, args ...any) error {
@@ -108,6 +110,11 @@ func (w *sqlxDBWrapper) Get(dest any, query string, args ...any) error {
 			printArgs(query, time.Since(then), args)
 		}(time.Now())
 	}
+	if w.debugbarPublish != nil {
+		defer func(then time.Time) {
+			w.debugbarPublish(query, float64(time.Since(then))/float64(time.Second), args...)
+		}(time.Now())
+	}
 
 	return w.DB.GetContext(ctx, dest, query, args...)
 }
@@ -134,6 +141,12 @@ func (w *sqlxDBWrapper) NamedExec(query string, arg any) (sql.Result, error) {
 		}(time.Now())
 	}
 
+	if w.debugbarPublish != nil {
+		defer func(then time.Time) {
+			w.debugbarPublish(query, float64(time.Since(then))/float64(time.Second), arg)
+		}(time.Now())
+	}
+
 	return w.DB.NamedExecContext(ctx, query, arg)
 }
 
@@ -161,6 +174,12 @@ func (w *sqlxDBWrapper) ExecNoTimeout(query string, args ...any) (sql.Result, er
 		}(time.Now())
 	}
 
+	if w.debugbarPublish != nil {
+		defer func(then time.Time) {
+			w.debugbarPublish(query, float64(time.Since(then))/float64(time.Second), args...)
+		}(time.Now())
+	}
+
 	return w.DB.ExecContext(context.Background(), query, args...)
 }
 
@@ -176,6 +195,12 @@ func (w *sqlxDBWrapper) ExecRaw(query string, args ...any) (sql.Result, error) {
 		}(time.Now())
 	}
 
+	if w.debugbarPublish != nil {
+		defer func(then time.Time) {
+			w.debugbarPublish(query, float64(time.Since(then))/float64(time.Second), args...)
+		}(time.Now())
+	}
+
 	return w.DB.ExecContext(ctx, query, args...)
 }
 
@@ -192,6 +217,12 @@ func (w *sqlxDBWrapper) NamedQuery(query string, arg any) (*sqlx.Rows, error) {
 		}(time.Now())
 	}
 
+	if w.debugbarPublish != nil {
+		defer func(then time.Time) {
+			w.debugbarPublish(query, float64(time.Since(then))/float64(time.Second), arg)
+		}(time.Now())
+	}
+
 	return w.DB.NamedQueryContext(ctx, query, arg)
 }
 
@@ -206,6 +237,12 @@ func (w *sqlxDBWrapper) QueryRowX(query string, args ...any) *sqlx.Row {
 		}(time.Now())
 	}
 
+	if w.debugbarPublish != nil {
+		defer func(then time.Time) {
+			w.debugbarPublish(query, float64(time.Since(then))/float64(time.Second), args...)
+		}(time.Now())
+	}
+
 	return w.DB.QueryRowxContext(ctx, query, args...)
 }
 
@@ -220,6 +257,12 @@ func (w *sqlxDBWrapper) QueryX(query string, args ...any) (*sqlx.Rows, error) {
 		}(time.Now())
 	}
 
+	if w.debugbarPublish != nil {
+		defer func(then time.Time) {
+			w.debugbarPublish(query, float64(time.Since(then))/float64(time.Second), args...)
+		}(time.Now())
+	}
+
 	return w.DB.QueryxContext(ctx, query, args)
 }
 
@@ -238,6 +281,12 @@ func (w *sqlxDBWrapper) SelectCtx(ctx context.Context, dest any, query string, a
 		}(time.Now())
 	}
 
+	if w.debugbarPublish != nil {
+		defer func(then time.Time) {
+			w.debugbarPublish(query, float64(time.Since(then))/float64(time.Second), args...)
+		}(time.Now())
+	}
+
 	return w.DB.SelectContext(ctx, dest, query, args...)
 }
 
@@ -252,15 +301,17 @@ func (w *sqlxDBWrapper) SelectBuilder(dest any, builder Builder) error {
 
 type sqlxTxWrapper struct {
 	*sqlx.Tx
-	queryTimeout time.Duration
-	trace        bool
+	queryTimeout    time.Duration
+	trace           bool
+	debugbarPublish func(string, float64, ...any)
 }
 
-func newSqlxTxWrapper(tx *sqlx.Tx, timeout time.Duration, trace bool) *sqlxTxWrapper {
+func newSqlxTxWrapper(tx *sqlx.Tx, timeout time.Duration, trace bool, debugbarPublish func(string, float64, ...any)) *sqlxTxWrapper {
 	return &sqlxTxWrapper{
-		Tx:           tx,
-		queryTimeout: timeout,
-		trace:        trace,
+		Tx:              tx,
+		queryTimeout:    timeout,
+		trace:           trace,
+		debugbarPublish: debugbarPublish,
 	}
 }
 
@@ -275,6 +326,12 @@ func (w *sqlxTxWrapper) Get(dest any, query string, args ...any) error {
 		}(time.Now())
 	}
 
+	if w.debugbarPublish != nil {
+		defer func(then time.Time) {
+			w.debugbarPublish(query, float64(time.Since(then))/float64(time.Second), args...)
+		}(time.Now())
+	}
+
 	return w.Tx.GetContext(ctx, dest, query, args...)
 }
 
@@ -302,6 +359,12 @@ func (w *sqlxTxWrapper) ExecNoTimeout(query string, args ...any) (sql.Result, er
 		}(time.Now())
 	}
 
+	if w.debugbarPublish != nil {
+		defer func(then time.Time) {
+			w.debugbarPublish(query, float64(time.Since(then))/float64(time.Second), args...)
+		}(time.Now())
+	}
+
 	return w.Tx.ExecContext(context.Background(), query, args...)
 }
 
@@ -326,6 +389,12 @@ func (w *sqlxTxWrapper) ExecRaw(query string, args ...any) (sql.Result, error) {
 		}(time.Now())
 	}
 
+	if w.debugbarPublish != nil {
+		defer func(then time.Time) {
+			w.debugbarPublish(query, float64(time.Since(then))/float64(time.Second), args...)
+		}(time.Now())
+	}
+
 	return w.Tx.ExecContext(ctx, query, args...)
 }
 
@@ -342,6 +411,12 @@ func (w *sqlxTxWrapper) NamedExec(query string, arg any) (sql.Result, error) {
 		}(time.Now())
 	}
 
+	if w.debugbarPublish != nil {
+		defer func(then time.Time) {
+			w.debugbarPublish(query, float64(time.Since(then))/float64(time.Second), arg)
+		}(time.Now())
+	}
+
 	return w.Tx.NamedExecContext(ctx, query, arg)
 }
 
@@ -358,6 +433,12 @@ func (w *sqlxTxWrapper) NamedQuery(query string, arg any) (*sqlx.Rows, error) {
 		}(time.Now())
 	}
 
+	if w.debugbarPublish != nil {
+		defer func(then time.Time) {
+			w.debugbarPublish(query, float64(time.Since(then))/float64(time.Second), arg)
+		}(time.Now())
+	}
+
 	// There is no tx.NamedQueryContext support in the sqlx API. (https://github.com/jmoiron/sqlx/issues/447)
 	// So we need to implement this ourselves.
 	type result struct {
@@ -400,6 +481,12 @@ func (w *sqlxTxWrapper) QueryRowX(query string, args ...any) *sqlx.Row {
 		}(time.Now())
 	}
 
+	if w.debugbarPublish != nil {
+		defer func(then time.Time) {
+			w.debugbarPublish(query, float64(time.Since(then))/float64(time.Second), args...)
+		}(time.Now())
+	}
+
 	return w.Tx.QueryRowxContext(ctx, query, args...)
 }
 
@@ -414,6 +501,12 @@ func (w *sqlxTxWrapper) QueryX(query string, args ...any) (*sqlx.Rows, error) {
 		}(time.Now())
 	}
 
+	if w.debugbarPublish != nil {
+		defer func(then time.Time) {
+			w.debugbarPublish(query, float64(time.Since(then))/float64(time.Second), args...)
+		}(time.Now())
+	}
+
 	return w.Tx.QueryxContext(ctx, query, args)
 }
 
@@ -428,6 +521,12 @@ func (w *sqlxTxWrapper) Select(dest any, query string, args ...any) error {
 		}(time.Now())
 	}
 
+	if w.debugbarPublish != nil {
+		defer func(then time.Time) {
+			w.debugbarPublish(query, float64(time.Since(then))/float64(time.Second), args...)
+		}(time.Now())
+	}
+
 	return w.Tx.SelectContext(ctx, dest, query, args...)
 }
 

store/sqlstore/store.go

@@ -130,6 +130,7 @@ type SqlStore struct {
 	replicaLagHandles []*dbsql.DB
 	stores            SqlStoreStores
 	settings          *model.SqlSettings
+	debugbarPublish   func(string, float64, ...any)
 	lockedToMaster    bool
 	context           context.Context
 	license           *model.License
@@ -140,12 +141,13 @@ type SqlStore struct {
 	pgDefaultTextSearchConfig string
 }
 
-func New(settings model.SqlSettings, metrics einterfaces.MetricsInterface) *SqlStore {
+func New(settings model.SqlSettings, metrics einterfaces.MetricsInterface, debugbarPublish func(string, float64, ...any)) *SqlStore {
 	store := &SqlStore{
-		rrCounter: 0,
-		srCounter: 0,
-		settings:  &settings,
-		metrics:   metrics,
+		rrCounter:       0,
+		srCounter:       0,
+		settings:        &settings,
+		metrics:         metrics,
+		debugbarPublish: debugbarPublish,
 	}
 
 	store.initConnection()
@@ -299,7 +301,9 @@ func (ss *SqlStore) initConnection() {
 	handle := SetupConnection("master", dataSource, ss.settings)
 	ss.masterX = newSqlxDBWrapper(sqlx.NewDb(handle, ss.DriverName()),
 		time.Duration(*ss.settings.QueryTimeout)*time.Second,
-		*ss.settings.Trace)
+		*ss.settings.Trace,
+		ss.debugbarPublish,
+	)
 	if ss.DriverName() == model.DatabaseDriverMysql {
 		ss.masterX.MapperFunc(noOpMapper)
 	}
@@ -313,7 +317,9 @@ func (ss *SqlStore) initConnection() {
 			handle := SetupConnection(fmt.Sprintf("replica-%v", i), replica, ss.settings)
 			ss.ReplicaXs[i] = newSqlxDBWrapper(sqlx.NewDb(handle, ss.DriverName()),
 				time.Duration(*ss.settings.QueryTimeout)*time.Second,
-				*ss.settings.Trace)
+				*ss.settings.Trace,
+				ss.debugbarPublish,
+			)
 			if ss.DriverName() == model.DatabaseDriverMysql {
 				ss.ReplicaXs[i].MapperFunc(noOpMapper)
 			}
@@ -329,7 +335,9 @@ func (ss *SqlStore) initConnection() {
 			handle := SetupConnection(fmt.Sprintf("search-replica-%v", i), replica, ss.settings)
 			ss.searchReplicaXs[i] = newSqlxDBWrapper(sqlx.NewDb(handle, ss.DriverName()),
 				time.Duration(*ss.settings.QueryTimeout)*time.Second,
-				*ss.settings.Trace)
+				*ss.settings.Trace,
+				ss.debugbarPublish,
+			)
 			if ss.DriverName() == model.DatabaseDriverMysql {
 				ss.searchReplicaXs[i].MapperFunc(noOpMapper)
 			}
@@ -434,7 +442,9 @@ func (ss *SqlStore) GetMasterX() *sqlxDBWrapper {
 func (ss *SqlStore) SetMasterX(db *sql.DB) {
 	ss.masterX = newSqlxDBWrapper(sqlx.NewDb(db, ss.DriverName()),
 		time.Duration(*ss.settings.QueryTimeout)*time.Second,
-		*ss.settings.Trace)
+		*ss.settings.Trace,
+		ss.debugbarPublish,
+	)
 	if ss.DriverName() == model.DatabaseDriverMysql {
 		ss.masterX.MapperFunc(noOpMapper)
 	}
@@ -1284,3 +1294,17 @@ func (ss *SqlStore) GetAppliedMigrations() ([]model.AppliedMigration, error) {
 
 	return migrations, nil
 }
+
+func (ss *SqlStore) Explain(query string, args []any) (string, error) {
+	var explain []string
+
+	if strings.HasPrefix(query, "ANALYZE") {
+		return "", errors.New("not allowed to explain queries with analyze at the beginning")
+	}
+
+	if err := ss.GetMasterX().Select(&explain, "EXPLAIN "+query, args...); err != nil {
+		return "", errors.Wrap(err, "unable to run the explain query")
+	}
+
+	return strings.Join(explain, "\n"), nil
+}

store/sqlstore/store_test.go

@@ -132,7 +132,7 @@ func initStores() {
 		wg.Add(1)
 		go func() {
 			defer wg.Done()
-			st.SqlStore = New(*st.SqlSettings, nil)
+			st.SqlStore = New(*st.SqlSettings, nil, nil)
 			st.Store = st.SqlStore
 			st.Store.DropAllTables()
 			st.Store.MarkSystemRanUnitTests()
@@ -171,7 +171,7 @@ func tearDownStores() {
 // Keeping it here to help avoiding future regressions.
 func TestStoreLicenseRace(t *testing.T) {
 	settings := makeSqlSettings(model.DatabaseDriverPostgres)
-	store := New(*settings, nil)
+	store := New(*settings, nil, nil)
 	defer func() {
 		store.Close()
 		storetest.CleanupSqlSettings(settings)
@@ -268,7 +268,7 @@ func TestGetReplica(t *testing.T) {
 
 			settings.DataSourceReplicas = dataSourceReplicas
 			settings.DataSourceSearchReplicas = dataSourceSearchReplicas
-			store := New(*settings, nil)
+			store := New(*settings, nil, nil)
 			defer func() {
 				store.Close()
 				storetest.CleanupSqlSettings(settings)
@@ -338,7 +338,7 @@ func TestGetReplica(t *testing.T) {
 
 			settings.DataSourceReplicas = dataSourceReplicas
 			settings.DataSourceSearchReplicas = dataSourceSearchReplicas
-			store := New(*settings, nil)
+			store := New(*settings, nil, nil)
 			defer func() {
 				store.Close()
 				storetest.CleanupSqlSettings(settings)
@@ -402,7 +402,7 @@ func TestGetDbVersion(t *testing.T) {
 		t.Run("Should return db version for "+driver, func(t *testing.T) {
 			t.Parallel()
 			settings := makeSqlSettings(driver)
-			store := New(*settings, nil)
+			store := New(*settings, nil, nil)
 
 			version, err := store.GetDbVersion(false)
 			require.NoError(t, err)
@@ -546,7 +546,7 @@ func TestUpAndDownMigrations(t *testing.T) {
 	for _, driver := range testDrivers {
 		t.Run("Should be reversible for "+driver, func(t *testing.T) {
 			settings := makeSqlSettings(driver)
-			store := New(*settings, nil)
+			store := New(*settings, nil, nil)
 			defer store.Close()
 
 			err := store.migrate(migrationsDirectionDown)
@@ -635,7 +635,7 @@ func TestGetAllConns(t *testing.T) {
 
 			settings.DataSourceReplicas = dataSourceReplicas
 			settings.DataSourceSearchReplicas = dataSourceSearchReplicas
-			store := New(*settings, nil)
+			store := New(*settings, nil, nil)
 			defer func() {
 				store.Close()
 				storetest.CleanupSqlSettings(settings)
@@ -819,7 +819,7 @@ func TestGetDBSchemaVersion(t *testing.T) {
 		t.Run("Should return latest version number of applied migrations for "+driver, func(t *testing.T) {
 			t.Parallel()
 			settings := makeSqlSettings(driver)
-			store := New(*settings, nil)
+			store := New(*settings, nil, nil)
 
 			assetsList, err := assets.ReadDir(filepath.Join("migrations", driver))
 			require.NoError(t, err)
@@ -853,7 +853,7 @@ func TestGetAppliedMigrations(t *testing.T) {
 		t.Run("Should return db applied migrations for "+driver, func(t *testing.T) {
 			t.Parallel()
 			settings := makeSqlSettings(driver)
-			store := New(*settings, nil)
+			store := New(*settings, nil, nil)
 
 			assetsList, err := assets.ReadDir(filepath.Join("migrations", driver))
 			require.NoError(t, err)