diff --git a/main.go b/main.go index c1ec82da6..f5077711e 100644 --- a/main.go +++ b/main.go @@ -43,7 +43,14 @@ var Commit = func() string { func main() { var err error - zapLogger, _ := zap.NewDevelopment() + + var zapLogger *zap.Logger + if config.ErupeConfig.DevMode { + zapLogger, _ = zap.NewDevelopment() + } else { + zapLogger, _ = zap.NewProduction() + } + defer zapLogger.Sync() logger := zapLogger.Named("main") @@ -76,20 +83,20 @@ func main() { }) if err != nil { - preventClose(fmt.Sprintf("Failed to create Discord bot: %s", err.Error())) + preventClose(fmt.Sprintf("Discord: Failed to start, %s", err.Error())) } // Discord bot err = bot.Start() if err != nil { - preventClose(fmt.Sprintf("Failed to start Discord bot: %s", err.Error())) + preventClose(fmt.Sprintf("Discord: Failed to start, %s", err.Error())) } discordBot = bot - logger.Info("Discord bot is enabled") + logger.Info("Discord: Started successfully") } else { - logger.Info("Discord bot is disabled") + logger.Info("Discord: Disabled") } // Create the postgres DB pool. @@ -104,15 +111,15 @@ func main() { db, err := sqlx.Open("postgres", connectString) if err != nil { - preventClose(fmt.Sprintf("Failed to open SQL database: %s", err.Error())) + preventClose(fmt.Sprintf("Database: Failed to open, %s", err.Error())) } // Test the DB connection. err = db.Ping() if err != nil { - preventClose(fmt.Sprintf("Failed to ping database: %s", err.Error())) + preventClose(fmt.Sprintf("Database: Failed to ping, %s", err.Error())) } - logger.Info("Connected to database") + logger.Info("Database: Started successfully") // Clear stale data _ = db.MustExec("DELETE FROM sign_sessions") @@ -120,9 +127,9 @@ func main() { // Clean the DB if the option is on. if config.ErupeConfig.DevMode && config.ErupeConfig.DevModeOptions.CleanDB { - logger.Info("Cleaning DB") + logger.Info("Database: Started clearing...") cleanDB(db) - logger.Info("Done cleaning DB") + logger.Info("Database: Finished clearing") } logger.Info(fmt.Sprintf("Server Time: %s", channelserver.TimeAdjusted().String())) @@ -141,9 +148,11 @@ func main() { }) err = entranceServer.Start() if err != nil { - preventClose(fmt.Sprintf("Failed to start entrance server: %s", err.Error())) + preventClose(fmt.Sprintf("Entrance: Failed to start, %s", err.Error())) } - logger.Info("Started entrance server") + logger.Info("Entrance: Started successfully") + } else { + logger.Info("Entrance: Disabled") } // Sign server. @@ -158,9 +167,11 @@ func main() { }) err = signServer.Start() if err != nil { - preventClose(fmt.Sprintf("Failed to start sign server: %s", err.Error())) + preventClose(fmt.Sprintf("Sign: Failed to start, %s", err.Error())) } - logger.Info("Started sign server") + logger.Info("Sign: Started successfully") + } else { + logger.Info("Sign: Disabled") } // New Sign server @@ -174,9 +185,11 @@ func main() { }) err = newSignServer.Start() if err != nil { - preventClose(fmt.Sprintf("Failed to start sign-v2 server: %s", err.Error())) + preventClose(fmt.Sprintf("SignV2: Failed to start, %s", err.Error())) } - logger.Info("Started new sign server") + logger.Info("SignV2: Started successfully") + } else { + logger.Info("SignV2: Disabled") } var channels []*channelserver.Server @@ -205,11 +218,11 @@ func main() { c.GlobalID = fmt.Sprintf("%02d%02d", j+1, i+1) err = c.Start() if err != nil { - preventClose(fmt.Sprintf("Failed to start channel server: %s", err.Error())) + preventClose(fmt.Sprintf("Channel: Failed to start, %s", err.Error())) } else { channelQuery += fmt.Sprintf(`INSERT INTO servers (server_id, season, current_players, world_name, world_description, land) VALUES (%d, %d, 0, '%s', '%s', %d);`, sid, si%3, ee.Name, ee.Description, i+1) channels = append(channels, &c) - logger.Info(fmt.Sprintf("Started channel server %d on port %d", count, ce.Port)) + logger.Info(fmt.Sprintf("Channel %d (%d): Started successfully", count, ce.Port)) ci++ count++ } @@ -233,7 +246,14 @@ func main() { signal.Notify(c, os.Interrupt, syscall.SIGTERM) <-c - logger.Info("Shutting down...") + for i := 0; i < 10; i++ { + message := fmt.Sprintf("Shutting down in %d...", 10-i) + for _, c := range channels { + c.BroadcastChatMessage(message) + } + logger.Info(message) + time.Sleep(time.Second) + } if config.ErupeConfig.Channel.Enabled { for _, c := range channels { diff --git a/server/channelserver/handlers_cast_binary.go b/server/channelserver/handlers_cast_binary.go index a7a9856e2..9ef5eec4e 100644 --- a/server/channelserver/handlers_cast_binary.go +++ b/server/channelserver/handlers_cast_binary.go @@ -38,16 +38,18 @@ var commands map[string]config.Command func init() { commands = make(map[string]config.Command) - zapLogger, _ := zap.NewDevelopment() + zapConfig := zap.NewDevelopmentConfig() + zapConfig.DisableCaller = true + zapLogger, _ := zapConfig.Build() defer zapLogger.Sync() logger := zapLogger.Named("commands") cmds := config.ErupeConfig.Commands for _, cmd := range cmds { commands[cmd.Name] = cmd if cmd.Enabled { - logger.Info(fmt.Sprintf("%s command is enabled, prefix: %s", cmd.Name, cmd.Prefix)) + logger.Info(fmt.Sprintf("Command %s: Enabled, prefix: %s", cmd.Name, cmd.Prefix)) } else { - logger.Info(fmt.Sprintf("%s command is disabled", cmd.Name)) + logger.Info(fmt.Sprintf("Command %s: Disabled", cmd.Name)) } } } diff --git a/server/entranceserver/entrance_server.go b/server/entranceserver/entrance_server.go index 7639c33da..c3f4b55eb 100644 --- a/server/entranceserver/entrance_server.go +++ b/server/entranceserver/entrance_server.go @@ -111,7 +111,9 @@ func (s *Server) handleEntranceServerConnection(conn net.Conn) { return } - s.logger.Debug("Got entrance server command:\n", zap.String("raw", hex.Dump(pkt))) + if s.erupeConfig.DevMode && s.erupeConfig.DevModeOptions.LogInboundMessages { + fmt.Printf("[Client] -> [Server]\nData [%d bytes]:\n%s\n", len(pkt), hex.Dump(pkt)) + } local := false if strings.Split(conn.RemoteAddr().String(), ":")[0] == "127.0.0.1" { diff --git a/server/entranceserver/make_resp.go b/server/entranceserver/make_resp.go index d2004d938..2d13709db 100644 --- a/server/entranceserver/make_resp.go +++ b/server/entranceserver/make_resp.go @@ -2,6 +2,8 @@ package entranceserver import ( "encoding/binary" + "encoding/hex" + "fmt" "net" "erupe-ce/common/stringsupport" @@ -92,6 +94,11 @@ func makeHeader(data []byte, respType string, entryCount uint16, key byte) []byt func makeSv2Resp(config *config.Config, s *Server, local bool) []byte { serverInfos := config.Entrance.Entries rawServerData := encodeServerInfo(config, s, local) + + if s.erupeConfig.DevMode && s.erupeConfig.DevModeOptions.LogOutboundMessages { + fmt.Printf("[Server] -> [Client]\nData [%d bytes]:\n%s\n", len(rawServerData), hex.Dump(rawServerData)) + } + bf := byteframe.NewByteFrame() bf.WriteBytes(makeHeader(rawServerData, "SV2", uint16(len(serverInfos)), 0x00)) return bf.Data() @@ -109,11 +116,15 @@ func makeUsrResp(pkt []byte, s *Server) []byte { err := s.db.QueryRow("SELECT(SELECT server_id FROM sign_sessions WHERE char_id=$1) AS _", cid).Scan(&sid) if err != nil { resp.WriteBytes(make([]byte, 4)) - continue } else { resp.WriteUint16(sid) resp.WriteUint16(0) } } + + if s.erupeConfig.DevMode && s.erupeConfig.DevModeOptions.LogOutboundMessages { + fmt.Printf("[Server] -> [Client]\nData [%d bytes]:\n%s\n", len(resp.Data()), hex.Dump(resp.Data())) + } + return makeHeader(resp.Data(), "USR", userEntries, 0x00) } diff --git a/server/signserver/session.go b/server/signserver/session.go index 6b2e38b8c..19270fafc 100644 --- a/server/signserver/session.go +++ b/server/signserver/session.go @@ -3,6 +3,7 @@ package signserver import ( "database/sql" "encoding/hex" + "fmt" "net" "sync" @@ -23,6 +24,11 @@ type Session struct { func (s *Session) work() { pkt, err := s.cryptConn.ReadPacket() + + if s.server.erupeConfig.DevMode && s.server.erupeConfig.DevModeOptions.LogInboundMessages { + fmt.Printf("\n[Client] -> [Server]\nData [%d bytes]:\n%s\n", len(pkt), hex.Dump(pkt)) + } + if err != nil { return } @@ -33,8 +39,6 @@ func (s *Session) work() { } func (s *Session) handlePacket(pkt []byte) error { - sugar := s.logger.Sugar() - bf := byteframe.NewByteFrameFromBytes(pkt) reqType := string(bf.ReadNullTerminatedBytes()) switch reqType { @@ -50,13 +54,16 @@ func (s *Session) handlePacket(pkt []byte) error { characterID := int(bf.ReadUint32()) _ = int(bf.ReadUint32()) // login_token_number s.server.deleteCharacter(characterID, loginTokenString) - sugar.Infof("Deleted character ID: %v\n", characterID) + s.logger.Info("Deleted character", zap.Int("CharacterID", characterID)) err := s.cryptConn.SendPacket([]byte{0x01}) // DEL_SUCCESS if err != nil { return nil } default: - sugar.Infof("Got unknown request type %s, data:\n%s\n", reqType, hex.Dump(bf.DataFromCurrent())) + s.logger.Warn("Unknown sign request", zap.String("reqType", reqType)) + if s.server.erupeConfig.DevMode && s.server.erupeConfig.DevModeOptions.LogInboundMessages { + fmt.Printf("\n[Client] -> [Server]\nData [%d bytes]:\n%s\n", len(pkt), hex.Dump(pkt)) + } } return nil @@ -66,14 +73,7 @@ func (s *Session) handleDSGNRequest(bf *byteframe.ByteFrame) error { reqUsername := string(bf.ReadNullTerminatedBytes()) reqPassword := string(bf.ReadNullTerminatedBytes()) - reqSkey := string(bf.ReadNullTerminatedBytes()) - - s.server.logger.Info( - "Got sign in request", - zap.String("reqUsername", reqUsername), - zap.String("reqPassword", reqPassword), - zap.String("reqSkey", reqSkey), - ) + _ = string(bf.ReadNullTerminatedBytes()) // Unk newCharaReq := false @@ -90,14 +90,14 @@ func (s *Session) handleDSGNRequest(bf *byteframe.ByteFrame) error { var serverRespBytes []byte switch { case err == sql.ErrNoRows: - s.logger.Info("Account not found", zap.String("reqUsername", reqUsername)) + s.logger.Info("User not found", zap.String("Username", reqUsername)) serverRespBytes = makeSignInFailureResp(SIGN_EAUTH) if s.server.erupeConfig.DevMode && s.server.erupeConfig.DevModeOptions.AutoCreateAccount { - s.logger.Info("Creating account", zap.String("reqUsername", reqUsername), zap.String("reqPassword", reqPassword)) + s.logger.Info("Creating user", zap.String("Username", reqUsername)) err = s.server.registerDBAccount(reqUsername, reqPassword) if err != nil { - s.logger.Info("Error on creating new account", zap.Error(err)) + s.logger.Error("Error registering new user", zap.Error(err)) serverRespBytes = makeSignInFailureResp(SIGN_EABORT) break } @@ -108,7 +108,7 @@ func (s *Session) handleDSGNRequest(bf *byteframe.ByteFrame) error { var id int err = s.server.db.QueryRow("SELECT id FROM users WHERE username = $1", reqUsername).Scan(&id) if err != nil { - s.logger.Info("Error on querying account id", zap.Error(err)) + s.logger.Error("Error getting new user ID", zap.Error(err)) serverRespBytes = makeSignInFailureResp(SIGN_EABORT) break } @@ -117,15 +117,15 @@ func (s *Session) handleDSGNRequest(bf *byteframe.ByteFrame) error { break case err != nil: serverRespBytes = makeSignInFailureResp(SIGN_EABORT) - s.logger.Warn("Got error on SQL query", zap.Error(err)) + s.logger.Error("Error getting user details", zap.Error(err)) break default: if bcrypt.CompareHashAndPassword([]byte(password), []byte(reqPassword)) == nil { - s.logger.Info("Passwords match!") + s.logger.Debug("Passwords match!") if newCharaReq { err = s.server.newUserChara(reqUsername) if err != nil { - s.logger.Info("Error on adding new character to account", zap.Error(err)) + s.logger.Error("Error adding new character to user", zap.Error(err)) serverRespBytes = makeSignInFailureResp(SIGN_EABORT) break } @@ -139,12 +139,16 @@ func (s *Session) handleDSGNRequest(bf *byteframe.ByteFrame) error { // } serverRespBytes = s.makeSignInResp(id) } else { - s.logger.Info("Passwords don't match!") + s.logger.Warn("Incorrect password") serverRespBytes = makeSignInFailureResp(SIGN_EPASS) } } + if s.server.erupeConfig.DevMode && s.server.erupeConfig.DevModeOptions.LogOutboundMessages { + fmt.Printf("\n[Server] -> [Client]\nData [%d bytes]:\n%s\n", len(serverRespBytes), hex.Dump(serverRespBytes)) + } + err = s.cryptConn.SendPacket(serverRespBytes) if err != nil { return err diff --git a/server/signserver/sign_server.go b/server/signserver/sign_server.go index 6d567e126..fd4bd9bed 100644 --- a/server/signserver/sign_server.go +++ b/server/signserver/sign_server.go @@ -55,7 +55,7 @@ func (s *Server) Start() error { // Shutdown exits the server gracefully. func (s *Server) Shutdown() { - s.logger.Debug("Shutting down") + s.logger.Debug("Shutting down...") s.Lock() s.isShuttingDown = true @@ -86,14 +86,14 @@ func (s *Server) acceptClients() { } func (s *Server) handleConnection(conn net.Conn) { - s.logger.Info("Got connection to sign server", zap.String("remoteaddr", conn.RemoteAddr().String())) + s.logger.Debug("New connection", zap.String("RemoteAddr", conn.RemoteAddr().String())) defer conn.Close() // Client initalizes the connection with a one-time buffer of 8 NULL bytes. nullInit := make([]byte, 8) _, err := io.ReadFull(conn, nullInit) if err != nil { - s.logger.Error("Error initialising sign server connection", zap.Error(err)) + s.logger.Error("Error initializing connection", zap.Error(err)) return }