From 8a938c889b25cfe55b06e4f36e82fe55d5e4e2f9 Mon Sep 17 00:00:00 2001
From: skiffer-git <44203734@qq.com>
Date: Wed, 20 Apr 2022 20:58:51 +0800
Subject: [PATCH] log

---
 cmd/Open-IM-SDK-Core                   |  2 +-
 internal/api/auth/auth.go              | 34 +++++++++++++---------
 internal/msg_gateway/gate/ws_server.go | 14 ++++-----
 internal/rpc/auth/auth.go              | 40 ++++++++++++++------------
 pkg/common/token_verify/jwt_token.go   |  8 +++---
 5 files changed, 54 insertions(+), 44 deletions(-)

diff --git a/cmd/Open-IM-SDK-Core b/cmd/Open-IM-SDK-Core
index 539290887..666684b5a 160000
--- a/cmd/Open-IM-SDK-Core
+++ b/cmd/Open-IM-SDK-Core
@@ -1 +1 @@
-Subproject commit 539290887aff41515b291b7ecf174af25887f870
+Subproject commit 666684b5ac6af2bc259cbfd8021d9ddc31d1bff8
diff --git a/internal/api/auth/auth.go b/internal/api/auth/auth.go
index 5e40298c2..abc909748 100644
--- a/internal/api/auth/auth.go
+++ b/internal/api/auth/auth.go
@@ -17,8 +17,9 @@ import (
 func UserRegister(c *gin.Context) {
 	params := api.UserRegisterReq{}
 	if err := c.BindJSON(&params); err != nil {
-		log.NewError("0", "BindJSON failed ", err.Error())
-		c.JSON(http.StatusBadRequest, gin.H{"errCode": 400, "errMsg": err.Error()})
+		errMsg := " BindJSON failed " + err.Error()
+		log.NewError("0", errMsg)
+		c.JSON(http.StatusBadRequest, gin.H{"errCode": 400, "errMsg": errMsg})
 		return
 	}
 
@@ -37,22 +38,24 @@ func UserRegister(c *gin.Context) {
 	client := rpc.NewAuthClient(etcdConn)
 	reply, err := client.UserRegister(context.Background(), req)
 	if err != nil {
-		log.NewError(req.OperationID, "call rpc err ", err.Error())
-		c.JSON(http.StatusInternalServerError, gin.H{"errCode": 500, "errMsg": "internal service err"})
+		errMsg := req.OperationID + " " + "client.UserRegister failed " + err.Error() + req.String()
+		log.NewError(req.OperationID, errMsg)
+		c.JSON(http.StatusInternalServerError, gin.H{"errCode": 500, "errMsg": errMsg})
 		return
 	}
 	if reply.CommonResp.ErrCode != 0 {
-		log.NewError(req.OperationID, "UserRegister failed ", err)
-		c.JSON(http.StatusInternalServerError, gin.H{"errCode": 500, "errMsg": reply.CommonResp.ErrMsg})
+		errMsg := req.OperationID + " " + " client.UserRegister failed " + reply.CommonResp.ErrMsg + req.String()
+		log.NewError(req.OperationID, errMsg)
+		c.JSON(http.StatusInternalServerError, gin.H{"errCode": 500, "errMsg": errMsg})
 		return
-
 	}
 
 	pbDataToken := &rpc.UserTokenReq{Platform: params.Platform, FromUserID: params.UserID, OperationID: params.OperationID}
 	replyToken, err := client.UserToken(context.Background(), pbDataToken)
 	if err != nil {
-		log.NewError(req.OperationID, "UserToken failed ", err.Error(), pbDataToken)
-		c.JSON(http.StatusInternalServerError, gin.H{"errCode": 500, "errMsg": err.Error()})
+		errMsg := req.OperationID + " " + " client.UserToken failed " + err.Error() + pbDataToken.String()
+		log.NewError(req.OperationID, errMsg)
+		c.JSON(http.StatusInternalServerError, gin.H{"errCode": 500, "errMsg": errMsg})
 		return
 	}
 	resp := api.UserRegisterResp{CommResp: api.CommResp{ErrCode: replyToken.CommonResp.ErrCode, ErrMsg: replyToken.CommonResp.ErrMsg},
@@ -65,14 +68,16 @@ func UserRegister(c *gin.Context) {
 func UserToken(c *gin.Context) {
 	params := api.UserTokenReq{}
 	if err := c.BindJSON(&params); err != nil {
-		log.NewError("0", "BindJSON failed ", err.Error())
-		c.JSON(http.StatusBadRequest, gin.H{"errCode": 400, "errMsg": err.Error()})
+		errMsg := " BindJSON failed " + err.Error()
+		log.NewError("0", errMsg)
+		c.JSON(http.StatusBadRequest, gin.H{"errCode": 400, "errMsg": errMsg})
 		return
 	}
 
 	if params.Secret != config.Config.Secret {
+		errMsg := params.OperationID + " params.Secret != config.Config.Secret "
 		log.NewError(params.OperationID, "params.Secret != config.Config.Secret", params.Secret, config.Config.Secret)
-		c.JSON(http.StatusBadRequest, gin.H{"errCode": 401, "errMsg": "not authorized"})
+		c.JSON(http.StatusBadRequest, gin.H{"errCode": 401, "errMsg": errMsg})
 		return
 	}
 	req := &rpc.UserTokenReq{Platform: params.Platform, FromUserID: params.UserID, OperationID: params.OperationID}
@@ -81,8 +86,9 @@ func UserToken(c *gin.Context) {
 	client := rpc.NewAuthClient(etcdConn)
 	reply, err := client.UserToken(context.Background(), req)
 	if err != nil {
-		log.NewError(req.OperationID, "UserToken failed ", err.Error(), req.String())
-		c.JSON(http.StatusInternalServerError, gin.H{"errCode": 500, "errMsg": err.Error()})
+		errMsg := req.OperationID + " UserToken failed " + err.Error() + req.String()
+		log.NewError(req.OperationID, errMsg)
+		c.JSON(http.StatusInternalServerError, gin.H{"errCode": 500, "errMsg": errMsg})
 		return
 	}
 	resp := api.UserTokenResp{CommResp: api.CommResp{ErrCode: reply.CommonResp.ErrCode, ErrMsg: reply.CommonResp.ErrMsg},
diff --git a/internal/msg_gateway/gate/ws_server.go b/internal/msg_gateway/gate/ws_server.go
index dd18f7bc8..e6f3a317e 100644
--- a/internal/msg_gateway/gate/ws_server.go
+++ b/internal/msg_gateway/gate/ws_server.go
@@ -54,7 +54,7 @@ func (ws *WServer) wsHandler(w http.ResponseWriter, r *http.Request) {
 		query := r.URL.Query()
 		conn, err := ws.wsUpGrader.Upgrade(w, r, nil) //Conn is obtained through the upgraded escalator
 		if err != nil {
-			log.ErrorByKv("upgrade http conn err", "", "err", err)
+			log.ErrorByKv("upgrade http conn err", "", "err", err, query)
 			return
 		} else {
 			//Connection mapping relationship,
@@ -196,6 +196,7 @@ func (ws *WServer) addUserConn(uid string, platformID int32, conn *UserConn, tok
 func (ws *WServer) delUserConn(conn *UserConn) {
 	rwLock.Lock()
 	defer rwLock.Unlock()
+	operationID := utils.OperationIDGenerator()
 	var platform, uid string
 	if oldStringMap, ok := ws.wsConnToUser[conn]; ok {
 		for k, v := range oldStringMap {
@@ -212,9 +213,9 @@ func (ws *WServer) delUserConn(conn *UserConn) {
 			for _, v := range ws.wsUserToConn {
 				count = count + len(v)
 			}
-			log.WarnByKv("WS delete operation", "", "wsUser deleted", ws.wsUserToConn, "disconnection_uid", uid, "disconnection_platform", platform, "online_user_num", len(ws.wsUserToConn), "online_conn_num", count)
+			log.NewWarn(operationID, "WS delete operation", "", "wsUser deleted", ws.wsUserToConn, "disconnection_uid", uid, "disconnection_platform", platform, "online_user_num", len(ws.wsUserToConn), "online_conn_num", count)
 		} else {
-			log.WarnByKv("WS delete operation", "", "wsUser deleted", ws.wsUserToConn, "disconnection_uid", uid, "disconnection_platform", platform, "online_user_num", len(ws.wsUserToConn))
+			log.NewWarn(operationID, "WS delete operation", "", "wsUser deleted", ws.wsUserToConn, "disconnection_uid", uid, "disconnection_platform", platform, "online_user_num", len(ws.wsUserToConn))
 		}
 		userCount = uint64(len(ws.wsUserToConn))
 		delete(ws.wsConnToUser, conn)
@@ -222,8 +223,7 @@ func (ws *WServer) delUserConn(conn *UserConn) {
 	}
 	err := conn.Close()
 	if err != nil {
-		log.ErrorByKv("close err", "", "uid", uid, "platform", platform)
-
+		log.Error(operationID, " close err", "", "uid", uid, "platform", platform)
 	}
 
 }
@@ -267,7 +267,7 @@ func (ws *WServer) headerCheck(w http.ResponseWriter, r *http.Request) bool {
 		operationID = query["operationID"][0]
 	}
 	if len(query["token"]) != 0 && len(query["sendID"]) != 0 && len(query["platformID"]) != 0 {
-		if ok, err, msg := token_verify.WsVerifyToken(query["token"][0], query["sendID"][0], query["platformID"][0]); !ok {
+		if ok, err, msg := token_verify.WsVerifyToken(query["token"][0], query["sendID"][0], query["platformID"][0], operationID); !ok {
 			//	e := err.(*constant.ErrInfo)
 			log.Error(operationID, "Token verify failed ", "query ", query, msg, err.Error())
 			w.Header().Set("Sec-Websocket-Version", "13")
@@ -281,7 +281,7 @@ func (ws *WServer) headerCheck(w http.ResponseWriter, r *http.Request) bool {
 	} else {
 		log.Error(operationID, "Args err", "query", query)
 		w.Header().Set("Sec-Websocket-Version", "13")
-		w.Header().Set("ws_err_msg", "args err")
+		w.Header().Set("ws_err_msg", "args err, need token, sendID, platformID")
 		http.Error(w, http.StatusText(status), status)
 		return false
 	}
diff --git a/internal/rpc/auth/auth.go b/internal/rpc/auth/auth.go
index 1aa0ec50b..15927bf5b 100644
--- a/internal/rpc/auth/auth.go
+++ b/internal/rpc/auth/auth.go
@@ -20,38 +20,41 @@ import (
 )
 
 func (rpc *rpcAuth) UserRegister(_ context.Context, req *pbAuth.UserRegisterReq) (*pbAuth.UserRegisterResp, error) {
-	log.NewInfo(req.OperationID, "UserRegister args ", req.String())
+	log.NewInfo(req.OperationID, utils.GetSelfFuncName(), " rpc args ", req.String())
 	var user db.User
 	utils.CopyStructFields(&user, req.UserInfo)
 	if req.UserInfo.Birth != 0 {
 		user.Birth = utils.UnixSecondToTime(int64(req.UserInfo.Birth))
 	}
+	log.Debug(req.OperationID, "copy ", user, req.UserInfo)
 	err := imdb.UserRegister(user)
 	if err != nil {
-		log.NewError(req.OperationID, "UserRegister failed ", err.Error(), user)
-		return &pbAuth.UserRegisterResp{CommonResp: &pbAuth.CommonResp{ErrCode: constant.ErrDB.ErrCode, ErrMsg: constant.ErrDB.ErrMsg}}, nil
+		errMsg := req.OperationID + " imdb.UserRegister failed " + err.Error() + user.UserID
+		log.NewError(req.OperationID, errMsg, user)
+		return &pbAuth.UserRegisterResp{CommonResp: &pbAuth.CommonResp{ErrCode: constant.ErrDB.ErrCode, ErrMsg: errMsg}}, nil
 	}
 
-	log.NewInfo(req.OperationID, "rpc UserRegister return")
+	log.NewInfo(req.OperationID, utils.GetSelfFuncName(), " rpc return ", pbAuth.UserRegisterResp{CommonResp: &pbAuth.CommonResp{}})
 	return &pbAuth.UserRegisterResp{CommonResp: &pbAuth.CommonResp{}}, nil
 }
 
 func (rpc *rpcAuth) UserToken(_ context.Context, req *pbAuth.UserTokenReq) (*pbAuth.UserTokenResp, error) {
-	log.NewInfo(req.OperationID, "UserToken args ", req.String())
-
+	log.NewInfo(req.OperationID, utils.GetSelfFuncName(), " rpc args ", req.String())
 	_, err := imdb.GetUserByUserID(req.FromUserID)
 	if err != nil {
-		log.NewError(req.OperationID, "GetUserByUserID failed ", err.Error(), req.FromUserID)
-		return &pbAuth.UserTokenResp{CommonResp: &pbAuth.CommonResp{ErrCode: constant.ErrDB.ErrCode, ErrMsg: constant.ErrDB.ErrMsg}}, nil
+		errMsg := req.OperationID + " imdb.GetUserByUserID failed " + err.Error() + req.FromUserID
+		log.NewError(req.OperationID, errMsg)
+		return &pbAuth.UserTokenResp{CommonResp: &pbAuth.CommonResp{ErrCode: constant.ErrDB.ErrCode, ErrMsg: errMsg}}, nil
 	}
 
 	tokens, expTime, err := token_verify.CreateToken(req.FromUserID, req.Platform)
 	if err != nil {
-		log.NewError(req.OperationID, "CreateToken failed ", err.Error(), req.FromUserID, req.Platform)
-		return &pbAuth.UserTokenResp{CommonResp: &pbAuth.CommonResp{ErrCode: constant.ErrDB.ErrCode, ErrMsg: constant.ErrDB.ErrMsg}}, nil
+		errMsg := req.OperationID + " token_verify.CreateToken failed " + err.Error() + req.FromUserID + utils.Int32ToString(req.Platform)
+		log.NewError(req.OperationID, errMsg)
+		return &pbAuth.UserTokenResp{CommonResp: &pbAuth.CommonResp{ErrCode: constant.ErrDB.ErrCode, ErrMsg: errMsg}}, nil
 	}
 
-	log.NewInfo(req.OperationID, "rpc UserToken return ", tokens, expTime)
+	log.NewInfo(req.OperationID, utils.GetSelfFuncName(), " rpc return ", pbAuth.UserTokenResp{CommonResp: &pbAuth.CommonResp{}, Token: tokens, ExpiredTime: expTime})
 	return &pbAuth.UserTokenResp{CommonResp: &pbAuth.CommonResp{}, Token: tokens, ExpiredTime: expTime}, nil
 }
 
@@ -73,15 +76,16 @@ func NewRpcAuthServer(port int) *rpcAuth {
 }
 
 func (rpc *rpcAuth) Run() {
-	log.NewInfo("0", "rpc auth start...")
+	operationID := utils.OperationIDGenerator()
+	log.NewInfo(operationID, "rpc auth start...")
 
 	address := utils.ServerIP + ":" + strconv.Itoa(rpc.rpcPort)
 	listener, err := net.Listen("tcp", address)
 	if err != nil {
-		log.NewError("0", "listen network failed ", err.Error(), address)
+		log.NewError(operationID, "listen network failed ", err.Error(), address)
 		return
 	}
-	log.NewInfo("0", "listen network success, ", address, listener)
+	log.NewInfo(operationID, "listen network success, ", address, listener)
 	//grpc server
 	srv := grpc.NewServer()
 	defer srv.GracefulStop()
@@ -90,15 +94,15 @@ func (rpc *rpcAuth) Run() {
 	pbAuth.RegisterAuthServer(srv, rpc)
 	err = getcdv3.RegisterEtcd(rpc.etcdSchema, strings.Join(rpc.etcdAddr, ","), utils.ServerIP, rpc.rpcPort, rpc.rpcRegisterName, 10)
 	if err != nil {
-		log.NewError("0", "RegisterEtcd failed ", err.Error(),
+		log.NewError(operationID, "RegisterEtcd failed ", err.Error(),
 			rpc.etcdSchema, strings.Join(rpc.etcdAddr, ","), utils.ServerIP, rpc.rpcPort, rpc.rpcRegisterName)
 		return
 	}
-	log.NewInfo("0", "RegisterAuthServer ok ", rpc.etcdSchema, strings.Join(rpc.etcdAddr, ","), utils.ServerIP, rpc.rpcPort, rpc.rpcRegisterName)
+	log.NewInfo(operationID, "RegisterAuthServer ok ", rpc.etcdSchema, strings.Join(rpc.etcdAddr, ","), utils.ServerIP, rpc.rpcPort, rpc.rpcRegisterName)
 	err = srv.Serve(listener)
 	if err != nil {
-		log.NewError("0", "Serve failed ", err.Error())
+		log.NewError(operationID, "Serve failed ", err.Error())
 		return
 	}
-	log.NewInfo("0", "rpc auth ok")
+	log.NewInfo(operationID, "rpc auth ok")
 }
diff --git a/pkg/common/token_verify/jwt_token.go b/pkg/common/token_verify/jwt_token.go
index e58424623..876f4e847 100644
--- a/pkg/common/token_verify/jwt_token.go
+++ b/pkg/common/token_verify/jwt_token.go
@@ -206,7 +206,7 @@ func ParseRedisInterfaceToken(redisToken interface{}) (*Claims, error) {
 func VerifyToken(token, uid string) (bool, error) {
 	claims, err := ParseToken(token, "")
 	if err != nil {
-		return false, err
+		return false, utils.Wrap(err, "ParseToken failed")
 	}
 	if claims.UID != uid {
 		return false, &constant.ErrTokenUnknown
@@ -215,8 +215,8 @@ func VerifyToken(token, uid string) (bool, error) {
 	log.NewDebug("", claims.UID, claims.Platform)
 	return true, nil
 }
-func WsVerifyToken(token, uid string, platformID string) (bool, error, string) {
-	claims, err := ParseToken(token, "")
+func WsVerifyToken(token, uid string, platformID string, operationID string) (bool, error, string) {
+	claims, err := ParseToken(token, operationID)
 	if err != nil {
 		return false, utils.Wrap(err, "parse token err"), "parse token err"
 	}
@@ -226,6 +226,6 @@ func WsVerifyToken(token, uid string, platformID string) (bool, error, string) {
 	if claims.Platform != constant.PlatformIDToName(utils.StringToInt32(platformID)) {
 		return false, utils.Wrap(&constant.ErrTokenUnknown, "platform is not same to token platform"), "platform is not same to token platform"
 	}
-	log.NewDebug("", claims.UID, claims.Platform)
+	log.NewDebug(operationID, utils.GetSelfFuncName(), " check ok ", claims.UID, uid, claims.Platform)
 	return true, nil, ""
 }