diff --git a/cmd/config/init.go b/cmd/config/init.go index 3fc56c725..57bc66428 100644 --- a/cmd/config/init.go +++ b/cmd/config/init.go @@ -245,6 +245,9 @@ func updateExistingProfileWithoutSecret(existing *core.MultiAppConfig, profileNa func configInitRun(opts *ConfigInitOptions) error { f := opts.Factory + keychain.SuppressKeychainReadErrorTracking(true) + defer keychain.SuppressKeychainReadErrorTracking(false) + // Read secret from stdin if --app-secret-stdin is set if opts.AppSecretStdin { scanner := bufio.NewScanner(f.IOStreams.In) diff --git a/cmd/error_auth_hint.go b/cmd/error_auth_hint.go index 0450402f9..ba15975cd 100644 --- a/cmd/error_auth_hint.go +++ b/cmd/error_auth_hint.go @@ -4,14 +4,18 @@ package cmd import ( + "errors" "fmt" "strings" + "time" internalauth "github.com/larksuite/cli/internal/auth" "github.com/larksuite/cli/internal/cmdutil" "github.com/larksuite/cli/internal/core" + "github.com/larksuite/cli/internal/credential" "github.com/larksuite/cli/internal/output" "github.com/larksuite/cli/internal/registry" + "github.com/larksuite/cli/internal/tracking" "github.com/larksuite/cli/shortcuts" shortcutcommon "github.com/larksuite/cli/shortcuts/common" "github.com/spf13/cobra" @@ -20,10 +24,14 @@ import ( // enrichMissingScopeError preserves the original need_user_authorization // message and appends a scope hint when the current command declares the // required scopes locally. +// It also logs the auth failure reason using tracking.LogAuthError. func enrichMissingScopeError(f *cmdutil.Factory, exitErr *output.ExitError) { if exitErr == nil || exitErr.Detail == nil { return } + + logAuthFailureReason(exitErr) + if !internalauth.IsNeedUserAuthorizationError(exitErr) { return } @@ -41,6 +49,97 @@ func enrichMissingScopeError(f *cmdutil.Factory, exitErr *output.ExitError) { exitErr.Detail.Hint += "\n" + scopeHint } +// logSecurityPolicyError logs a security policy error using tracking.LogAuthError. +func logSecurityPolicyError(spErr *internalauth.SecurityPolicyError) { + codeStr := securityPolicyCodeString(spErr.Code) + errMsg := fmt.Sprintf("reason=security_policy code=%s message=%q", codeStr, spErr.Message) + tracking.LogAuthError(tracking.AuthComponentAuth, tracking.AuthOpSecurityPolicy, fmt.Errorf(errMsg)) +} + +// logRawAuthFailure logs auth-related failures for Raw errors (e.g. from `api` command). +// This preserves the original API error detail while still logging auth failures. +func logRawAuthFailure(exitErr *output.ExitError) { + if exitErr.Detail == nil { + return + } + + if exitErr.Detail.Type == "permission" { + errMsg := fmt.Sprintf("reason=permission_denied code=%d message=%q", exitErr.Detail.Code, exitErr.Detail.Message) + tracking.LogAuthError(tracking.AuthComponentAuth, tracking.AuthOpPermissionDenied, fmt.Errorf(errMsg)) + return + } + + if exitErr.Detail.Type == "auth" { + errMsg := fmt.Sprintf("reason=auth_error message=%q", exitErr.Detail.Message) + tracking.LogAuthError(tracking.AuthComponentAuth, tracking.AuthOpAuthError, fmt.Errorf(errMsg)) + } +} + +// logAuthFailureReason extracts authorization-related errors from exitErr and logs +// the failure reason using tracking.LogAuthError. +func logAuthFailureReason(exitErr *output.ExitError) { + if exitErr.Detail == nil { + return + } + + // Handle NeedAuthorizationError first + var needAuthErr *internalauth.NeedAuthorizationError + if errors.As(exitErr.Err, &needAuthErr) { + errMsg := buildAuthFailureErrorMessage(needAuthErr) + tracking.LogAuthError(tracking.AuthComponentAuth, tracking.AuthOpNeedAuthorization, fmt.Errorf(errMsg)) + return + } + + // Handle TokenUnavailableError + var unavailableErr *credential.TokenUnavailableError + if errors.As(exitErr.Err, &unavailableErr) { + errMsg := fmt.Sprintf("reason=no_token source=%s type=%s", unavailableErr.Source, unavailableErr.Type) + tracking.LogAuthError(tracking.AuthComponentAuth, tracking.AuthOpTokenUnavailable, fmt.Errorf(errMsg)) + return + } + + // Handle general auth errors (type "auth") + if exitErr.Detail.Type == "auth" { + errMsg := fmt.Sprintf("reason=auth_error message=%q", exitErr.Detail.Message) + tracking.LogAuthError(tracking.AuthComponentAuth, tracking.AuthOpAuthError, fmt.Errorf(errMsg)) + } +} + +// buildAuthFailureErrorMessage constructs a detailed error message for auth failure logging. +func buildAuthFailureErrorMessage(err *internalauth.NeedAuthorizationError) string { + if err == nil { + return "unknown auth failure" + } + + var parts []string + parts = append(parts, fmt.Sprintf("user=%s", err.UserOpenId)) + + switch err.Reason { + case internalauth.ReasonNoToken: + parts = append(parts, "reason=no_token") + case internalauth.ReasonTokenExpired: + parts = append(parts, "reason=token_expired") + case internalauth.ReasonRefreshExpired: + parts = append(parts, "reason=refresh_expired") + if err.GrantedAt > 0 { + grantedTime := time.UnixMilli(err.GrantedAt).Format(time.RFC3339) + parts = append(parts, fmt.Sprintf("refresh_token_granted_at=%s", grantedTime)) + } + case internalauth.ReasonRefreshFailed: + parts = append(parts, "reason=refresh_failed") + if err.GrantedAt > 0 { + grantedTime := time.UnixMilli(err.GrantedAt).Format(time.RFC3339) + parts = append(parts, fmt.Sprintf("refresh_token_granted_at=%s", grantedTime)) + } + case internalauth.ReasonPermissionDenied: + parts = append(parts, "reason=permission_denied") + default: + parts = append(parts, fmt.Sprintf("reason=%s", err.Reason)) + } + + return strings.Join(parts, " ") +} + // resolveDeclaredScopesForCurrentCommand returns the scopes declared by the // current command for the resolved identity, checking shortcuts first and then // service methods from local registry metadata. diff --git a/cmd/root.go b/cmd/root.go index 00d9a24bc..b0d3b17ff 100644 --- a/cmd/root.go +++ b/cmd/root.go @@ -26,6 +26,7 @@ import ( "github.com/larksuite/cli/internal/output" "github.com/larksuite/cli/internal/registry" "github.com/larksuite/cli/internal/skillscheck" + "github.com/larksuite/cli/internal/tracking" "github.com/larksuite/cli/internal/update" "github.com/spf13/cobra" ) @@ -207,15 +208,18 @@ func handleRootError(f *cmdutil.Factory, err error) int { // that differs from the standard ErrDetail, so it's handled separately. var spErr *internalauth.SecurityPolicyError if errors.As(err, &spErr) { + logSecurityPolicyError(spErr) writeSecurityPolicyError(errOut, spErr) return 1 } // All other structured errors normalize to ExitError. if exitErr := asExitError(err); exitErr != nil { - if !exitErr.Raw { + if exitErr.Raw { // Raw errors (e.g. from `api` command) preserve the original API - // error detail; skip enrichment which would clear it. + // error detail; skip enrichment but still log auth failures. + logRawAuthFailure(exitErr) + } else { enrichMissingScopeError(f, exitErr) enrichPermissionError(f, exitErr) } @@ -235,6 +239,12 @@ func asExitError(err error) *output.ExitError { if errors.As(err, &cfgErr) { return output.ErrWithHint(cfgErr.Code, cfgErr.Type, cfgErr.Message, cfgErr.Hint) } + + var needAuthErr *internalauth.NeedAuthorizationError + if errors.As(err, &needAuthErr) { + return output.ErrAuth("authentication required: %s", err) + } + var exitErr *output.ExitError if errors.As(err, &exitErr) { return exitErr @@ -242,20 +252,24 @@ func asExitError(err error) *output.ExitError { return nil } +// securityPolicyCodeString maps a security policy numeric code to a human-readable string. +func securityPolicyCodeString(code int) string { + switch code { + case internalauth.LarkErrBlockByPolicyTryAuth: + return "challenge_required" + case internalauth.LarkErrBlockByPolicy: + return "access_denied" + default: + return strconv.Itoa(code) + } +} + // writeSecurityPolicyError writes the security-policy-specific JSON envelope to w. // This format intentionally differs from the standard ErrDetail envelope: // it uses string codes ("challenge_required"/"access_denied") and extra fields // (retryable, challenge_url) for machine-readable policy error handling. func writeSecurityPolicyError(w io.Writer, spErr *internalauth.SecurityPolicyError) { - var codeStr string - switch spErr.Code { - case internalauth.LarkErrBlockByPolicyTryAuth: - codeStr = "challenge_required" - case internalauth.LarkErrBlockByPolicy: - codeStr = "access_denied" - default: - codeStr = strconv.Itoa(spErr.Code) - } + codeStr := securityPolicyCodeString(spErr.Code) errData := map[string]interface{}{ "type": "auth_error", @@ -423,6 +437,8 @@ func enrichPermissionError(f *cmdutil.Factory, exitErr *output.ExitError) { isBot := f.ResolvedIdentity.IsBot() larkCode := exitErr.Detail.Code + + var reason internalauth.NeedAuthorizationReason switch larkCode { case output.LarkErrUserScopeInsufficient, output.LarkErrUserNotAuthorized: // User has not authorized the scope → re-authorize @@ -433,12 +449,14 @@ func enrichPermissionError(f *cmdutil.Factory, exitErr *output.ExitError) { exitErr.Detail.Hint = fmt.Sprintf("run `lark-cli auth login --scope \"%s\"` in the background. It blocks and outputs a verification URL — retrieve the URL and open it in a browser to complete login.", recommended) } exitErr.Detail.ConsoleURL = consoleURL + reason = internalauth.ReasonPermissionDenied case output.LarkErrAppScopeNotEnabled: // App has not enabled the API scope → admin console exitErr.Detail.Message = fmt.Sprintf("App scope not enabled: required scope %s [%d]", recommended, larkCode) exitErr.Detail.Hint = "enable the scope in developer console (see console_url)" exitErr.Detail.ConsoleURL = consoleURL + reason = internalauth.ReasonPermissionDenied default: // Other permission errors (matched by keyword) @@ -450,6 +468,13 @@ func enrichPermissionError(f *cmdutil.Factory, exitErr *output.ExitError) { "enable scope in console (see console_url), or run `lark-cli auth login --scope \"%s\"` in the background. It blocks and outputs a verification URL — retrieve the URL and open it in a browser to complete login.", recommended) } exitErr.Detail.ConsoleURL = consoleURL + reason = internalauth.ReasonPermissionDenied + } + + // Log permission error + if reason != "" { + errMsg := fmt.Sprintf("user=%s reason=%s scopes=%v", cfg.UserOpenId, reason, scopes) + tracking.LogAuthError(tracking.AuthComponentAuth, tracking.AuthOpPermissionDenied, fmt.Errorf(errMsg)) } } diff --git a/internal/auth/app_registration.go b/internal/auth/app_registration.go index 2bdf50fba..c039c6528 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() - logHTTPResponse(resp) + logAuthResponse(responsePath(resp), resp.StatusCode, resp.Header.Get("x-tt-logid")) 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 } - logHTTPResponse(resp) + logAuthResponse(responsePath(resp), resp.StatusCode, resp.Header.Get("x-tt-logid")) 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 b57a9edae..7c7b2c83b 100644 --- a/internal/auth/auth_response_log.go +++ b/internal/auth/auth_response_log.go @@ -6,36 +6,28 @@ package auth import ( "net/http" - "github.com/larksuite/cli/internal/keychain" - larkcore "github.com/larksuite/oapi-sdk-go/v3/core" + "github.com/larksuite/cli/internal/tracking" ) -// 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 +func logAuthResponse(path string, statusCode int, logID string) { + if path == "" { + path = "missing" } - path := "missing" - if resp.Request != nil && resp.Request.URL != nil { - path = resp.Request.URL.Path + if shouldSkipAuthResponseLog(path, statusCode) { + return } - keychain.LogAuthResponse(path, resp.StatusCode, resp.Header.Get("x-tt-logid")) + tracking.LogAuthResponse(path, statusCode, 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" - } - - if apiResp == nil { - keychain.LogAuthResponse(path, 0, "") - return +func responsePath(resp *http.Response) string { + if resp != nil && resp.Request != nil && resp.Request.URL != nil { + return resp.Request.URL.Path } + return "missing" +} - keychain.LogAuthResponse(path, apiResp.StatusCode, apiResp.Header.Get("x-tt-logid")) +func shouldSkipAuthResponseLog(path string, statusCode int) bool { + return path == "missing" || statusCode == 400 } diff --git a/internal/auth/device_flow.go b/internal/auth/device_flow.go index fb611d121..f9cf2764a 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() - logHTTPResponse(resp) + logAuthResponse(responsePath(resp), resp.StatusCode, resp.Header.Get("x-tt-logid")) body, err := io.ReadAll(resp.Body) if err != nil { @@ -184,7 +184,7 @@ func PollDeviceToken(ctx context.Context, httpClient *http.Client, appId, appSec currentInterval = minInt(currentInterval+1, maxPollInterval) continue } - logHTTPResponse(resp) + logAuthResponse(responsePath(resp), resp.StatusCode, resp.Header.Get("x-tt-logid")) 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 8b3f4d0c9..656fc033f 100644 --- a/internal/auth/device_flow_test.go +++ b/internal/auth/device_flow_test.go @@ -16,7 +16,7 @@ import ( "github.com/larksuite/cli/internal/core" "github.com/larksuite/cli/internal/httpmock" - "github.com/larksuite/cli/internal/keychain" + "github.com/larksuite/cli/internal/tracking" ) type roundTripFunc func(*http.Request) (*http.Response, error) @@ -47,7 +47,8 @@ func TestResolveOAuthEndpoints_Lark(t *testing.T) { } } -// TestRequestDeviceAuthorization_LogsResponse checks if API responses are logged correctly. +// TestRequestDeviceAuthorization_LogsResponse checks that responses with +// unresolvable paths (path="missing") are not logged. func TestRequestDeviceAuthorization_LogsResponse(t *testing.T) { reg := &httpmock.Registry{} t.Cleanup(func() { reg.Verify(t) }) @@ -70,7 +71,7 @@ func TestRequestDeviceAuthorization_LogsResponse(t *testing.T) { }) var buf bytes.Buffer - restore := keychain.SetAuthLogHooksForTest(log.New(&buf, "", 0), func() time.Time { + restore := tracking.SetAuthLogHooksForTest(log.New(&buf, "", 0), func() time.Time { return time.Date(2026, 4, 2, 3, 4, 5, 0, time.UTC) }, func() []string { return []string{"lark-cli", "auth", "login", "--device-code", "device-code-secret", "--app-secret=top-secret"} @@ -82,66 +83,36 @@ func TestRequestDeviceAuthorization_LogsResponse(t *testing.T) { 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=missing") { - 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) - } -} - -// TestFormatAuthCmdline_TruncatesExtraArgs verifies that long command lines are truncated. -func TestFormatAuthCmdline_TruncatesExtraArgs(t *testing.T) { - got := keychain.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) + if got := buf.String(); got != "" { + t.Fatalf("expected no log for missing path, got %q", got) } } -// TestLogAuthResponse_IgnoresTypedNilHTTPResponse tests that a typed nil HTTP response is ignored gracefully. -func TestLogAuthResponse_IgnoresTypedNilHTTPResponse(t *testing.T) { +// TestLogAuthResponse_IgnoresNilHTTPResponse tests that a nil HTTP response produces no log output. +func TestLogAuthResponse_IgnoresNilHTTPResponse(t *testing.T) { var buf bytes.Buffer - restore := keychain.SetAuthLogHooksForTest(log.New(&buf, "", 0), nil, nil) + restore := tracking.SetAuthLogHooksForTest(log.New(&buf, "", 0), nil, nil) t.Cleanup(restore) - var resp *http.Response - logHTTPResponse(resp) - + if got := responsePath(nil); got != "missing" { + t.Fatalf("responsePath(nil) = %q, want %q", got, "missing") + } if got := buf.String(); got != "" { t.Fatalf("expected no log output, got %q", got) } } -// TestLogAuthResponse_HandlesNilSDKResponse verifies that a nil SDK response is handled without panicking. -func TestLogAuthResponse_HandlesNilSDKResponse(t *testing.T) { +// TestLogAuthResponse_LogsNilSDKResponseWithZeroStatus verifies that a nil SDK response is logged with status=0. +func TestLogAuthResponse_LogsNilSDKResponseWithZeroStatus(t *testing.T) { var buf bytes.Buffer - restore := keychain.SetAuthLogHooksForTest(log.New(&buf, "", 0), func() time.Time { + restore := tracking.SetAuthLogHooksForTest(log.New(&buf, "", 0), func() time.Time { return time.Date(2026, 4, 2, 3, 4, 5, 0, time.UTC) }, func() []string { return []string{"lark-cli", "auth", "status", "--verify"} }) t.Cleanup(restore) - logSDKResponse(PathUserInfoV1, nil) + logAuthResponse(PathUserInfoV1, 0, "") got := buf.String() if !strings.Contains(got, "path="+PathUserInfoV1) { @@ -154,14 +125,17 @@ func TestLogAuthResponse_HandlesNilSDKResponse(t *testing.T) { func TestLogAuthError_RecordsStructuredEntry(t *testing.T) { var buf bytes.Buffer - restore := keychain.SetAuthLogHooksForTest(log.New(&buf, "", 0), func() time.Time { + restoreLocal := tracking.SetAuthLogHooksForTest(log.New(&buf, "", 0), func() time.Time { return time.Date(2026, 4, 2, 3, 4, 5, 0, time.UTC) }, func() []string { return []string{"lark-cli", "auth", "login", "--device-code", "secret"} }) - t.Cleanup(restore) + t.Cleanup(restoreLocal) + + restoreRemote := tracking.SetAuthLogRemoteHooksForTest(nil, "", nil, false) + t.Cleanup(restoreRemote) - keychain.LogAuthError("keychain", "Set", fmt.Errorf("keychain Set error: %w", http.ErrUseLastResponse)) + tracking.LogAuthError(tracking.AuthComponentKeychain, tracking.AuthOpKeychainSet, fmt.Errorf("keychain Set error: %w", http.ErrUseLastResponse)) got := buf.String() if !strings.Contains(got, "auth-error") { @@ -181,6 +155,65 @@ func TestLogAuthError_RecordsStructuredEntry(t *testing.T) { } } +func TestShouldSkipAuthResponseLog(t *testing.T) { + tests := []struct { + name string + path string + statusCode int + want bool + }{ + { + name: "oauth token 400 skipped", + path: PathOAuthTokenV2, + statusCode: 400, + want: true, + }, + { + name: "oauth token 200 not skipped", + path: PathOAuthTokenV2, + statusCode: 200, + want: false, + }, + { + name: "oauth token 401 not skipped", + path: PathOAuthTokenV2, + statusCode: 401, + want: false, + }, + { + name: "oauth token 500 not skipped", + path: PathOAuthTokenV2, + statusCode: 500, + want: false, + }, + { + name: "other path 400 skipped", + path: PathUserInfoV1, + statusCode: 400, + want: true, + }, + { + name: "other path 200 not skipped", + path: PathUserInfoV1, + statusCode: 200, + want: false, + }, + { + name: "missing path skipped", + path: "missing", + statusCode: 200, + want: true, + }, + } + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + if got := shouldSkipAuthResponseLog(tt.path, tt.statusCode); got != tt.want { + t.Errorf("shouldSkipAuthResponseLog(%q, %d) = %v, want %v", tt.path, tt.statusCode, got, tt.want) + } + }) + } +} + func TestPollDeviceToken_DefaultsZeroIntervalToFiveSeconds(t *testing.T) { t.Parallel() diff --git a/internal/auth/errors.go b/internal/auth/errors.go index b5186f72c..5ae023367 100644 --- a/internal/auth/errors.go +++ b/internal/auth/errors.go @@ -29,13 +29,29 @@ var TokenRetryCodes = map[int]bool{ output.LarkErrTokenExpired: true, } +// NeedAuthorizationReason describes why authorization is needed. +type NeedAuthorizationReason string + +const ( + ReasonNoToken NeedAuthorizationReason = "no_token" // No token exists + ReasonTokenExpired NeedAuthorizationReason = "token_expired" // Access token expired + ReasonRefreshExpired NeedAuthorizationReason = "refresh_expired" // Refresh token expired + ReasonRefreshFailed NeedAuthorizationReason = "refresh_failed" // Refresh attempt failed + ReasonPermissionDenied NeedAuthorizationReason = "permission_denied" // Insufficient permissions/scopes +) + // NeedAuthorizationError is thrown when no valid UAT exists. type NeedAuthorizationError struct { UserOpenId string + Reason NeedAuthorizationReason + GrantedAt int64 // Unix ms, only set when Reason is ReasonTokenExpired or ReasonRefreshExpired } // Error returns the error message for NeedAuthorizationError. func (e *NeedAuthorizationError) Error() string { + if e.Reason != "" { + return fmt.Sprintf("%s (user: %s, reason: %s)", needUserAuthorizationMarker, e.UserOpenId, e.Reason) + } return fmt.Sprintf("%s (user: %s)", needUserAuthorizationMarker, e.UserOpenId) } diff --git a/internal/auth/uat_client.go b/internal/auth/uat_client.go index 35bf4133a..152500de3 100644 --- a/internal/auth/uat_client.go +++ b/internal/auth/uat_client.go @@ -69,7 +69,7 @@ var refreshLocks sync.Map func GetValidAccessToken(httpClient *http.Client, opts UATCallOptions) (string, error) { stored := GetStoredToken(opts.AppId, opts.UserOpenId) if stored == nil { - return "", &NeedAuthorizationError{UserOpenId: opts.UserOpenId} + return "", &NeedAuthorizationError{UserOpenId: opts.UserOpenId, Reason: ReasonNoToken} } status := TokenStatus(stored) @@ -84,12 +84,16 @@ func GetValidAccessToken(httpClient *http.Client, opts UATCallOptions) (string, return "", err } if refreshed == nil { - return "", &NeedAuthorizationError{UserOpenId: opts.UserOpenId} + reason := ReasonRefreshFailed + if stored.RefreshExpiresAt > 0 && time.Now().UnixMilli() >= stored.RefreshExpiresAt { + reason = ReasonRefreshExpired + } + return "", &NeedAuthorizationError{UserOpenId: opts.UserOpenId, Reason: reason, GrantedAt: stored.GrantedAt} } return refreshed.AccessToken, nil } - // expired + // expired (refresh token also expired) if err := RemoveStoredToken(opts.AppId, opts.UserOpenId); err != nil { if opts.ErrOut != nil { fmt.Fprintf(opts.ErrOut, "[lark-cli] [WARN] uat-client: failed to remove token: %v\n", err) @@ -97,7 +101,7 @@ func GetValidAccessToken(httpClient *http.Client, opts UATCallOptions) (string, fmt.Fprintf(os.Stderr, "[lark-cli] [WARN] uat-client: failed to remove token: %v\n", err) } } - return "", &NeedAuthorizationError{UserOpenId: opts.UserOpenId} + return "", &NeedAuthorizationError{UserOpenId: opts.UserOpenId, Reason: ReasonRefreshExpired, GrantedAt: stored.GrantedAt} } // refreshWithLock acquires a file lock before attempting to refresh the token. @@ -204,7 +208,7 @@ func doRefreshToken(httpClient *http.Client, opts UATCallOptions, stored *Stored return nil, err } defer resp.Body.Close() - logHTTPResponse(resp) + logAuthResponse(responsePath(resp), resp.StatusCode, resp.Header.Get("x-tt-logid")) body, err := io.ReadAll(resp.Body) if err != nil { diff --git a/internal/auth/verify.go b/internal/auth/verify.go index 403ad4481..6b3774afc 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 } - logSDKResponse(PathUserInfoV1, apiResp) + logAuthResponse(PathUserInfoV1, apiResp.StatusCode, apiResp.Header.Get("x-tt-logid")) var resp struct { Code int `json:"code"` diff --git a/internal/auth/verify_test.go b/internal/auth/verify_test.go index d513a66a3..c082348f9 100644 --- a/internal/auth/verify_test.go +++ b/internal/auth/verify_test.go @@ -12,7 +12,7 @@ import ( "testing" "time" - "github.com/larksuite/cli/internal/keychain" + "github.com/larksuite/cli/internal/tracking" lark "github.com/larksuite/oapi-sdk-go/v3" larkcore "github.com/larksuite/oapi-sdk-go/v3/core" @@ -86,12 +86,15 @@ func TestVerifyUserToken(t *testing.T) { ) var buf bytes.Buffer - restore := keychain.SetAuthLogHooksForTest(log.New(&buf, "", 0), func() time.Time { + restoreLocal := tracking.SetAuthLogHooksForTest(log.New(&buf, "", 0), func() time.Time { return time.Date(2026, 4, 2, 3, 4, 5, 0, time.UTC) }, func() []string { return []string{"lark-cli", "auth", "status"} }) - t.Cleanup(restore) + t.Cleanup(restoreLocal) + + restoreRemote := tracking.SetAuthLogRemoteHooksForTest(nil, "", nil, false) + t.Cleanup(restoreRemote) err := VerifyUserToken(context.Background(), sdk, "test-token") if tt.wantErr { diff --git a/internal/cmdutil/factory_default.go b/internal/cmdutil/factory_default.go index f18a816b3..83e29c289 100644 --- a/internal/cmdutil/factory_default.go +++ b/internal/cmdutil/factory_default.go @@ -9,6 +9,7 @@ import ( "io" "net/http" "os" + "strings" "sync" "time" @@ -23,6 +24,7 @@ import ( "github.com/larksuite/cli/internal/keychain" "github.com/larksuite/cli/internal/registry" _ "github.com/larksuite/cli/internal/security/contentsafety" // register content safety provider + "github.com/larksuite/cli/internal/tracking" "github.com/larksuite/cli/internal/util" _ "github.com/larksuite/cli/internal/vfs/localfileio" // register default FileIO provider ) @@ -48,9 +50,8 @@ func NewDefault(streams *IOStreams, inv InvocationContext) *Factory { ws := core.DetectWorkspaceFromEnv(os.Getenv) core.SetCurrentWorkspace(ws) - // Inject workspace-aware dir into keychain's log system. - // This breaks the core↔keychain import cycle by using a function variable. - keychain.RuntimeDirFunc = core.GetRuntimeDir + // Initialize tracking globals + initTrackingGlobals(inv.Profile) // Phase 0: FileIO provider (no dependency) f.FileIOProvider = fileio.GetProvider() @@ -75,6 +76,7 @@ func NewDefault(streams *IOStreams, inv InvocationContext) *Factory { } cfg := acct.ToCliConfig() registry.InitWithBrand(cfg.Brand) + tracking.SetTrackingFromConfig(string(cfg.Brand), cfg.AppID) return cfg, nil }) @@ -168,3 +170,29 @@ func buildCredentialProvider(deps credentialDeps) *credential.CredentialProvider // warning is safe. return credential.NewCredentialProvider(providers, defaultAcct, defaultToken, deps.HttpClient) } + +func initTrackingGlobals(profileOverride string) { + tracking.RuntimeDirFunc = core.GetRuntimeDir + + raw, err := core.LoadMultiAppConfig() + if err != nil { + return + } + app := raw.CurrentAppConfig(profileOverride) + if app == nil { + return + } + tracking.SetTrackingFromConfig(string(app.Brand), app.AppId) + + appId := app.AppId + tracking.OfflineAccessChecker = func() bool { + if len(app.Users) == 0 { + return false + } + token := auth.GetStoredToken(appId, app.Users[0].UserOpenId) + if token == nil { + return false + } + return strings.Contains(token.Scope, "offline_access") + } +} diff --git a/internal/cmdutil/testing.go b/internal/cmdutil/testing.go index 8d8be452b..e1672ee68 100644 --- a/internal/cmdutil/testing.go +++ b/internal/cmdutil/testing.go @@ -8,6 +8,7 @@ import ( "context" "net/http" "os" + "sync" "testing" lark "github.com/larksuite/oapi-sdk-go/v3" @@ -17,6 +18,7 @@ import ( "github.com/larksuite/cli/internal/core" "github.com/larksuite/cli/internal/credential" "github.com/larksuite/cli/internal/httpmock" + "github.com/larksuite/cli/internal/tracking" "github.com/larksuite/cli/internal/vfs" ) @@ -27,11 +29,17 @@ func (n *noopKeychain) Get(service, account string) (string, error) { return "", func (n *noopKeychain) Set(service, account, value string) error { return nil } func (n *noopKeychain) Remove(service, account string) error { return nil } +var disableRemoteOnce sync.Once + // TestFactory creates a Factory for testing. // Returns (factory, stdout buffer, stderr buffer, http mock registry). func TestFactory(t *testing.T, config *core.CliConfig) (*Factory, *bytes.Buffer, *bytes.Buffer, *httpmock.Registry) { t.Helper() + disableRemoteOnce.Do(func() { + tracking.SetAuthLogRemoteHooksForTest(nil, "", nil, false) + }) + reg := &httpmock.Registry{} t.Cleanup(func() { reg.Verify(t) }) diff --git a/internal/keychain/auth_log.go b/internal/keychain/auth_log.go deleted file mode 100644 index 7b175942c..000000000 --- a/internal/keychain/auth_log.go +++ /dev/null @@ -1,191 +0,0 @@ -// Copyright (c) 2026 Lark Technologies Pte. Ltd. -// SPDX-License-Identifier: MIT - -package keychain - -import ( - "fmt" - "log" - "os" - "path/filepath" - "strings" - "sync" - "time" - - "github.com/larksuite/cli/internal/validate" - "github.com/larksuite/cli/internal/vfs" -) - -// RuntimeDirFunc returns the workspace-aware config directory. -// Default: falls back to LARKSUITE_CLI_CONFIG_DIR or ~/.lark-cli (pre-workspace behavior). -// Injected by cmdutil.NewDefault → core.GetRuntimeDir after workspace detection. -// This avoids an import cycle (core → keychain → core). -var RuntimeDirFunc = defaultRuntimeDir - -func defaultRuntimeDir() string { - if dir := os.Getenv("LARKSUITE_CLI_CONFIG_DIR"); dir != "" { - return dir - } - home, err := vfs.UserHomeDir() - if err != nil || home == "" { - // Silent fallback to a relative ".lark-cli": this package has no - // IOStreams in scope, so we cannot surface a warning here without - // violating the IOStreams injection boundary (enforced by lint). - // Users who hit this path should set LARKSUITE_CLI_CONFIG_DIR - // explicitly; the relative path will otherwise surface as an - // explicit I/O error at first use. - home = "" - } - return filepath.Join(home, ".lark-cli") -} - -var ( - authResponseLogger *log.Logger - authResponseLoggerOnce = &sync.Once{} - - authResponseLogNow = time.Now - authResponseLogArgs = func() []string { return os.Args } -) - -func authLogDir() string { - // LARKSUITE_CLI_LOG_DIR is the highest-priority override. - // When set, it bypasses workspace subtree routing entirely. - if dir := os.Getenv("LARKSUITE_CLI_LOG_DIR"); dir != "" { - safeDir, err := validate.SafeEnvDirPath(dir, "LARKSUITE_CLI_LOG_DIR") - if err == nil { - return safeDir - } - } - - // Fall back to the workspace-aware runtime dir. RuntimeDirFunc is injected - // by factory after workspace detection; before injection it defaults to - // the pre-workspace behavior so older call paths remain correct. - return filepath.Join(RuntimeDirFunc(), "logs") -} - -func initAuthLogger() { - authResponseLoggerOnce.Do(func() { - if authResponseLogger != nil { - return - } - - dir := authLogDir() - now := authResponseLogNow() - if err := vfs.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 := vfs.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 := vfs.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) { - _ = vfs.Remove(filepath.Join(dir, entry.Name())) - } - } -} diff --git a/internal/keychain/auth_log_test.go b/internal/keychain/auth_log_test.go deleted file mode 100644 index 423d2b1cb..000000000 --- a/internal/keychain/auth_log_test.go +++ /dev/null @@ -1,38 +0,0 @@ -// Copyright (c) 2026 Lark Technologies Pte. Ltd. -// SPDX-License-Identifier: MIT - -package keychain - -import ( - "path/filepath" - "testing" -) - -// TestAuthLogDir_UsesValidatedLogDirEnv verifies that a valid absolute -// LARKSUITE_CLI_LOG_DIR is normalized and used as the auth log directory. -func TestAuthLogDir_UsesValidatedLogDirEnv(t *testing.T) { - base := t.TempDir() - base, _ = filepath.EvalSymlinks(base) - t.Setenv("LARKSUITE_CLI_LOG_DIR", filepath.Join(base, "logs", "..", "auth")) - t.Setenv("LARKSUITE_CLI_CONFIG_DIR", "") - - got := authLogDir() - want := filepath.Join(base, "auth") - if got != want { - t.Fatalf("authLogDir() = %q, want %q", got, want) - } -} - -// TestAuthLogDir_InvalidLogDirFallsBackToConfigDir verifies that an invalid -// LARKSUITE_CLI_LOG_DIR falls back to LARKSUITE_CLI_CONFIG_DIR/logs. -func TestAuthLogDir_InvalidLogDirFallsBackToConfigDir(t *testing.T) { - t.Setenv("LARKSUITE_CLI_LOG_DIR", "relative-logs") - configDir := t.TempDir() - t.Setenv("LARKSUITE_CLI_CONFIG_DIR", configDir) - - got := authLogDir() - want := filepath.Join(configDir, "logs") - if got != want { - t.Fatalf("authLogDir() = %q, want %q", got, want) - } -} diff --git a/internal/keychain/keychain.go b/internal/keychain/keychain.go index e2cdecc11..006da1a21 100644 --- a/internal/keychain/keychain.go +++ b/internal/keychain/keychain.go @@ -10,6 +10,7 @@ import ( "fmt" "github.com/larksuite/cli/internal/output" + "github.com/larksuite/cli/internal/tracking" ) var ( @@ -28,9 +29,15 @@ const ( LarkCliService = "lark-cli" ) +var suppressKeychainReadErrorTracking bool + +func SuppressKeychainReadErrorTracking(suppress bool) { + suppressKeychainReadErrorTracking = suppress +} + // 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 { +func wrapError(op tracking.AuthOp, err error) error { if err == nil || errors.Is(err, ErrNotFound) { return err } @@ -42,10 +49,12 @@ func wrapError(op string, err error) error { hint = "The keychain master key may have been cleaned up or deleted. If running inside a sandbox or CI environment, please ensure the process has the necessary permissions to access the keychain, you can try running this outside the sandbox. Otherwise, please reconfigure the CLI by running lark-cli config init." } - func() { - defer func() { recover() }() - LogAuthError("keychain", op, fmt.Errorf("keychain %s error: %w", op, err)) - }() + if !suppressKeychainReadErrorTracking || op != tracking.AuthOpKeychainGet { + func() { + defer func() { recover() }() + tracking.LogAuthError(tracking.AuthComponentKeychain, op, fmt.Errorf("keychain %s error: %w", op, err)) + }() + } return output.ErrWithHint(output.ExitAPI, "config", msg, hint) } @@ -63,15 +72,15 @@ type KeychainAccess interface { // Returns empty string if the entry does not exist. func Get(service, account string) (string, error) { val, err := platformGet(service, account) - return val, wrapError("Get", err) + return val, wrapError(tracking.AuthOpKeychainGet, err) } // Set stores a value in the keychain, overwriting any existing entry. func Set(service, account, data string) error { - return wrapError("Set", platformSet(service, account, data)) + return wrapError(tracking.AuthOpKeychainSet, platformSet(service, account, data)) } // Remove deletes an entry from the keychain. No error if not found. func Remove(service, account string) error { - return wrapError("Remove", platformRemove(service, account)) + return wrapError(tracking.AuthOpKeychainRemove, platformRemove(service, account)) } diff --git a/internal/tracking/auth.go b/internal/tracking/auth.go new file mode 100644 index 000000000..bc13aebf8 --- /dev/null +++ b/internal/tracking/auth.go @@ -0,0 +1,368 @@ +// Copyright (c) 2026 Lark Technologies Pte. Ltd. +// SPDX-License-Identifier: MIT + +package tracking + +import ( + "bytes" + "context" + "encoding/json" + "fmt" + "io" + "log" + "net/http" + "os" + "path/filepath" + "strings" + "sync" + "time" + + "github.com/google/uuid" + "github.com/larksuite/cli/internal/build" + "github.com/larksuite/cli/internal/vfs" +) + +type authEventKind string + +const ( + authEventResponse authEventKind = "auth_response" + authEventError authEventKind = "auth_error" +) + +type AuthComponent string + +const ( + AuthComponentAuth AuthComponent = "auth" + AuthComponentKeychain AuthComponent = "keychain" +) + +type AuthOp string + +const ( + AuthOpSecurityPolicy AuthOp = "security_policy" + AuthOpPermissionDenied AuthOp = "permission_denied" + AuthOpAuthError AuthOp = "auth_error" + AuthOpNeedAuthorization AuthOp = "need_authorization" + AuthOpTokenUnavailable AuthOp = "token_unavailable" + AuthOpKeychainGet AuthOp = "Get" + AuthOpKeychainSet AuthOp = "Set" + AuthOpKeychainRemove AuthOp = "Remove" +) + +type authEvent struct { + Kind authEventKind + Time time.Time + Cmdline string + Path string + Status int + LogID string + Component AuthComponent + Op AuthOp + Error string + HasOfflineAccess bool +} + +var ( + authResponseLogger *log.Logger + authResponseLoggerOnce = &sync.Once{} + + authResponseLogNow = time.Now + authResponseLogArgs = func() []string { return os.Args } +) + +func initAuthLogger() { + authResponseLoggerOnce.Do(func() { + if authResponseLogger != nil { + return + } + + dir := logDir() + now := authResponseLogNow() + if err := vfs.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 := vfs.OpenFile(logPath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0600); err == nil { + authResponseLogger = log.New(f, "", 0) + cleanupOldAuthLogs(dir, now) + } + }) +} +func LogAuthResponse(path string, status int, logID string) { + emitAuthEvent(authEvent{ + Kind: authEventResponse, + Time: authResponseLogNow(), + Cmdline: formatCmdline(authResponseLogArgs()), + Path: path, + Status: status, + LogID: logID, + HasOfflineAccess: checkOfflineAccess(), + }) +} + +func LogAuthError(component AuthComponent, op AuthOp, err error) { + if err == nil { + return + } + emitAuthEvent(authEvent{ + Kind: authEventError, + Time: authResponseLogNow(), + Cmdline: formatCmdline(authResponseLogArgs()), + Component: component, + Op: op, + Error: err.Error(), + HasOfflineAccess: checkOfflineAccessForError(component), + }) +} + +func checkOfflineAccess() bool { + if OfflineAccessChecker == nil { + return false + } + defer func() { recover() }() + return OfflineAccessChecker() +} + +func checkOfflineAccessForError(component AuthComponent) bool { + if component == AuthComponentKeychain { + return false + } + return checkOfflineAccess() +} + +func emitAuthEvent(event authEvent) { + emitLocalAuthEvent(event) + emitRemoteAuthEvent(event) +} + +func emitLocalAuthEvent(event authEvent) { + initAuthLogger() + if authResponseLogger == nil { + return + } + + switch event.Kind { + case authEventResponse: + authResponseLogger.Printf( + "[lark-cli] auth-response: time=%s path=%s status=%d x-tt-logid=%s cmdline=%s", + event.Time.Format(time.RFC3339Nano), + event.Path, + event.Status, + event.LogID, + event.Cmdline, + ) + case authEventError: + authResponseLogger.Printf( + "[lark-cli] auth-error: time=%s component=%s op=%s error=%q cmdline=%s", + event.Time.Format(time.RFC3339Nano), + event.Component, + event.Op, + event.Error, + event.Cmdline, + ) + } +} + +func emitRemoteAuthEvent(event authEvent) { + endpoint := resolveTelemetryEndpoint(brand) + if !remoteEnabled || endpoint == "" { + return + } + + defer func() { + _ = recover() + }() + + _ = postRemoteAuthEvent(event, endpoint) +} + +func postRemoteAuthEvent(event authEvent, endpoint string) error { + userUniqueID, err := userUniqueIDProvider() + if err != nil || strings.TrimSpace(userUniqueID) == "" { + fallbackID, fallbackErr := uuid.NewV7() + if fallbackErr != nil { + return fallbackErr + } + userUniqueID = fallbackID.String() + } + + payload, err := buildRemoteAuthPayload(event, userUniqueID) + if err != nil { + return err + } + + body, err := json.Marshal(payload) + if err != nil { + return err + } + + ctx, cancel := context.WithTimeout(context.Background(), remoteTimeout) + defer cancel() + + req, err := http.NewRequestWithContext(ctx, http.MethodPost, endpoint, bytes.NewReader(body)) + if err != nil { + return err + } + req.Header.Set("Content-Type", "application/json") + + resp, err := remoteClient.Do(req) + if err != nil { + return err + } + defer resp.Body.Close() + _, _ = io.Copy(io.Discard, resp.Body) + if resp.StatusCode >= http.StatusBadRequest { + return fmt.Errorf("auth log remote sink returned status %d", resp.StatusCode) + } + return nil +} + +func buildRemoteAuthPayload(event authEvent, userUniqueID string) ([]remoteRequestItem, error) { + ts := event.Time.Unix() + params, err := buildRemoteAuthParams(event, ts) + if err != nil { + return nil, err + } + + item := remoteRequestItem{ + User: remoteUser{ + DeviceID: "", + UserID: 0, + UserUniqueID: userUniqueID, + }, + Header: remoteHeader{ + AppID: remoteAppID, + AppName: "", + AppVersion: build.Version, + AppChannel: "", + DeviceModel: "", + OSName: osName(), + ABSDKVersion: "", + Custom: map[string]any{}, + }, + Events: []remoteEvent{{ + Event: authRemoteEventName(event), + Params: params, + Time: ts, + LocalTimeMS: event.Time.UnixMilli(), + }}, + Caller: remoteCaller, + } + return []remoteRequestItem{item}, nil +} + +func buildRemoteAuthParams(event authEvent, ts int64) (string, error) { + data := map[string]any{ + "cmdline": event.Cmdline, + "has_offline_access": event.HasOfflineAccess, + "lark_cli_version": build.Version, + "op_client_id": appID, + "timestamp_s": ts, + } + + switch event.Kind { + case authEventResponse: + data["path"] = event.Path + data["status"] = event.Status + data["x_tt_logid"] = event.LogID + case authEventError: + data["component"] = event.Component + data["op"] = event.Op + data["error"] = event.Error + } + + raw, err := json.Marshal(data) + if err != nil { + return "", err + } + return string(raw), nil +} + +func authRemoteEventName(event authEvent) string { + if event.Kind == authEventError { + return "cli_auth_error" + } + return "cli_auth_response" +} + +func SetAuthLogHooksForTest(logger *log.Logger, now func() time.Time, args func() []string) func() { + prevLogger := authResponseLogger + prevNow := authResponseLogNow + prevArgs := authResponseLogArgs + prevOnce := authResponseLoggerOnce + prevRemoteEnabled := remoteEnabled + + authResponseLogger = logger + authResponseLoggerOnce = &sync.Once{} + remoteEnabled = false + + if now != nil { + authResponseLogNow = now + } + if args != nil { + authResponseLogArgs = args + } + + return func() { + authResponseLogger = prevLogger + authResponseLogNow = prevNow + authResponseLogArgs = prevArgs + authResponseLoggerOnce = prevOnce + remoteEnabled = prevRemoteEnabled + } +} + +func SetAuthLogRemoteHooksForTest(client *http.Client, b string, provider func() (string, error), enabled bool) func() { + prevClient := remoteClient + prevBrand := brand + prevProvider := userUniqueIDProvider + prevEnabled := remoteEnabled + + if client != nil { + remoteClient = client + } + brand = b + if provider != nil { + userUniqueIDProvider = provider + } + remoteEnabled = enabled + + return func() { + remoteClient = prevClient + brand = prevBrand + userUniqueIDProvider = prevProvider + remoteEnabled = prevEnabled + } +} + +func cleanupOldAuthLogs(dir string, now time.Time) { + defer func() { recover() }() + + entries, err := vfs.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) { + _ = vfs.Remove(filepath.Join(dir, entry.Name())) + } + } +} diff --git a/internal/tracking/event.go b/internal/tracking/event.go new file mode 100644 index 000000000..8ed86c379 --- /dev/null +++ b/internal/tracking/event.go @@ -0,0 +1,163 @@ +// Copyright (c) 2026 Lark Technologies Pte. Ltd. +// SPDX-License-Identifier: MIT + +package tracking + +import ( + "fmt" + "net/http" + "os" + "path/filepath" + "runtime" + "strings" + "sync" + "time" + + "github.com/google/uuid" + "github.com/larksuite/cli/internal/validate" + "github.com/larksuite/cli/internal/vfs" + "github.com/larksuite/cli/internal/vfs/localfileio" +) + +const ( + remoteCaller = "lark-cli" + remoteAppID = 1011422 + remoteTimeout = 3 * time.Second +) + +type remoteRequestItem struct { + User remoteUser `json:"user"` + Header remoteHeader `json:"header"` + Events []remoteEvent `json:"events"` + Caller string `json:"caller"` +} + +type remoteUser struct { + DeviceID string `json:"device_id"` + UserID int64 `json:"user_id"` + UserUniqueID string `json:"user_unique_id"` +} + +type remoteHeader struct { + AppID int64 `json:"app_id"` + AppName string `json:"app_name"` + AppVersion string `json:"app_version"` + AppChannel string `json:"app_channel"` + DeviceModel string `json:"device_model"` + OSName string `json:"os_name"` + ABSDKVersion string `json:"ab_sdk_version"` + Custom map[string]any `json:"custom"` +} + +type remoteEvent struct { + Event string `json:"event"` + Params string `json:"params"` + Time int64 `json:"time"` + LocalTimeMS int64 `json:"local_time_ms"` +} + +var RuntimeDirFunc = defaultRuntimeDir + +var userUniqueIDProvider = loadOrCreateUserUniqueID + +var OfflineAccessChecker func() bool + +var brand string + +var appID string + +func SetTrackingFromConfig(b string, id string) { + brand = b + appID = id +} + +var userUniqueIDMu sync.Mutex + +func loadOrCreateUserUniqueID() (string, error) { + userUniqueIDMu.Lock() + defer userUniqueIDMu.Unlock() + + dir := logDir() + idFile := filepath.Join(dir, "user_uniq_id") + + if data, err := vfs.ReadFile(idFile); err == nil { + if id := strings.TrimSpace(string(data)); id != "" { + return id, nil + } + } + + newID, err := uuid.NewV7() + if err != nil { + return "", fmt.Errorf("generate user unique id: %w", err) + } + id := newID.String() + + if err := vfs.MkdirAll(dir, 0700); err != nil { + return "", fmt.Errorf("create cache dir: %w", err) + } + if err := localfileio.AtomicWrite(idFile, []byte(id+"\n"), 0600); err != nil { + return "", fmt.Errorf("write user unique id: %w", err) + } + return id, nil +} + +func defaultRuntimeDir() string { + if dir := os.Getenv("LARKSUITE_CLI_CONFIG_DIR"); dir != "" { + return dir + } + home, err := vfs.UserHomeDir() + if err != nil || home == "" { + home = "" + } + return filepath.Join(home, ".lark-cli") +} + +var ( + remoteEnabled = true + remoteClient = &http.Client{Timeout: remoteTimeout} +) + +func logDir() string { + if dir := os.Getenv("LARKSUITE_CLI_LOG_DIR"); dir != "" { + safeDir, err := validate.SafeEnvDirPath(dir, "LARKSUITE_CLI_LOG_DIR") + if err == nil { + return safeDir + } + } + + return filepath.Join(RuntimeDirFunc(), "logs") +} + +func formatCmdline(args []string) string { + if len(args) == 0 { + return "" + } + + if len(args) <= 3 { + return strings.Join(args, " ") + } + + return strings.Join(args[:3], " ") + " ..." +} + +func osName() string { + switch runtime.GOOS { + case "windows": + return "Windows" + case "darwin": + return "macOS" + case "linux": + return "Linux" + default: + return runtime.GOOS + } +} + +const telemetryEndpointFeishu = "https://mcs-bd.feishu.cn/v1/list" + +func resolveTelemetryEndpoint(brand string) string { + if brand == "feishu" { + return telemetryEndpointFeishu + } + return "" +} diff --git a/internal/tracking/event_test.go b/internal/tracking/event_test.go new file mode 100644 index 000000000..1d59b35d0 --- /dev/null +++ b/internal/tracking/event_test.go @@ -0,0 +1,322 @@ +// Copyright (c) 2026 Lark Technologies Pte. Ltd. +// SPDX-License-Identifier: MIT + +package tracking + +import ( + "encoding/json" + "errors" + "net/http" + "net/http/httptest" + "path/filepath" + "testing" + "time" + + "github.com/google/uuid" + "github.com/larksuite/cli/internal/build" +) + +func TestLogDir_UsesValidatedLogDirEnv(t *testing.T) { + base := t.TempDir() + base, _ = filepath.EvalSymlinks(base) + t.Setenv("LARKSUITE_CLI_LOG_DIR", filepath.Join(base, "logs", "..", "auth")) + t.Setenv("LARKSUITE_CLI_CONFIG_DIR", "") + + got := logDir() + want := filepath.Join(base, "auth") + if got != want { + t.Fatalf("logDir() = %q, want %q", got, want) + } +} + +func TestLogDir_InvalidLogDirFallsBackToConfigDir(t *testing.T) { + t.Setenv("LARKSUITE_CLI_LOG_DIR", "relative-logs") + configDir := t.TempDir() + t.Setenv("LARKSUITE_CLI_CONFIG_DIR", configDir) + + got := logDir() + want := filepath.Join(configDir, "logs") + if got != want { + t.Fatalf("logDir() = %q, want %q", got, want) + } +} + +func TestBuildRemoteAuthPayload_Response(t *testing.T) { + event := authEvent{ + Kind: authEventResponse, + Time: time.Date(2026, 5, 19, 12, 0, 0, 0, time.UTC), + Cmdline: "lark-cli auth login ...", + Path: "/open-apis/authen/v1/user_info", + Status: 200, + LogID: "log-123", + } + + payload, err := buildRemoteAuthPayload(event, "uuid-123") + if err != nil { + t.Fatalf("buildRemoteAuthPayload() error = %v", err) + } + if len(payload) != 1 { + t.Fatalf("payload len = %d, want 1", len(payload)) + } + item := payload[0] + if item.User.UserUniqueID != "uuid-123" { + t.Fatalf("user_unique_id = %q, want %q", item.User.UserUniqueID, "uuid-123") + } + if item.Header.AppName != "" { + t.Fatalf("app_name = %q, want empty", item.Header.AppName) + } + if item.Caller != remoteCaller { + t.Fatalf("caller = %q, want %q", item.Caller, remoteCaller) + } + if len(item.Events) != 1 { + t.Fatalf("events len = %d, want 1", len(item.Events)) + } + if item.Events[0].Event != "cli_auth_response" { + t.Fatalf("event = %q, want %q", item.Events[0].Event, "cli_auth_response") + } + var params map[string]any + if err := json.Unmarshal([]byte(item.Events[0].Params), ¶ms); err != nil { + t.Fatalf("params is not valid JSON string: %v", err) + } + if params["path"] != event.Path { + t.Fatalf("params.path = %v, want %q", params["path"], event.Path) + } + if int(params["status"].(float64)) != event.Status { + t.Fatalf("params.status = %v, want %d", params["status"], event.Status) + } + if params["x_tt_logid"] != event.LogID { + t.Fatalf("params.x_tt_logid = %v, want %q", params["x_tt_logid"], event.LogID) + } + if params["lark_cli_version"] != build.Version { + t.Fatalf("params.lark_cli_version = %v, want %q", params["lark_cli_version"], build.Version) + } +} + +func TestCheckOfflineAccess(t *testing.T) { + if OfflineAccessChecker != nil { + t.Fatal("OfflineAccessChecker should be nil by default") + } + if checkOfflineAccess() { + t.Fatal("checkOfflineAccess() = true when checker is nil, want false") + } + + OfflineAccessChecker = func() bool { return true } + if !checkOfflineAccess() { + t.Fatal("checkOfflineAccess() = false, want true") + } + + OfflineAccessChecker = func() bool { panic("boom") } + if checkOfflineAccess() { + t.Fatal("checkOfflineAccess() = true after panic, want false") + } + + OfflineAccessChecker = nil +} + +func TestCheckOfflineAccessForError(t *testing.T) { + OfflineAccessChecker = func() bool { return true } + + if checkOfflineAccessForError(AuthComponentKeychain) { + t.Fatal("checkOfflineAccessForError(keychain) = true, want false") + } + if !checkOfflineAccessForError(AuthComponentAuth) { + t.Fatal("checkOfflineAccessForError(auth) = false, want true") + } + + OfflineAccessChecker = nil +} + +func TestBuildRemoteAuthPayload_HasOfflineAccess(t *testing.T) { + event := authEvent{ + Kind: authEventResponse, + Time: time.Date(2026, 5, 19, 12, 0, 0, 0, time.UTC), + Cmdline: "lark-cli auth login ...", + Path: "/open-apis/authen/v2/oauth/token", + Status: 200, + LogID: "log-789", + HasOfflineAccess: true, + } + + payload, err := buildRemoteAuthPayload(event, "uuid-123") + if err != nil { + t.Fatalf("buildRemoteAuthPayload() error = %v", err) + } + if len(payload) != 1 { + t.Fatalf("payload len = %d, want 1", len(payload)) + } + var params map[string]any + if err := json.Unmarshal([]byte(payload[0].Events[0].Params), ¶ms); err != nil { + t.Fatalf("params is not valid JSON string: %v", err) + } + got, ok := params["has_offline_access"] + if !ok { + t.Fatal("has_offline_access not found in params") + } + if got != true { + t.Fatalf("has_offline_access = %v, want true", got) + } +} + +func TestPostRemoteAuthEvent_PostsExpectedPayload(t *testing.T) { + event := authEvent{ + Kind: authEventError, + Time: time.Date(2026, 5, 19, 12, 0, 0, 0, time.UTC), + Cmdline: "lark-cli auth login ...", + Component: AuthComponentAuth, + Op: AuthOpPermissionDenied, + Error: "reason=permission_denied", + } + + var gotMethod, gotContentType string + var gotPayload []remoteRequestItem + server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + gotMethod = r.Method + gotContentType = r.Header.Get("Content-Type") + defer r.Body.Close() + if err := json.NewDecoder(r.Body).Decode(&gotPayload); err != nil { + t.Fatalf("decode request body: %v", err) + } + w.WriteHeader(http.StatusOK) + })) + defer server.Close() + + restore := SetAuthLogRemoteHooksForTest(server.Client(), "feishu", func() (string, error) { + return "uuid-456", nil + }, true) + defer restore() + + if err := postRemoteAuthEvent(event, server.URL); err != nil { + t.Fatalf("postRemoteAuthEvent() error = %v", err) + } + if gotMethod != http.MethodPost { + t.Fatalf("method = %q, want %q", gotMethod, http.MethodPost) + } + if gotContentType != "application/json" { + t.Fatalf("content-type = %q, want application/json", gotContentType) + } + if len(gotPayload) != 1 { + t.Fatalf("payload len = %d, want 1", len(gotPayload)) + } + if gotPayload[0].Header.AppName != "" { + t.Fatalf("app_name = %q, want empty", gotPayload[0].Header.AppName) + } + if gotPayload[0].User.UserUniqueID != "uuid-456" { + t.Fatalf("user_unique_id = %q, want %q", gotPayload[0].User.UserUniqueID, "uuid-456") + } + if gotPayload[0].Events[0].Event != "cli_auth_error" { + t.Fatalf("event = %q, want %q", gotPayload[0].Events[0].Event, "cli_auth_error") + } + var params map[string]any + if err := json.Unmarshal([]byte(gotPayload[0].Events[0].Params), ¶ms); err != nil { + t.Fatalf("params is not valid JSON string: %v", err) + } + if params["lark_cli_version"] != build.Version { + t.Fatalf("params.lark_cli_version = %v, want %q", params["lark_cli_version"], build.Version) + } +} + +func TestEmitRemoteAuthEvent_FailOpenOnTransportError(t *testing.T) { + restore := SetAuthLogRemoteHooksForTest(&http.Client{Transport: roundTripFunc(func(*http.Request) (*http.Response, error) { + return nil, errors.New("network down") + })}, "feishu", func() (string, error) { + return "uuid-789", nil + }, true) + defer restore() + + emitRemoteAuthEvent(authEvent{Kind: authEventResponse, Time: time.Now(), Cmdline: "lark-cli auth status", Path: "/foo", Status: 200}) +} + +func TestPostRemoteAuthEvent_FallbackGeneratesUUIDv7(t *testing.T) { + event := authEvent{ + Kind: authEventResponse, + Time: time.Date(2026, 5, 19, 12, 0, 0, 0, time.UTC), + Cmdline: "lark-cli auth status", + Path: "/foo", + Status: 200, + } + + var gotPayload []remoteRequestItem + server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + defer r.Body.Close() + if err := json.NewDecoder(r.Body).Decode(&gotPayload); err != nil { + t.Fatalf("decode request body: %v", err) + } + w.WriteHeader(http.StatusOK) + })) + defer server.Close() + + restore := SetAuthLogRemoteHooksForTest(server.Client(), "feishu", func() (string, error) { + return "", errors.New("provider unavailable") + }, true) + defer restore() + + if err := postRemoteAuthEvent(event, server.URL); err != nil { + t.Fatalf("postRemoteAuthEvent() error = %v", err) + } + if len(gotPayload) != 1 { + t.Fatalf("payload len = %d, want 1", len(gotPayload)) + } + parsed, err := uuid.Parse(gotPayload[0].User.UserUniqueID) + if err != nil { + t.Fatalf("uuid.Parse(user_unique_id) error = %v", err) + } + if parsed.Version() != 7 { + t.Fatalf("uuid version = %d, want 7", parsed.Version()) + } +} + +func TestEmitRemoteAuthEvent_SkipsWhenEndpointProviderDisablesReporting(t *testing.T) { + called := false + server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + called = true + w.WriteHeader(http.StatusOK) + })) + defer server.Close() + + restore := SetAuthLogRemoteHooksForTest(server.Client(), "lark", func() (string, error) { + return "uuid-123", nil + }, true) + defer restore() + + emitRemoteAuthEvent(authEvent{Kind: authEventResponse, Time: time.Now(), Cmdline: "lark-cli auth status", Path: "/foo", Status: 200}) + if called { + t.Fatal("remote endpoint called, want skipped") + } +} + +type roundTripFunc func(*http.Request) (*http.Response, error) + +func (fn roundTripFunc) RoundTrip(req *http.Request) (*http.Response, error) { + return fn(req) +} + +func TestFormatCmdline_TruncatesExtraArgs(t *testing.T) { + got := formatCmdline([]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("formatCmdline() = %q, want %q", got, want) + } +} + +func TestResolveTelemetryEndpoint(t *testing.T) { + if got := resolveTelemetryEndpoint("feishu"); got != "https://mcs-bd.feishu.cn/v1/list" { + t.Errorf("resolveTelemetryEndpoint(feishu) = %q, want https://mcs-bd.feishu.cn/v1/list", got) + } + if got := resolveTelemetryEndpoint("lark"); got != "" { + t.Errorf("resolveTelemetryEndpoint(lark) = %q, want empty", got) + } + if got := resolveTelemetryEndpoint(""); got != "" { + t.Errorf("resolveTelemetryEndpoint(\"\") = %q, want empty", got) + } + if got := resolveTelemetryEndpoint("unknown"); got != "" { + t.Errorf("resolveTelemetryEndpoint(unknown) = %q, want empty", got) + } +} diff --git a/internal/vfs/fs.go b/internal/vfs/fs.go index 70298d5a2..71b7301c6 100644 --- a/internal/vfs/fs.go +++ b/internal/vfs/fs.go @@ -29,7 +29,6 @@ type FS interface { ReadDir(name string) ([]os.DirEntry, error) Remove(name string) error Rename(oldpath, newpath string) error - // Path resolution EvalSymlinks(path string) (string, error) Executable() (string, error)