Commit 4b4b2661 authored by Mo Firouz's avatar Mo Firouz
Browse files

Make file logger explicit. Implicitly print logs to terminal. Use debug level correctly. (#197)

parent 5717eaad

main.go

+31 −31
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())



	cmdLogger := server.NewJSONLogger(os.Stdout, true)

	tmpLogger := server.NewJSONLogger(os.Stdout, "info")



	if len(os.Args) > 1 {

		switch os.Args[1] {
@@ -74,23 +74,23 @@ func main() { 
			fmt.Println(semver)

			return

		case "migrate":

			migrate.Parse(os.Args[2:], cmdLogger)

			migrate.Parse(os.Args[2:], tmpLogger)

		}

	}



	config := server.ParseArgs(cmdLogger, os.Args)

	jsonLogger, multiLogger := server.SetupLogging(config)

	config := server.ParseArgs(tmpLogger, os.Args)

	logger, startupLogger := server.SetupLogging(config)



	multiLogger.Info("Nakama starting")

	multiLogger.Info("Node", zap.String("name", config.GetName()), zap.String("version", semver), zap.String("runtime", runtime.Version()), zap.Int("cpu", runtime.NumCPU()))

	multiLogger.Info("Data directory", zap.String("path", config.GetDataDir()))

	multiLogger.Info("Database connections", zap.Strings("dsns", config.GetDatabase().Addresses))

	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()))

	startupLogger.Info("Data directory", zap.String("path", config.GetDataDir()))

	startupLogger.Info("Database connections", zap.Strings("dsns", config.GetDatabase().Addresses))



	db, dbVersion := dbConnect(multiLogger, config)

	multiLogger.Info("Database information", zap.String("version", dbVersion))

	db, dbVersion := dbConnect(startupLogger, config)

	startupLogger.Info("Database information", zap.String("version", dbVersion))



	// Check migration status and fail fast if the schema has diverged.

	migrate.StartupCheck(multiLogger, db)

	migrate.StartupCheck(startupLogger, db)



	// Access to social provider integrations.

	socialClient := social.NewClient(5 * time.Second)
@@ -98,51 +98,51 @@ func main() { 
	once := &sync.Once{}



	// Start up server components.

	matchmaker := server.NewLocalMatchmaker(multiLogger, config.GetName())

	matchmaker := server.NewLocalMatchmaker(startupLogger, config.GetName())

	sessionRegistry := server.NewSessionRegistry()

	tracker := server.StartLocalTracker(jsonLogger, sessionRegistry, jsonpbMarshaler, config.GetName())

	tracker := server.StartLocalTracker(logger, sessionRegistry, jsonpbMarshaler, config.GetName())

	router := server.NewLocalMessageRouter(sessionRegistry, tracker, jsonpbMarshaler)

	stdLibs, modules, err := server.LoadRuntimeModules(jsonLogger, multiLogger, config)

	stdLibs, modules, err := server.LoadRuntimeModules(startupLogger, config)

	if err != nil {

		multiLogger.Fatal("Failed reading runtime modules", zap.Error(err))

		startupLogger.Fatal("Failed reading runtime modules", zap.Error(err))

	}

	leaderboardCache := server.NewLocalLeaderboardCache(jsonLogger, multiLogger, db)

	matchRegistry := server.NewLocalMatchRegistry(jsonLogger, db, config, socialClient, leaderboardCache, sessionRegistry, tracker, router, stdLibs, once, config.GetName())

	leaderboardCache := server.NewLocalLeaderboardCache(logger, startupLogger, db)

	matchRegistry := server.NewLocalMatchRegistry(logger, db, config, socialClient, leaderboardCache, sessionRegistry, tracker, router, stdLibs, once, config.GetName())

	tracker.SetMatchLeaveListener(matchRegistry.Leave)

	// Separate module evaluation/validation from module loading.

	// We need the match registry to be available to wire all functions exposed to the runtime, which in turn needs the modules at least cached first.

	regCallbacks, err := server.ValidateRuntimeModules(jsonLogger, multiLogger, db, config, socialClient, leaderboardCache, sessionRegistry, matchRegistry, tracker, router, stdLibs, modules, once)

	regCallbacks, err := server.ValidateRuntimeModules(logger, startupLogger, db, config, socialClient, leaderboardCache, sessionRegistry, matchRegistry, tracker, router, stdLibs, modules, once)

	if err != nil {

		multiLogger.Fatal("Failed initializing runtime modules", zap.Error(err))

		startupLogger.Fatal("Failed initializing runtime modules", zap.Error(err))

	}

	runtimePool := server.NewRuntimePool(jsonLogger, multiLogger, db, config, socialClient, leaderboardCache, sessionRegistry, matchRegistry, tracker, router, stdLibs, modules, regCallbacks, once)

	runtimePool := server.NewRuntimePool(logger, db, config, socialClient, leaderboardCache, sessionRegistry, matchRegistry, tracker, router, stdLibs, modules, regCallbacks, once)

	pipeline := server.NewPipeline(config, db, jsonpbMarshaler, jsonpbUnmarshaler, sessionRegistry, matchRegistry, matchmaker, tracker, router, runtimePool)

	metrics := server.NewMetrics(multiLogger, config)

	metrics := server.NewMetrics(logger, startupLogger, config)



	consoleServer := server.StartConsoleServer(jsonLogger, multiLogger, config, db)

	apiServer := server.StartApiServer(jsonLogger, multiLogger, db, jsonpbMarshaler, jsonpbUnmarshaler, config, socialClient, leaderboardCache, sessionRegistry, matchRegistry, matchmaker, tracker, router, pipeline, runtimePool)

	consoleServer := server.StartConsoleServer(logger, startupLogger, config, db)

	apiServer := server.StartApiServer(logger, startupLogger, db, jsonpbMarshaler, jsonpbUnmarshaler, config, socialClient, leaderboardCache, sessionRegistry, matchRegistry, matchmaker, tracker, router, pipeline, runtimePool)



	gaenabled := len(os.Getenv("NAKAMA_TELEMETRY")) < 1

	cookie := newOrLoadCookie(config)

	gacode := "UA-89792135-1"

	if gaenabled {

		runTelemetry(jsonLogger, http.DefaultClient, gacode, cookie)

		runTelemetry(startupLogger, http.DefaultClient, gacode, cookie)

	}



	// Respect OS stop signals.

	c := make(chan os.Signal, 2)

	signal.Notify(c, os.Interrupt, syscall.SIGINT, syscall.SIGTERM)



	multiLogger.Info("Startup done")

	startupLogger.Info("Startup done")



	// Wait for a termination signal.

	<-c

	multiLogger.Info("Shutting down")

	startupLogger.Info("Shutting down")



	// Gracefully stop server components.

	apiServer.Stop()

	consoleServer.Stop()

	metrics.Stop(jsonLogger)

	metrics.Stop(logger)

	matchRegistry.Stop()

	tracker.Stop()

	sessionRegistry.Stop()
@@ -203,22 +203,22 @@ func dbConnect(multiLogger *zap.Logger, config server.Config) (*sql.DB, string) 
//

// This information is sent via Google Analytics which allows the Nakama team to

// analyze usage patterns and errors in order to help improve the server.

func runTelemetry(logger *zap.Logger, httpc *http.Client, gacode string, cookie string) {

func runTelemetry(startupLogger *zap.Logger, httpc *http.Client, gacode string, cookie string) {

	err := ga.SendSessionStart(httpc, gacode, cookie)

	if err != nil {

		logger.Debug("Send start session event failed.", zap.Error(err))

		startupLogger.Debug("Send start session event failed.", zap.Error(err))

		return

	}



	err = ga.SendEvent(httpc, gacode, cookie, &ga.Event{Ec: "version", Ea: fmt.Sprintf("%s+%s", version, commitID)})

	if err != nil {

		logger.Debug("Send event failed.", zap.Error(err))

		startupLogger.Debug("Send event failed.", zap.Error(err))

		return

	}



	err = ga.SendEvent(httpc, gacode, cookie, &ga.Event{Ec: "variant", Ea: "nakama"})

	if err != nil {

		logger.Debug("Send event failed.", zap.Error(err))

		startupLogger.Debug("Send event failed.", zap.Error(err))

		return

	}

}

server/api.go

+8 −7
Original line number Diff line number Diff line
@@ -65,7 +65,7 @@ type ApiServer struct { 
	grpcGatewayServer *http.Server

}



func StartApiServer(logger *zap.Logger, multiLogger *zap.Logger, db *sql.DB, jsonpbMarshaler *jsonpb.Marshaler, jsonpbUnmarshaler *jsonpb.Unmarshaler, config Config, socialClient *social.Client, leaderboardCache LeaderboardCache, sessionRegistry *SessionRegistry, matchRegistry MatchRegistry, matchmaker Matchmaker, tracker Tracker, router MessageRouter, pipeline *Pipeline, runtimePool *RuntimePool) *ApiServer {

func StartApiServer(logger *zap.Logger, startupLogger *zap.Logger, db *sql.DB, jsonpbMarshaler *jsonpb.Marshaler, jsonpbUnmarshaler *jsonpb.Unmarshaler, config Config, socialClient *social.Client, leaderboardCache LeaderboardCache, sessionRegistry *SessionRegistry, matchRegistry MatchRegistry, matchmaker Matchmaker, tracker Tracker, router MessageRouter, pipeline *Pipeline, runtimePool *RuntimePool) *ApiServer {

	serverOpts := []grpc.ServerOption{

		grpc.StatsHandler(&ocgrpc.ServerHandler{IsPublicEndpoint: true}),

		grpc.MaxRecvMsgSize(int(config.GetSocket().MaxMessageSizeBytes)),
@@ -91,15 +91,15 @@ func StartApiServer(logger *zap.Logger, multiLogger *zap.Logger, db *sql.DB, jso 


	// Register and start GRPC server.

	api.RegisterNakamaServer(grpcServer, s)

	multiLogger.Info("Starting API server for gRPC requests", zap.Int("port", config.GetSocket().Port-1))

	startupLogger.Info("Starting API server for gRPC requests", zap.Int("port", config.GetSocket().Port-1))

	go func() {

		listener, err := net.Listen("tcp", fmt.Sprintf(":%d", config.GetSocket().Port-1))

		if err != nil {

			multiLogger.Fatal("API server listener failed to start", zap.Error(err))

			startupLogger.Fatal("API server listener failed to start", zap.Error(err))

		}



		if err := grpcServer.Serve(listener); err != nil {

			multiLogger.Fatal("API server listener failed", zap.Error(err))

			startupLogger.Fatal("API server listener failed", zap.Error(err))

		}

	}()
@@ -118,7 +118,7 @@ func StartApiServer(logger *zap.Logger, multiLogger *zap.Logger, db *sql.DB, jso 
		dialOpts = append(dialOpts, grpc.WithInsecure())

	}

	if err := api.RegisterNakamaHandlerFromEndpoint(ctx, grpcGateway, dialAddr, dialOpts); err != nil {

		multiLogger.Fatal("API server gateway registration failed", zap.Error(err))

		startupLogger.Fatal("API server gateway registration failed", zap.Error(err))

	}



	grpcGatewayRouter := mux.NewRouter()
@@ -152,10 +152,10 @@ func StartApiServer(logger *zap.Logger, multiLogger *zap.Logger, db *sql.DB, jso 
		s.grpcGatewayServer.TLSConfig = &tls.Config{Certificates: config.GetSocket().TLSCert}

	}



	multiLogger.Info("Starting API server gateway for HTTP requests", zap.Int("port", config.GetSocket().Port))

	startupLogger.Info("Starting API server gateway for HTTP requests", zap.Int("port", config.GetSocket().Port))

	go func() {

		if err := s.grpcGatewayServer.ListenAndServe(); err != nil && err != http.ErrServerClosed {

			multiLogger.Fatal("API server gateway listener failed", zap.Error(err))

			startupLogger.Fatal("API server gateway listener failed", zap.Error(err))

		}

	}()
@@ -177,6 +177,7 @@ func (s *ApiServer) Healthcheck(ctx context.Context, in *empty.Empty) (*empty.Em 


func apiInterceptorFunc(logger *zap.Logger, config Config, runtimePool *RuntimePool, jsonpbMarshaler *jsonpb.Marshaler, jsonpbUnmarshaler *jsonpb.Unmarshaler) func(context.Context, interface{}, *grpc.UnaryServerInfo, grpc.UnaryHandler) (interface{}, error) {

	return func(ctx context.Context, req interface{}, info *grpc.UnaryServerInfo, handler grpc.UnaryHandler) (interface{}, error) {

		logger.Debug("Security interceptor fired", zap.Any("ctx", ctx), zap.Any("req", req), zap.Any("info", info))

		ctx, err := securityInterceptorFunc(logger, config, ctx, req, info)

		if err != nil {

			return nil, err

server/api_link.go

+4 −4
Original line number Diff line number Diff line
@@ -164,7 +164,7 @@ func (s *ApiServer) LinkFacebook(ctx context.Context, in *api.LinkFacebookReques 


	facebookProfile, err := s.socialClient.GetFacebookProfile(in.Account.Token)

	if err != nil {

		s.logger.Debug("Could not authenticate Facebook profile.", zap.Error(err))

		s.logger.Info("Could not authenticate Facebook profile.", zap.Error(err))

		return nil, status.Error(codes.Unauthenticated, "Could not authenticate Facebook profile.")

	}
@@ -212,7 +212,7 @@ func (s *ApiServer) LinkGameCenter(ctx context.Context, in *api.AccountGameCente 


	valid, err := s.socialClient.CheckGameCenterID(in.PlayerId, in.BundleId, in.TimestampSeconds, in.Salt, in.Signature, in.PublicKeyUrl)

	if !valid || err != nil {

		s.logger.Debug("Could not authenticate GameCenter profile.", zap.Error(err), zap.Bool("valid", valid))

		s.logger.Info("Could not authenticate GameCenter profile.", zap.Error(err), zap.Bool("valid", valid))

		return nil, status.Error(codes.Unauthenticated, "Could not authenticate GameCenter profile.")

	}
@@ -245,7 +245,7 @@ func (s *ApiServer) LinkGoogle(ctx context.Context, in *api.AccountGoogle) (*emp 


	googleProfile, err := s.socialClient.CheckGoogleToken(in.Token)

	if err != nil {

		s.logger.Debug("Could not authenticate Google profile.", zap.Error(err))

		s.logger.Info("Could not authenticate Google profile.", zap.Error(err))

		return nil, status.Error(codes.Unauthenticated, "Could not authenticate Google profile.")

	}
@@ -282,7 +282,7 @@ func (s *ApiServer) LinkSteam(ctx context.Context, in *api.AccountSteam) (*empty 


	steamProfile, err := s.socialClient.GetSteamProfile(s.config.GetSocial().Steam.PublisherKey, s.config.GetSocial().Steam.AppID, in.Token)

	if err != nil {

		s.logger.Debug("Could not authenticate Steam profile.", zap.Error(err))

		s.logger.Info("Could not authenticate Steam profile.", zap.Error(err))

		return nil, status.Error(codes.Unauthenticated, "Could not authenticate Steam profile.")

	}

server/api_rpc.go

+2 −1
Original line number Diff line number Diff line
@@ -21,6 +21,7 @@ import ( 
	"github.com/satori/go.uuid"

	"github.com/yuin/gopher-lua"

	"go.uber.org/zap"

	"go.uber.org/zap/zapcore"

	"golang.org/x/net/context"

	"google.golang.org/grpc/codes"

	"google.golang.org/grpc/status"
@@ -62,7 +63,7 @@ func (s *ApiServer) RpcFunc(ctx context.Context, in *api.Rpc) (*api.Rpc, error) 


	if fnErr != nil {

		s.logger.Error("Runtime RPC function caused an error", zap.String("id", in.Id), zap.Error(fnErr))

		if apiErr, ok := fnErr.(*lua.ApiError); ok && !s.config.GetLog().Verbose {

		if apiErr, ok := fnErr.(*lua.ApiError); ok && !s.logger.Core().Enabled(zapcore.InfoLevel) {

			msg := apiErr.Object.String()

			if strings.HasPrefix(msg, lf.Proto.SourceName) {

				msg = msg[len(lf.Proto.SourceName):]

server/api_unlink.go

+4 −4
Original line number Diff line number Diff line
@@ -149,7 +149,7 @@ func (s *ApiServer) UnlinkFacebook(ctx context.Context, in *api.AccountFacebook) 


	facebookProfile, err := s.socialClient.GetFacebookProfile(in.Token)

	if err != nil {

		s.logger.Debug("Could not authenticate Facebook profile.", zap.Error(err))

		s.logger.Info("Could not authenticate Facebook profile.", zap.Error(err))

		return nil, status.Error(codes.Unauthenticated, "Could not authenticate Facebook profile.")

	}
@@ -194,7 +194,7 @@ func (s *ApiServer) UnlinkGameCenter(ctx context.Context, in *api.AccountGameCen 


	valid, err := s.socialClient.CheckGameCenterID(in.PlayerId, in.BundleId, in.TimestampSeconds, in.Salt, in.Signature, in.PublicKeyUrl)

	if !valid || err != nil {

		s.logger.Debug("Could not authenticate GameCenter profile.", zap.Error(err), zap.Bool("valid", valid))

		s.logger.Info("Could not authenticate GameCenter profile.", zap.Error(err), zap.Bool("valid", valid))

		return nil, status.Error(codes.Unauthenticated, "Could not authenticate GameCenter profile.")

	}
@@ -229,7 +229,7 @@ func (s *ApiServer) UnlinkGoogle(ctx context.Context, in *api.AccountGoogle) (*e 


	googleProfile, err := s.socialClient.CheckGoogleToken(in.Token)

	if err != nil {

		s.logger.Debug("Could not authenticate Google profile.", zap.Error(err))

		s.logger.Info("Could not authenticate Google profile.", zap.Error(err))

		return nil, status.Error(codes.Unauthenticated, "Could not authenticate Google profile.")

	}
@@ -268,7 +268,7 @@ func (s *ApiServer) UnlinkSteam(ctx context.Context, in *api.AccountSteam) (*emp 


	steamProfile, err := s.socialClient.GetSteamProfile(s.config.GetSocial().Steam.PublisherKey, s.config.GetSocial().Steam.AppID, in.Token)

	if err != nil {

		s.logger.Debug("Could not authenticate Steam profile.", zap.Error(err))

		s.logger.Info("Could not authenticate Steam profile.", zap.Error(err))

		return nil, status.Error(codes.Unauthenticated, "Could not authenticate Steam profile.")

	}