Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat: 重构日志 #91

Merged
merged 2 commits into from
May 30, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
14 changes: 3 additions & 11 deletions api_auth_app_access_token_get.go
Original file line number Diff line number Diff line change
Expand Up @@ -24,15 +24,13 @@ import (
// docs: https://open.feishu.cn/document/ukTMukTMukTM/uADN14CM0UjLwQTN
func (r *AuthService) GetAppAccessToken(ctx context.Context) (*TokenExpire, *Response, error) {
if r.cli.mock.mockGetAppAccessToken != nil {
r.cli.Log(ctx, LogLevelDebug, "[lark] Auth#GetAppAccessToken mock enable")
r.cli.Log(ctx, LogLevelTrace, "[lark] Auth#GetAppAccessToken mock enable")
return r.cli.mock.mockGetAppAccessToken(ctx)
}

r.cli.Log(ctx, LogLevelInfo, "[lark] Auth#GetAppAccessToken call api")

val, ttl, err := r.cli.store.Get(ctx, genAppTokenKey(r.cli.isISV, r.cli.appID))
if err != nil && err != ErrStoreNotFound {
r.cli.Log(ctx, LogLevelError, "[lark] Auth#GetAppAccessToken get token from store failed: %s", err)
r.cli.Log(ctx, LogLevelError, "[lark] Auth#GetAppAccessToken get_token_cache failed, err=%s", err)
} else if val != "" && ttl > 0 {
return &TokenExpire{Token: val, Expire: int64(ttl.Seconds())}, &Response{}, nil
}
Expand Down Expand Up @@ -64,18 +62,12 @@ func (r *AuthService) GetAppAccessToken(ctx context.Context) (*TokenExpire, *Res

response, err := r.cli.RawRequest(ctx, req, resp)
if err != nil {
r.cli.Log(ctx, LogLevelError, "[lark] Auth#GetAppAccessToken POST %s failed: %s", uri, err)
return nil, response, err
} else if resp.Code != 0 {
r.cli.Log(ctx, LogLevelError, "[lark] Auth#GetAppAccessToken POST %s failed, code: %d, msg: %s", uri, resp.Code, resp.Msg)
return nil, response, NewError("Token", "GetAppAccessToken", resp.Code, resp.Msg)
}

r.cli.Log(ctx, LogLevelDebug, "[lark] Auth#GetAppAccessToken log_id: %s, response: %s", response.LogID, jsonString(resp))

err = r.cli.store.Set(ctx, genAppTokenKey(r.cli.isISV, r.cli.appID), resp.AppAccessToken, time.Second*time.Duration(resp.Expire))
if err != nil {
r.cli.Log(ctx, LogLevelError, "[lark] Auth#GetAppAccessToken set token to store failed: %s", err)
r.cli.Log(ctx, LogLevelError, "[lark] Auth#GetAppAccessToken set_token_cache failed, err=%s", err)
}

return &TokenExpire{
Expand Down
8 changes: 7 additions & 1 deletion api_auth_app_ticket.go
Original file line number Diff line number Diff line change
Expand Up @@ -28,12 +28,18 @@ func (r *Lark) WithTenant(tenantKey string) *Lark {
// GetAppTicket ...
func (r *AuthService) GetAppTicket(ctx context.Context) (string, error) {
s, _, err := r.cli.store.Get(ctx, genISVAppTicketKey(r.cli.appID))
if err != nil && err != ErrStoreNotFound {
r.cli.Log(ctx, LogLevelError, "[lark] Auth#GetAppTicket get_ticket_cache failed, app_id=%s, err=%s", r.cli.appID, err)
}
if err == ErrStoreNotFound && r.cli.getAppTicketFunc != nil {
ticket, err := r.cli.getAppTicketFunc(ctx, r.cli, r.cli.appID)
if err != nil {
r.cli.Log(ctx, LogLevelError, "[lark] Auth#GetAppTicket get_ticket failed, app_id=%s, err=%s", r.cli.appID, err)
return "", err
}
_ = r.SetAppTicket(ctx, ticket)
if err = r.SetAppTicket(ctx, ticket); err != nil {
r.cli.Log(ctx, LogLevelError, "[lark] Auth#GetAppTicket set_ticket_cache failed, app_id=%s, err=%s", r.cli.appID, err)
}
return ticket, nil
}
return s, err
Expand Down
29 changes: 10 additions & 19 deletions api_auth_tenant_access_token_get.go
Original file line number Diff line number Diff line change
Expand Up @@ -26,15 +26,13 @@ import (
// https://open.feishu.cn/document/ukTMukTMukTM/ukDNz4SO0MjL5QzM/auth-v3/auth/tenant_access_token
func (r *AuthService) GetTenantAccessToken(ctx context.Context) (*TokenExpire, *Response, error) {
if r.cli.mock.mockGetTenantAccessToken != nil {
r.cli.Log(ctx, LogLevelDebug, "[lark] Auth#GetTenantAccessToken mock enable")
r.cli.Log(ctx, LogLevelTrace, "[lark] Auth#GetTenantAccessToken mock enable")
return r.cli.mock.mockGetTenantAccessToken(ctx)
}

r.cli.Log(ctx, LogLevelInfo, "[lark] Auth#GetTenantAccessToken call api")

val, ttl, err := r.cli.store.Get(ctx, genTenantTokenKey(r.cli.isISV, r.cli.appID, r.cli.tenantKey))
if err != nil && err != ErrStoreNotFound {
r.cli.Log(ctx, LogLevelError, "[lark] Auth#GetTenantAccessToken get token from store failed: %s", err)
r.cli.Log(ctx, LogLevelError, "[lark] Auth#GetTenantAccessToken get_from_cache failed, err=%s", err)
} else if val != "" && ttl > 0 {
return &TokenExpire{Token: val, Expire: int64(ttl.Seconds())}, &Response{}, nil
}
Expand Down Expand Up @@ -67,20 +65,12 @@ func (r *AuthService) GetTenantAccessToken(ctx context.Context) (*TokenExpire, *

response, err := r.cli.RawRequest(ctx, req, resp)
if err != nil {
r.cli.Log(ctx, LogLevelError, "[lark] Auth#GetTenantAccessToken GET %s failed: %s", uri, err)
return nil, response, err
} else if resp.Code != 0 {
r.cli.Log(ctx, LogLevelError, "[lark] Auth#GetTenantAccessToken GET %s failed, code: %d, msg: %s", uri, resp.Code, resp.Msg)
return nil, response, NewError("Token", "GetTenantAccessToken", resp.Code, resp.Msg)
}

r.cli.Log(ctx, LogLevelDebug, "[lark] Auth#GetTenantAccessToken log_id: %s, response: %s", response.LogID, jsonString(resp))

err = r.cli.store.Set(ctx, genTenantTokenKey(r.cli.isISV, r.cli.appID, r.cli.tenantKey), resp.TenantAccessToken, time.Second*time.Duration(resp.Expire))
if err != nil {
r.cli.Log(ctx, LogLevelError, "[lark] Auth#GetTenantAccessToken set token to store failed: %s", err)
if err = r.cli.store.Set(ctx, genTenantTokenKey(r.cli.isISV, r.cli.appID, r.cli.tenantKey), resp.TenantAccessToken, time.Second*time.Duration(resp.Expire)); err != nil {
r.cli.Log(ctx, LogLevelError, "[lark] Auth#GetTenantAccessToken set_token_cache failed, err=%s", err)
}

return &TokenExpire{
Token: resp.TenantAccessToken,
Expire: resp.Expire,
Expand Down Expand Up @@ -112,9 +102,10 @@ type getTenantAccessTokenReq struct {
}

type getTenantAccessTokenResp struct {
Code int64 `json:"code,omitempty"` // 错误码,非 0 表示失败
Msg string `json:"msg,omitempty"` // 错误描述
TenantAccessToken string `json:"tenant_access_token"`
AppAccessToken string `json:"app_access_token"`
Expire int64 `json:"expire"`
Code int64 `json:"code,omitempty"` // 错误码,非 0 表示失败
Msg string `json:"msg,omitempty"` // 错误描述
TenantAccessToken string `json:"tenant_access_token"`
AppAccessToken string `json:"app_access_token"`
Expire int64 `json:"expire"`
Error *ErrorDetail `json:"error,omitempty"`
}
81 changes: 52 additions & 29 deletions impl_request.go
Original file line number Diff line number Diff line change
Expand Up @@ -70,33 +70,62 @@ func (r *Mock) UnMockRawRequest() {
}

func (r *Lark) rawRequest(ctx context.Context, req *RawRequestReq, resp interface{}) (response *Response, err error) {
r.Log(ctx, LogLevelInfo, "[lark] %s#%s call api", req.Scope, req.API)

// 1. parse request
rawHttpReq, err := r.parseRawHttpRequest(ctx, req)
if err != nil {
// 这里日志不需要区分 level, 输出 [error] 日志
r.Log(ctx, LogLevelError, "[lark] %s#%s %s %s parse_req failed, err=%s", req.Scope, req.API, req.Method, req.URL, err)
return response, err
}

// 2. do request
response, err = r.doRequest(ctx, rawHttpReq, resp)
// 2. request log
logLevel := r.getLogLevel(req.Scope, req.API)
switch logLevel {
case LogLevelDebug:
r.Log(ctx, LogLevelDebug, "[lark] %s#%s %s %s start, body=%s", rawHttpReq.Scope, rawHttpReq.API, rawHttpReq.Method, rawHttpReq.URL, string(rawHttpReq.RawBody))
case LogLevelInfo:
r.Log(ctx, LogLevelInfo, "[lark] %s#%s %s %s start", rawHttpReq.Scope, rawHttpReq.API, rawHttpReq.Method, rawHttpReq.URL)
default:
// error 不需要 req 日志, 合并到 resp 一起
}

logID, statusCode := getResponseLogID(response)
// 3. do request
var respContent string
response, respContent, err = r.doRequest(ctx, rawHttpReq, resp)
if err != nil {
r.Log(ctx, LogLevelError, "[lark] %s#%s %s %s failed, log_id: %s, status_code: %d, error: %s", req.Scope, req.API, req.Method, req.URL, logID, statusCode, err)
switch logLevel {
case LogLevelDebug:
// [debug]: 详细 error 日志
r.Log(ctx, LogLevelError, "[lark] %s#%s %s %s failed, log_id=%s, status=%d, body=%s", rawHttpReq.Scope, rawHttpReq.API, rawHttpReq.Method, rawHttpReq.URL, response.LogID, response.StatusCode, respContent)
default:
// [其他]: 简单 error 日志
r.Log(ctx, LogLevelError, "[lark] %s#%s %s %s failed, log_id=%s, status=%d", rawHttpReq.Scope, rawHttpReq.API, rawHttpReq.Method, rawHttpReq.URL, response.LogID, response.StatusCode)
}
return response, err
}

code, msg, detailErr := getCodeMsg(resp)

// 4. response log
if response.StatusCode >= http.StatusBadRequest || code != 0 {
r.Log(ctx, LogLevelError, "[lark] %s#%s %s %s failed, log_id=%s, status=%d, code=%d, msg=%s, detail=%s", rawHttpReq.Scope, rawHttpReq.API, rawHttpReq.Method, rawHttpReq.URL, response.LogID, response.StatusCode, code, msg, detailErr)
} else {
switch logLevel {
case LogLevelDebug:
r.Log(ctx, LogLevelDebug, "[lark] %s#%s %s %s success, log_id=%s, body=%s", rawHttpReq.Scope, rawHttpReq.API, rawHttpReq.Method, rawHttpReq.URL, response.LogID, respContent)
case LogLevelInfo:
r.Log(ctx, LogLevelInfo, "[lark] %s#%s %s %s success, log_id=%s", rawHttpReq.Scope, rawHttpReq.API, rawHttpReq.Method, rawHttpReq.URL, response.LogID)
default:
// error 不需要 resp 日志
}
}

// 5. response
if code != 0 {
e := NewError(req.Scope, req.API, code, msg)
e.(*Error).ErrorDetail = detailErr
r.Log(ctx, LogLevelError, "[lark] %s#%s %s %s failed, log_id: %s, status_code: %d, code: %d, msg: %s", req.Scope, req.API, req.Method, req.URL, logID, statusCode, code, msg)
return response, e
}

r.Log(ctx, LogLevelDebug, "[lark] %s#%s success, log_id: %s, status_code: %d, response: %s", req.Scope, req.API, logID, statusCode, "TODO")

return response, nil
}

Expand Down Expand Up @@ -149,17 +178,12 @@ func (r *Lark) parseRawHttpRequest(ctx context.Context, req *RawRequestReq) (*ra
return rawHttpReq, nil
}

func (r *Lark) doRequest(ctx context.Context, rawHttpReq *rawHttpRequest, realResponse interface{}) (*Response, error) {
func (r *Lark) doRequest(ctx context.Context, rawHttpReq *rawHttpRequest, realResponse interface{}) (*Response, string, error) {
response := new(Response)
response.Method = rawHttpReq.Method
response.URL = rawHttpReq.URL
response.Header = map[string][]string{}

if r.logLevel <= LogLevelTrace {
r.Log(ctx, LogLevelTrace, "[lark] request %s#%s, %s %s, header=%s, body=%s", rawHttpReq.Scope, rawHttpReq.API,
rawHttpReq.Method, rawHttpReq.URL, jsonHeader(rawHttpReq.Headers), string(rawHttpReq.RawBody))
}

if rawHttpReq.Timeout > 0 {
var cancel context.CancelFunc
ctx, cancel = context.WithTimeout(ctx, rawHttpReq.Timeout)
Expand All @@ -168,15 +192,15 @@ func (r *Lark) doRequest(ctx context.Context, rawHttpReq *rawHttpRequest, realRe

req, err := http.NewRequestWithContext(ctx, rawHttpReq.Method, rawHttpReq.URL, rawHttpReq.Body)
if err != nil {
return response, err
return response, "", err
}
for k, v := range rawHttpReq.Headers {
req.Header.Set(k, v)
}

resp, err := r.httpClient.Do(ctx, req)
if err != nil {
return response, err
return response, "", err
}

_, media, _ := mime.ParseMediaType(resp.Header.Get("Content-Disposition"))
Expand All @@ -197,15 +221,14 @@ func (r *Lark) doRequest(ctx context.Context, rawHttpReq *rawHttpRequest, realRe

bs, err := ioutil.ReadAll(resp.Body)
if err != nil {
return response, err
return response, "", err
}

if r.logLevel <= LogLevelTrace {
if respFilename == "" {
r.Log(ctx, LogLevelTrace, "[lark] response %s#%s, %s %s, body=%s", rawHttpReq.Scope, rawHttpReq.API, rawHttpReq.Method, rawHttpReq.URL, string(bs))
} else {
r.Log(ctx, LogLevelTrace, "[lark] response %s#%s, %s %s, body=<FILE: %d>", rawHttpReq.Scope, rawHttpReq.API, rawHttpReq.Method, rawHttpReq.URL, len(bs))
}
var respContent string
if respFilename == "" {
respContent = string(bs)
} else {
respContent = fmt.Sprintf("<FILE: %d>", len(bs))
}

if realResponse != nil {
Expand All @@ -220,20 +243,20 @@ func (r *Lark) doRequest(ctx context.Context, rawHttpReq *rawHttpRequest, realRe
setter.SetFilename(respFilename)
}
if isSpecResp {
return response, nil
return response, respContent, nil
}
}

if len(bs) == 0 && resp.StatusCode >= http.StatusBadRequest {
return response, fmt.Errorf("request fail: %s", resp.Status)
return response, respContent, fmt.Errorf("request fail: %s", resp.Status)
}

if err = json.Unmarshal(bs, realResponse); err != nil {
return response, fmt.Errorf("invalid json: %s, err: %s", bs, err)
return response, respContent, fmt.Errorf("invalid json: %s, err: %s", bs, err)
}
}

return response, nil
return response, respContent, nil
}

func (r *rawHttpRequest) parseHeader(ctx context.Context, ins *Lark, req *RawRequestReq) error {
Expand Down
6 changes: 6 additions & 0 deletions lark.go
Original file line number Diff line number Diff line change
Expand Up @@ -157,6 +157,12 @@ func WithNonBlockingCallback(noBlocking bool) ClientOptionFunc {
}
}

func WithDisableErrorLog(disableErrorLog bool) ClientOptionFunc {
return func(lark *Lark) {
lark.disableErrorLog = disableErrorLog
}
}

// MethodOptionFunc new method option
type MethodOptionFunc func(*MethodOption)

Expand Down
46 changes: 45 additions & 1 deletion logger.go
Original file line number Diff line number Diff line change
Expand Up @@ -32,11 +32,33 @@ type Logger interface {
}

// LogLevel ...
//
// 正常情况下:
// trace: 大于两条日志: 1,2. Token 获取日志, 3,4: 同 debug 的两条日志
// debug: 两条日志: 1. xx start, body=<body>, 2. xx success, log_id=<logid>, body=<body>
// info: 两条日志: 1. xx start 2. xx success, log_id=<logid>
// warn,error: 没有日志
//
// 出错的情况:
// 各日志级别都会输出 error 级别的日志, 如果是<=debug, 会有 body, 否则没有
// 如果不希望输出 error 日志, 可以通过 WithDisableErrorLog 将 error 降级到 warn 日志
//
// 1. 开启了 mock 的情况下, mock 链路打印一条 debug 日志
//
// 2. req:
// 2.1 trace/debug: [debug] 日志 + 请求体
// 2.2 info: [info] 日志 + 无请求体
// 2.3 warn/error: 没有日志
//
// 3. resp:
// 3.1 trace/debug: 无论有无错误: [debug] 日志 + 返回体
// 3.2 info: 无论有无错误: [info] 日志 + 无返回体
// 3.3 warn/error: 有错误: [error] 日志 + 无返回体; 无错误: 无日志
type LogLevel int

// LogLevelTrace ...
const (
LogLevelTrace LogLevel = iota + 1 // 只有两个 log req 和 resp 的 文本内容
LogLevelTrace LogLevel = iota + 1
LogLevelDebug
LogLevelInfo
LogLevelWarn
Expand All @@ -61,7 +83,29 @@ func (r LogLevel) String() string {
}
}

func (r *Lark) getLogLevel(scope, api string) LogLevel {
switch api {
case "GetAppAccessToken", "GetTenantAccessToken", "GetAppTicket":
// 针对内部自动调用的 3 个 token 相关接口
// 如果 log 级别被调用方设置为 trace, 则表示调用方需要非常详细的日志, 仍旧输出 token 接口详细日志
// 否则, 认为 token 的 req 和 resp 不需要日志, 只需要 error 日志
if r.logLevel == LogLevelTrace {
return LogLevelDebug
}
return LogLevelError
}
if r.logLevel <= LogLevelDebug {
return LogLevelDebug
} else if r.logLevel <= LogLevelInfo {
return LogLevelInfo
}
return LogLevelError
}

func (r *Lark) Log(ctx context.Context, level LogLevel, msg string, args ...interface{}) {
if level == LogLevelError && r.disableErrorLog {
level = LogLevelWarn
}
if r.logger != nil && r.logLevel <= level {
r.logger.Log(ctx, level, msg, args...)
}
Expand Down
Loading