Commit 273d33f3 authored by Mo Firouz's avatar Mo Firouz Committed by Andrei Mihu
Browse files

Add support for Stackdriver logging format. (#291)

parent 68c02ba1
Loading
Loading
Loading
Loading
+3 −0
Original line number Diff line number Diff line
@@ -4,6 +4,9 @@ All notable changes to this project are documented below.
The format is based on [keep a changelog](http://keepachangelog.com) and this project uses [semantic versioning](http://semver.org).

## [Unreleased]
### Added
- Additional logging format option for Stackdriver Logging.

### Fixed
- Correctly return group user results in Lua runtime listing operation.
- Correctly handle leaderboard records previous page cursor.
+2 −2
Original line number Diff line number Diff line
@@ -43,13 +43,13 @@ LABEL variant=nakama
LABEL description="Distributed server for social and realtime games and apps."

RUN mkdir -p /nakama/data/modules && \
    apk --no-cache add ca-certificates curl iproute2 unzip rsync git
    apk --no-cache add ca-certificates curl iproute2 unzip rsync git tini

WORKDIR /nakama/
COPY --from=builder "/go/build/nakama" /nakama/
EXPOSE 7349 7350 7351

ENTRYPOINT ["./nakama"]
ENTRYPOINT ["/sbin/tini", "--", "/nakama/nakama"]

HEALTHCHECK --interval=5m --timeout=3s \
  CMD curl -f http://localhost:7350/ || exit 1
+2 −1
Original line number Diff line number Diff line
@@ -66,7 +66,7 @@ func main() {
	// Initialize the global random obj with customs seed.
	rand.Seed(time.Now().UnixNano())

	tmpLogger := server.NewJSONLogger(os.Stdout, zapcore.InfoLevel)
	tmpLogger := server.NewJSONLogger(os.Stdout, zapcore.InfoLevel, server.JSONFormat)

	if len(os.Args) > 1 {
		switch os.Args[1] {
@@ -80,6 +80,7 @@ func main() {

	config := server.ParseArgs(tmpLogger, os.Args)
	logger, startupLogger := server.SetupLogging(tmpLogger, config)
	server.CheckConfig(logger, config)

	startupLogger.Info("Nakama starting")
	startupLogger.Info("Node", zap.String("name", config.GetName()), zap.String("version", semver), zap.String("runtime", runtime.Version()), zap.Int("cpu", runtime.NumCPU()))
+50 −33
Original line number Diff line number Diff line
@@ -21,12 +21,15 @@ import (
	"math"
	"net/url"
	"os"
	"strings"
	"time"

	"github.com/gobuffalo/packr"
	"github.com/heroiclabs/nakama/server"
	"github.com/lib/pq"
	"github.com/rubenv/sql-migrate"
	"go.uber.org/zap"
	"go.uber.org/zap/zapcore"
)

const (
@@ -45,7 +48,7 @@ type statusRow struct {
type migrationService struct {
	dbAddress    string
	limit        int
	logger     *zap.Logger
	loggerFormat server.LoggingFormat
	migrations   *migrate.AssetMigrationSource
	db           *sql.DB
}
@@ -79,15 +82,14 @@ func StartupCheck(logger *zap.Logger, db *sql.DB) {
	}
}

func Parse(args []string, logger *zap.Logger) {
func Parse(args []string, tmpLogger *zap.Logger) {
	if len(args) == 0 {
		logger.Fatal("Migrate requires a subcommand. Available commands are: 'up', 'down', 'redo', 'status'.")
		tmpLogger.Fatal("Migrate requires a subcommand. Available commands are: 'up', 'down', 'redo', 'status'.")
	}

	migrate.SetTable(migrationTable)
	migrationBox := packr.NewBox("./sql") // path must be string not a variable for packr to understand
	ms := &migrationService{
		logger: logger,
		migrations: &migrate.AssetMigrationSource{
			Asset: migrationBox.Find,
			AssetDir: func(path string) ([]string, error) {
@@ -96,7 +98,7 @@ func Parse(args []string, logger *zap.Logger) {
		},
	}

	var exec func()
	var exec func(logger *zap.Logger)
	switch args[0] {
	case "up":
		exec = ms.up
@@ -107,10 +109,11 @@ func Parse(args []string, logger *zap.Logger) {
	case "status":
		exec = ms.status
	default:
		logger.Fatal("Unrecognized migrate subcommand. Available commands are: 'up', 'down', 'redo', 'status'.")
		tmpLogger.Fatal("Unrecognized migrate subcommand. Available commands are: 'up', 'down', 'redo', 'status'.")
	}

	ms.parseSubcommand(args[1:])
	ms.parseSubcommand(args[1:], tmpLogger)
	logger := server.NewJSONLogger(os.Stdout, zapcore.InfoLevel, ms.loggerFormat)

	rawUrl := fmt.Sprintf("postgresql://%s", ms.dbAddress)
	parsedUrl, err := url.Parse(rawUrl)
@@ -170,67 +173,67 @@ func Parse(args []string, logger *zap.Logger) {
	}
	ms.db = db

	exec()
	exec(logger)
	os.Exit(0)
}

func (ms *migrationService) up() {
func (ms *migrationService) up(logger *zap.Logger) {
	if ms.limit < defaultLimit {
		ms.limit = 0
	}

	appliedMigrations, err := migrate.ExecMax(ms.db, dialect, ms.migrations, migrate.Up, ms.limit)
	if err != nil {
		ms.logger.Fatal("Failed to apply migrations", zap.Int("count", appliedMigrations), zap.Error(err))
		logger.Fatal("Failed to apply migrations", zap.Int("count", appliedMigrations), zap.Error(err))
	}

	ms.logger.Info("Successfully applied migration", zap.Int("count", appliedMigrations))
	logger.Info("Successfully applied migration", zap.Int("count", appliedMigrations))
}

func (ms *migrationService) down() {
func (ms *migrationService) down(logger *zap.Logger) {
	if ms.limit < defaultLimit {
		ms.limit = 1
	}

	appliedMigrations, err := migrate.ExecMax(ms.db, dialect, ms.migrations, migrate.Down, ms.limit)
	if err != nil {
		ms.logger.Fatal("Failed to migrate back", zap.Int("count", appliedMigrations), zap.Error(err))
		logger.Fatal("Failed to migrate back", zap.Int("count", appliedMigrations), zap.Error(err))
	}

	ms.logger.Info("Successfully migrated back", zap.Int("count", appliedMigrations))
	logger.Info("Successfully migrated back", zap.Int("count", appliedMigrations))
}

func (ms *migrationService) redo() {
func (ms *migrationService) redo(logger *zap.Logger) {
	if ms.limit > defaultLimit {
		ms.logger.Warn("Limit is ignored when redo is invoked")
		logger.Warn("Limit is ignored when redo is invoked")
	}

	appliedMigrations, err := migrate.ExecMax(ms.db, dialect, ms.migrations, migrate.Down, 1)
	if err != nil {
		ms.logger.Fatal("Failed to migrate back", zap.Int("count", appliedMigrations), zap.Error(err))
		logger.Fatal("Failed to migrate back", zap.Int("count", appliedMigrations), zap.Error(err))
	}
	ms.logger.Info("Successfully migrated back", zap.Int("count", appliedMigrations))
	logger.Info("Successfully migrated back", zap.Int("count", appliedMigrations))

	appliedMigrations, err = migrate.ExecMax(ms.db, dialect, ms.migrations, migrate.Up, 1)
	if err != nil {
		ms.logger.Fatal("Failed to apply migrations", zap.Int("count", appliedMigrations), zap.Error(err))
		logger.Fatal("Failed to apply migrations", zap.Int("count", appliedMigrations), zap.Error(err))
	}
	ms.logger.Info("Successfully applied migration", zap.Int("count", appliedMigrations))
	logger.Info("Successfully applied migration", zap.Int("count", appliedMigrations))
}

func (ms *migrationService) status() {
func (ms *migrationService) status(logger *zap.Logger) {
	if ms.limit > defaultLimit {
		ms.logger.Warn("Limit is ignored when status is invoked")
		logger.Warn("Limit is ignored when status is invoked")
	}

	migrations, err := ms.migrations.FindMigrations()
	if err != nil {
		ms.logger.Fatal("Could not find migrations", zap.Error(err))
		logger.Fatal("Could not find migrations", zap.Error(err))
	}

	records, err := migrate.GetMigrationRecords(ms.db, dialect)
	if err != nil {
		ms.logger.Fatal("Could not get migration records", zap.Error(err))
		logger.Fatal("Could not get migration records", zap.Error(err))
	}

	rows := make(map[string]*statusRow)
@@ -249,23 +252,37 @@ func (ms *migrationService) status() {

	for _, m := range migrations {
		if rows[m.Id].Migrated {
			ms.logger.Info(m.Id, zap.String("applied", rows[m.Id].AppliedAt.Format(time.RFC822Z)))
			logger.Info(m.Id, zap.String("applied", rows[m.Id].AppliedAt.Format(time.RFC822Z)))
		} else {
			ms.logger.Info(m.Id, zap.String("applied", ""))
			logger.Info(m.Id, zap.String("applied", ""))
		}
	}
}

func (ms *migrationService) parseSubcommand(args []string) {
func (ms *migrationService) parseSubcommand(args []string, logger *zap.Logger) {
	var loggerFormat string
	flags := flag.NewFlagSet("migrate", flag.ExitOnError)
	flags.StringVar(&ms.dbAddress, "database.address", "root@localhost:26257", "Address of CockroachDB server (username:password@address:port/dbname)")
	flags.IntVar(&ms.limit, "limit", defaultLimit, "Number of migrations to apply forwards or backwards.")
	flags.StringVar(&loggerFormat, "logger.format", "json", "Number of migrations to apply forwards or backwards.")

	if err := flags.Parse(args); err != nil {
		ms.logger.Fatal("Could not parse migration flags.")
		logger.Fatal("Could not parse migration flags.")
	}

	if ms.dbAddress == "" {
		ms.logger.Fatal("Database connection details are required.")
		logger.Fatal("Database connection details are required.")
	}

	ms.loggerFormat = server.JSONFormat
	switch strings.ToLower(loggerFormat) {
	case "":
		fallthrough
	case "json":
		ms.loggerFormat = server.JSONFormat
	case "stackdriver":
		ms.loggerFormat = server.StackdriverFormat
	default:
		logger.Fatal("Logger mode invalid, must be one of: '', 'json', or 'stackdriver")
	}
}
+59 −55
Original line number Diff line number Diff line
@@ -93,110 +93,112 @@ func ParseArgs(logger *zap.Logger, args []string) Config {
		logger.Fatal("Could not parse command line arguments", zap.Error(err))
	}

	mainConfig.GetRuntime().Environment = convertRuntimeEnv(logger, runtimeEnvironment, mainConfig.GetRuntime().Env)

	return mainConfig
}

func CheckConfig(logger *zap.Logger, config Config) {
	// Fail fast on invalid values.
	if l := len(mainConfig.Name); l < 1 || l > 16 {
	if l := len(config.GetName()); l < 1 || l > 16 {
		logger.Fatal("Name must be 1-16 characters", zap.String("param", "name"))
	}
	if mainConfig.ShutdownGraceSec < 0 {
		logger.Fatal("Shutdown grace period must be >= 0", zap.Int("shutdown_grace_sec", mainConfig.ShutdownGraceSec))
	if config.GetShutdownGraceSec() < 0 {
		logger.Fatal("Shutdown grace period must be >= 0", zap.Int("shutdown_grace_sec", config.GetShutdownGraceSec()))
	}
	if mainConfig.GetSocket().ServerKey == "" {
	if config.GetSocket().ServerKey == "" {
		logger.Fatal("Server key must be set", zap.String("param", "socket.server_key"))
	}
	if mainConfig.GetSession().EncryptionKey == "" {
	if config.GetSession().EncryptionKey == "" {
		logger.Fatal("Encryption key must be set", zap.String("param", "session.encryption_key"))
	}
	if mainConfig.GetRuntime().HTTPKey == "" {
	if config.GetRuntime().HTTPKey == "" {
		logger.Fatal("Runtime HTTP key must be set", zap.String("param", "runtime.http_key"))
	}
	if mainConfig.GetConsole().Username == "" {
	if config.GetConsole().Username == "" {
		logger.Fatal("Console username must be set", zap.String("param", "console.username"))
	}
	if mainConfig.GetConsole().Password == "" {
	if config.GetConsole().Password == "" {
		logger.Fatal("Console password must be set", zap.String("param", "console.password"))
	}
	if p := mainConfig.GetSocket().Protocol; p != "tcp" && p != "tcp4" && p != "tcp6" {
		logger.Fatal("Socket protocol must be one of: tcp, tcp4, tcp6", zap.String("socket.protocol", mainConfig.GetSocket().Protocol))
	if p := config.GetSocket().Protocol; p != "tcp" && p != "tcp4" && p != "tcp6" {
		logger.Fatal("Socket protocol must be one of: tcp, tcp4, tcp6", zap.String("socket.protocol", config.GetSocket().Protocol))
	}
	if mainConfig.GetSocket().PingPeriodMs >= mainConfig.GetSocket().PongWaitMs {
		logger.Fatal("Ping period value must be less than pong wait value", zap.Int("socket.ping_period_ms", mainConfig.GetSocket().PingPeriodMs), zap.Int("socket.pong_wait_ms", mainConfig.GetSocket().PongWaitMs))
	if config.GetSocket().PingPeriodMs >= config.GetSocket().PongWaitMs {
		logger.Fatal("Ping period value must be less than pong wait value", zap.Int("socket.ping_period_ms", config.GetSocket().PingPeriodMs), zap.Int("socket.pong_wait_ms", config.GetSocket().PongWaitMs))
	}
	if mainConfig.GetRuntime().MinCount < 0 {
		logger.Fatal("Minimum runtime instance count must be >= 0", zap.Int("runtime.min_count", mainConfig.GetRuntime().MinCount))
	if config.GetRuntime().MinCount < 0 {
		logger.Fatal("Minimum runtime instance count must be >= 0", zap.Int("runtime.min_count", config.GetRuntime().MinCount))
	}
	if mainConfig.GetRuntime().MaxCount < 1 {
		logger.Fatal("Maximum runtime instance count must be >= 1", zap.Int("runtime.max_count", mainConfig.GetRuntime().MaxCount))
	if config.GetRuntime().MaxCount < 1 {
		logger.Fatal("Maximum runtime instance count must be >= 1", zap.Int("runtime.max_count", config.GetRuntime().MaxCount))
	}
	if mainConfig.GetRuntime().MinCount > mainConfig.GetRuntime().MaxCount {
		logger.Fatal("Minimum runtime instance count must be less than or equal to maximum runtime instance count", zap.Int("runtime.min_count", mainConfig.GetRuntime().MinCount), zap.Int("runtime.max_count", mainConfig.GetRuntime().MaxCount))
	if config.GetRuntime().MinCount > config.GetRuntime().MaxCount {
		logger.Fatal("Minimum runtime instance count must be less than or equal to maximum runtime instance count", zap.Int("runtime.min_count", config.GetRuntime().MinCount), zap.Int("runtime.max_count", config.GetRuntime().MaxCount))
	}
	if mainConfig.GetRuntime().CallStackSize < 1 {
		logger.Fatal("Runtime instance call stack size must be >= 1", zap.Int("runtime.call_stack_size", mainConfig.GetRuntime().CallStackSize))
	if config.GetRuntime().CallStackSize < 1 {
		logger.Fatal("Runtime instance call stack size must be >= 1", zap.Int("runtime.call_stack_size", config.GetRuntime().CallStackSize))
	}
	if mainConfig.GetRuntime().RegistrySize < 128 {
		logger.Fatal("Runtime instance registry size must be >= 128", zap.Int("runtime.registry_size", mainConfig.GetRuntime().RegistrySize))
	if config.GetRuntime().RegistrySize < 128 {
		logger.Fatal("Runtime instance registry size must be >= 128", zap.Int("runtime.registry_size", config.GetRuntime().RegistrySize))
	}
	if mainConfig.GetMatch().InputQueueSize < 1 {
		logger.Fatal("Match input queue size must be >= 1", zap.Int("match.input_queue_size", mainConfig.GetMatch().InputQueueSize))
	if config.GetMatch().InputQueueSize < 1 {
		logger.Fatal("Match input queue size must be >= 1", zap.Int("match.input_queue_size", config.GetMatch().InputQueueSize))
	}
	if mainConfig.GetMatch().CallQueueSize < 1 {
		logger.Fatal("Match call queue size must be >= 1", zap.Int("match.call_queue_size", mainConfig.GetMatch().CallQueueSize))
	if config.GetMatch().CallQueueSize < 1 {
		logger.Fatal("Match call queue size must be >= 1", zap.Int("match.call_queue_size", config.GetMatch().CallQueueSize))
	}
	if mainConfig.GetMatch().JoinAttemptQueueSize < 1 {
		logger.Fatal("Match join attempt queue size must be >= 1", zap.Int("match.join_attempt_queue_size", mainConfig.GetMatch().JoinAttemptQueueSize))
	if config.GetMatch().JoinAttemptQueueSize < 1 {
		logger.Fatal("Match join attempt queue size must be >= 1", zap.Int("match.join_attempt_queue_size", config.GetMatch().JoinAttemptQueueSize))
	}
	if mainConfig.GetMatch().DeferredQueueSize < 1 {
		logger.Fatal("Match deferred queue size must be >= 1", zap.Int("match.deferred_queue_size", mainConfig.GetMatch().DeferredQueueSize))
	if config.GetMatch().DeferredQueueSize < 1 {
		logger.Fatal("Match deferred queue size must be >= 1", zap.Int("match.deferred_queue_size", config.GetMatch().DeferredQueueSize))
	}
	if mainConfig.GetMatch().JoinMarkerDeadlineMs < 1 {
		logger.Fatal("Match join marker deadline must be >= 1", zap.Int("match.join_marker_deadline_ms", mainConfig.GetMatch().JoinMarkerDeadlineMs))
	if config.GetMatch().JoinMarkerDeadlineMs < 1 {
		logger.Fatal("Match join marker deadline must be >= 1", zap.Int("match.join_marker_deadline_ms", config.GetMatch().JoinMarkerDeadlineMs))
	}
	if mainConfig.GetTracker().EventQueueSize < 1 {
		logger.Fatal("Tracker presence event queue size must be >= 1", zap.Int("tracker.event_queue_size", mainConfig.GetTracker().EventQueueSize))
	if config.GetTracker().EventQueueSize < 1 {
		logger.Fatal("Tracker presence event queue size must be >= 1", zap.Int("tracker.event_queue_size", config.GetTracker().EventQueueSize))
	}

	// If the runtime path is not overridden, set it to `datadir/modules`.
	if mainConfig.GetRuntime().Path == "" {
		mainConfig.GetRuntime().Path = filepath.Join(mainConfig.GetDataDir(), "modules")
	if config.GetRuntime().Path == "" {
		config.GetRuntime().Path = filepath.Join(config.GetDataDir(), "modules")
	}

	mainConfig.GetRuntime().Environment = convertRuntimeEnv(logger, runtimeEnvironment, mainConfig.GetRuntime().Env)

	// Log warnings for insecure default parameter values.
	if mainConfig.GetConsole().Username == "admin" {
	if config.GetConsole().Username == "admin" {
		logger.Warn("WARNING: insecure default parameter value, change this for production!", zap.String("param", "console.username"))
	}
	if mainConfig.GetConsole().Password == "password" {
	if config.GetConsole().Password == "password" {
		logger.Warn("WARNING: insecure default parameter value, change this for production!", zap.String("param", "console.password"))
	}
	if mainConfig.GetSocket().ServerKey == "defaultkey" {
	if config.GetSocket().ServerKey == "defaultkey" {
		logger.Warn("WARNING: insecure default parameter value, change this for production!", zap.String("param", "socket.server_key"))
	}
	if mainConfig.GetSession().EncryptionKey == "defaultencryptionkey" {
	if config.GetSession().EncryptionKey == "defaultencryptionkey" {
		logger.Warn("WARNING: insecure default parameter value, change this for production!", zap.String("param", "session.encryption_key"))
	}
	if mainConfig.GetRuntime().HTTPKey == "defaultkey" {
	if config.GetRuntime().HTTPKey == "defaultkey" {
		logger.Warn("WARNING: insecure default parameter value, change this for production!", zap.String("param", "runtime.http_key"))
	}

	// Log warnings for SSL usage.
	if mainConfig.GetSocket().SSLCertificate != "" && mainConfig.GetSocket().SSLPrivateKey == "" {
	if config.GetSocket().SSLCertificate != "" && config.GetSocket().SSLPrivateKey == "" {
		logger.Fatal("SSL configuration invalid, specify both socket.ssl_certificate and socket.ssl_private_key", zap.String("param", "socket.ssl_certificate"))
	}
	if mainConfig.GetSocket().SSLCertificate == "" && mainConfig.GetSocket().SSLPrivateKey != "" {
	if config.GetSocket().SSLCertificate == "" && config.GetSocket().SSLPrivateKey != "" {
		logger.Fatal("SSL configuration invalid, specify both socket.ssl_certificate and socket.ssl_private_key", zap.String("param", "socket.ssl_private_key"))
	}
	if mainConfig.GetSocket().SSLCertificate != "" && mainConfig.GetSocket().SSLPrivateKey != "" {
	if config.GetSocket().SSLCertificate != "" && config.GetSocket().SSLPrivateKey != "" {
		logger.Warn("WARNING: enabling direct SSL termination is not recommended, use an SSL-capable proxy or load balancer for production!")
		cert, err := tls.LoadX509KeyPair(mainConfig.GetSocket().SSLCertificate, mainConfig.GetSocket().SSLPrivateKey)
		cert, err := tls.LoadX509KeyPair(config.GetSocket().SSLCertificate, config.GetSocket().SSLPrivateKey)
		if err != nil {
			logger.Fatal("Error loading SSL certificate", zap.Error(err))
		}
		logger.Info("SSL mode enabled")
		mainConfig.Socket.TLSCert = []tls.Certificate{cert}
		config.GetSocket().TLSCert = []tls.Certificate{cert}
	}

	return mainConfig
}

func convertRuntimeEnv(logger *zap.Logger, existingEnv map[string]string, mergeEnv []string) map[string]string {
@@ -330,6 +332,7 @@ type LoggerConfig struct {
	MaxBackups int    `yaml:"max_backups" json:"max_backups" usage:"The maximum number of old log files to retain. The default is to retain all old log files (though MaxAge may still cause them to get deleted.)"`
	LocalTime  bool   `yaml:"local_time" json:"local_time" usage:"This determines if the time used for formatting the timestamps in backup files is the computer's local time. The default is to use UTC time."`
	Compress   bool   `yaml:"compress" json:"compress" usage:"This determines if the rotated log files should be compressed using gzip."`
	Format     string `yaml:"format" json:"format" usage:"Set logging output format. Can either be 'JSON' or 'Stackdriver'. Default is 'JSON'."`
}

// NewLoggerConfig creates a new LoggerConfig struct.
@@ -344,6 +347,7 @@ func NewLoggerConfig() *LoggerConfig {
		MaxBackups: 0,
		LocalTime:  false,
		Compress:   false,
		Format:     "json",
	}
}

Loading