From aee8e509fe352327354803174c3ca488286f7589 Mon Sep 17 00:00:00 2001 From: zhaojunchang Date: Thu, 2 Apr 2026 19:03:22 +0800 Subject: [PATCH 01/16] feat(auth): add response logging and centralize path constants --- cmd/auth/auth.go | 5 +- internal/auth/app_registration.go | 6 +- internal/auth/auth_response_log.go | 155 +++++++++++++++++++++++++++++ internal/auth/device_flow.go | 6 +- internal/auth/device_flow_test.go | 66 ++++++++++++ internal/auth/paths.go | 16 +++ internal/auth/uat_client.go | 1 + internal/auth/verify.go | 3 +- internal/auth/verify_test.go | 47 ++++++++- 9 files changed, 297 insertions(+), 8 deletions(-) create mode 100644 internal/auth/auth_response_log.go create mode 100644 internal/auth/paths.go diff --git a/cmd/auth/auth.go b/cmd/auth/auth.go index f8a4f1c89..a7672cc53 100644 --- a/cmd/auth/auth.go +++ b/cmd/auth/auth.go @@ -14,6 +14,7 @@ import ( larkcore "github.com/larksuite/oapi-sdk-go/v3/core" "github.com/spf13/cobra" + larkauth "github.com/larksuite/cli/internal/auth" "github.com/larksuite/cli/internal/cmdutil" ) @@ -48,7 +49,7 @@ type userInfoResponse struct { func getUserInfo(ctx context.Context, sdk *lark.Client, accessToken string) (openId, name string, err error) { apiResp, err := sdk.Do(ctx, &larkcore.ApiReq{ HttpMethod: http.MethodGet, - ApiPath: "/open-apis/authen/v1/user_info", + ApiPath: larkauth.PathUserInfoV1, SupportedAccessTokenTypes: []larkcore.AccessTokenType{larkcore.AccessTokenTypeUser}, }, larkcore.WithUserAccessToken(accessToken)) if err != nil { @@ -109,7 +110,7 @@ func getAppInfo(ctx context.Context, f *cmdutil.Factory, appId string) (*appInfo apiResp, err := sdk.Do(ctx, &larkcore.ApiReq{ HttpMethod: http.MethodGet, - ApiPath: "/open-apis/application/v6/applications/" + appId, + ApiPath: larkauth.ApplicationInfoPath(appId), QueryParams: queryParams, SupportedAccessTokenTypes: []larkcore.AccessTokenType{larkcore.AccessTokenTypeTenant}, }) diff --git a/internal/auth/app_registration.go b/internal/auth/app_registration.go index 819863d61..e06e6fec5 100644 --- a/internal/auth/app_registration.go +++ b/internal/auth/app_registration.go @@ -47,7 +47,7 @@ func RequestAppRegistration(httpClient *http.Client, brand core.LarkBrand, errOu ep := core.ResolveEndpoints(brand) regEp := core.ResolveEndpoints(core.BrandFeishu) // registration begin always uses feishu - endpoint := regEp.Accounts + "/oauth/v1/app/registration" + endpoint := regEp.Accounts + PathAppRegistration form := url.Values{} form.Set("action", "begin") @@ -66,6 +66,7 @@ func RequestAppRegistration(httpClient *http.Client, brand core.LarkBrand, errOu return nil, err } defer resp.Body.Close() + logAuthResponse(resp) body, err := io.ReadAll(resp.Body) if err != nil { @@ -129,7 +130,7 @@ func PollAppRegistration(ctx context.Context, httpClient *http.Client, brand cor const maxPollAttempts = 200 ep := core.ResolveEndpoints(brand) - endpoint := ep.Accounts + "/oauth/v1/app/registration" + endpoint := ep.Accounts + PathAppRegistration deadline := time.Now().Add(time.Duration(expiresIn) * time.Second) currentInterval := interval attempts := 0 @@ -162,6 +163,7 @@ func PollAppRegistration(ctx context.Context, httpClient *http.Client, brand cor currentInterval = minInt(currentInterval+1, maxPollInterval) continue } + logAuthResponse(resp) body, err := io.ReadAll(resp.Body) resp.Body.Close() diff --git a/internal/auth/auth_response_log.go b/internal/auth/auth_response_log.go new file mode 100644 index 000000000..03419e859 --- /dev/null +++ b/internal/auth/auth_response_log.go @@ -0,0 +1,155 @@ +package auth + +import ( + "fmt" + "io" + "net/http" + "os" + "path/filepath" + "strings" + "sync" + "time" + + "github.com/larksuite/cli/internal/core" + larkcore "github.com/larksuite/oapi-sdk-go/v3/core" +) + +var ( + authResponseLogWriter io.Writer = defaultLogWriter{} + authResponseLogNow = time.Now + authResponseLogArgs = func() []string { return os.Args } + + logMu sync.Mutex +) + +type defaultLogWriter struct{} + +func (defaultLogWriter) Write(p []byte) (n int, err error) { + logMu.Lock() + defer logMu.Unlock() + + dir := filepath.Join(core.GetConfigDir(), "logs") + if err := os.MkdirAll(dir, 0700); err != nil { + return 0, err + } + + // Format: auth-2006-01-02.log + now := authResponseLogNow() + logName := fmt.Sprintf("auth-%s.log", now.Format("2006-01-02")) + logPath := filepath.Join(dir, logName) + + f, err := os.OpenFile(logPath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0600) + if err != nil { + return 0, err + } + defer f.Close() + + // Clean up old logs (keep 7 days) + go cleanupOldLogs(dir, now) + + return f.Write(p) +} + +func cleanupOldLogs(dir string, now time.Time) { + defer func() { + if r := recover(); r != nil { + // Record the panic so we can debug without crashing the main program + msg := fmt.Sprintf("[lark-cli] [WARN] background log cleanup panicked: %v\n", r) + _, _ = authResponseLogWriter.Write([]byte(msg)) + } + }() + + entries, err := os.ReadDir(dir) + if err != nil { + return + } + + cutoff := now.AddDate(0, 0, -7) + for _, entry := range entries { + if entry.IsDir() || !strings.HasPrefix(entry.Name(), "auth-") || !strings.HasSuffix(entry.Name(), ".log") { + continue + } + + // Extract date from filename + dateStr := strings.TrimPrefix(entry.Name(), "auth-") + dateStr = strings.TrimSuffix(dateStr, ".log") + + logDate, err := time.Parse("2006-01-02", dateStr) + if err != nil { + continue + } + + // If log is older than 7 days, delete it + if logDate.Before(cutoff) { + _ = os.Remove(filepath.Join(dir, entry.Name())) + } + } +} + +type authResponse interface { + logStatusCode() int + logHeader(key string) string + logPath() string +} + +type httpAuthResponse struct { + *http.Response +} + +func (r httpAuthResponse) logStatusCode() int { + return r.StatusCode +} + +func (r httpAuthResponse) logHeader(key string) string { + return r.Header.Get(key) +} + +func (r httpAuthResponse) logPath() string { + if r.Request != nil && r.Request.URL != nil { + return r.Request.URL.Path + } + return "miss" +} + +type sdkAuthResponse struct { + path string + *larkcore.ApiResp +} + +func (r sdkAuthResponse) logStatusCode() int { + return r.StatusCode +} + +func (r sdkAuthResponse) logHeader(key string) string { + return r.Header.Get(key) +} + +func (r sdkAuthResponse) logPath() string { + return r.path +} + +func logAuthResponse(resp interface{}) { + if authResponseLogWriter == nil || resp == nil { + return + } + + var r authResponse + switch v := resp.(type) { + case *http.Response: + r = httpAuthResponse{v} + case authResponse: + r = v + default: + return + } + + fmt.Fprintf( + authResponseLogWriter, + "[lark-cli] auth-response: time=%s path=%s status=%d x-tt-logid=%s cmdline=%s\n", + authResponseLogNow().Format(time.RFC3339Nano), + r.logPath(), + r.logStatusCode(), + r.logHeader("x-tt-logid"), + strings.Join(authResponseLogArgs(), " "), + ) +} diff --git a/internal/auth/device_flow.go b/internal/auth/device_flow.go index c79aaa224..e21f972c0 100644 --- a/internal/auth/device_flow.go +++ b/internal/auth/device_flow.go @@ -54,8 +54,8 @@ type OAuthEndpoints struct { func ResolveOAuthEndpoints(brand core.LarkBrand) OAuthEndpoints { ep := core.ResolveEndpoints(brand) return OAuthEndpoints{ - DeviceAuthorization: ep.Accounts + "/oauth/v1/device_authorization", - Token: ep.Open + "/open-apis/authen/v2/oauth/token", + DeviceAuthorization: ep.Accounts + PathDeviceAuthorization, + Token: ep.Open + PathOAuthTokenV2, } } @@ -93,6 +93,7 @@ func RequestDeviceAuthorization(httpClient *http.Client, appId, appSecret string return nil, err } defer resp.Body.Close() + logAuthResponse(resp) body, err := io.ReadAll(resp.Body) if err != nil { @@ -179,6 +180,7 @@ func PollDeviceToken(ctx context.Context, httpClient *http.Client, appId, appSec currentInterval = minInt(currentInterval+1, maxPollInterval) continue } + logAuthResponse(resp) body, err := io.ReadAll(resp.Body) resp.Body.Close() diff --git a/internal/auth/device_flow_test.go b/internal/auth/device_flow_test.go index 3cd5dad70..2229485d2 100644 --- a/internal/auth/device_flow_test.go +++ b/internal/auth/device_flow_test.go @@ -4,9 +4,14 @@ package auth import ( + "bytes" + "net/http" + "strings" "testing" + "time" "github.com/larksuite/cli/internal/core" + "github.com/larksuite/cli/internal/httpmock" ) func TestResolveOAuthEndpoints_Feishu(t *testing.T) { @@ -28,3 +33,64 @@ func TestResolveOAuthEndpoints_Lark(t *testing.T) { t.Errorf("Token = %q", ep.Token) } } + +func TestRequestDeviceAuthorization_LogsResponse(t *testing.T) { + reg := &httpmock.Registry{} + t.Cleanup(func() { reg.Verify(t) }) + + reg.Register(&httpmock.Stub{ + Method: "POST", + URL: PathDeviceAuthorization, + Body: map[string]interface{}{ + "device_code": "device-code", + "user_code": "user-code", + "verification_uri": "https://example.com/verify", + "verification_uri_complete": "https://example.com/verify?code=123", + "expires_in": 240, + "interval": 5, + }, + Headers: http.Header{ + "Content-Type": []string{"application/json"}, + "X-Tt-Logid": []string{"device-log-id"}, + }, + }) + + var buf bytes.Buffer + prevWriter := authResponseLogWriter + prevNow := authResponseLogNow + prevArgs := authResponseLogArgs + authResponseLogWriter = &buf + authResponseLogNow = func() time.Time { + return time.Date(2026, 4, 2, 3, 4, 5, 0, time.UTC) + } + authResponseLogArgs = func() []string { + return []string{"lark-cli", "auth", "login"} + } + t.Cleanup(func() { + authResponseLogWriter = prevWriter + authResponseLogNow = prevNow + authResponseLogArgs = prevArgs + }) + + _, err := RequestDeviceAuthorization(httpmock.NewClient(reg), "cli_a", "secret_b", core.BrandFeishu, "", nil) + if err != nil { + t.Fatalf("RequestDeviceAuthorization() error: %v", err) + } + + got := buf.String() + if !strings.Contains(got, "time=2026-04-02T03:04:05Z") { + t.Fatalf("expected time in log, got %q", got) + } + if !strings.Contains(got, "path=miss") { + t.Fatalf("expected path in log, got %q", got) + } + if !strings.Contains(got, "status=200") { + t.Fatalf("expected status=200 in log, got %q", got) + } + if !strings.Contains(got, "x-tt-logid=device-log-id") { + t.Fatalf("expected x-tt-logid in log, got %q", got) + } + if !strings.Contains(got, "cmdline=lark-cli auth login") { + t.Fatalf("expected cmdline in log, got %q", got) + } +} diff --git a/internal/auth/paths.go b/internal/auth/paths.go new file mode 100644 index 000000000..2dc3b021f --- /dev/null +++ b/internal/auth/paths.go @@ -0,0 +1,16 @@ +// Copyright (c) 2026 Lark Technologies Pte. Ltd. +// SPDX-License-Identifier: MIT + +package auth + +const ( + PathDeviceAuthorization = "/oauth/v1/device_authorization" + PathAppRegistration = "/oauth/v1/app/registration" + PathOAuthTokenV2 = "/open-apis/authen/v2/oauth/token" + PathUserInfoV1 = "/open-apis/authen/v1/user_info" + PathApplicationInfoV6Prefix = "/open-apis/application/v6/applications/" +) + +func ApplicationInfoPath(appId string) string { + return PathApplicationInfoV6Prefix + appId +} diff --git a/internal/auth/uat_client.go b/internal/auth/uat_client.go index 133c9c7e1..1a2479246 100644 --- a/internal/auth/uat_client.go +++ b/internal/auth/uat_client.go @@ -200,6 +200,7 @@ func doRefreshToken(httpClient *http.Client, opts UATCallOptions, stored *Stored return nil, err } defer resp.Body.Close() + logAuthResponse(resp) body, err := io.ReadAll(resp.Body) if err != nil { diff --git a/internal/auth/verify.go b/internal/auth/verify.go index c10c9f81b..c50141f33 100644 --- a/internal/auth/verify.go +++ b/internal/auth/verify.go @@ -18,12 +18,13 @@ import ( func VerifyUserToken(ctx context.Context, sdk *lark.Client, accessToken string) error { apiResp, err := sdk.Do(ctx, &larkcore.ApiReq{ HttpMethod: http.MethodGet, - ApiPath: "/open-apis/authen/v1/user_info", + ApiPath: PathUserInfoV1, SupportedAccessTokenTypes: []larkcore.AccessTokenType{larkcore.AccessTokenTypeUser}, }, larkcore.WithUserAccessToken(accessToken)) if err != nil { return err } + logAuthResponse(sdkAuthResponse{PathUserInfoV1, apiResp}) var resp struct { Code int `json:"code"` diff --git a/internal/auth/verify_test.go b/internal/auth/verify_test.go index 507d221f3..f6578c8d5 100644 --- a/internal/auth/verify_test.go +++ b/internal/auth/verify_test.go @@ -4,9 +4,12 @@ package auth import ( + "bytes" "context" + "net/http" "strings" "testing" + "time" lark "github.com/larksuite/oapi-sdk-go/v3" larkcore "github.com/larksuite/oapi-sdk-go/v3/core" @@ -34,23 +37,27 @@ func TestVerifyUserToken(t *testing.T) { body interface{} wantErr bool errSubstr string + wantLog bool }{ { name: "success", body: map[string]interface{}{"code": 0, "msg": "ok"}, wantErr: false, + wantLog: true, }, { name: "token invalid", body: map[string]interface{}{"code": 99991668, "msg": "invalid token"}, wantErr: true, errSubstr: "[99991668]", + wantLog: true, }, { name: "non-JSON response", body: "not json", wantErr: true, errSubstr: "invalid character", + wantLog: false, }, } @@ -61,8 +68,12 @@ func TestVerifyUserToken(t *testing.T) { reg.Register(&httpmock.Stub{ Method: "GET", - URL: "/open-apis/authen/v1/user_info", + URL: PathUserInfoV1, Body: tt.body, + Headers: http.Header{ + "Content-Type": []string{"application/json"}, + "X-Tt-Logid": []string{"verify-log-id"}, + }, }) sdk := lark.NewClient("test-app", "test-secret", @@ -70,6 +81,23 @@ func TestVerifyUserToken(t *testing.T) { lark.WithHttpClient(httpmock.NewClient(reg)), ) + var buf bytes.Buffer + prevWriter := authResponseLogWriter + prevNow := authResponseLogNow + prevArgs := authResponseLogArgs + authResponseLogWriter = &buf + authResponseLogNow = func() time.Time { + return time.Date(2026, 4, 2, 3, 4, 5, 0, time.UTC) + } + authResponseLogArgs = func() []string { + return []string{"lark-cli", "auth", "status"} + } + t.Cleanup(func() { + authResponseLogWriter = prevWriter + authResponseLogNow = prevNow + authResponseLogArgs = prevArgs + }) + err := VerifyUserToken(context.Background(), sdk, "test-token") if tt.wantErr { if err == nil { @@ -83,6 +111,23 @@ func TestVerifyUserToken(t *testing.T) { t.Fatalf("unexpected error: %v", err) } } + got := buf.String() + if tt.wantLog { + if !strings.Contains(got, "path="+PathUserInfoV1) { + t.Fatalf("expected path in log, got %q", got) + } + if !strings.Contains(got, "status=200") { + t.Fatalf("expected status=200 in log, got %q", got) + } + if !strings.Contains(got, "x-tt-logid=verify-log-id") { + t.Fatalf("expected x-tt-logid in log, got %q", got) + } + if !strings.Contains(got, "cmdline=lark-cli auth status") { + t.Fatalf("expected cmdline in log, got %q", got) + } + } else if got != "" { + t.Fatalf("expected no log output, got %q", got) + } }) } } From 0f95cbe66f85218847e7696e2f3bc26fd6baa1ee Mon Sep 17 00:00:00 2001 From: zhaojunchang Date: Thu, 2 Apr 2026 20:18:52 +0800 Subject: [PATCH 02/16] refactor(auth): improve response logging and error handling --- internal/auth/app_registration.go | 4 +- internal/auth/auth_response_log.go | 90 +++++++++++++----------------- internal/auth/device_flow.go | 4 +- internal/auth/device_flow_test.go | 67 +++++++++++++++++++++- internal/auth/uat_client.go | 2 +- internal/auth/verify.go | 2 +- 6 files changed, 108 insertions(+), 61 deletions(-) diff --git a/internal/auth/app_registration.go b/internal/auth/app_registration.go index e06e6fec5..2bdf50fba 100644 --- a/internal/auth/app_registration.go +++ b/internal/auth/app_registration.go @@ -66,7 +66,7 @@ func RequestAppRegistration(httpClient *http.Client, brand core.LarkBrand, errOu return nil, err } defer resp.Body.Close() - logAuthResponse(resp) + logHTTPResponse(resp) body, err := io.ReadAll(resp.Body) if err != nil { @@ -163,7 +163,7 @@ func PollAppRegistration(ctx context.Context, httpClient *http.Client, brand cor currentInterval = minInt(currentInterval+1, maxPollInterval) continue } - logAuthResponse(resp) + logHTTPResponse(resp) body, err := io.ReadAll(resp.Body) resp.Body.Close() diff --git a/internal/auth/auth_response_log.go b/internal/auth/auth_response_log.go index 03419e859..ae1313a8b 100644 --- a/internal/auth/auth_response_log.go +++ b/internal/auth/auth_response_log.go @@ -53,9 +53,9 @@ func (defaultLogWriter) Write(p []byte) (n int, err error) { func cleanupOldLogs(dir string, now time.Time) { defer func() { if r := recover(); r != nil { - // Record the panic so we can debug without crashing the main program - msg := fmt.Sprintf("[lark-cli] [WARN] background log cleanup panicked: %v\n", r) - _, _ = authResponseLogWriter.Write([]byte(msg)) + // Record the panic so we can debug without crashing the main program. + // Do NOT use authResponseLogWriter here to avoid deadlocks or infinite loops. + fmt.Fprintf(os.Stderr, "[lark-cli] [WARN] background log cleanup panicked: %v\n", r) } }() @@ -86,70 +86,56 @@ func cleanupOldLogs(dir string, now time.Time) { } } -type authResponse interface { - logStatusCode() int - logHeader(key string) string - logPath() string -} - -type httpAuthResponse struct { - *http.Response -} +func formatAuthCmdline(args []string) string { + if len(args) == 0 { + return "" + } -func (r httpAuthResponse) logStatusCode() int { - return r.StatusCode -} + if len(args) <= 3 { + return strings.Join(args, " ") + } -func (r httpAuthResponse) logHeader(key string) string { - return r.Header.Get(key) + return strings.Join(args[:3], " ") + " ..." } -func (r httpAuthResponse) logPath() string { - if r.Request != nil && r.Request.URL != nil { - return r.Request.URL.Path +func doLogAuthResponse(path string, status int, logID string) { + if authResponseLogWriter == nil { + return } - return "miss" -} -type sdkAuthResponse struct { - path string - *larkcore.ApiResp + fmt.Fprintf( + authResponseLogWriter, + "[lark-cli] auth-response: time=%s path=%s status=%d x-tt-logid=%s cmdline=%s\n", + authResponseLogNow().Format(time.RFC3339Nano), + path, + status, + logID, + formatAuthCmdline(authResponseLogArgs()), + ) } -func (r sdkAuthResponse) logStatusCode() int { - return r.StatusCode -} +func logHTTPResponse(resp *http.Response) { + if resp == nil { + return + } -func (r sdkAuthResponse) logHeader(key string) string { - return r.Header.Get(key) -} + path := "missing" + if resp.Request != nil && resp.Request.URL != nil { + path = resp.Request.URL.Path + } -func (r sdkAuthResponse) logPath() string { - return r.path + doLogAuthResponse(path, resp.StatusCode, resp.Header.Get("x-tt-logid")) } -func logAuthResponse(resp interface{}) { - if authResponseLogWriter == nil || resp == nil { - return +func logSDKResponse(path string, apiResp *larkcore.ApiResp) { + if path == "" { + path = "missing" } - var r authResponse - switch v := resp.(type) { - case *http.Response: - r = httpAuthResponse{v} - case authResponse: - r = v - default: + if apiResp == nil { + doLogAuthResponse(path, 0, "") return } - fmt.Fprintf( - authResponseLogWriter, - "[lark-cli] auth-response: time=%s path=%s status=%d x-tt-logid=%s cmdline=%s\n", - authResponseLogNow().Format(time.RFC3339Nano), - r.logPath(), - r.logStatusCode(), - r.logHeader("x-tt-logid"), - strings.Join(authResponseLogArgs(), " "), - ) + doLogAuthResponse(path, apiResp.StatusCode, apiResp.Header.Get("x-tt-logid")) } diff --git a/internal/auth/device_flow.go b/internal/auth/device_flow.go index e21f972c0..37536c148 100644 --- a/internal/auth/device_flow.go +++ b/internal/auth/device_flow.go @@ -93,7 +93,7 @@ func RequestDeviceAuthorization(httpClient *http.Client, appId, appSecret string return nil, err } defer resp.Body.Close() - logAuthResponse(resp) + logHTTPResponse(resp) body, err := io.ReadAll(resp.Body) if err != nil { @@ -180,7 +180,7 @@ func PollDeviceToken(ctx context.Context, httpClient *http.Client, appId, appSec currentInterval = minInt(currentInterval+1, maxPollInterval) continue } - logAuthResponse(resp) + logHTTPResponse(resp) body, err := io.ReadAll(resp.Body) resp.Body.Close() diff --git a/internal/auth/device_flow_test.go b/internal/auth/device_flow_test.go index 2229485d2..9ab063a6c 100644 --- a/internal/auth/device_flow_test.go +++ b/internal/auth/device_flow_test.go @@ -64,7 +64,7 @@ func TestRequestDeviceAuthorization_LogsResponse(t *testing.T) { return time.Date(2026, 4, 2, 3, 4, 5, 0, time.UTC) } authResponseLogArgs = func() []string { - return []string{"lark-cli", "auth", "login"} + return []string{"lark-cli", "auth", "login", "--device-code", "device-code-secret", "--app-secret=top-secret"} } t.Cleanup(func() { authResponseLogWriter = prevWriter @@ -81,7 +81,7 @@ func TestRequestDeviceAuthorization_LogsResponse(t *testing.T) { if !strings.Contains(got, "time=2026-04-02T03:04:05Z") { t.Fatalf("expected time in log, got %q", got) } - if !strings.Contains(got, "path=miss") { + if !strings.Contains(got, "path=missing") { t.Fatalf("expected path in log, got %q", got) } if !strings.Contains(got, "status=200") { @@ -90,7 +90,68 @@ func TestRequestDeviceAuthorization_LogsResponse(t *testing.T) { if !strings.Contains(got, "x-tt-logid=device-log-id") { t.Fatalf("expected x-tt-logid in log, got %q", got) } - if !strings.Contains(got, "cmdline=lark-cli auth login") { + if !strings.Contains(got, "cmdline=lark-cli auth login ...") { t.Fatalf("expected cmdline in log, got %q", got) } } + +func TestFormatAuthCmdline_TruncatesExtraArgs(t *testing.T) { + got := formatAuthCmdline([]string{ + "lark-cli", + "auth", + "login", + "--device-code", "device-code-secret", + "--app-secret=top-secret", + "--scope", "contact:read", + }) + + want := "lark-cli auth login ..." + if got != want { + t.Fatalf("formatAuthCmdline() = %q, want %q", got, want) + } +} + +func TestLogAuthResponse_IgnoresTypedNilHTTPResponse(t *testing.T) { + var buf bytes.Buffer + prevWriter := authResponseLogWriter + authResponseLogWriter = &buf + t.Cleanup(func() { + authResponseLogWriter = prevWriter + }) + + var resp *http.Response + logHTTPResponse(resp) + + if got := buf.String(); got != "" { + t.Fatalf("expected no log output, got %q", got) + } +} + +func TestLogAuthResponse_HandlesNilSDKResponse(t *testing.T) { + var buf bytes.Buffer + prevWriter := authResponseLogWriter + prevNow := authResponseLogNow + prevArgs := authResponseLogArgs + authResponseLogWriter = &buf + authResponseLogNow = func() time.Time { + return time.Date(2026, 4, 2, 3, 4, 5, 0, time.UTC) + } + authResponseLogArgs = func() []string { + return []string{"lark-cli", "auth", "status", "--verify"} + } + t.Cleanup(func() { + authResponseLogWriter = prevWriter + authResponseLogNow = prevNow + authResponseLogArgs = prevArgs + }) + + logSDKResponse(PathUserInfoV1, nil) + + got := buf.String() + if !strings.Contains(got, "path="+PathUserInfoV1) { + t.Fatalf("expected sdk path in log, got %q", got) + } + if !strings.Contains(got, "status=0") { + t.Fatalf("expected zero status in log, got %q", got) + } +} diff --git a/internal/auth/uat_client.go b/internal/auth/uat_client.go index 1a2479246..9a4e7d487 100644 --- a/internal/auth/uat_client.go +++ b/internal/auth/uat_client.go @@ -200,7 +200,7 @@ func doRefreshToken(httpClient *http.Client, opts UATCallOptions, stored *Stored return nil, err } defer resp.Body.Close() - logAuthResponse(resp) + logHTTPResponse(resp) body, err := io.ReadAll(resp.Body) if err != nil { diff --git a/internal/auth/verify.go b/internal/auth/verify.go index c50141f33..403ad4481 100644 --- a/internal/auth/verify.go +++ b/internal/auth/verify.go @@ -24,7 +24,7 @@ func VerifyUserToken(ctx context.Context, sdk *lark.Client, accessToken string) if err != nil { return err } - logAuthResponse(sdkAuthResponse{PathUserInfoV1, apiResp}) + logSDKResponse(PathUserInfoV1, apiResp) var resp struct { Code int `json:"code"` From 581d6e117246080b9a00471639fcc8ab7ecab757 Mon Sep 17 00:00:00 2001 From: zhaojunchang Date: Thu, 2 Apr 2026 20:57:36 +0800 Subject: [PATCH 03/16] fix(auth): ensure log cleanup runs only once per process Add flag to track if cleanup has run and prevent duplicate executions Add test to verify cleanup only runs once --- internal/auth/auth_response_log.go | 15 ++++++--- internal/auth/device_flow_test.go | 50 ++++++++++++++++++++++++++++++ 2 files changed, 60 insertions(+), 5 deletions(-) diff --git a/internal/auth/auth_response_log.go b/internal/auth/auth_response_log.go index ae1313a8b..17c2a6aa0 100644 --- a/internal/auth/auth_response_log.go +++ b/internal/auth/auth_response_log.go @@ -15,9 +15,11 @@ import ( ) var ( - authResponseLogWriter io.Writer = defaultLogWriter{} - authResponseLogNow = time.Now - authResponseLogArgs = func() []string { return os.Args } + authResponseLogWriter io.Writer = defaultLogWriter{} + authResponseLogNow = time.Now + authResponseLogArgs = func() []string { return os.Args } + authResponseLogCleanup = cleanupOldLogs + authResponseLogCleaned bool logMu sync.Mutex ) @@ -44,8 +46,11 @@ func (defaultLogWriter) Write(p []byte) (n int, err error) { } defer f.Close() - // Clean up old logs (keep 7 days) - go cleanupOldLogs(dir, now) + // Best-effort cleanup: run at most once per process. + if !authResponseLogCleaned { + authResponseLogCleaned = true + go authResponseLogCleanup(dir, now) + } return f.Write(p) } diff --git a/internal/auth/device_flow_test.go b/internal/auth/device_flow_test.go index 9ab063a6c..c5a34faf0 100644 --- a/internal/auth/device_flow_test.go +++ b/internal/auth/device_flow_test.go @@ -6,6 +6,7 @@ package auth import ( "bytes" "net/http" + "path/filepath" "strings" "testing" "time" @@ -155,3 +156,52 @@ func TestLogAuthResponse_HandlesNilSDKResponse(t *testing.T) { t.Fatalf("expected zero status in log, got %q", got) } } + +func TestDefaultLogWriter_CleansUpAtMostOncePerProcess(t *testing.T) { + t.Setenv("LARKSUITE_CLI_CONFIG_DIR", t.TempDir()) + + prevNow := authResponseLogNow + prevCleanup := authResponseLogCleanup + prevCleanedFlag := authResponseLogCleaned + authResponseLogCleaned = false + cleanupCalls := 0 + + // Use a channel to wait for the async cleanup goroutine to finish in tests + done := make(chan struct{}, 1) + + authResponseLogCleanup = func(dir string, now time.Time) { + cleanupCalls++ + if dir != filepath.Join(core.GetConfigDir(), "logs") { + t.Errorf("cleanup dir = %q", dir) + } + done <- struct{}{} + } + t.Cleanup(func() { + authResponseLogNow = prevNow + authResponseLogCleanup = prevCleanup + authResponseLogCleaned = prevCleanedFlag + }) + + writer := defaultLogWriter{} + authResponseLogNow = func() time.Time { + return time.Date(2026, 4, 2, 3, 4, 5, 0, time.UTC) + } + + // First write should trigger async cleanup + if _, err := writer.Write([]byte("first\n")); err != nil { + t.Fatalf("first Write() error: %v", err) + } + <-done // Wait for the first async cleanup to finish + + // Second write should NOT trigger cleanup + if _, err := writer.Write([]byte("second\n")); err != nil { + t.Fatalf("second Write() error: %v", err) + } + + // Give it a tiny bit of time just to be absolutely sure no background routine was spawned + time.Sleep(10 * time.Millisecond) + + if cleanupCalls != 1 { + t.Fatalf("cleanupCalls = %d, want 1 (should only clean once per process)", cleanupCalls) + } +} From e7bd87a2b70cc644c2d9ee66306d9e8bd16fe641 Mon Sep 17 00:00:00 2001 From: zhaojunchang Date: Thu, 2 Apr 2026 21:46:06 +0800 Subject: [PATCH 04/16] refactor(auth): simplify log writer and cleanup logic --- internal/auth/auth_response_log.go | 44 ++++++++++++++-------------- internal/auth/device_flow_test.go | 47 ++++++++++-------------------- 2 files changed, 37 insertions(+), 54 deletions(-) diff --git a/internal/auth/auth_response_log.go b/internal/auth/auth_response_log.go index 17c2a6aa0..ec89886ec 100644 --- a/internal/auth/auth_response_log.go +++ b/internal/auth/auth_response_log.go @@ -19,7 +19,6 @@ var ( authResponseLogNow = time.Now authResponseLogArgs = func() []string { return os.Args } authResponseLogCleanup = cleanupOldLogs - authResponseLogCleaned bool logMu sync.Mutex ) @@ -27,32 +26,33 @@ var ( type defaultLogWriter struct{} func (defaultLogWriter) Write(p []byte) (n int, err error) { - logMu.Lock() - defer logMu.Unlock() - dir := filepath.Join(core.GetConfigDir(), "logs") - if err := os.MkdirAll(dir, 0700); err != nil { - return 0, err - } - - // Format: auth-2006-01-02.log now := authResponseLogNow() - logName := fmt.Sprintf("auth-%s.log", now.Format("2006-01-02")) - logPath := filepath.Join(dir, logName) - f, err := os.OpenFile(logPath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0600) - if err != nil { - return 0, err - } - defer f.Close() + n, err = func() (int, error) { + logMu.Lock() + defer logMu.Unlock() - // Best-effort cleanup: run at most once per process. - if !authResponseLogCleaned { - authResponseLogCleaned = true - go authResponseLogCleanup(dir, now) - } + if err := os.MkdirAll(dir, 0700); err != nil { + return 0, err + } + + // Format: auth-2006-01-02.log + logName := fmt.Sprintf("auth-%s.log", now.Format("2006-01-02")) + logPath := filepath.Join(dir, logName) + + f, err := os.OpenFile(logPath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0600) + if err != nil { + return 0, err + } + defer f.Close() + + return f.Write(p) + }() + + go authResponseLogCleanup(dir, now) - return f.Write(p) + return n, err } func cleanupOldLogs(dir string, now time.Time) { diff --git a/internal/auth/device_flow_test.go b/internal/auth/device_flow_test.go index c5a34faf0..a680c50b3 100644 --- a/internal/auth/device_flow_test.go +++ b/internal/auth/device_flow_test.go @@ -6,7 +6,6 @@ package auth import ( "bytes" "net/http" - "path/filepath" "strings" "testing" "time" @@ -157,51 +156,35 @@ func TestLogAuthResponse_HandlesNilSDKResponse(t *testing.T) { } } -func TestDefaultLogWriter_CleansUpAtMostOncePerProcess(t *testing.T) { +func TestDefaultLogWriter_ReleasesLockOnPanic(t *testing.T) { t.Setenv("LARKSUITE_CLI_CONFIG_DIR", t.TempDir()) prevNow := authResponseLogNow prevCleanup := authResponseLogCleanup - prevCleanedFlag := authResponseLogCleaned - authResponseLogCleaned = false - cleanupCalls := 0 - - // Use a channel to wait for the async cleanup goroutine to finish in tests - done := make(chan struct{}, 1) - - authResponseLogCleanup = func(dir string, now time.Time) { - cleanupCalls++ - if dir != filepath.Join(core.GetConfigDir(), "logs") { - t.Errorf("cleanup dir = %q", dir) - } - done <- struct{}{} - } + authResponseLogCleanup = func(dir string, now time.Time) {} t.Cleanup(func() { authResponseLogNow = prevNow authResponseLogCleanup = prevCleanup - authResponseLogCleaned = prevCleanedFlag }) writer := defaultLogWriter{} authResponseLogNow = func() time.Time { - return time.Date(2026, 4, 2, 3, 4, 5, 0, time.UTC) - } - - // First write should trigger async cleanup - if _, err := writer.Write([]byte("first\n")); err != nil { - t.Fatalf("first Write() error: %v", err) + panic("boom") } - <-done // Wait for the first async cleanup to finish - // Second write should NOT trigger cleanup + func() { + defer func() { + if r := recover(); r == nil { + t.Fatal("expected panic from authResponseLogNow") + } + }() + _, _ = writer.Write([]byte("first\n")) + }() + + authResponseLogNow = func() time.Time { + return time.Date(2026, 4, 2, 3, 4, 5, 0, time.UTC) + } if _, err := writer.Write([]byte("second\n")); err != nil { t.Fatalf("second Write() error: %v", err) } - - // Give it a tiny bit of time just to be absolutely sure no background routine was spawned - time.Sleep(10 * time.Millisecond) - - if cleanupCalls != 1 { - t.Fatalf("cleanupCalls = %d, want 1 (should only clean once per process)", cleanupCalls) - } } From 207eef40d5bf21999d4928a47a16bb37ccbdf35f Mon Sep 17 00:00:00 2001 From: zhaojunchang Date: Thu, 2 Apr 2026 22:19:52 +0800 Subject: [PATCH 05/16] docs(auth): add comments to auth paths and logging functions --- internal/auth/auth_response_log.go | 13 +++++++++++++ internal/auth/paths.go | 7 +++++++ 2 files changed, 20 insertions(+) diff --git a/internal/auth/auth_response_log.go b/internal/auth/auth_response_log.go index ec89886ec..3c01641f1 100644 --- a/internal/auth/auth_response_log.go +++ b/internal/auth/auth_response_log.go @@ -23,8 +23,11 @@ var ( logMu sync.Mutex ) +// defaultLogWriter is the default io.Writer implementation for authentication response logs. type defaultLogWriter struct{} +// Write appends the provided bytes to the daily log file in the configured logs directory. +// It also triggers a background cleanup of logs older than 7 days. func (defaultLogWriter) Write(p []byte) (n int, err error) { dir := filepath.Join(core.GetConfigDir(), "logs") now := authResponseLogNow() @@ -55,6 +58,8 @@ func (defaultLogWriter) Write(p []byte) (n int, err error) { return n, err } +// cleanupOldLogs removes authentication log files older than 7 days. +// It executes safely and catches panics to avoid crashing the main application. func cleanupOldLogs(dir string, now time.Time) { defer func() { if r := recover(); r != nil { @@ -91,6 +96,8 @@ func cleanupOldLogs(dir string, now time.Time) { } } +// formatAuthCmdline creates a safe representation of the command line arguments for logging. +// It limits the command to the first 3 arguments to avoid leaking sensitive information. func formatAuthCmdline(args []string) string { if len(args) == 0 { return "" @@ -103,6 +110,8 @@ func formatAuthCmdline(args []string) string { return strings.Join(args[:3], " ") + " ..." } +// doLogAuthResponse formats and writes a structured authentication log entry. +// It records the path, HTTP status code, request log ID, and the command line. func doLogAuthResponse(path string, status int, logID string) { if authResponseLogWriter == nil { return @@ -119,6 +128,8 @@ func doLogAuthResponse(path string, status int, logID string) { ) } +// logHTTPResponse logs the HTTP response details for an authentication request. +// It extracts the request path, status code, and x-tt-logid from the given HTTP response. func logHTTPResponse(resp *http.Response) { if resp == nil { return @@ -132,6 +143,8 @@ func logHTTPResponse(resp *http.Response) { doLogAuthResponse(path, resp.StatusCode, resp.Header.Get("x-tt-logid")) } +// logSDKResponse logs the SDK response details for an authentication request. +// It extracts the status code and x-tt-logid from the given API response object. func logSDKResponse(path string, apiResp *larkcore.ApiResp) { if path == "" { path = "missing" diff --git a/internal/auth/paths.go b/internal/auth/paths.go index 2dc3b021f..285179326 100644 --- a/internal/auth/paths.go +++ b/internal/auth/paths.go @@ -3,14 +3,21 @@ package auth +// Common authentication paths used for logging and API calls. const ( + // PathDeviceAuthorization is the endpoint for device authorization. PathDeviceAuthorization = "/oauth/v1/device_authorization" + // PathAppRegistration is the endpoint for application registration. PathAppRegistration = "/oauth/v1/app/registration" + // PathOAuthTokenV2 is the endpoint for requesting an OAuth token (v2). PathOAuthTokenV2 = "/open-apis/authen/v2/oauth/token" + // PathUserInfoV1 is the endpoint for fetching user information. PathUserInfoV1 = "/open-apis/authen/v1/user_info" + // PathApplicationInfoV6Prefix is the prefix endpoint for fetching application info. PathApplicationInfoV6Prefix = "/open-apis/application/v6/applications/" ) +// ApplicationInfoPath returns the full API path for querying an application's information. func ApplicationInfoPath(appId string) string { return PathApplicationInfoV6Prefix + appId } From 36d7589c6d6d2d73090a1de72986532534803684 Mon Sep 17 00:00:00 2001 From: zhaojunchang Date: Thu, 2 Apr 2026 22:26:26 +0800 Subject: [PATCH 06/16] style(auth): fix indentation in path constants --- internal/auth/paths.go | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/internal/auth/paths.go b/internal/auth/paths.go index 285179326..26441c640 100644 --- a/internal/auth/paths.go +++ b/internal/auth/paths.go @@ -6,13 +6,13 @@ package auth // Common authentication paths used for logging and API calls. const ( // PathDeviceAuthorization is the endpoint for device authorization. - PathDeviceAuthorization = "/oauth/v1/device_authorization" + PathDeviceAuthorization = "/oauth/v1/device_authorization" // PathAppRegistration is the endpoint for application registration. - PathAppRegistration = "/oauth/v1/app/registration" + PathAppRegistration = "/oauth/v1/app/registration" // PathOAuthTokenV2 is the endpoint for requesting an OAuth token (v2). - PathOAuthTokenV2 = "/open-apis/authen/v2/oauth/token" + PathOAuthTokenV2 = "/open-apis/authen/v2/oauth/token" // PathUserInfoV1 is the endpoint for fetching user information. - PathUserInfoV1 = "/open-apis/authen/v1/user_info" + PathUserInfoV1 = "/open-apis/authen/v1/user_info" // PathApplicationInfoV6Prefix is the prefix endpoint for fetching application info. PathApplicationInfoV6Prefix = "/open-apis/application/v6/applications/" ) From e22e3f342ce64fc2a6a3c2d215a35229ead72e52 Mon Sep 17 00:00:00 2001 From: zhaojunchang Date: Thu, 2 Apr 2026 22:52:18 +0800 Subject: [PATCH 07/16] docs(auth): add missing function comments across auth package --- internal/auth/device_flow.go | 3 +++ internal/auth/errors.go | 3 +++ internal/auth/token_store.go | 1 + internal/auth/transport.go | 4 ++++ internal/auth/uat_client.go | 3 +++ 5 files changed, 14 insertions(+) diff --git a/internal/auth/device_flow.go b/internal/auth/device_flow.go index 37536c148..7d2c8ca41 100644 --- a/internal/auth/device_flow.go +++ b/internal/auth/device_flow.go @@ -260,6 +260,7 @@ func PollDeviceToken(ctx context.Context, httpClient *http.Client, appId, appSec // helpers +// minInt returns the smaller of a or b. func minInt(a, b int) int { if a < b { return a @@ -267,6 +268,7 @@ func minInt(a, b int) int { return b } +// getStr retrieves a string value from a map, returning an empty string if not found or not a string. func getStr(m map[string]interface{}, key string) string { if v, ok := m[key]; ok { if s, ok := v.(string); ok { @@ -276,6 +278,7 @@ func getStr(m map[string]interface{}, key string) string { return "" } +// getInt retrieves an integer value from a map, returning a fallback value if not found or not a number. func getInt(m map[string]interface{}, key string, fallback int) int { if v, ok := m[key]; ok { switch n := v.(type) { diff --git a/internal/auth/errors.go b/internal/auth/errors.go index 76bd5995f..2a61eeab2 100644 --- a/internal/auth/errors.go +++ b/internal/auth/errors.go @@ -31,6 +31,7 @@ type NeedAuthorizationError struct { UserOpenId string } +// Error returns the error message for NeedAuthorizationError. func (e *NeedAuthorizationError) Error() string { return fmt.Sprintf("need_user_authorization (user: %s)", e.UserOpenId) } @@ -44,6 +45,7 @@ type SecurityPolicyError struct { Err error } +// Error returns the error message for SecurityPolicyError. func (e *SecurityPolicyError) Error() string { if e.Err != nil { return fmt.Sprintf("security policy error [%d]: %s: %v", e.Code, e.Message, e.Err) @@ -51,6 +53,7 @@ func (e *SecurityPolicyError) Error() string { return fmt.Sprintf("security policy error [%d]: %s", e.Code, e.Message) } +// Unwrap returns the underlying error. func (e *SecurityPolicyError) Unwrap() error { return e.Err } diff --git a/internal/auth/token_store.go b/internal/auth/token_store.go index 7e52f6704..bbf4b9875 100644 --- a/internal/auth/token_store.go +++ b/internal/auth/token_store.go @@ -25,6 +25,7 @@ type StoredUAToken struct { const refreshAheadMs = 5 * 60 * 1000 // 5 minutes +// accountKey generates a unique key for an account based on its AppID and UserOpenID. func accountKey(appId, userOpenId string) string { return fmt.Sprintf("%s:%s", appId, userOpenId) } diff --git a/internal/auth/transport.go b/internal/auth/transport.go index 2a1670499..4864cd23e 100644 --- a/internal/auth/transport.go +++ b/internal/auth/transport.go @@ -19,6 +19,7 @@ type SecurityPolicyTransport struct { Base http.RoundTripper } +// base returns the underlying RoundTripper or http.DefaultTransport if nil. func (t *SecurityPolicyTransport) base() http.RoundTripper { if t.Base != nil { return t.Base @@ -82,6 +83,7 @@ func (t *SecurityPolicyTransport) RoundTrip(req *http.Request) (*http.Response, return resp, nil } +// tryHandleMCPResponse attempts to parse a JSON-RPC (MCP) formatted error response. func (t *SecurityPolicyTransport) tryHandleMCPResponse(result map[string]interface{}) error { // MCP (JSON-RPC) response format: // { @@ -130,6 +132,7 @@ func (t *SecurityPolicyTransport) tryHandleMCPResponse(result map[string]interfa return nil } +// tryHandleOAPIResponse attempts to parse a standard Lark OpenAPI formatted error response. func (t *SecurityPolicyTransport) tryHandleOAPIResponse(result map[string]interface{}) error { // 1. Extract code code := getInt(result, "code", 0) @@ -180,6 +183,7 @@ func (t *SecurityPolicyTransport) tryHandleOAPIResponse(result map[string]interf return nil } +// isValidChallengeURL checks if the given URL is a valid challenge URL. func isValidChallengeURL(rawURL string) bool { if rawURL == "" { return false diff --git a/internal/auth/uat_client.go b/internal/auth/uat_client.go index 9a4e7d487..f04b61440 100644 --- a/internal/auth/uat_client.go +++ b/internal/auth/uat_client.go @@ -23,6 +23,7 @@ import ( var safeIDChars = regexp.MustCompile(`[^a-zA-Z0-9._-]`) +// sanitizeID replaces empty IDs with "default" to prevent file path issues. func sanitizeID(id string) string { return safeIDChars.ReplaceAllString(id, "_") } @@ -98,6 +99,7 @@ func GetValidAccessToken(httpClient *http.Client, opts UATCallOptions) (string, return "", &NeedAuthorizationError{UserOpenId: opts.UserOpenId} } +// refreshWithLock acquires a file lock before attempting to refresh the token. func refreshWithLock(httpClient *http.Client, opts UATCallOptions, stored *StoredUAToken) (*StoredUAToken, error) { key := fmt.Sprintf("%s:%s", opts.AppId, opts.UserOpenId) @@ -165,6 +167,7 @@ func refreshWithLock(httpClient *http.Client, opts UATCallOptions, stored *Store return doRefreshToken(httpClient, opts, stored) } +// doRefreshToken performs the actual HTTP request to refresh the token. func doRefreshToken(httpClient *http.Client, opts UATCallOptions, stored *StoredUAToken) (*StoredUAToken, error) { errOut := opts.ErrOut if errOut == nil { From 771be63240a765945e08bc1467371e5f4074432e Mon Sep 17 00:00:00 2001 From: zhaojunchang Date: Thu, 2 Apr 2026 23:02:07 +0800 Subject: [PATCH 08/16] docs(tests): add descriptive comments to auth test functions --- internal/auth/app_registration_test.go | 1 + internal/auth/device_flow_test.go | 7 +++++++ internal/auth/scope_test.go | 2 ++ internal/auth/uat_client_options_test.go | 1 + internal/auth/verify_test.go | 2 ++ 5 files changed, 13 insertions(+) diff --git a/internal/auth/app_registration_test.go b/internal/auth/app_registration_test.go index e706a8621..34466a48f 100644 --- a/internal/auth/app_registration_test.go +++ b/internal/auth/app_registration_test.go @@ -9,6 +9,7 @@ import ( "github.com/smartystreets/goconvey/convey" ) +// Test_BuildVerificationURL verifies that tracking parameters are correctly appended. func Test_BuildVerificationURL(t *testing.T) { t.Run("URL不含问号则添加?分隔符", func(t *testing.T) { result := BuildVerificationURL("https://example.com/verify", "1.0.0") diff --git a/internal/auth/device_flow_test.go b/internal/auth/device_flow_test.go index a680c50b3..6d81abc38 100644 --- a/internal/auth/device_flow_test.go +++ b/internal/auth/device_flow_test.go @@ -14,6 +14,7 @@ import ( "github.com/larksuite/cli/internal/httpmock" ) +// TestResolveOAuthEndpoints_Feishu validates endpoints for the Feishu brand. func TestResolveOAuthEndpoints_Feishu(t *testing.T) { ep := ResolveOAuthEndpoints(core.BrandFeishu) if ep.DeviceAuthorization != "https://accounts.feishu.cn/oauth/v1/device_authorization" { @@ -24,6 +25,7 @@ func TestResolveOAuthEndpoints_Feishu(t *testing.T) { } } +// TestResolveOAuthEndpoints_Lark validates endpoints for the Lark brand. func TestResolveOAuthEndpoints_Lark(t *testing.T) { ep := ResolveOAuthEndpoints(core.BrandLark) if ep.DeviceAuthorization != "https://accounts.larksuite.com/oauth/v1/device_authorization" { @@ -34,6 +36,7 @@ func TestResolveOAuthEndpoints_Lark(t *testing.T) { } } +// TestRequestDeviceAuthorization_LogsResponse checks if API responses are logged correctly. func TestRequestDeviceAuthorization_LogsResponse(t *testing.T) { reg := &httpmock.Registry{} t.Cleanup(func() { reg.Verify(t) }) @@ -95,6 +98,7 @@ func TestRequestDeviceAuthorization_LogsResponse(t *testing.T) { } } +// TestFormatAuthCmdline_TruncatesExtraArgs verifies that long command lines are truncated. func TestFormatAuthCmdline_TruncatesExtraArgs(t *testing.T) { got := formatAuthCmdline([]string{ "lark-cli", @@ -111,6 +115,7 @@ func TestFormatAuthCmdline_TruncatesExtraArgs(t *testing.T) { } } +// TestLogAuthResponse_IgnoresTypedNilHTTPResponse tests that a typed nil HTTP response is ignored gracefully. func TestLogAuthResponse_IgnoresTypedNilHTTPResponse(t *testing.T) { var buf bytes.Buffer prevWriter := authResponseLogWriter @@ -127,6 +132,7 @@ func TestLogAuthResponse_IgnoresTypedNilHTTPResponse(t *testing.T) { } } +// TestLogAuthResponse_HandlesNilSDKResponse verifies that a nil SDK response is handled without panicking. func TestLogAuthResponse_HandlesNilSDKResponse(t *testing.T) { var buf bytes.Buffer prevWriter := authResponseLogWriter @@ -156,6 +162,7 @@ func TestLogAuthResponse_HandlesNilSDKResponse(t *testing.T) { } } +// TestDefaultLogWriter_ReleasesLockOnPanic ensures log locks are released even if a panic occurs. func TestDefaultLogWriter_ReleasesLockOnPanic(t *testing.T) { t.Setenv("LARKSUITE_CLI_CONFIG_DIR", t.TempDir()) diff --git a/internal/auth/scope_test.go b/internal/auth/scope_test.go index b58d0b987..86f669f37 100644 --- a/internal/auth/scope_test.go +++ b/internal/auth/scope_test.go @@ -7,6 +7,7 @@ import ( "testing" ) +// TestMissingScopes tests the calculation of missing scopes. func TestMissingScopes(t *testing.T) { tests := []struct { name string @@ -62,6 +63,7 @@ func TestMissingScopes(t *testing.T) { } } +// sliceEqual compares two string slices for equality. func sliceEqual(a, b []string) bool { if len(a) == 0 && len(b) == 0 { return true diff --git a/internal/auth/uat_client_options_test.go b/internal/auth/uat_client_options_test.go index 2c7d26c16..d1f825773 100644 --- a/internal/auth/uat_client_options_test.go +++ b/internal/auth/uat_client_options_test.go @@ -10,6 +10,7 @@ import ( "github.com/larksuite/cli/internal/core" ) +// TestNewUATCallOptions validates the extraction of options from CLI config. func TestNewUATCallOptions(t *testing.T) { cfg := &core.CliConfig{ AppID: "app123", diff --git a/internal/auth/verify_test.go b/internal/auth/verify_test.go index f6578c8d5..88fa34365 100644 --- a/internal/auth/verify_test.go +++ b/internal/auth/verify_test.go @@ -17,6 +17,7 @@ import ( "github.com/larksuite/cli/internal/httpmock" ) +// TestVerifyUserToken_TransportError verifies handling of underlying transport errors. func TestVerifyUserToken_TransportError(t *testing.T) { reg := &httpmock.Registry{} // Register no stubs — any request will fail with "no stub" error @@ -31,6 +32,7 @@ func TestVerifyUserToken_TransportError(t *testing.T) { } } +// TestVerifyUserToken validates normal and error response paths of the user token validation. func TestVerifyUserToken(t *testing.T) { tests := []struct { name string From 4d2d38ab0ff191ae570cb7ce699db7f6542ad5a5 Mon Sep 17 00:00:00 2001 From: zhaojunchang Date: Thu, 2 Apr 2026 23:23:48 +0800 Subject: [PATCH 09/16] test(auth): rename test case and cleanup unused params --- internal/auth/device_flow_test.go | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/internal/auth/device_flow_test.go b/internal/auth/device_flow_test.go index 6d81abc38..3dcfc90b6 100644 --- a/internal/auth/device_flow_test.go +++ b/internal/auth/device_flow_test.go @@ -162,13 +162,13 @@ func TestLogAuthResponse_HandlesNilSDKResponse(t *testing.T) { } } -// TestDefaultLogWriter_ReleasesLockOnPanic ensures log locks are released even if a panic occurs. -func TestDefaultLogWriter_ReleasesLockOnPanic(t *testing.T) { +// TestDefaultLogWriter_PanicsBeforeLock ensures log code behaves correctly when panic occurs before the lock is acquired. +func TestDefaultLogWriter_PanicsBeforeLock(t *testing.T) { t.Setenv("LARKSUITE_CLI_CONFIG_DIR", t.TempDir()) prevNow := authResponseLogNow prevCleanup := authResponseLogCleanup - authResponseLogCleanup = func(dir string, now time.Time) {} + authResponseLogCleanup = func(_ string, _ time.Time) {} t.Cleanup(func() { authResponseLogNow = prevNow authResponseLogCleanup = prevCleanup From ce0760a93be19729e1a08b6f39c831f27a23584f Mon Sep 17 00:00:00 2001 From: zhaojunchang Date: Thu, 2 Apr 2026 23:26:43 +0800 Subject: [PATCH 10/16] fix(auth): handle file close error in auth response logging --- internal/auth/auth_response_log.go | 13 +++++++++---- 1 file changed, 9 insertions(+), 4 deletions(-) diff --git a/internal/auth/auth_response_log.go b/internal/auth/auth_response_log.go index 3c01641f1..19400485b 100644 --- a/internal/auth/auth_response_log.go +++ b/internal/auth/auth_response_log.go @@ -32,7 +32,7 @@ func (defaultLogWriter) Write(p []byte) (n int, err error) { dir := filepath.Join(core.GetConfigDir(), "logs") now := authResponseLogNow() - n, err = func() (int, error) { + n, err = func() (n int, writeErr error) { logMu.Lock() defer logMu.Unlock() @@ -48,9 +48,14 @@ func (defaultLogWriter) Write(p []byte) (n int, err error) { if err != nil { return 0, err } - defer f.Close() - - return f.Write(p) + defer func() { + if cerr := f.Close(); cerr != nil && writeErr == nil { + writeErr = cerr + } + }() + + n, writeErr = f.Write(p) + return n, writeErr }() go authResponseLogCleanup(dir, now) From bc5562682b4047e8876997abb57e1d9739efc066 Mon Sep 17 00:00:00 2001 From: zhaojunchang Date: Thu, 2 Apr 2026 23:37:01 +0800 Subject: [PATCH 11/16] fix(auth): ensure log cleanup runs only once --- internal/auth/auth_response_log.go | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-) diff --git a/internal/auth/auth_response_log.go b/internal/auth/auth_response_log.go index 19400485b..30eef9a13 100644 --- a/internal/auth/auth_response_log.go +++ b/internal/auth/auth_response_log.go @@ -20,7 +20,8 @@ var ( authResponseLogArgs = func() []string { return os.Args } authResponseLogCleanup = cleanupOldLogs - logMu sync.Mutex + logMu sync.Mutex + cleanupOnce sync.Once ) // defaultLogWriter is the default io.Writer implementation for authentication response logs. @@ -58,7 +59,9 @@ func (defaultLogWriter) Write(p []byte) (n int, err error) { return n, writeErr }() - go authResponseLogCleanup(dir, now) + cleanupOnce.Do(func() { + go authResponseLogCleanup(dir, now) + }) return n, err } From 5f4276cd05d3ccad8e2abe72f913d315c92ed205 Mon Sep 17 00:00:00 2001 From: zhaojunchang Date: Fri, 3 Apr 2026 11:15:48 +0800 Subject: [PATCH 12/16] refactor(auth): replace custom log writer with standard logger --- internal/auth/auth_response_log.go | 89 ++++++++++++------------------ internal/auth/device_flow_test.go | 53 ++++-------------- internal/auth/verify_test.go | 7 ++- 3 files changed, 49 insertions(+), 100 deletions(-) diff --git a/internal/auth/auth_response_log.go b/internal/auth/auth_response_log.go index 30eef9a13..60f057c63 100644 --- a/internal/auth/auth_response_log.go +++ b/internal/auth/auth_response_log.go @@ -2,7 +2,7 @@ package auth import ( "fmt" - "io" + "log" "net/http" "os" "path/filepath" @@ -15,64 +15,21 @@ import ( ) var ( - authResponseLogWriter io.Writer = defaultLogWriter{} - authResponseLogNow = time.Now - authResponseLogArgs = func() []string { return os.Args } - authResponseLogCleanup = cleanupOldLogs + authResponseLogger *log.Logger + authResponseLoggerOnce sync.Once - logMu sync.Mutex - cleanupOnce sync.Once + authResponseLogNow = time.Now + authResponseLogArgs = func() []string { return os.Args } + authResponseLogCleanup = cleanupOldLogs ) -// defaultLogWriter is the default io.Writer implementation for authentication response logs. -type defaultLogWriter struct{} - -// Write appends the provided bytes to the daily log file in the configured logs directory. -// It also triggers a background cleanup of logs older than 7 days. -func (defaultLogWriter) Write(p []byte) (n int, err error) { - dir := filepath.Join(core.GetConfigDir(), "logs") - now := authResponseLogNow() - - n, err = func() (n int, writeErr error) { - logMu.Lock() - defer logMu.Unlock() - - if err := os.MkdirAll(dir, 0700); err != nil { - return 0, err - } - - // Format: auth-2006-01-02.log - logName := fmt.Sprintf("auth-%s.log", now.Format("2006-01-02")) - logPath := filepath.Join(dir, logName) - - f, err := os.OpenFile(logPath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0600) - if err != nil { - return 0, err - } - defer func() { - if cerr := f.Close(); cerr != nil && writeErr == nil { - writeErr = cerr - } - }() - - n, writeErr = f.Write(p) - return n, writeErr - }() - - cleanupOnce.Do(func() { - go authResponseLogCleanup(dir, now) - }) - - return n, err -} - // cleanupOldLogs removes authentication log files older than 7 days. // It executes safely and catches panics to avoid crashing the main application. func cleanupOldLogs(dir string, now time.Time) { defer func() { if r := recover(); r != nil { // Record the panic so we can debug without crashing the main program. - // Do NOT use authResponseLogWriter here to avoid deadlocks or infinite loops. + // Do NOT use authResponseLogger here to avoid deadlocks or infinite loops. fmt.Fprintf(os.Stderr, "[lark-cli] [WARN] background log cleanup panicked: %v\n", r) } }() @@ -82,6 +39,8 @@ func cleanupOldLogs(dir string, now time.Time) { return } + // Calculate the start of the current day to ensure consistent day boundaries + now = time.Date(now.Year(), now.Month(), now.Day(), 0, 0, 0, 0, now.Location()) cutoff := now.AddDate(0, 0, -7) for _, entry := range entries { if entry.IsDir() || !strings.HasPrefix(entry.Name(), "auth-") || !strings.HasSuffix(entry.Name(), ".log") { @@ -92,11 +51,15 @@ func cleanupOldLogs(dir string, now time.Time) { dateStr := strings.TrimPrefix(entry.Name(), "auth-") dateStr = strings.TrimSuffix(dateStr, ".log") + // Log date is parsed as UTC midnight logDate, err := time.Parse("2006-01-02", dateStr) if err != nil { continue } + // Align logDate to the same location as now for accurate comparison + logDate = time.Date(logDate.Year(), logDate.Month(), logDate.Day(), 0, 0, 0, 0, now.Location()) + // If log is older than 7 days, delete it if logDate.Before(cutoff) { _ = os.Remove(filepath.Join(dir, entry.Name())) @@ -121,13 +84,31 @@ func formatAuthCmdline(args []string) string { // doLogAuthResponse formats and writes a structured authentication log entry. // It records the path, HTTP status code, request log ID, and the command line. func doLogAuthResponse(path string, status int, logID string) { - if authResponseLogWriter == nil { + authResponseLoggerOnce.Do(func() { + if authResponseLogger != nil { + return + } + + dir := filepath.Join(core.GetConfigDir(), "logs") + now := authResponseLogNow() + if err := os.MkdirAll(dir, 0700); err != nil { + return + } + + logName := fmt.Sprintf("auth-%s.log", now.Format("2006-01-02")) + logPath := filepath.Join(dir, logName) + if f, err := os.OpenFile(logPath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0600); err == nil { + authResponseLogger = log.New(f, "", 0) + go authResponseLogCleanup(dir, now) + } + }) + + if authResponseLogger == nil { return } - fmt.Fprintf( - authResponseLogWriter, - "[lark-cli] auth-response: time=%s path=%s status=%d x-tt-logid=%s cmdline=%s\n", + authResponseLogger.Printf( + "[lark-cli] auth-response: time=%s path=%s status=%d x-tt-logid=%s cmdline=%s", authResponseLogNow().Format(time.RFC3339Nano), path, status, diff --git a/internal/auth/device_flow_test.go b/internal/auth/device_flow_test.go index 3dcfc90b6..128dbb33c 100644 --- a/internal/auth/device_flow_test.go +++ b/internal/auth/device_flow_test.go @@ -5,6 +5,7 @@ package auth import ( "bytes" + "log" "net/http" "strings" "testing" @@ -59,10 +60,10 @@ func TestRequestDeviceAuthorization_LogsResponse(t *testing.T) { }) var buf bytes.Buffer - prevWriter := authResponseLogWriter + prevLogger := authResponseLogger prevNow := authResponseLogNow prevArgs := authResponseLogArgs - authResponseLogWriter = &buf + authResponseLogger = log.New(&buf, "", 0) authResponseLogNow = func() time.Time { return time.Date(2026, 4, 2, 3, 4, 5, 0, time.UTC) } @@ -70,7 +71,7 @@ func TestRequestDeviceAuthorization_LogsResponse(t *testing.T) { return []string{"lark-cli", "auth", "login", "--device-code", "device-code-secret", "--app-secret=top-secret"} } t.Cleanup(func() { - authResponseLogWriter = prevWriter + authResponseLogger = prevLogger authResponseLogNow = prevNow authResponseLogArgs = prevArgs }) @@ -118,10 +119,10 @@ func TestFormatAuthCmdline_TruncatesExtraArgs(t *testing.T) { // TestLogAuthResponse_IgnoresTypedNilHTTPResponse tests that a typed nil HTTP response is ignored gracefully. func TestLogAuthResponse_IgnoresTypedNilHTTPResponse(t *testing.T) { var buf bytes.Buffer - prevWriter := authResponseLogWriter - authResponseLogWriter = &buf + prevLogger := authResponseLogger + authResponseLogger = log.New(&buf, "", 0) t.Cleanup(func() { - authResponseLogWriter = prevWriter + authResponseLogger = prevLogger }) var resp *http.Response @@ -135,10 +136,10 @@ func TestLogAuthResponse_IgnoresTypedNilHTTPResponse(t *testing.T) { // TestLogAuthResponse_HandlesNilSDKResponse verifies that a nil SDK response is handled without panicking. func TestLogAuthResponse_HandlesNilSDKResponse(t *testing.T) { var buf bytes.Buffer - prevWriter := authResponseLogWriter + prevLogger := authResponseLogger prevNow := authResponseLogNow prevArgs := authResponseLogArgs - authResponseLogWriter = &buf + authResponseLogger = log.New(&buf, "", 0) authResponseLogNow = func() time.Time { return time.Date(2026, 4, 2, 3, 4, 5, 0, time.UTC) } @@ -146,7 +147,7 @@ func TestLogAuthResponse_HandlesNilSDKResponse(t *testing.T) { return []string{"lark-cli", "auth", "status", "--verify"} } t.Cleanup(func() { - authResponseLogWriter = prevWriter + authResponseLogger = prevLogger authResponseLogNow = prevNow authResponseLogArgs = prevArgs }) @@ -161,37 +162,3 @@ func TestLogAuthResponse_HandlesNilSDKResponse(t *testing.T) { t.Fatalf("expected zero status in log, got %q", got) } } - -// TestDefaultLogWriter_PanicsBeforeLock ensures log code behaves correctly when panic occurs before the lock is acquired. -func TestDefaultLogWriter_PanicsBeforeLock(t *testing.T) { - t.Setenv("LARKSUITE_CLI_CONFIG_DIR", t.TempDir()) - - prevNow := authResponseLogNow - prevCleanup := authResponseLogCleanup - authResponseLogCleanup = func(_ string, _ time.Time) {} - t.Cleanup(func() { - authResponseLogNow = prevNow - authResponseLogCleanup = prevCleanup - }) - - writer := defaultLogWriter{} - authResponseLogNow = func() time.Time { - panic("boom") - } - - func() { - defer func() { - if r := recover(); r == nil { - t.Fatal("expected panic from authResponseLogNow") - } - }() - _, _ = writer.Write([]byte("first\n")) - }() - - authResponseLogNow = func() time.Time { - return time.Date(2026, 4, 2, 3, 4, 5, 0, time.UTC) - } - if _, err := writer.Write([]byte("second\n")); err != nil { - t.Fatalf("second Write() error: %v", err) - } -} diff --git a/internal/auth/verify_test.go b/internal/auth/verify_test.go index 88fa34365..bcbaa93c1 100644 --- a/internal/auth/verify_test.go +++ b/internal/auth/verify_test.go @@ -6,6 +6,7 @@ package auth import ( "bytes" "context" + "log" "net/http" "strings" "testing" @@ -84,10 +85,10 @@ func TestVerifyUserToken(t *testing.T) { ) var buf bytes.Buffer - prevWriter := authResponseLogWriter + prevLogger := authResponseLogger prevNow := authResponseLogNow prevArgs := authResponseLogArgs - authResponseLogWriter = &buf + authResponseLogger = log.New(&buf, "", 0) authResponseLogNow = func() time.Time { return time.Date(2026, 4, 2, 3, 4, 5, 0, time.UTC) } @@ -95,7 +96,7 @@ func TestVerifyUserToken(t *testing.T) { return []string{"lark-cli", "auth", "status"} } t.Cleanup(func() { - authResponseLogWriter = prevWriter + authResponseLogger = prevLogger authResponseLogNow = prevNow authResponseLogArgs = prevArgs }) From 32b6ede67dcdb4a3d34d57e577d9375d4075e3dd Mon Sep 17 00:00:00 2001 From: zhaojunchang Date: Fri, 3 Apr 2026 12:51:09 +0800 Subject: [PATCH 13/16] feat(auth): add structured logging for keychain errors --- internal/auth/auth_response_log.go | 75 ++++++++++++++++++++++++++++++ internal/auth/device_flow_test.go | 40 ++++++++++++++++ internal/keychain/keychain.go | 29 ++++++++++-- 3 files changed, 141 insertions(+), 3 deletions(-) diff --git a/internal/auth/auth_response_log.go b/internal/auth/auth_response_log.go index 60f057c63..1c784002e 100644 --- a/internal/auth/auth_response_log.go +++ b/internal/auth/auth_response_log.go @@ -11,6 +11,7 @@ import ( "time" "github.com/larksuite/cli/internal/core" + "github.com/larksuite/cli/internal/keychain" larkcore "github.com/larksuite/oapi-sdk-go/v3/core" ) @@ -23,6 +24,10 @@ var ( authResponseLogCleanup = cleanupOldLogs ) +func init() { + RegisterKeychainLogger() +} + // cleanupOldLogs removes authentication log files older than 7 days. // It executes safely and catches panics to avoid crashing the main application. func cleanupOldLogs(dir string, now time.Time) { @@ -117,6 +122,76 @@ func doLogAuthResponse(path string, status int, logID string) { ) } +// logKeychainError logs keychain failures into the shared auth log for troubleshooting. +func logKeychainError(err error) { + if err == nil { + return + } + + doLogAuthError("keychain", parseKeychainErrorOp(err), err) +} + +// RegisterKeychainLogger sets up the keychain error logger callback to use our internal auth logger. +func RegisterKeychainLogger() { + keychain.RegisterAuthLogger(logKeychainError) +} + +func parseKeychainErrorOp(err error) string { + if err == nil { + return "unknown" + } + + const prefix = "keychain " + const marker = " error:" + msg := err.Error() + if !strings.HasPrefix(msg, prefix) { + return "unknown" + } + + rest := strings.TrimPrefix(msg, prefix) + op, _, ok := strings.Cut(rest, marker) + if !ok || op == "" { + return "unknown" + } + + return op +} + +// doLogAuthError formats and writes a structured auth error log entry. +func doLogAuthError(component, op string, err error) { + authResponseLoggerOnce.Do(func() { + if authResponseLogger != nil { + return + } + + dir := filepath.Join(core.GetConfigDir(), "logs") + now := authResponseLogNow() + if err := os.MkdirAll(dir, 0700); err != nil { + return + } + + logName := fmt.Sprintf("auth-%s.log", now.Format("2006-01-02")) + logPath := filepath.Join(dir, logName) + if f, err := os.OpenFile(logPath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0600); err == nil { + authResponseLogger = log.New(f, "", 0) + go authResponseLogCleanup(dir, now) + } + }) + + if authResponseLogger == nil { + return + } + + authResponseLogger.Printf( + "[lark-cli] auth-error: time=%s component=%s op=%s error=%q cmdline=%s", + authResponseLogNow().Format(time.RFC3339Nano), + component, + op, + err.Error(), + formatAuthCmdline(authResponseLogArgs()), + ) +} + // logHTTPResponse logs the HTTP response details for an authentication request. // It extracts the request path, status code, and x-tt-logid from the given HTTP response. func logHTTPResponse(resp *http.Response) { diff --git a/internal/auth/device_flow_test.go b/internal/auth/device_flow_test.go index 128dbb33c..9f2958d8b 100644 --- a/internal/auth/device_flow_test.go +++ b/internal/auth/device_flow_test.go @@ -5,6 +5,7 @@ package auth import ( "bytes" + "fmt" "log" "net/http" "strings" @@ -162,3 +163,42 @@ func TestLogAuthResponse_HandlesNilSDKResponse(t *testing.T) { t.Fatalf("expected zero status in log, got %q", got) } } + +// TestLogKeychainError_RecordsStructuredEntry verifies keychain failures are written to auth logs. +func TestLogKeychainError_RecordsStructuredEntry(t *testing.T) { + var buf bytes.Buffer + prevLogger := authResponseLogger + prevNow := authResponseLogNow + prevArgs := authResponseLogArgs + authResponseLogger = log.New(&buf, "", 0) + authResponseLogNow = func() time.Time { + return time.Date(2026, 4, 2, 3, 4, 5, 0, time.UTC) + } + authResponseLogArgs = func() []string { + return []string{"lark-cli", "auth", "login", "--device-code", "secret"} + } + t.Cleanup(func() { + authResponseLogger = prevLogger + authResponseLogNow = prevNow + authResponseLogArgs = prevArgs + }) + + logKeychainError(fmt.Errorf("keychain Set error: %w", http.ErrUseLastResponse)) + + got := buf.String() + if !strings.Contains(got, "auth-error") { + t.Fatalf("expected auth-error log entry, got %q", got) + } + if !strings.Contains(got, "component=keychain") { + t.Fatalf("expected component in log, got %q", got) + } + if !strings.Contains(got, "op=Set") { + t.Fatalf("expected op in log, got %q", got) + } + if !strings.Contains(got, "error=\"keychain Set error: net/http: use last response\"") { + t.Fatalf("expected quoted error in log, got %q", got) + } + if !strings.Contains(got, "cmdline=lark-cli auth login ...") { + t.Fatalf("expected truncated cmdline in log, got %q", got) + } +} diff --git a/internal/keychain/keychain.go b/internal/keychain/keychain.go index a5dc74b57..c8c21256a 100644 --- a/internal/keychain/keychain.go +++ b/internal/keychain/keychain.go @@ -12,7 +12,13 @@ import ( "github.com/larksuite/cli/internal/output" ) -var errNotInitialized = errors.New("keychain not initialized") +var ( + // ErrNotFound is returned when the requested credential is not found. + ErrNotFound = errors.New("keychain: item not found") + + // errNotInitialized is an internal error indicating the master key is missing or invalid. + errNotInitialized = errors.New("keychain not initialized") +) const ( // LarkCliService is the unified keychain service name for all secrets @@ -22,12 +28,21 @@ const ( LarkCliService = "lark-cli" ) +var authLogErrorFn func(error) + +// RegisterAuthLogger registers a callback function to log keychain errors. +// This is called by the auth package to avoid cyclic dependencies. +func RegisterAuthLogger(fn func(error)) { + authLogErrorFn = fn +} + // wrapError is a helper to wrap underlying errors into output.ExitError. // It formats the error message and provides a hint for troubleshooting keychain access issues. func wrapError(op string, err error) error { - if err == nil { - return nil + if err == nil || errors.Is(err, ErrNotFound) { + return err } + msg := fmt.Sprintf("keychain %s failed: %v", op, err) hint := "Check if the OS keychain/credential manager is locked or accessible. If running inside a sandbox or CI environment, please ensure the process has the necessary permissions to access the keychain." @@ -35,6 +50,14 @@ func wrapError(op string, err error) error { hint = "The keychain master key may have been cleaned up or deleted. Please reconfigure the CLI by running `lark-cli config init`." } + logger := authLogErrorFn + if logger != nil { + func() { + defer func() { recover() }() + logger(fmt.Errorf("keychain %s error: %w", op, err)) + }() + } + return output.ErrWithHint(output.ExitAPI, "config", msg, hint) } From ba689fdfef1c67b07d81aa41808994b80e4ed93e Mon Sep 17 00:00:00 2001 From: zhaojunchang Date: Fri, 3 Apr 2026 13:05:10 +0800 Subject: [PATCH 14/16] fix(auth): remove goroutine from auth log cleanup to prevent race condition --- internal/auth/auth_response_log.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/internal/auth/auth_response_log.go b/internal/auth/auth_response_log.go index 1c784002e..ede122526 100644 --- a/internal/auth/auth_response_log.go +++ b/internal/auth/auth_response_log.go @@ -104,7 +104,7 @@ func doLogAuthResponse(path string, status int, logID string) { logPath := filepath.Join(dir, logName) if f, err := os.OpenFile(logPath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0600); err == nil { authResponseLogger = log.New(f, "", 0) - go authResponseLogCleanup(dir, now) + authResponseLogCleanup(dir, now) } }) From d7651b88703a5a97cd3eb933ad76971612bc45ec Mon Sep 17 00:00:00 2001 From: zhaojunchang Date: Fri, 3 Apr 2026 14:18:37 +0800 Subject: [PATCH 15/16] fix(auth): remove goroutine from auth log cleanup to prevent race condition --- internal/auth/auth_response_log.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/internal/auth/auth_response_log.go b/internal/auth/auth_response_log.go index ede122526..6db00aa58 100644 --- a/internal/auth/auth_response_log.go +++ b/internal/auth/auth_response_log.go @@ -174,7 +174,7 @@ func doLogAuthError(component, op string, err error) { logPath := filepath.Join(dir, logName) if f, err := os.OpenFile(logPath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0600); err == nil { authResponseLogger = log.New(f, "", 0) - go authResponseLogCleanup(dir, now) + authResponseLogCleanup(dir, now) } }) From 4be056571a0760fbaf70d8b69f1244c19d503305 Mon Sep 17 00:00:00 2001 From: zhaojunchang Date: Fri, 3 Apr 2026 15:26:28 +0800 Subject: [PATCH 16/16] refactor(auth): move auth logging logic to keychain package --- internal/auth/auth_response_log.go | 191 +---------------------------- internal/auth/device_flow_test.go | 60 +++------ internal/auth/verify_test.go | 16 +-- internal/keychain/auth_log.go | 159 ++++++++++++++++++++++++ internal/keychain/keychain.go | 19 +-- 5 files changed, 185 insertions(+), 260 deletions(-) create mode 100644 internal/keychain/auth_log.go diff --git a/internal/auth/auth_response_log.go b/internal/auth/auth_response_log.go index 6db00aa58..0695027e5 100644 --- a/internal/auth/auth_response_log.go +++ b/internal/auth/auth_response_log.go @@ -1,197 +1,12 @@ package auth import ( - "fmt" - "log" "net/http" - "os" - "path/filepath" - "strings" - "sync" - "time" - "github.com/larksuite/cli/internal/core" "github.com/larksuite/cli/internal/keychain" larkcore "github.com/larksuite/oapi-sdk-go/v3/core" ) -var ( - authResponseLogger *log.Logger - authResponseLoggerOnce sync.Once - - authResponseLogNow = time.Now - authResponseLogArgs = func() []string { return os.Args } - authResponseLogCleanup = cleanupOldLogs -) - -func init() { - RegisterKeychainLogger() -} - -// cleanupOldLogs removes authentication log files older than 7 days. -// It executes safely and catches panics to avoid crashing the main application. -func cleanupOldLogs(dir string, now time.Time) { - defer func() { - if r := recover(); r != nil { - // Record the panic so we can debug without crashing the main program. - // Do NOT use authResponseLogger here to avoid deadlocks or infinite loops. - fmt.Fprintf(os.Stderr, "[lark-cli] [WARN] background log cleanup panicked: %v\n", r) - } - }() - - entries, err := os.ReadDir(dir) - if err != nil { - return - } - - // Calculate the start of the current day to ensure consistent day boundaries - now = time.Date(now.Year(), now.Month(), now.Day(), 0, 0, 0, 0, now.Location()) - cutoff := now.AddDate(0, 0, -7) - for _, entry := range entries { - if entry.IsDir() || !strings.HasPrefix(entry.Name(), "auth-") || !strings.HasSuffix(entry.Name(), ".log") { - continue - } - - // Extract date from filename - dateStr := strings.TrimPrefix(entry.Name(), "auth-") - dateStr = strings.TrimSuffix(dateStr, ".log") - - // Log date is parsed as UTC midnight - logDate, err := time.Parse("2006-01-02", dateStr) - if err != nil { - continue - } - - // Align logDate to the same location as now for accurate comparison - logDate = time.Date(logDate.Year(), logDate.Month(), logDate.Day(), 0, 0, 0, 0, now.Location()) - - // If log is older than 7 days, delete it - if logDate.Before(cutoff) { - _ = os.Remove(filepath.Join(dir, entry.Name())) - } - } -} - -// formatAuthCmdline creates a safe representation of the command line arguments for logging. -// It limits the command to the first 3 arguments to avoid leaking sensitive information. -func formatAuthCmdline(args []string) string { - if len(args) == 0 { - return "" - } - - if len(args) <= 3 { - return strings.Join(args, " ") - } - - return strings.Join(args[:3], " ") + " ..." -} - -// doLogAuthResponse formats and writes a structured authentication log entry. -// It records the path, HTTP status code, request log ID, and the command line. -func doLogAuthResponse(path string, status int, logID string) { - authResponseLoggerOnce.Do(func() { - if authResponseLogger != nil { - return - } - - dir := filepath.Join(core.GetConfigDir(), "logs") - now := authResponseLogNow() - if err := os.MkdirAll(dir, 0700); err != nil { - return - } - - logName := fmt.Sprintf("auth-%s.log", now.Format("2006-01-02")) - logPath := filepath.Join(dir, logName) - if f, err := os.OpenFile(logPath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0600); err == nil { - authResponseLogger = log.New(f, "", 0) - authResponseLogCleanup(dir, now) - } - }) - - if authResponseLogger == nil { - return - } - - authResponseLogger.Printf( - "[lark-cli] auth-response: time=%s path=%s status=%d x-tt-logid=%s cmdline=%s", - authResponseLogNow().Format(time.RFC3339Nano), - path, - status, - logID, - formatAuthCmdline(authResponseLogArgs()), - ) -} - -// logKeychainError logs keychain failures into the shared auth log for troubleshooting. -func logKeychainError(err error) { - if err == nil { - return - } - - doLogAuthError("keychain", parseKeychainErrorOp(err), err) -} - -// RegisterKeychainLogger sets up the keychain error logger callback to use our internal auth logger. -func RegisterKeychainLogger() { - keychain.RegisterAuthLogger(logKeychainError) -} - -func parseKeychainErrorOp(err error) string { - if err == nil { - return "unknown" - } - - const prefix = "keychain " - const marker = " error:" - msg := err.Error() - if !strings.HasPrefix(msg, prefix) { - return "unknown" - } - - rest := strings.TrimPrefix(msg, prefix) - op, _, ok := strings.Cut(rest, marker) - if !ok || op == "" { - return "unknown" - } - - return op -} - -// doLogAuthError formats and writes a structured auth error log entry. -func doLogAuthError(component, op string, err error) { - authResponseLoggerOnce.Do(func() { - if authResponseLogger != nil { - return - } - - dir := filepath.Join(core.GetConfigDir(), "logs") - now := authResponseLogNow() - if err := os.MkdirAll(dir, 0700); err != nil { - return - } - - logName := fmt.Sprintf("auth-%s.log", now.Format("2006-01-02")) - logPath := filepath.Join(dir, logName) - if f, err := os.OpenFile(logPath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0600); err == nil { - authResponseLogger = log.New(f, "", 0) - authResponseLogCleanup(dir, now) - } - }) - - if authResponseLogger == nil { - return - } - - authResponseLogger.Printf( - "[lark-cli] auth-error: time=%s component=%s op=%s error=%q cmdline=%s", - authResponseLogNow().Format(time.RFC3339Nano), - component, - op, - err.Error(), - formatAuthCmdline(authResponseLogArgs()), - ) -} - // logHTTPResponse logs the HTTP response details for an authentication request. // It extracts the request path, status code, and x-tt-logid from the given HTTP response. func logHTTPResponse(resp *http.Response) { @@ -204,7 +19,7 @@ func logHTTPResponse(resp *http.Response) { path = resp.Request.URL.Path } - doLogAuthResponse(path, resp.StatusCode, resp.Header.Get("x-tt-logid")) + keychain.LogAuthResponse(path, resp.StatusCode, resp.Header.Get("x-tt-logid")) } // logSDKResponse logs the SDK response details for an authentication request. @@ -215,9 +30,9 @@ func logSDKResponse(path string, apiResp *larkcore.ApiResp) { } if apiResp == nil { - doLogAuthResponse(path, 0, "") + keychain.LogAuthResponse(path, 0, "") return } - doLogAuthResponse(path, apiResp.StatusCode, apiResp.Header.Get("x-tt-logid")) + keychain.LogAuthResponse(path, apiResp.StatusCode, apiResp.Header.Get("x-tt-logid")) } diff --git a/internal/auth/device_flow_test.go b/internal/auth/device_flow_test.go index 9f2958d8b..5493220af 100644 --- a/internal/auth/device_flow_test.go +++ b/internal/auth/device_flow_test.go @@ -14,6 +14,7 @@ import ( "github.com/larksuite/cli/internal/core" "github.com/larksuite/cli/internal/httpmock" + "github.com/larksuite/cli/internal/keychain" ) // TestResolveOAuthEndpoints_Feishu validates endpoints for the Feishu brand. @@ -61,21 +62,12 @@ func TestRequestDeviceAuthorization_LogsResponse(t *testing.T) { }) var buf bytes.Buffer - prevLogger := authResponseLogger - prevNow := authResponseLogNow - prevArgs := authResponseLogArgs - authResponseLogger = log.New(&buf, "", 0) - authResponseLogNow = func() time.Time { + restore := keychain.SetAuthLogHooksForTest(log.New(&buf, "", 0), func() time.Time { return time.Date(2026, 4, 2, 3, 4, 5, 0, time.UTC) - } - authResponseLogArgs = func() []string { + }, func() []string { return []string{"lark-cli", "auth", "login", "--device-code", "device-code-secret", "--app-secret=top-secret"} - } - t.Cleanup(func() { - authResponseLogger = prevLogger - authResponseLogNow = prevNow - authResponseLogArgs = prevArgs }) + t.Cleanup(restore) _, err := RequestDeviceAuthorization(httpmock.NewClient(reg), "cli_a", "secret_b", core.BrandFeishu, "", nil) if err != nil { @@ -102,7 +94,7 @@ func TestRequestDeviceAuthorization_LogsResponse(t *testing.T) { // TestFormatAuthCmdline_TruncatesExtraArgs verifies that long command lines are truncated. func TestFormatAuthCmdline_TruncatesExtraArgs(t *testing.T) { - got := formatAuthCmdline([]string{ + got := keychain.FormatAuthCmdline([]string{ "lark-cli", "auth", "login", @@ -120,11 +112,8 @@ func TestFormatAuthCmdline_TruncatesExtraArgs(t *testing.T) { // TestLogAuthResponse_IgnoresTypedNilHTTPResponse tests that a typed nil HTTP response is ignored gracefully. func TestLogAuthResponse_IgnoresTypedNilHTTPResponse(t *testing.T) { var buf bytes.Buffer - prevLogger := authResponseLogger - authResponseLogger = log.New(&buf, "", 0) - t.Cleanup(func() { - authResponseLogger = prevLogger - }) + restore := keychain.SetAuthLogHooksForTest(log.New(&buf, "", 0), nil, nil) + t.Cleanup(restore) var resp *http.Response logHTTPResponse(resp) @@ -137,21 +126,12 @@ func TestLogAuthResponse_IgnoresTypedNilHTTPResponse(t *testing.T) { // TestLogAuthResponse_HandlesNilSDKResponse verifies that a nil SDK response is handled without panicking. func TestLogAuthResponse_HandlesNilSDKResponse(t *testing.T) { var buf bytes.Buffer - prevLogger := authResponseLogger - prevNow := authResponseLogNow - prevArgs := authResponseLogArgs - authResponseLogger = log.New(&buf, "", 0) - authResponseLogNow = func() time.Time { + restore := keychain.SetAuthLogHooksForTest(log.New(&buf, "", 0), func() time.Time { return time.Date(2026, 4, 2, 3, 4, 5, 0, time.UTC) - } - authResponseLogArgs = func() []string { + }, func() []string { return []string{"lark-cli", "auth", "status", "--verify"} - } - t.Cleanup(func() { - authResponseLogger = prevLogger - authResponseLogNow = prevNow - authResponseLogArgs = prevArgs }) + t.Cleanup(restore) logSDKResponse(PathUserInfoV1, nil) @@ -164,26 +144,16 @@ func TestLogAuthResponse_HandlesNilSDKResponse(t *testing.T) { } } -// TestLogKeychainError_RecordsStructuredEntry verifies keychain failures are written to auth logs. -func TestLogKeychainError_RecordsStructuredEntry(t *testing.T) { +func TestLogAuthError_RecordsStructuredEntry(t *testing.T) { var buf bytes.Buffer - prevLogger := authResponseLogger - prevNow := authResponseLogNow - prevArgs := authResponseLogArgs - authResponseLogger = log.New(&buf, "", 0) - authResponseLogNow = func() time.Time { + restore := keychain.SetAuthLogHooksForTest(log.New(&buf, "", 0), func() time.Time { return time.Date(2026, 4, 2, 3, 4, 5, 0, time.UTC) - } - authResponseLogArgs = func() []string { + }, func() []string { return []string{"lark-cli", "auth", "login", "--device-code", "secret"} - } - t.Cleanup(func() { - authResponseLogger = prevLogger - authResponseLogNow = prevNow - authResponseLogArgs = prevArgs }) + t.Cleanup(restore) - logKeychainError(fmt.Errorf("keychain Set error: %w", http.ErrUseLastResponse)) + keychain.LogAuthError("keychain", "Set", fmt.Errorf("keychain Set error: %w", http.ErrUseLastResponse)) got := buf.String() if !strings.Contains(got, "auth-error") { diff --git a/internal/auth/verify_test.go b/internal/auth/verify_test.go index bcbaa93c1..d513a66a3 100644 --- a/internal/auth/verify_test.go +++ b/internal/auth/verify_test.go @@ -12,6 +12,7 @@ import ( "testing" "time" + "github.com/larksuite/cli/internal/keychain" lark "github.com/larksuite/oapi-sdk-go/v3" larkcore "github.com/larksuite/oapi-sdk-go/v3/core" @@ -85,21 +86,12 @@ func TestVerifyUserToken(t *testing.T) { ) var buf bytes.Buffer - prevLogger := authResponseLogger - prevNow := authResponseLogNow - prevArgs := authResponseLogArgs - authResponseLogger = log.New(&buf, "", 0) - authResponseLogNow = func() time.Time { + restore := keychain.SetAuthLogHooksForTest(log.New(&buf, "", 0), func() time.Time { return time.Date(2026, 4, 2, 3, 4, 5, 0, time.UTC) - } - authResponseLogArgs = func() []string { + }, func() []string { return []string{"lark-cli", "auth", "status"} - } - t.Cleanup(func() { - authResponseLogger = prevLogger - authResponseLogNow = prevNow - authResponseLogArgs = prevArgs }) + t.Cleanup(restore) err := VerifyUserToken(context.Background(), sdk, "test-token") if tt.wantErr { diff --git a/internal/keychain/auth_log.go b/internal/keychain/auth_log.go new file mode 100644 index 000000000..64558bd93 --- /dev/null +++ b/internal/keychain/auth_log.go @@ -0,0 +1,159 @@ +package keychain + +import ( + "fmt" + "log" + "os" + "path/filepath" + "strings" + "sync" + "time" +) + +var ( + authResponseLogger *log.Logger + authResponseLoggerOnce = &sync.Once{} + + authResponseLogNow = time.Now + authResponseLogArgs = func() []string { return os.Args } +) + +func authLogDir() string { + if dir := os.Getenv("LARKSUITE_CLI_CONFIG_DIR"); dir != "" { + return filepath.Join(dir, "logs") + } + + home, err := os.UserHomeDir() + if err != nil || home == "" { + fmt.Fprintf(os.Stderr, "warning: unable to determine home directory: %v\n", err) + } + + return filepath.Join(home, ".lark-cli", "logs") +} + +func initAuthLogger() { + authResponseLoggerOnce.Do(func() { + if authResponseLogger != nil { + return + } + + dir := authLogDir() + now := authResponseLogNow() + if err := os.MkdirAll(dir, 0700); err != nil { + return + } + + logName := fmt.Sprintf("auth-%s.log", now.Format("2006-01-02")) + logPath := filepath.Join(dir, logName) + if f, err := os.OpenFile(logPath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0600); err == nil { + authResponseLogger = log.New(f, "", 0) + cleanupOldLogs(dir, now) + } + }) +} + +func FormatAuthCmdline(args []string) string { + if len(args) == 0 { + return "" + } + + if len(args) <= 3 { + return strings.Join(args, " ") + } + + return strings.Join(args[:3], " ") + " ..." +} + +func LogAuthResponse(path string, status int, logID string) { + initAuthLogger() + if authResponseLogger == nil { + return + } + + authResponseLogger.Printf( + "[lark-cli] auth-response: time=%s path=%s status=%d x-tt-logid=%s cmdline=%s", + authResponseLogNow().Format(time.RFC3339Nano), + path, + status, + logID, + FormatAuthCmdline(authResponseLogArgs()), + ) +} + +func LogAuthError(component, op string, err error) { + if err == nil { + return + } + + initAuthLogger() + if authResponseLogger == nil { + return + } + + authResponseLogger.Printf( + "[lark-cli] auth-error: time=%s component=%s op=%s error=%q cmdline=%s", + authResponseLogNow().Format(time.RFC3339Nano), + component, + op, + err.Error(), + FormatAuthCmdline(authResponseLogArgs()), + ) +} + +func SetAuthLogHooksForTest(logger *log.Logger, now func() time.Time, args func() []string) func() { + prevLogger := authResponseLogger + prevNow := authResponseLogNow + prevArgs := authResponseLogArgs + prevOnce := authResponseLoggerOnce + + authResponseLogger = logger + authResponseLoggerOnce = &sync.Once{} + + if now != nil { + authResponseLogNow = now + } + if args != nil { + authResponseLogArgs = args + } + + return func() { + authResponseLogger = prevLogger + authResponseLogNow = prevNow + authResponseLogArgs = prevArgs + authResponseLoggerOnce = prevOnce + } +} + +func cleanupOldLogs(dir string, now time.Time) { + defer func() { + if r := recover(); r != nil { + fmt.Fprintf(os.Stderr, "[lark-cli] [WARN] background log cleanup panicked: %v\n", r) + } + }() + + entries, err := os.ReadDir(dir) + if err != nil { + return + } + + now = time.Date(now.Year(), now.Month(), now.Day(), 0, 0, 0, 0, now.Location()) + cutoff := now.AddDate(0, 0, -7) + for _, entry := range entries { + if entry.IsDir() || !strings.HasPrefix(entry.Name(), "auth-") || !strings.HasSuffix(entry.Name(), ".log") { + continue + } + + dateStr := strings.TrimPrefix(entry.Name(), "auth-") + dateStr = strings.TrimSuffix(dateStr, ".log") + + logDate, err := time.Parse("2006-01-02", dateStr) + if err != nil { + continue + } + + logDate = time.Date(logDate.Year(), logDate.Month(), logDate.Day(), 0, 0, 0, 0, now.Location()) + if logDate.Before(cutoff) { + _ = os.Remove(filepath.Join(dir, entry.Name())) + } + } +} diff --git a/internal/keychain/keychain.go b/internal/keychain/keychain.go index c8c21256a..187184593 100644 --- a/internal/keychain/keychain.go +++ b/internal/keychain/keychain.go @@ -28,14 +28,6 @@ const ( LarkCliService = "lark-cli" ) -var authLogErrorFn func(error) - -// RegisterAuthLogger registers a callback function to log keychain errors. -// This is called by the auth package to avoid cyclic dependencies. -func RegisterAuthLogger(fn func(error)) { - authLogErrorFn = fn -} - // wrapError is a helper to wrap underlying errors into output.ExitError. // It formats the error message and provides a hint for troubleshooting keychain access issues. func wrapError(op string, err error) error { @@ -50,13 +42,10 @@ func wrapError(op string, err error) error { hint = "The keychain master key may have been cleaned up or deleted. Please reconfigure the CLI by running `lark-cli config init`." } - logger := authLogErrorFn - if logger != nil { - func() { - defer func() { recover() }() - logger(fmt.Errorf("keychain %s error: %w", op, err)) - }() - } + func() { + defer func() { recover() }() + LogAuthError("keychain", op, fmt.Errorf("keychain %s error: %w", op, err)) + }() return output.ErrWithHint(output.ExitAPI, "config", msg, hint) }