diff --git a/sdk/login/main.go b/sdk/login/main.go index b6ad765..8912579 100644 --- a/sdk/login/main.go +++ b/sdk/login/main.go @@ -6,10 +6,16 @@ import ( "backend/sdk/login/model/test" "backend/sdk/login/model/tuyou" "backend/util" + "context" + "encoding/json" "fmt" "io" "log" + "net/http" "os" + "os/signal" + "runtime/debug" + "syscall" "time" "github.com/gin-gonic/gin" @@ -40,10 +46,10 @@ func init() { } // 打开一个普通的最新日志文件(不使用 symlink),用于提供固定路径的最新日志 - currFile, err := os.OpenFile("./log/login.log", os.O_CREATE|os.O_WRONLY|os.O_TRUNC, 0644) + currFile, err := os.OpenFile("./log/login.log", os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0644) if err != nil { // 如果打开失败,仍然继续使用轮转器+控制台 - log.Printf("warning: failed to open current log file: %v", err) + logStructured("warn", "failed to open current log file", map[string]any{"error": err.Error()}) logWriter = io.MultiWriter(rl, os.Stdout) errWriter = io.MultiWriter(rl, os.Stderr) } else { @@ -62,14 +68,104 @@ func init() { go util.MonitorServerList() } +func logStructured(level string, message string, fields map[string]any) { + payload := map[string]any{ + "level": level, + "msg": message, + "time": time.Now().Format(time.RFC3339), + } + for key, value := range fields { + payload[key] = value + } + data, err := json.Marshal(payload) + if err != nil { + log.Printf("level=%s msg=%q marshal_error=%v", level, message, err) + return + } + log.Print(string(data)) +} + +func requestLogger() gin.HandlerFunc { + return func(c *gin.Context) { + startedAt := time.Now() + c.Next() + + logStructured("info", "http request", map[string]any{ + "clientIp": c.ClientIP(), + "latencyMs": time.Since(startedAt).Milliseconds(), + "method": c.Request.Method, + "path": c.Request.URL.Path, + "query": c.Request.URL.RawQuery, + "status": c.Writer.Status(), + "userAgent": c.Request.UserAgent(), + }) + } +} + +func recoveryLogger() gin.HandlerFunc { + return gin.CustomRecovery(func(c *gin.Context, recovered any) { + logStructured("error", "panic recovered", map[string]any{ + "clientIp": c.ClientIP(), + "method": c.Request.Method, + "path": c.Request.URL.Path, + "query": c.Request.URL.RawQuery, + "panic": fmt.Sprint(recovered), + "stackTrace": string(debug.Stack()), + "userAgent": c.Request.UserAgent(), + }) + c.AbortWithStatus(http.StatusInternalServerError) + }) +} + func main() { - r := gin.Default() + r := gin.New() + r.Use(requestLogger()) + r.Use(recoveryLogger()) loginApi := r.Group("/api/auth") { // 认证 loginApi.GET("/tuyou/login", tuyou.Login) loginApi.GET("/test/login", test.Login) } - log.Printf("Login SDK started on port %d", logincommon.AppConf.Port) - r.Run(fmt.Sprintf(":%d", logincommon.AppConf.Port)) + server := &http.Server{ + Addr: fmt.Sprintf(":%d", logincommon.AppConf.Port), + Handler: r, + ReadHeaderTimeout: 5 * time.Second, + ReadTimeout: 15 * time.Second, + WriteTimeout: 30 * time.Second, + IdleTimeout: 60 * time.Second, + } + + shutdownCtx, stop := signal.NotifyContext(context.Background(), os.Interrupt, syscall.SIGINT, syscall.SIGTERM) + defer stop() + + serverErr := make(chan error, 1) + go func() { + logStructured("info", "login sdk started", map[string]any{ + "port": logincommon.AppConf.Port, + "version": logincommon.AppConf.Version, + }) + if err := server.ListenAndServe(); err != nil && err != http.ErrServerClosed { + serverErr <- err + } + close(serverErr) + }() + + select { + case err, ok := <-serverErr: + if ok && err != nil { + logStructured("error", "login sdk start failed", map[string]any{"error": err.Error()}) + os.Exit(1) + } + case <-shutdownCtx.Done(): + logStructured("info", "login sdk shutting down", map[string]any{"reason": shutdownCtx.Err().Error()}) + } + + gracefulCtx, cancel := context.WithTimeout(context.Background(), 10*time.Second) + defer cancel() + if err := server.Shutdown(gracefulCtx); err != nil { + logStructured("error", "login sdk shutdown failed", map[string]any{"error": err.Error()}) + os.Exit(1) + } + logStructured("info", "login sdk stopped", nil) } diff --git a/sdk/login/model/test/test.go b/sdk/login/model/test/test.go index 6635c3e..45129da 100644 --- a/sdk/login/model/test/test.go +++ b/sdk/login/model/test/test.go @@ -3,6 +3,7 @@ package test import ( "backend/sdk/login/model/base" "backend/util" + "time" "github.com/gin-gonic/gin" ) @@ -12,6 +13,7 @@ type TestModel struct { func Login(c *gin.Context) { var p base.Param + startedAt := time.Now() // read parameters from query string for GET requests p.Uid = c.Query("uid") p.Token = c.Query("token") @@ -19,13 +21,44 @@ func Login(c *gin.Context) { p.AreaCode = util.Int(c.Query("areaCode")) p.Version = c.Query("version") if p.Uid == "" || p.Token == "" { + util.LogStructured("warn", "login request missing required params", map[string]any{ + "appId": p.AppId, + "areaCode": p.AreaCode, + "channel": "test", + "uid": p.Uid, + "version": p.Version, + }) c.JSON(400, gin.H{"error": "missing uid or token"}) return } + util.LogStructured("info", "login verify started", map[string]any{ + "appId": p.AppId, + "areaCode": p.AreaCode, + "channel": "test", + "uid": p.Uid, + "version": p.Version, + }) if err := (&TestModel{}).VerifyToken(p.Uid, p.Token); err != nil { + util.LogStructured("warn", "login verify failed", map[string]any{ + "appId": p.AppId, + "areaCode": p.AreaCode, + "channel": "test", + "error": err.Error(), + "latencyMs": time.Since(startedAt).Milliseconds(), + "uid": p.Uid, + "version": p.Version, + }) c.JSON(401, gin.H{"error": "invalid token"}) return } + util.LogStructured("info", "login verify succeeded", map[string]any{ + "appId": p.AppId, + "areaCode": p.AreaCode, + "channel": "test", + "latencyMs": time.Since(startedAt).Milliseconds(), + "uid": p.Uid, + "version": p.Version, + }) util.LoginResponse(c, p.AppId, p.AreaCode, p.Version) } diff --git a/sdk/login/model/tuyou/tuyou.go b/sdk/login/model/tuyou/tuyou.go index 1b04024..df1267c 100644 --- a/sdk/login/model/tuyou/tuyou.go +++ b/sdk/login/model/tuyou/tuyou.go @@ -9,7 +9,6 @@ import ( "encoding/json" "fmt" "io" - "log" "net/http" "time" @@ -38,6 +37,7 @@ var UrlList = map[int]string{ func Login(c *gin.Context) { var p base.Param + startedAt := time.Now() // read parameters from query string for GET requests p.Uid = c.Query("uid") p.Token = c.Query("token") @@ -45,10 +45,33 @@ func Login(c *gin.Context) { p.AreaCode = util.Int(c.Query("areaCode")) p.Version = c.Query("version") if p.Uid == "" || p.Token == "" { + util.LogStructured("warn", "login request missing required params", map[string]any{ + "appId": p.AppId, + "areaCode": p.AreaCode, + "channel": "tuyou", + "uid": p.Uid, + "version": p.Version, + }) c.JSON(400, gin.H{"error": "missing uid or token"}) return } + util.LogStructured("info", "login verify started", map[string]any{ + "appId": p.AppId, + "areaCode": p.AreaCode, + "channel": "tuyou", + "uid": p.Uid, + "version": p.Version, + }) if err := (&TuyouModel{}).VerifyToken(p.AppId, p.Uid, p.Token); err != nil { + util.LogStructured("warn", "login verify failed", map[string]any{ + "appId": p.AppId, + "areaCode": p.AreaCode, + "channel": "tuyou", + "error": err.Error(), + "latencyMs": time.Since(startedAt).Milliseconds(), + "uid": p.Uid, + "version": p.Version, + }) feishu.SendNotifyMsg(&Type.NotifyData{ NotifyMsg: "登录验证失败", Host: "途游", @@ -59,6 +82,14 @@ func Login(c *gin.Context) { c.JSON(401, gin.H{"error": "invalid token"}) return } + util.LogStructured("info", "login verify succeeded", map[string]any{ + "appId": p.AppId, + "areaCode": p.AreaCode, + "channel": "tuyou", + "latencyMs": time.Since(startedAt).Milliseconds(), + "uid": p.Uid, + "version": p.Version, + }) util.LoginResponse(c, p.AppId, p.AreaCode, p.Version) } @@ -72,6 +103,10 @@ func (t *TuyouModel) VerifyToken(AppId int, Uid string, Token string) error { } Url := UrlList[AppId] if Url == "" { + util.LogStructured("warn", "login verify unsupported app", map[string]any{ + "appId": AppId, + "uid": Uid, + }) return fmt.Errorf("unsupported AppId: %d", AppId) } req, err := http.NewRequest("GET", fmt.Sprint(Url, "/open/v4/user/verifyAuthorCode"), nil) @@ -95,6 +130,12 @@ func (t *TuyouModel) VerifyToken(AppId int, Uid string, Token string) error { } if resp.StatusCode != http.StatusOK { + util.LogStructured("warn", "login verify upstream returned non-200", map[string]any{ + "appId": AppId, + "latencyMs": time.Now().UnixMilli() - now, + "statusCode": resp.StatusCode, + "uid": Uid, + }) return fmt.Errorf("verify failed: status=%d body=%s", resp.StatusCode, string(body)) } @@ -111,12 +152,28 @@ func (t *TuyouModel) VerifyToken(AppId int, Uid string, Token string) error { } if err := json.Unmarshal(body, &respObj); err != nil { + util.LogStructured("error", "login verify upstream response invalid", map[string]any{ + "appId": AppId, + "latencyMs": time.Now().UnixMilli() - now, + "uid": Uid, + }) return fmt.Errorf("invalid verify response: %w; body=%s", err, string(body)) } if respObj.Result.Verify != "ok" { + util.LogStructured("warn", "login verify rejected by upstream", map[string]any{ + "appId": AppId, + "latencyMs": time.Now().UnixMilli() - now, + "uid": Uid, + "verify": respObj.Result.Verify, + }) return fmt.Errorf("verify failed: verify=%s body=%s", respObj.Result.Verify, string(body)) } - log.Printf("Tuyou verify success: cost time %dms\n", time.Now().UnixMilli()-now) + util.LogStructured("info", "login verify upstream succeeded", map[string]any{ + "appId": AppId, + "latencyMs": time.Now().UnixMilli() - now, + "track": respObj.Track, + "uid": Uid, + }) return nil } diff --git a/util/login.go b/util/login.go index 63c9dc8..e942747 100644 --- a/util/login.go +++ b/util/login.go @@ -26,15 +26,27 @@ type ServerConfig struct { } var serverList map[int][]ServerConfig +var serverListMu sync.RWMutex func LoginResponse(c *gin.Context, AppId, AreaCode int, Version string) { Uid := c.Query("uid") + startedAt := time.Now() Port, Host, ServerId := GetUserInfo(AppId, AreaCode, Uid, Version) + LogStructured("info", "login response resolved", map[string]any{ + "appId": AppId, + "areaCode": AreaCode, + "host": Host, + "latencyMs": time.Since(startedAt).Milliseconds(), + "port": Port, + "serverId": ServerId, + "uid": Uid, + "version": Version, + }) LoginSuccess(c, "login success", Port, Host, ServerId) } func GetUserInfo(AppId, AreaCode int, Uid, Version string) (int, string, int) { - // now := time.Now().UnixMilli() + startedAt := time.Now() lockUid(Uid) defer unlockUid(Uid) // Db := MPool.GetGameDB() @@ -43,40 +55,59 @@ func GetUserInfo(AppId, AreaCode int, Uid, Version string) (int, string, int) { var Host string var Port int ServerId = 0 - ServerList := GetServerInfo(AppId, AreaCode) - if len(ServerList) == 0 || Uid == "" || Version == "" { + serverCandidates := GetServerInfo(AppId, AreaCode) + if len(serverCandidates) == 0 || Uid == "" || Version == "" { + LogStructured("warn", "login server selection skipped", map[string]any{ + "appId": AppId, + "areaCode": AreaCode, + "candidateCount": len(serverCandidates), + "latencyMs": time.Since(startedAt).Milliseconds(), + "uid": Uid, + "version": Version, + }) return 0, "", 0 } + selectionReason := "" + savedNode := 0 node, err := GetUserConnectNode(Uid) if err != nil { + LogStructured("warn", "login saved node lookup failed", map[string]any{ + "appId": AppId, + "areaCode": AreaCode, + "error": err.Error(), + "uid": Uid, + "version": Version, + }) node = 0 } + savedNode = node if node > 0 { - for _, server := range ServerList { + for _, server := range serverCandidates { if server.ServerId == node && server.Status == 1 && Version == server.Version { ServerId = server.ServerId Host = server.Host Port = server.Port + selectionReason = "saved_node" break } } } if ServerId == 0 { - new_server_list := make([]ServerConfig, 0) + newServerList := make([]ServerConfig, 0) // 先尝试找版本号完全匹配且未满的服务器 - for _, server := range ServerList { + for _, server := range serverCandidates { if server.Status != 1 { continue } if Version != "" && server.Version == Version { - new_server_list = append(new_server_list, server) + newServerList = append(newServerList, server) } } // 过滤出未满员且状态正常的候选服务器 // 加权随机选择 - if len(new_server_list) > 0 { + if len(newServerList) > 0 { totalWeight := 0 - for _, s := range new_server_list { + for _, s := range newServerList { w := s.Weight if w <= 0 { w = 1 @@ -85,13 +116,14 @@ func GetUserInfo(AppId, AreaCode int, Uid, Version string) (int, string, int) { } if totalWeight == 0 { // 兜底,选择第一个 - ServerId = new_server_list[0].ServerId - Host = new_server_list[0].Host - Port = new_server_list[0].Port + ServerId = newServerList[0].ServerId + Host = newServerList[0].Host + Port = newServerList[0].Port + selectionReason = "version_match_first" } else { r := rand.Intn(totalWeight) acc := 0 - for _, s := range new_server_list { + for _, s := range newServerList { w := s.Weight if w <= 0 { w = 1 @@ -101,6 +133,7 @@ func GetUserInfo(AppId, AreaCode int, Uid, Version string) (int, string, int) { ServerId = s.ServerId Host = s.Host Port = s.Port + selectionReason = "version_match_weighted" break } } @@ -109,15 +142,37 @@ func GetUserInfo(AppId, AreaCode int, Uid, Version string) (int, string, int) { } if ServerId == 0 { - ServerId = ServerList[0].ServerId - Host = ServerList[0].Host - Port = ServerList[0].Port + ServerId = serverCandidates[0].ServerId + Host = serverCandidates[0].Host + Port = serverCandidates[0].Port + selectionReason = "first_available_fallback" } // 更新玩家所在节点 - if err == nil { - SaveUserConnectNode(Uid, ServerId) + if ServerId > 0 { + if err := SaveUserConnectNode(Uid, ServerId); err != nil { + LogStructured("warn", "login saved node persist failed", map[string]any{ + "appId": AppId, + "areaCode": AreaCode, + "error": err.Error(), + "serverId": ServerId, + "uid": Uid, + "version": Version, + }) + } } - //log.Printf("GetUserInfo selected server %d for uid %s, cost time %dms\n", ServerId, Uid, time.Now().UnixMilli()-now) + LogStructured("info", "login server selected", map[string]any{ + "appId": AppId, + "areaCode": AreaCode, + "candidateCount": len(serverCandidates), + "host": Host, + "latencyMs": time.Since(startedAt).Milliseconds(), + "port": Port, + "savedNode": savedNode, + "selectedNode": ServerId, + "selectionReason": selectionReason, + "uid": Uid, + "version": Version, + }) return Port, Host, ServerId } @@ -230,8 +285,16 @@ func abs(x int) int { } func GetServerInfo(AppId, AreaCode int) []ServerConfig { + serverListMu.RLock() + defer serverListMu.RUnlock() if serverList != nil { - return serverList[AppId] + servers := serverList[AppId] + if len(servers) == 0 { + return []ServerConfig{} + } + serversCopy := make([]ServerConfig, len(servers)) + copy(serversCopy, servers) + return serversCopy } return []ServerConfig{} } @@ -261,7 +324,9 @@ func _initServerList() { } tempServerList[server.AppId] = append(tempServerList[server.AppId], server) } + serverListMu.Lock() serverList = tempServerList + serverListMu.Unlock() } func GetAllServersByAppId(appid int) []ServerConfig {