Merge branch 'master' into advanced-permissions-phase-2

17 files changed, 107 insertions, 104 deletions

diff --git a/store/layered_store.go b/store/layered_store.go
index d713226a9..603976fc0 100644
--- a/store/layered_store.go
+++ b/store/layered_store.go
@@ -6,8 +6,8 @@ package store
 import (
 	"context"
 
-	l4g "github.com/alecthomas/log4go"
 	"github.com/mattermost/mattermost-server/einterfaces"
+	"github.com/mattermost/mattermost-server/mlog"
 	"github.com/mattermost/mattermost-server/model"
 )
 
@@ -44,7 +44,7 @@ func NewLayeredStore(db LayeredStoreDatabaseLayer, metrics einterfaces.MetricsIn
 
 	// Setup the chain
 	if ENABLE_EXPERIMENTAL_REDIS {
-		l4g.Debug("Experimental redis enabled.")
+		mlog.Debug("Experimental redis enabled.")
 		store.RedisLayer = NewRedisSupplier()
 		store.RedisLayer.SetChainNext(store.DatabaseLayer)
 		store.LayerChainHead = store.RedisLayer
diff --git a/store/redis_supplier.go b/store/redis_supplier.go
index 751227be9..ce8cb0f0d 100644
--- a/store/redis_supplier.go
+++ b/store/redis_supplier.go
@@ -9,8 +9,8 @@ import (
 
 	"time"
 
-	l4g "github.com/alecthomas/log4go"
 	"github.com/go-redis/redis"
+	"github.com/mattermost/mattermost-server/mlog"
 )
 
 const REDIS_EXPIRY_TIME = 30 * time.Minute
@@ -45,7 +45,7 @@ func NewRedisSupplier() *RedisSupplier {
 	})
 
 	if _, err := supplier.client.Ping().Result(); err != nil {
-		l4g.Error("Unable to ping redis server: " + err.Error())
+		mlog.Error("Unable to ping redis server: " + err.Error())
 		return nil
 	}
 
diff --git a/store/redis_supplier_reactions.go b/store/redis_supplier_reactions.go
index cece8113d..ec9a4b4e0 100644
--- a/store/redis_supplier_reactions.go
+++ b/store/redis_supplier_reactions.go
@@ -6,21 +6,20 @@ package store
 import (
 	"context"
 
-	l4g "github.com/alecthomas/log4go"
-
+	"github.com/mattermost/mattermost-server/mlog"
 	"github.com/mattermost/mattermost-server/model"
 )
 
 func (s *RedisSupplier) ReactionSave(ctx context.Context, reaction *model.Reaction, hints ...LayeredStoreHint) *LayeredStoreSupplierResult {
 	if err := s.client.Del("reactions:" + reaction.PostId).Err(); err != nil {
-		l4g.Error("Redis failed to remove key reactions:" + reaction.PostId + " Error: " + err.Error())
+		mlog.Error("Redis failed to remove key reactions:" + reaction.PostId + " Error: " + err.Error())
 	}
 	return s.Next().ReactionSave(ctx, reaction, hints...)
 }
 
 func (s *RedisSupplier) ReactionDelete(ctx context.Context, reaction *model.Reaction, hints ...LayeredStoreHint) *LayeredStoreSupplierResult {
 	if err := s.client.Del("reactions:" + reaction.PostId).Err(); err != nil {
-		l4g.Error("Redis failed to remove key reactions:" + reaction.PostId + " Error: " + err.Error())
+		mlog.Error("Redis failed to remove key reactions:" + reaction.PostId + " Error: " + err.Error())
 	}
 	return s.Next().ReactionDelete(ctx, reaction, hints...)
 }
@@ -34,13 +33,13 @@ func (s *RedisSupplier) ReactionGetForPost(ctx context.Context, postId string, h
 		return result
 	}
 	if err != nil {
-		l4g.Error("Redis encountered an error on read: " + err.Error())
+		mlog.Error("Redis encountered an error on read: " + err.Error())
 	}
 
 	result := s.Next().ReactionGetForPost(ctx, postId, hints...)
 
 	if err := s.save("reactions:"+postId, result.Data, REDIS_EXPIRY_TIME); err != nil {
-		l4g.Error("Redis encountered and error on write: " + err.Error())
+		mlog.Error("Redis encountered and error on write: " + err.Error())
 	}
 
 	return result
diff --git a/store/redis_supplier_roles.go b/store/redis_supplier_roles.go
index c4f269268..ec4142273 100644
--- a/store/redis_supplier_roles.go
+++ b/store/redis_supplier_roles.go
@@ -7,8 +7,7 @@ import (
 	"context"
 	"fmt"
 
-	l4g "github.com/alecthomas/log4go"
-
+	"github.com/mattermost/mattermost-server/mlog"
 	"github.com/mattermost/mattermost-server/model"
 )
 
@@ -16,7 +15,7 @@ func (s *RedisSupplier) RoleSave(ctx context.Context, role *model.Role, hints ..
 	key := buildRedisKeyForRoleName(role.Name)
 
 	if err := s.client.Del(key).Err(); err != nil {
-		l4g.Error("Redis failed to remove key " + key + " Error: " + err.Error())
+		mlog.Error("Redis failed to remove key " + key + " Error: " + err.Error())
 	}
 
 	return s.Next().RoleSave(ctx, role, hints...)
@@ -34,7 +33,7 @@ func (s *RedisSupplier) RoleGetByName(ctx context.Context, name string, hints ..
 	var role *model.Role
 	found, err := s.load(key, &role)
 	if err != nil {
-		l4g.Error("Redis encountered an error on read: " + err.Error())
+		mlog.Error("Redis encountered an error on read: " + err.Error())
 	} else if found {
 		result := NewSupplierResult()
 		result.Data = role
@@ -45,7 +44,7 @@ func (s *RedisSupplier) RoleGetByName(ctx context.Context, name string, hints ..
 
 	if result.Err == nil {
 		if err := s.save(key, result.Data, REDIS_EXPIRY_TIME); err != nil {
-			l4g.Error("Redis encountered and error on write: " + err.Error())
+			mlog.Error("Redis encountered and error on write: " + err.Error())
 		}
 	}
 
@@ -64,7 +63,7 @@ func (s *RedisSupplier) RoleGetByNames(ctx context.Context, roleNames []string,
 		} else {
 			rolesToQuery = append(rolesToQuery, roleName)
 			if err != nil {
-				l4g.Error("Redis encountered an error on read: " + err.Error())
+				mlog.Error("Redis encountered an error on read: " + err.Error())
 			}
 		}
 	}
@@ -75,7 +74,7 @@ func (s *RedisSupplier) RoleGetByNames(ctx context.Context, roleNames []string,
 		rolesFound := result.Data.([]*model.Role)
 		for _, role := range rolesFound {
 			if err := s.save(buildRedisKeyForRoleName(role.Name), role, REDIS_EXPIRY_TIME); err != nil {
-				l4g.Error("Redis encountered and error on write: " + err.Error())
+				mlog.Error("Redis encountered and error on write: " + err.Error())
 			}
 		}
 		result.Data = append(foundRoles, result.Data.([]*model.Role)...)
@@ -102,10 +101,10 @@ func (s *RedisSupplier) RoleDelete(ctx context.Context, roleId string, hints ...
 func (s *RedisSupplier) RolePermanentDeleteAll(ctx context.Context, hints ...LayeredStoreHint) *LayeredStoreSupplierResult {
 	defer func() {
 		if keys, err := s.client.Keys("roles:*").Result(); err != nil {
-			l4g.Error("Redis encountered an error on read: " + err.Error())
+			mlog.Error("Redis encountered an error on read: " + err.Error())
 		} else {
 			if err := s.client.Del(keys...).Err(); err != nil {
-				l4g.Error("Redis encountered an error on delete: " + err.Error())
+				mlog.Error("Redis encountered an error on delete: " + err.Error())
 			}
 		}
 	}()
diff --git a/store/sqlstore/channel_member_history_store.go b/store/sqlstore/channel_member_history_store.go
index 6fc78b514..70ad16467 100644
--- a/store/sqlstore/channel_member_history_store.go
+++ b/store/sqlstore/channel_member_history_store.go
@@ -4,11 +4,12 @@
 package sqlstore
 
 import (
+	"fmt"
 	"net/http"
 
 	"database/sql"
 
-	l4g "github.com/alecthomas/log4go"
+	"github.com/mattermost/mattermost-server/mlog"
 	"github.com/mattermost/mattermost-server/model"
 	"github.com/mattermost/mattermost-server/store"
 )
@@ -60,7 +61,7 @@ func (s SqlChannelMemberHistoryStore) LogLeaveEvent(userId string, channelId str
 			result.Err = model.NewAppError("SqlChannelMemberHistoryStore.LogLeaveEvent", "store.sql_channel_member_history.log_leave_event.update_error", params, err.Error(), http.StatusInternalServerError)
 		} else if rows, err := sqlResult.RowsAffected(); err == nil && rows != 1 {
 			// there was no join event to update - this is best effort, so no need to raise an error
-			l4g.Warn("Channel join event for user %v and channel %v not found", userId, channelId)
+			mlog.Warn(fmt.Sprintf("Channel join event for user %v and channel %v not found", userId, channelId), mlog.String("user_id", userId))
 		}
 	})
 }
diff --git a/store/sqlstore/channel_store.go b/store/sqlstore/channel_store.go
index 0ddbc7221..b12c553a4 100644
--- a/store/sqlstore/channel_store.go
+++ b/store/sqlstore/channel_store.go
@@ -11,10 +11,10 @@ import (
 	"strconv"
 	"strings"
 
-	l4g "github.com/alecthomas/log4go"
 	"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"
@@ -1088,7 +1088,7 @@ func (s SqlChannelStore) IsUserInChannelUseCache(userId string, channelId string
 	}
 
 	if result := <-s.GetAllChannelMembersForUser(userId, true); result.Err != nil {
-		l4g.Error("SqlChannelStore.IsUserInChannelUseCache: " + result.Err.Error())
+		mlog.Error("SqlChannelStore.IsUserInChannelUseCache: " + result.Err.Error())
 		return false
 	} else {
 		ids := result.Data.(map[string]string)
diff --git a/store/sqlstore/command_webhook_store.go b/store/sqlstore/command_webhook_store.go
index 40fa8577c..1ea4f7328 100644
--- a/store/sqlstore/command_webhook_store.go
+++ b/store/sqlstore/command_webhook_store.go
@@ -7,8 +7,7 @@ import (
 	"database/sql"
 	"net/http"
 
-	l4g "github.com/alecthomas/log4go"
-
+	"github.com/mattermost/mattermost-server/mlog"
 	"github.com/mattermost/mattermost-server/model"
 	"github.com/mattermost/mattermost-server/store"
 )
@@ -86,9 +85,9 @@ func (s SqlCommandWebhookStore) TryUse(id string, limit int) store.StoreChannel
 }
 
 func (s SqlCommandWebhookStore) Cleanup() {
-	l4g.Debug("Cleaning up command webhook store.")
+	mlog.Debug("Cleaning up command webhook store.")
 	exptime := model.GetMillis() - model.COMMAND_WEBHOOK_LIFETIME
 	if _, err := s.GetMaster().Exec("DELETE FROM CommandWebhooks WHERE CreateAt < :ExpTime", map[string]interface{}{"ExpTime": exptime}); err != nil {
-		l4g.Error("Unable to cleanup command webhook store.")
+		mlog.Error("Unable to cleanup command webhook store.")
 	}
 }
diff --git a/store/sqlstore/post_store.go b/store/sqlstore/post_store.go
index dc7248057..75154791c 100644
--- a/store/sqlstore/post_store.go
+++ b/store/sqlstore/post_store.go
@@ -12,8 +12,8 @@ import (
 	"strings"
 	"sync"
 
-	l4g "github.com/alecthomas/log4go"
 	"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"
@@ -947,7 +947,7 @@ func (s *SqlPostStore) Search(teamId string, userId string, params *model.Search
 
 		_, err := s.GetSearchReplica().Select(&posts, searchQuery, queryParams)
 		if err != nil {
-			l4g.Warn(utils.T("store.sql_post.search.warn"), err.Error())
+			mlog.Warn(fmt.Sprintf("Query error searching posts: %v", err.Error()))
 			// Don't return the error to the caller as it is of no use to the user. Instead return an empty set of search results.
 		} else {
 			for _, p := range posts {
@@ -1147,7 +1147,7 @@ func (s *SqlPostStore) GetPostsByIds(postIds []string) store.StoreChannel {
 		_, err := s.GetReplica().Select(&posts, query, params)
 
 		if err != nil {
-			l4g.Error(err)
+			mlog.Error(fmt.Sprint(err))
 			result.Err = model.NewAppError("SqlPostStore.GetPostsByIds", "store.sql_post.get_posts_by_ids.app_error", nil, "", http.StatusInternalServerError)
 		} else {
 			result.Data = posts
@@ -1247,7 +1247,7 @@ func (s *SqlPostStore) determineMaxPostSize() int {
 				table_name = 'posts'
 			AND	column_name = 'message'
 		`); err != nil {
-			l4g.Error(utils.T("store.sql_post.query_max_post_size.error") + err.Error())
+			mlog.Error(utils.T("store.sql_post.query_max_post_size.error") + err.Error())
 		}
 	} else if s.DriverName() == model.DATABASE_DRIVER_MYSQL {
 		// The Post.Message column in MySQL has historically been TEXT, with a maximum
@@ -1263,10 +1263,10 @@ func (s *SqlPostStore) determineMaxPostSize() int {
 			AND	column_name = 'Message'
 			LIMIT 0, 1
 		`); err != nil {
-			l4g.Error(utils.T("store.sql_post.query_max_post_size.error") + err.Error())
+			mlog.Error(utils.T("store.sql_post.query_max_post_size.error") + err.Error())
 		}
 	} else {
-		l4g.Warn(utils.T("store.sql_post.query_max_post_size.unrecognized_driver"))
+		mlog.Warn("No implementation found to determine the maximum supported post size")
 	}
 
 	// Assume a worst-case representation of four bytes per rune.
@@ -1279,7 +1279,7 @@ func (s *SqlPostStore) determineMaxPostSize() int {
 		maxPostSize = model.POST_MESSAGE_MAX_RUNES_V1
 	}
 
-	l4g.Info(utils.T("store.sql_post.query_max_post_size.max_post_size_bytes"), maxPostSize, maxPostSizeBytes)
+	mlog.Info(fmt.Sprintf("Post.Message supports at most %d characters (%d bytes)", maxPostSize, maxPostSizeBytes))
 
 	return maxPostSize
 }
diff --git a/store/sqlstore/preference_store.go b/store/sqlstore/preference_store.go
index 791b51d2f..bfe5f6613 100644
--- a/store/sqlstore/preference_store.go
+++ b/store/sqlstore/preference_store.go
@@ -6,9 +6,9 @@ package sqlstore
 import (
 	"net/http"
 
-	l4g "github.com/alecthomas/log4go"
 	"github.com/mattermost/gorp"
 
+	"github.com/mattermost/mattermost-server/mlog"
 	"github.com/mattermost/mattermost-server/model"
 	"github.com/mattermost/mattermost-server/store"
 )
@@ -38,7 +38,7 @@ func (s SqlPreferenceStore) CreateIndexesIfNotExists() {
 }
 
 func (s SqlPreferenceStore) DeleteUnusedFeatures() {
-	l4g.Debug("Deleting any unused pre-release features")
+	mlog.Debug("Deleting any unused pre-release features")
 
 	sql := `DELETE
 		FROM Preferences
diff --git a/store/sqlstore/session_store.go b/store/sqlstore/session_store.go
index 221603865..c63abefbb 100644
--- a/store/sqlstore/session_store.go
+++ b/store/sqlstore/session_store.go
@@ -4,10 +4,11 @@
 package sqlstore
 
 import (
+	"fmt"
 	"net/http"
 	"time"
 
-	l4g "github.com/alecthomas/log4go"
+	"github.com/mattermost/mattermost-server/mlog"
 	"github.com/mattermost/mattermost-server/model"
 	"github.com/mattermost/mattermost-server/store"
 )
@@ -223,7 +224,7 @@ func (me SqlSessionStore) AnalyticsSessionCount() store.StoreChannel {
 }
 
 func (me SqlSessionStore) Cleanup(expiryTime int64, batchSize int64) {
-	l4g.Debug("Cleaning up session store.")
+	mlog.Debug("Cleaning up session store.")
 
 	var query string
 	if me.DriverName() == model.DATABASE_DRIVER_POSTGRES {
@@ -236,13 +237,13 @@ func (me SqlSessionStore) Cleanup(expiryTime int64, batchSize int64) {
 
 	for rowsAffected > 0 {
 		if sqlResult, err := me.GetMaster().Exec(query, map[string]interface{}{"ExpiresAt": expiryTime, "Limit": batchSize}); err != nil {
-			l4g.Error("Unable to cleanup session store. err=%v", err.Error())
+			mlog.Error(fmt.Sprintf("Unable to cleanup session store. err=%v", err.Error()))
 			return
 		} else {
 			var rowErr error
 			rowsAffected, rowErr = sqlResult.RowsAffected()
 			if rowErr != nil {
-				l4g.Error("Unable to cleanup session store. err=%v", err.Error())
+				mlog.Error(fmt.Sprintf("Unable to cleanup session store. err=%v", err.Error()))
 				return
 			}
 		}
diff --git a/store/sqlstore/store_test.go b/store/sqlstore/store_test.go
index 41d6a9b7e..58065d65d 100644
--- a/store/sqlstore/store_test.go
+++ b/store/sqlstore/store_test.go
@@ -8,6 +8,7 @@ import (
 	"sync"
 	"testing"
 
+	"github.com/mattermost/mattermost-server/mlog"
 	"github.com/mattermost/mattermost-server/model"
 	"github.com/mattermost/mattermost-server/store"
 	"github.com/mattermost/mattermost-server/store/storetest"
@@ -98,6 +99,15 @@ func tearDownStores() {
 }
 
 func TestMain(m *testing.M) {
+	// Setup a global logger to catch tests logging outside of app context
+	// The global logger will be stomped by apps initalizing but that's fine for testing. Ideally this won't happen.
+	mlog.InitGlobalLogger(mlog.NewLogger(&mlog.LoggerConfiguration{
+		EnableConsole: true,
+		ConsoleJson:   true,
+		ConsoleLevel:  "error",
+		EnableFile:    false,
+	}))
+
 	utils.TranslationsPreInit()
 
 	status := 0
diff --git a/store/sqlstore/supplier.go b/store/sqlstore/supplier.go
index 0e7823edd..d36a55097 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"
@@ -146,7 +146,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)
 	}
@@ -191,13 +191,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)
@@ -205,11 +205,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)
 			}
 		}
@@ -230,7 +230,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)
 	}
@@ -340,7 +340,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)
 		}
@@ -362,7 +362,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)
 		}
@@ -376,7 +376,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)
 		}
@@ -384,7 +384,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
@@ -408,7 +408,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)
 		}
@@ -431,7 +431,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)
 		}
@@ -446,7 +446,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)
 		}
@@ -454,7 +454,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
@@ -470,7 +470,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)
 		}
@@ -480,7 +480,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)
 		}
@@ -488,7 +488,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
@@ -537,7 +537,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)
 	}
@@ -552,7 +552,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)
 	}
@@ -573,7 +573,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)
 	}
@@ -595,7 +595,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)
 	}
@@ -616,7 +616,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)
 	}
@@ -657,7 +657,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]
@@ -669,7 +669,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)
 		}
@@ -677,7 +677,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)
 		}
@@ -693,19 +693,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)
 	}
@@ -724,7 +724,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)
 		}
@@ -734,7 +734,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)
 		}
@@ -745,19 +745,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)
 	}
@@ -794,7 +794,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()
diff --git a/store/sqlstore/supplier_reactions.go b/store/sqlstore/supplier_reactions.go
index aa3b078ea..5a9c9302a 100644
--- a/store/sqlstore/supplier_reactions.go
+++ b/store/sqlstore/supplier_reactions.go
@@ -5,14 +5,13 @@ package sqlstore
 
 import (
 	"context"
+	"fmt"
 	"net/http"
 
-	l4g "github.com/alecthomas/log4go"
-
 	"github.com/mattermost/gorp"
+	"github.com/mattermost/mattermost-server/mlog"
 	"github.com/mattermost/mattermost-server/model"
 	"github.com/mattermost/mattermost-server/store"
-	"github.com/mattermost/mattermost-server/utils"
 )
 
 func initSqlSupplierReactions(sqlStore SqlStore) {
@@ -136,7 +135,7 @@ func (s *SqlSupplier) ReactionDeleteAllWithEmojiName(ctx context.Context, emojiN
 	for _, reaction := range reactions {
 		if _, err := s.GetMaster().Exec(UPDATE_POST_HAS_REACTIONS_ON_DELETE_QUERY,
 			map[string]interface{}{"PostId": reaction.PostId, "UpdateAt": model.GetMillis()}); err != nil {
-			l4g.Warn(utils.T("store.sql_reaction.delete_all_with_emoji_name.update_post.warn"), reaction.PostId, err.Error())
+			mlog.Warn(fmt.Sprintf("Unable to update Post.HasReactions while removing reactions post_id=%v, error=%v", reaction.PostId, err.Error()))
 		}
 	}
 
diff --git a/store/sqlstore/tokens_store.go b/store/sqlstore/tokens_store.go
index ccb58cef1..6dde1bfbf 100644
--- a/store/sqlstore/tokens_store.go
+++ b/store/sqlstore/tokens_store.go
@@ -7,8 +7,7 @@ import (
 	"database/sql"
 	"net/http"
 
-	l4g "github.com/alecthomas/log4go"
-
+	"github.com/mattermost/mattermost-server/mlog"
 	"github.com/mattermost/mattermost-server/model"
 	"github.com/mattermost/mattermost-server/store"
 )
@@ -70,9 +69,9 @@ func (s SqlTokenStore) GetByToken(tokenString string) store.StoreChannel {
 }
 
 func (s SqlTokenStore) Cleanup() {
-	l4g.Debug("Cleaning up token store.")
+	mlog.Debug("Cleaning up token store.")
 	deltime := model.GetMillis() - model.MAX_TOKEN_EXIPRY_TIME
 	if _, err := s.GetMaster().Exec("DELETE FROM Tokens WHERE CreateAt < :DelTime", map[string]interface{}{"DelTime": deltime}); err != nil {
-		l4g.Error("Unable to cleanup token store.")
+		mlog.Error("Unable to cleanup token store.")
 	}
 }
diff --git a/store/sqlstore/upgrade.go b/store/sqlstore/upgrade.go
index 1d288eae0..3fc3ba79b 100644
--- a/store/sqlstore/upgrade.go
+++ b/store/sqlstore/upgrade.go
@@ -5,14 +5,13 @@ package sqlstore
 
 import (
 	"encoding/json"
+	"fmt"
 	"os"
 	"strings"
 	"time"
 
-	l4g "github.com/alecthomas/log4go"
-
+	"github.com/mattermost/mattermost-server/mlog"
 	"github.com/mattermost/mattermost-server/model"
-	"github.com/mattermost/mattermost-server/utils"
 )
 
 const (
@@ -82,17 +81,17 @@ func UpgradeDatabase(sqlStore SqlStore) {
 	// so lets set it to the current version.
 	if sqlStore.GetCurrentSchemaVersion() == "" {
 		if result := <-sqlStore.System().SaveOrUpdate(&model.System{Name: "Version", Value: model.CurrentVersion}); result.Err != nil {
-			l4g.Critical(result.Err.Error())
+			mlog.Critical(result.Err.Error())
 			time.Sleep(time.Second)
 			os.Exit(EXIT_VERSION_SAVE_MISSING)
 		}
 
-		l4g.Info("The database schema has been set to version %v", model.CurrentVersion)
+		mlog.Info(fmt.Sprintf("The database schema has been set to version %v", model.CurrentVersion))
 	}
 
 	// If we're not on the current version then it's too old to be upgraded
 	if sqlStore.GetCurrentSchemaVersion() != model.CurrentVersion {
-		l4g.Critical(utils.T("store.sql.schema_version.critical"), sqlStore.GetCurrentSchemaVersion(), OLDEST_SUPPORTED_VERSION, model.CurrentVersion, OLDEST_SUPPORTED_VERSION)
+		mlog.Critical(fmt.Sprintf("Database schema version %v is no longer supported. This Mattermost server supports automatic upgrades from schema version %v through schema version %v. Downgrades are not supported. Please manually upgrade to at least version %v before continuing", sqlStore.GetCurrentSchemaVersion(), OLDEST_SUPPORTED_VERSION, model.CurrentVersion, OLDEST_SUPPORTED_VERSION))
 		time.Sleep(time.Second)
 		os.Exit(EXIT_TOO_OLD)
 	}
@@ -100,18 +99,18 @@ func UpgradeDatabase(sqlStore SqlStore) {
 
 func saveSchemaVersion(sqlStore SqlStore, version string) {
 	if result := <-sqlStore.System().Update(&model.System{Name: "Version", Value: version}); result.Err != nil {
-		l4g.Critical(result.Err.Error())
+		mlog.Critical(result.Err.Error())
 		time.Sleep(time.Second)
 		os.Exit(EXIT_VERSION_SAVE)
 	}
 
-	l4g.Warn(utils.T("store.sql.upgraded.warn"), version)
+	mlog.Warn(fmt.Sprintf("The database schema has been upgraded to version %v", version))
 }
 
 func shouldPerformUpgrade(sqlStore SqlStore, currentSchemaVersion string, expectedSchemaVersion string) bool {
 	if sqlStore.GetCurrentSchemaVersion() == currentSchemaVersion {
-		l4g.Warn(utils.T("store.sql.schema_out_of_date.warn"), currentSchemaVersion)
-		l4g.Warn(utils.T("store.sql.schema_upgrade_attempt.warn"), expectedSchemaVersion)
+		mlog.Warn(fmt.Sprintf("The database schema version of %v appears to be out of date", currentSchemaVersion))
+		mlog.Warn(fmt.Sprintf("Attempting to upgrade the database schema version to %v", expectedSchemaVersion))
 
 		return true
 	}
@@ -135,7 +134,7 @@ func UpgradeDatabaseToVersion32(sqlStore SqlStore) {
 }
 
 func themeMigrationFailed(err error) {
-	l4g.Critical(utils.T("store.sql_user.migrate_theme.critical"), err)
+	mlog.Critical(fmt.Sprintf("Failed to migrate User.ThemeProps to Preferences table %v", err))
 	time.Sleep(time.Second)
 	os.Exit(EXIT_THEME_MIGRATION)
 }
@@ -403,7 +402,7 @@ func UpgradeDatabaseToVersion49(sqlStore SqlStore) {
 		defaultTimezone := model.DefaultUserTimezone()
 		defaultTimezoneValue, err := json.Marshal(defaultTimezone)
 		if err != nil {
-			l4g.Critical(err)
+			mlog.Critical(fmt.Sprint(err))
 		}
 		sqlStore.CreateColumnIfNotExists("Users", "Timezone", "varchar(256)", "varchar(256)", string(defaultTimezoneValue))
 		sqlStore.RemoveIndexIfExists("idx_channels_displayname", "Channels")
diff --git a/store/store.go b/store/store.go
index 98c394a21..1085198bd 100644
--- a/store/store.go
+++ b/store/store.go
@@ -6,8 +6,6 @@ package store
 import (
 	"time"
 
-	l4g "github.com/alecthomas/log4go"
-
 	"github.com/mattermost/mattermost-server/model"
 )
 
@@ -32,7 +30,7 @@ func Do(f func(result *StoreResult)) StoreChannel {
 func Must(sc StoreChannel) interface{} {
 	r := <-sc
 	if r.Err != nil {
-		l4g.Close()
+
 		time.Sleep(time.Second)
 		panic(r.Err)
 	}
diff --git a/store/storetest/docker.go b/store/storetest/docker.go
index cd2a3075a..f3830a6fe 100644
--- a/store/storetest/docker.go
+++ b/store/storetest/docker.go
@@ -12,8 +12,7 @@ import (
 	"strings"
 	"time"
 
-	l4g "github.com/alecthomas/log4go"
-
+	"github.com/mattermost/mattermost-server/mlog"
 	"github.com/mattermost/mattermost-server/model"
 )
 
@@ -31,7 +30,7 @@ type RunningContainer struct {
 }
 
 func (c *RunningContainer) Stop() error {
-	l4g.Info("Removing container: %v", c.Id)
+	mlog.Info(fmt.Sprintf("Removing container: %v", c.Id))
 	return exec.Command("docker", "rm", "-f", c.Id).Run()
 }
 
@@ -47,7 +46,7 @@ func NewMySQLContainer() (*RunningContainer, *model.SqlSettings, error) {
 	if err != nil {
 		return nil, nil, err
 	}
-	l4g.Info("Waiting for mysql connectivity")
+	mlog.Info("Waiting for mysql connectivity")
 	port := container.NetworkSettings.Ports["3306/tcp"][0].HostPort
 	if err := waitForPort(port); err != nil {
 		container.Stop()
@@ -66,7 +65,7 @@ func NewPostgreSQLContainer() (*RunningContainer, *model.SqlSettings, error) {
 	if err != nil {
 		return nil, nil, err
 	}
-	l4g.Info("Waiting for postgres connectivity")
+	mlog.Info("Waiting for postgres connectivity")
 	port := container.NetworkSettings.Ports["5432/tcp"][0].HostPort
 	if err := waitForPort(port); err != nil {
 		container.Stop()
@@ -111,7 +110,7 @@ func runContainer(args []string) (*RunningContainer, error) {
 		exec.Command("docker", "rm", "-f", id).Run()
 		return nil, err
 	}
-	l4g.Info("Running container: %v", id)
+	mlog.Info(fmt.Sprintf("Running container: %v", id))
 	return &RunningContainer{containers[0]}, nil
 }