From 686c2fbab7607d42183ae685a27ea3d7dce8c3f6 Mon Sep 17 00:00:00 2001 From: Christopher Speller Date: Fri, 27 Apr 2018 12:49:45 -0700 Subject: Structured logging (#8673) * Implementing structured logging * Changes to en.json to allow refactor to run. * Fixing global logger * Structured logger initalization. * Add caller. * Do some log redirection. * Auto refactor * Cleaning up l4g reference and removing dependancy. * Removing junk. * Copyright headers. * Fixing tests * Revert "Changes to en.json to allow refactor to run." This reverts commit fd8249e99bcad0231e6ea65cd77c32aae9a54026. * Fixing some auto refactor strangeness and typo. * Making keys more human readable. --- store/sqlstore/supplier.go | 66 +++++++++++++++++++++++----------------------- 1 file changed, 33 insertions(+), 33 deletions(-) (limited to 'store/sqlstore/supplier.go') diff --git a/store/sqlstore/supplier.go b/store/sqlstore/supplier.go index 8f37db0cd..69b30be59 100644 --- a/store/sqlstore/supplier.go +++ b/store/sqlstore/supplier.go @@ -15,11 +15,11 @@ import ( "sync/atomic" "time" - l4g "github.com/alecthomas/log4go" "github.com/go-sql-driver/mysql" "github.com/lib/pq" "github.com/mattermost/gorp" "github.com/mattermost/mattermost-server/einterfaces" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/store" "github.com/mattermost/mattermost-server/utils" @@ -144,7 +144,7 @@ func NewSqlSupplier(settings model.SqlSettings, metrics einterfaces.MetricsInter err := supplier.GetMaster().CreateTablesIfNotExists() if err != nil { - l4g.Critical(utils.T("store.sql.creating_tables.critical"), err) + mlog.Critical(fmt.Sprintf("Error creating database tables: %v", err)) time.Sleep(time.Second) os.Exit(EXIT_CREATE_TABLE) } @@ -189,13 +189,13 @@ func (s *SqlSupplier) Next() store.LayeredStoreSupplier { func setupConnection(con_type string, dataSource string, settings *model.SqlSettings) *gorp.DbMap { db, err := dbsql.Open(*settings.DriverName, dataSource) if err != nil { - l4g.Critical("Failed to open SQL connection to err:%v", err.Error()) + mlog.Critical(fmt.Sprintf("Failed to open SQL connection to err:%v", err.Error())) time.Sleep(time.Second) os.Exit(EXIT_DB_OPEN) } for i := 0; i < DB_PING_ATTEMPTS; i++ { - l4g.Info("Pinging SQL %v database", con_type) + mlog.Info(fmt.Sprintf("Pinging SQL %v database", con_type)) ctx, cancel := context.WithTimeout(context.Background(), DB_PING_TIMEOUT_SECS*time.Second) defer cancel() err = db.PingContext(ctx) @@ -203,11 +203,11 @@ func setupConnection(con_type string, dataSource string, settings *model.SqlSett break } else { if i == DB_PING_ATTEMPTS-1 { - l4g.Critical("Failed to ping DB, server will exit err=%v", err) + mlog.Critical(fmt.Sprintf("Failed to ping DB, server will exit err=%v", err)) time.Sleep(time.Second) os.Exit(EXIT_PING) } else { - l4g.Error("Failed to ping DB retrying in %v seconds err=%v", DB_PING_TIMEOUT_SECS, err) + mlog.Error(fmt.Sprintf("Failed to ping DB retrying in %v seconds err=%v", DB_PING_TIMEOUT_SECS, err)) time.Sleep(DB_PING_TIMEOUT_SECS * time.Second) } } @@ -228,7 +228,7 @@ func setupConnection(con_type string, dataSource string, settings *model.SqlSett } else if *settings.DriverName == model.DATABASE_DRIVER_POSTGRES { dbmap = &gorp.DbMap{Db: db, TypeConverter: mattermConverter{}, Dialect: gorp.PostgresDialect{}, QueryTimeout: connectionTimeout} } else { - l4g.Critical(utils.T("store.sql.dialect_driver.critical")) + mlog.Critical("Failed to create dialect specific driver") time.Sleep(time.Second) os.Exit(EXIT_NO_DRIVER) } @@ -338,7 +338,7 @@ func (ss *SqlSupplier) DoesTableExist(tableName string) bool { ) if err != nil { - l4g.Critical(utils.T("store.sql.table_exists.critical"), err) + mlog.Critical(fmt.Sprintf("Failed to check if table exists %v", err)) time.Sleep(time.Second) os.Exit(EXIT_TABLE_EXISTS) } @@ -360,7 +360,7 @@ func (ss *SqlSupplier) DoesTableExist(tableName string) bool { ) if err != nil { - l4g.Critical(utils.T("store.sql.table_exists.critical"), err) + mlog.Critical(fmt.Sprintf("Failed to check if table exists %v", err)) time.Sleep(time.Second) os.Exit(EXIT_TABLE_EXISTS_MYSQL) } @@ -382,7 +382,7 @@ func (ss *SqlSupplier) DoesTableExist(tableName string) bool { return count > 0 } else { - l4g.Critical(utils.T("store.sql.column_exists_missing_driver.critical")) + mlog.Critical("Failed to check if column exists because of missing driver") time.Sleep(time.Second) os.Exit(EXIT_COLUMN_EXISTS) return false @@ -406,7 +406,7 @@ func (ss *SqlSupplier) DoesColumnExist(tableName string, columnName string) bool return false } - l4g.Critical(utils.T("store.sql.column_exists.critical"), err) + mlog.Critical(fmt.Sprintf("Failed to check if column exists %v", err)) time.Sleep(time.Second) os.Exit(EXIT_DOES_COLUMN_EXISTS_POSTGRES) } @@ -429,7 +429,7 @@ func (ss *SqlSupplier) DoesColumnExist(tableName string, columnName string) bool ) if err != nil { - l4g.Critical(utils.T("store.sql.column_exists.critical"), err) + mlog.Critical(fmt.Sprintf("Failed to check if column exists %v", err)) time.Sleep(time.Second) os.Exit(EXIT_DOES_COLUMN_EXISTS_MYSQL) } @@ -452,7 +452,7 @@ func (ss *SqlSupplier) DoesColumnExist(tableName string, columnName string) bool return count > 0 } else { - l4g.Critical(utils.T("store.sql.column_exists_missing_driver.critical")) + mlog.Critical("Failed to check if column exists because of missing driver") time.Sleep(time.Second) os.Exit(EXIT_DOES_COLUMN_EXISTS_MISSING) return false @@ -468,7 +468,7 @@ func (ss *SqlSupplier) CreateColumnIfNotExists(tableName string, columnName stri if ss.DriverName() == model.DATABASE_DRIVER_POSTGRES { _, err := ss.GetMaster().ExecNoTimeout("ALTER TABLE " + tableName + " ADD " + columnName + " " + postgresColType + " DEFAULT '" + defaultValue + "'") if err != nil { - l4g.Critical(utils.T("store.sql.create_column.critical"), err) + mlog.Critical(fmt.Sprintf("Failed to create column %v", err)) time.Sleep(time.Second) os.Exit(EXIT_CREATE_COLUMN_POSTGRES) } @@ -478,7 +478,7 @@ func (ss *SqlSupplier) CreateColumnIfNotExists(tableName string, columnName stri } else if ss.DriverName() == model.DATABASE_DRIVER_MYSQL { _, err := ss.GetMaster().ExecNoTimeout("ALTER TABLE " + tableName + " ADD " + columnName + " " + mySqlColType + " DEFAULT '" + defaultValue + "'") if err != nil { - l4g.Critical(utils.T("store.sql.create_column.critical"), err) + mlog.Critical(fmt.Sprintf("Failed to create column %v", err)) time.Sleep(time.Second) os.Exit(EXIT_CREATE_COLUMN_MYSQL) } @@ -486,7 +486,7 @@ func (ss *SqlSupplier) CreateColumnIfNotExists(tableName string, columnName stri return true } else { - l4g.Critical(utils.T("store.sql.create_column_missing_driver.critical")) + mlog.Critical("Failed to create column because of missing driver") time.Sleep(time.Second) os.Exit(EXIT_CREATE_COLUMN_MISSING) return false @@ -501,7 +501,7 @@ func (ss *SqlSupplier) RemoveColumnIfExists(tableName string, columnName string) _, err := ss.GetMaster().ExecNoTimeout("ALTER TABLE " + tableName + " DROP COLUMN " + columnName) if err != nil { - l4g.Critical("Failed to drop column %v", err) + mlog.Critical(fmt.Sprintf("Failed to drop column %v", err)) time.Sleep(time.Second) os.Exit(EXIT_REMOVE_COLUMN) } @@ -516,7 +516,7 @@ func (ss *SqlSupplier) RemoveTableIfExists(tableName string) bool { _, err := ss.GetMaster().ExecNoTimeout("DROP TABLE " + tableName) if err != nil { - l4g.Critical("Failed to drop table %v", err) + mlog.Critical(fmt.Sprintf("Failed to drop table %v", err)) time.Sleep(time.Second) os.Exit(EXIT_REMOVE_TABLE) } @@ -537,7 +537,7 @@ func (ss *SqlSupplier) RenameColumnIfExists(tableName string, oldColumnName stri } if err != nil { - l4g.Critical(utils.T("store.sql.rename_column.critical"), err) + mlog.Critical(fmt.Sprintf("Failed to rename column %v", err)) time.Sleep(time.Second) os.Exit(EXIT_RENAME_COLUMN) } @@ -559,7 +559,7 @@ func (ss *SqlSupplier) GetMaxLengthOfColumnIfExists(tableName string, columnName } if err != nil { - l4g.Critical(utils.T("store.sql.maxlength_column.critical"), err) + mlog.Critical(fmt.Sprintf("Failed to get max length of column %v", err)) time.Sleep(time.Second) os.Exit(EXIT_MAX_COLUMN) } @@ -580,7 +580,7 @@ func (ss *SqlSupplier) AlterColumnTypeIfExists(tableName string, columnName stri } if err != nil { - l4g.Critical(utils.T("store.sql.alter_column_type.critical"), err) + mlog.Critical(fmt.Sprintf("Failed to alter column type %v", err)) time.Sleep(time.Second) os.Exit(EXIT_ALTER_COLUMN) } @@ -621,7 +621,7 @@ func (ss *SqlSupplier) createIndexIfNotExists(indexName string, tableName string query := "" if indexType == INDEX_TYPE_FULL_TEXT { if len(columnNames) != 1 { - l4g.Critical("Unable to create multi column full text index") + mlog.Critical("Unable to create multi column full text index") os.Exit(EXIT_CREATE_INDEX_POSTGRES) } columnName := columnNames[0] @@ -633,7 +633,7 @@ func (ss *SqlSupplier) createIndexIfNotExists(indexName string, tableName string _, err := ss.GetMaster().ExecNoTimeout(query) if err != nil { - l4g.Critical("Failed to create index %v, %v", errExists, err) + mlog.Critical(fmt.Sprintf("Failed to create index %v, %v", errExists, err)) time.Sleep(time.Second) os.Exit(EXIT_CREATE_INDEX_POSTGRES) } @@ -641,7 +641,7 @@ func (ss *SqlSupplier) createIndexIfNotExists(indexName string, tableName string count, err := ss.GetMaster().SelectInt("SELECT COUNT(0) AS index_exists FROM information_schema.statistics WHERE TABLE_SCHEMA = DATABASE() and table_name = ? AND index_name = ?", tableName, indexName) if err != nil { - l4g.Critical(utils.T("store.sql.check_index.critical"), err) + mlog.Critical(fmt.Sprintf("Failed to check index %v", err)) time.Sleep(time.Second) os.Exit(EXIT_CREATE_INDEX_MYSQL) } @@ -657,19 +657,19 @@ func (ss *SqlSupplier) createIndexIfNotExists(indexName string, tableName string _, err = ss.GetMaster().ExecNoTimeout("CREATE " + uniqueStr + fullTextIndex + " INDEX " + indexName + " ON " + tableName + " (" + strings.Join(columnNames, ", ") + ")") if err != nil { - l4g.Critical("Failed to create index %v", err) + mlog.Critical(fmt.Sprintf("Failed to create index %v", err)) time.Sleep(time.Second) os.Exit(EXIT_CREATE_INDEX_FULL_MYSQL) } } else if ss.DriverName() == model.DATABASE_DRIVER_SQLITE { _, err := ss.GetMaster().ExecNoTimeout("CREATE INDEX IF NOT EXISTS " + indexName + " ON " + tableName + " (" + strings.Join(columnNames, ", ") + ")") if err != nil { - l4g.Critical("Failed to create index %v", err) + mlog.Critical(fmt.Sprintf("Failed to create index %v", err)) time.Sleep(time.Second) os.Exit(EXIT_CREATE_INDEX_SQLITE) } } else { - l4g.Critical(utils.T("store.sql.create_index_missing_driver.critical")) + mlog.Critical("Failed to create index because of missing driver") time.Sleep(time.Second) os.Exit(EXIT_CREATE_INDEX_MISSING) } @@ -688,7 +688,7 @@ func (ss *SqlSupplier) RemoveIndexIfExists(indexName string, tableName string) b _, err = ss.GetMaster().ExecNoTimeout("DROP INDEX " + indexName) if err != nil { - l4g.Critical(utils.T("store.sql.remove_index.critical"), err) + mlog.Critical(fmt.Sprintf("Failed to remove index %v", err)) time.Sleep(time.Second) os.Exit(EXIT_REMOVE_INDEX_POSTGRES) } @@ -698,7 +698,7 @@ func (ss *SqlSupplier) RemoveIndexIfExists(indexName string, tableName string) b count, err := ss.GetMaster().SelectInt("SELECT COUNT(0) AS index_exists FROM information_schema.statistics WHERE TABLE_SCHEMA = DATABASE() and table_name = ? AND index_name = ?", tableName, indexName) if err != nil { - l4g.Critical(utils.T("store.sql.check_index.critical"), err) + mlog.Critical(fmt.Sprintf("Failed to check index %v", err)) time.Sleep(time.Second) os.Exit(EXIT_REMOVE_INDEX_MYSQL) } @@ -709,19 +709,19 @@ func (ss *SqlSupplier) RemoveIndexIfExists(indexName string, tableName string) b _, err = ss.GetMaster().ExecNoTimeout("DROP INDEX " + indexName + " ON " + tableName) if err != nil { - l4g.Critical(utils.T("store.sql.remove_index.critical"), err) + mlog.Critical(fmt.Sprintf("Failed to remove index %v", err)) time.Sleep(time.Second) os.Exit(EXIT_REMOVE_INDEX_MYSQL) } } else if ss.DriverName() == model.DATABASE_DRIVER_SQLITE { _, err := ss.GetMaster().ExecNoTimeout("DROP INDEX IF EXISTS " + indexName) if err != nil { - l4g.Critical(utils.T("store.sql.remove_index.critical"), err) + mlog.Critical(fmt.Sprintf("Failed to remove index %v", err)) time.Sleep(time.Second) os.Exit(EXIT_REMOVE_INDEX_SQLITE) } } else { - l4g.Critical(utils.T("store.sql.create_index_missing_driver.critical")) + mlog.Critical("Failed to create index because of missing driver") time.Sleep(time.Second) os.Exit(EXIT_REMOVE_INDEX_MISSING) } @@ -758,7 +758,7 @@ func (ss *SqlSupplier) GetAllConns() []*gorp.DbMap { } func (ss *SqlSupplier) Close() { - l4g.Info(utils.T("store.sql.closing.info")) + mlog.Info("Closing SqlStore") ss.master.Db.Close() for _, replica := range ss.replicas { replica.Db.Close() -- cgit v1.2.3-1-g7c22 From 2e6b3da1d3466db379fef0d61a23e2878d17ee9d Mon Sep 17 00:00:00 2001 From: Christopher Speller Date: Fri, 27 Apr 2018 13:31:50 -0700 Subject: Fixing some merge conflicts with structured logging. (#8685) --- store/sqlstore/supplier.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) (limited to 'store/sqlstore/supplier.go') diff --git a/store/sqlstore/supplier.go b/store/sqlstore/supplier.go index 69b30be59..0b02d9d47 100644 --- a/store/sqlstore/supplier.go +++ b/store/sqlstore/supplier.go @@ -374,7 +374,7 @@ func (ss *SqlSupplier) DoesTableExist(tableName string) bool { ) if err != nil { - l4g.Critical(utils.T("store.sql.table_exists.critical"), err) + mlog.Critical(fmt.Sprintf("Failed to check if table exists %v", err)) time.Sleep(time.Second) os.Exit(EXIT_TABLE_EXISTS_SQLITE) } @@ -444,7 +444,7 @@ func (ss *SqlSupplier) DoesColumnExist(tableName string, columnName string) bool ) if err != nil { - l4g.Critical(utils.T("store.sql.column_exists.critical"), err) + mlog.Critical(fmt.Sprintf("Failed to check if column exists %v", err)) time.Sleep(time.Second) os.Exit(EXIT_DOES_COLUMN_EXISTS_SQLITE) } -- cgit v1.2.3-1-g7c22