diff --git a/plugins/channels/weixin_ilink/login.go b/plugins/channels/weixin_ilink/login.go index 7f475ae..a25a0cd 100644 --- a/plugins/channels/weixin_ilink/login.go +++ b/plugins/channels/weixin_ilink/login.go @@ -74,6 +74,7 @@ func (a *Adapter) runLogin(sess *loginSession, sessCtx context.Context) { ticker := time.NewTicker(a.cfg.LoginInterval) defer ticker.Stop() + prevStatus := "" for { status, err := a.pollQRStatus(timeoutCtx, sess.qrcode) if err != nil { @@ -86,6 +87,15 @@ func (a *Adapter) runLogin(sess *loginSession, sessCtx context.Context) { } return } + // Track the raw wire phase so StartLogin can protect a scanned/confirming bind + // from being re-minted. Log only on a status change to avoid noise, and never + // the qrcode identifier or tokens. + sess.setPhase(status.Status) + if status.Status != prevStatus { + prevStatus = status.Status + a.log.Info("weixin_ilink: get_qrcode_status", "status", status.Status) + } + switch status.Status { case "confirmed": if status.BotToken == "" { @@ -102,6 +112,12 @@ func (a *Adapter) runLogin(sess *loginSession, sessCtx context.Context) { case "verify_code_blocked": a.failLogin(sess, fmt.Errorf("weixin_ilink: verify code blocked, too many failed attempts")) return + case "scaned": + // The code has been scanned and awaits confirmation on the phone. Keep the + // session and keep polling — re-minting here would discard the pending + // confirmation. Expose the state through the backward-compatible waiting + // status plus a detail so the panel can prompt the user to confirm. + a.setLoginState(LoginStatusWaiting, loginScannedDetail) case "scaned_but_redirect": if status.RedirectHost != "" { a.setPollBaseURL(status.RedirectHost) @@ -142,6 +158,8 @@ func (a *Adapter) completeLogin(sess *loginSession, status qrcodeStatusResp) { a.loginDetail = "" a.mu.Unlock() + a.log.Info("weixin_ilink: login confirmed", "bot_id", status.BotID) + a.loginMu.Lock() if a.loginSession == sess { a.loginSession = nil @@ -155,6 +173,7 @@ func (a *Adapter) completeLogin(sess *loginSession, status qrcodeStatusResp) { // scanned bot is already linked to this instance, so the server issues no new // credentials and any existing token remains valid. func (a *Adapter) completeBindedRedirect(sess *loginSession) { + a.log.Info("weixin_ilink: login already bound (binded_redirect)") a.mu.Lock() a.connected = a.cfg.BotToken != "" a.loginStatus = LoginStatusConfirmed @@ -170,16 +189,22 @@ func (a *Adapter) completeBindedRedirect(sess *loginSession) { sess.done <- nil } -// failLogin records a failed scan-login and signals the waiting Connect path. +// failLogin records a failed scan-login and signals the waiting Connect path. A +// superseded session (one cancelled so StartLogin could mint a fresh QR for an +// unscanned code) never clobbers the newer session's state, but its Connect wait +// must still be released. func (a *Adapter) failLogin(sess *loginSession, err error) { - a.setLoginState(LoginStatusFailed, err.Error()) - a.loginMu.Lock() - if a.loginSession == sess { + isCurrent := a.loginSession == sess + if isCurrent { a.loginSession = nil } a.loginMu.Unlock() + if isCurrent { + a.log.Warn("weixin_ilink: login failed", "err", err) + a.setLoginState(LoginStatusFailed, err.Error()) + } sess.done <- err } @@ -212,6 +237,9 @@ func (a *Adapter) fetchQRCode(ctx context.Context) (qrcodeResp, error) { if out.Qrcode == "" { return qrcodeResp{}, fmt.Errorf("weixin_ilink: get_bot_qrcode returned empty qrcode") } + // Log only the renderable QR URL, never the raw qrcode identifier (it is a secret + // echoed to get_qrcode_status). The timestamp is attached by the logger. + a.log.Info("weixin_ilink: get_bot_qrcode ok", "url", out.QrcodeImgContent) return out, nil } diff --git a/plugins/channels/weixin_ilink/login_admin.go b/plugins/channels/weixin_ilink/login_admin.go index 57b59c9..98f284c 100644 --- a/plugins/channels/weixin_ilink/login_admin.go +++ b/plugins/channels/weixin_ilink/login_admin.go @@ -11,6 +11,7 @@ import ( "context" "errors" "fmt" + "sync" "time" ) @@ -37,6 +38,12 @@ const ( const ( loginNeedVerifyCodeHint = "请输入微信显示的数字" loginBindedRedirectDetail = "已连接过此 OpenClaw，无需重复连接" + // loginScannedDetail is the detail reported while the QR has been scanned and is + // awaiting confirmation on the phone. It reuses LoginStatusWaiting so the panel + // stays backward-compatible; the raw wire "scaned" state is tracked separately on + // the session (loginSession.phase) so StartLogin can protect the bind from being + // re-minted mid-confirmation. + loginScannedDetail = "已被扫描，请在微信确认" ) // ErrAlreadyLoggedIn is returned by StartLogin when a bot token is already @@ -60,12 +67,47 @@ type loginSession struct { cancel context.CancelFunc // done carries the login outcome; the poll goroutine writes exactly once. done chan error + + // phase is the latest get_qrcode_status value the poll goroutine observed. It is + // guarded by phaseMu and is distinct from loginStatus, which is the panel-observable + // state and stays backward-compatible ("waiting") during a "scaned" confirmation. + phaseMu sync.Mutex + phase string +} + +// setPhase records the latest observed wire status. +func (s *loginSession) setPhase(p string) { + s.phaseMu.Lock() + s.phase = p + s.phaseMu.Unlock() +} + +// currentPhase returns the latest observed wire status. +func (s *loginSession) currentPhase() string { + s.phaseMu.Lock() + defer s.phaseMu.Unlock() + return s.phase +} + +// confirmingPhase reports whether the QR bind is mid-flow in a way that re-minting a +// fresh code would discard: the code has been scanned and awaits confirmation, the +// server redirected the polling host after a scan, or the server asked for a pairing +// code. Such sessions are reused, never re-minted. +func (s *loginSession) confirmingPhase() bool { + switch s.currentPhase() { + case "scaned", "scaned_but_redirect", "need_verifycode": + return true + default: + return false + } } // qrReuseWindow is how long a just-minted QR is reused on an immediate re-click // before StartLogin re-mints a fresh one. WeChat bot QRs are short-lived, so a // "扫码登录/刷新二维码" click must yield a brand-new code — reusing an old QR is -// exactly what makes WeChat report "二维码过期". +// exactly what makes WeChat report "二维码过期". A QR that is already scanned +// (confirmingPhase) is always reused regardless of this window so the bind is not +// dropped mid-confirmation. const qrReuseWindow = 5 * time.Second // StartLogin begins a scan-login and returns the QR code to display. It is @@ -82,12 +124,23 @@ func (a *Adapter) StartLogin(ctx context.Context) (LoginQR, error) { return LoginQR{}, ErrAlreadyLoggedIn } if sess := a.loginSession; sess != nil { - // Reuse only within a tiny window (a literal double-click); otherwise re-mint - // a brand-new QR so the panel's "扫码登录/刷新二维码" never serves a stale, - // expired WeChat code. The old poll goroutine is cancelled. + // A bind is in progress. Re-minting would cancel the poll and, if the user has + // already scanned or the server is mid-flow, discard the pending confirmation — + // WeChat's confirm would then never land. Protect those sessions by reusing the + // current QR unconditionally. Only a QR still waiting to be scanned and past the + // tiny reuse window is re-minted, so an explicit "刷新二维码" yields a fresh code. + if sess.confirmingPhase() { + a.log.Info("weixin_ilink: login in progress, reusing qrcode", "phase", sess.currentPhase()) + return LoginQR{Qrcode: sess.qrcode, Image: sess.image}, nil + } + // A literal double-click within the reuse window: serve the same code. if time.Since(sess.startedAt) < qrReuseWindow { return LoginQR{Qrcode: sess.qrcode, Image: sess.image}, nil } + // Not scanned yet and past the reuse window: mint a fresh code, cancelling the + // old (unscanned) poll. failLogin guards a cancelled goroutine from clobbering + // the new session's state. + a.log.Info("weixin_ilink: previous qrcode not scanned, minting a fresh one") if sess.cancel != nil { sess.cancel() } @@ -113,8 +166,6 @@ func (a *Adapter) StartLogin(ctx context.Context) (LoginQR, error) { // Reset any IDC redirect host recorded by a previous (re-)scan so a new login // starts polling the configured base URL. a.setPollBaseURL("") - // Log only the renderable URL, never the raw qrcode (it is a secret). - a.log.Info("scan the qr code to bind the bot", "url", raw.QrcodeImgContent) go a.runLogin(sess, sessCtx) return LoginQR{Qrcode: sess.qrcode, Image: sess.image}, nil diff --git a/plugins/channels/weixin_ilink/login_reuse_test.go b/plugins/channels/weixin_ilink/login_reuse_test.go new file mode 100644 index 0000000..65f7c29 --- /dev/null +++ b/plugins/channels/weixin_ilink/login_reuse_test.go @@ -0,0 +1,204 @@ +package weixin_ilink + +import ( + "bytes" + "context" + "fmt" + "log/slog" + "strings" + "testing" + "time" +) + +// TestStartLogin_ScanedExposesWaitingDetail verifies that an observed "scaned" wire +// status is surfaced to the panel as the backward-compatible waiting status with the +// "please confirm" detail, so the frontend keeps its waiting UI without a new status. +func TestStartLogin_ScanedExposesWaitingDetail(t *testing.T) { + t.Parallel() + srv := newJSONServer(t, nil, func(req recordedReq) handlerResult { + switch req.path { + case "/ilink/bot/get_bot_qrcode": + return handlerResult{body: jsonBody(map[string]any{ + "qrcode": "qr-s1", "qrcode_img_content": "https://img/s1", + })} + case "/ilink/bot/get_qrcode_status": + return handlerResult{body: jsonBody(map[string]any{"status": "scaned"})} + } + return handlerResult{status: 404} + }) + + cfg := Config{BaseURL: srv.URL, LoginInterval: time.Millisecond, LoginTimeout: 5 * time.Second} + ad := newAdapter(t, cfg, srv) + if _, err := ad.StartLogin(context.Background()); err != nil { + t.Fatalf("StartLogin: %v", err) + } + waitFor(t, func() bool { + status, detail := ad.LoginStatus(context.Background()) + return status == LoginStatusWaiting && detail == loginScannedDetail + }) +} + +// TestStartLogin_ScanedPastWindowReusesQR verifies the re-mint protection: once the +// poll has observed "scaned" (awaiting confirmation), StartLogin reuses the current QR +// even past the qrReuseWindow and never issues a second get_bot_qrcode — the pending +// confirm is not dropped. +func TestStartLogin_ScanedPastWindowReusesQR(t *testing.T) { + t.Parallel() + rec := &reqRecorder{} + srv := newJSONServer(t, rec, func(req recordedReq) handlerResult { + switch req.path { + case "/ilink/bot/get_bot_qrcode": + return handlerResult{body: jsonBody(map[string]any{ + "qrcode": "qr-scaned", "qrcode_img_content": "https://img/scaned", + })} + case "/ilink/bot/get_qrcode_status": + return handlerResult{body: jsonBody(map[string]any{"status": "scaned"})} + } + return handlerResult{status: 404} + }) + + cfg := Config{BaseURL: srv.URL, LoginInterval: time.Millisecond, LoginTimeout: 5 * time.Second} + ad := newAdapter(t, cfg, srv) + first, err := ad.StartLogin(context.Background()) + if err != nil { + t.Fatalf("first StartLogin: %v", err) + } + + // Wait until the poll goroutine has observed "scaned" (the session is confirming). + waitFor(t, func() bool { + ad.loginMu.Lock() + defer ad.loginMu.Unlock() + return ad.loginSession != nil && ad.loginSession.currentPhase() == "scaned" + }) + + // Push startedAt well past the reuse window so only the protection, not the window, + // could keep the QR. Then a refresh must still reuse it. + ad.loginMu.Lock() + if ad.loginSession != nil { + ad.loginSession.startedAt = time.Now().Add(-(qrReuseWindow + time.Second)) + } + ad.loginMu.Unlock() + + second, err := ad.StartLogin(context.Background()) + if err != nil { + t.Fatalf("second StartLogin: %v", err) + } + if first.Qrcode != second.Qrcode || first.Image != second.Image { + t.Fatalf("scaned session re-minted: first=%+v second=%+v (want identical reuse)", first, second) + } + if got := len(rec.find(func(q recordedReq) bool { return q.path == "/ilink/bot/get_bot_qrcode" })); got != 1 { + t.Fatalf("get_bot_qrcode called %d times, want 1 (confirming session must not be re-minted)", got) + } +} + +// TestStartLogin_WaitingPastWindowReMints verifies the explicit-refresh scenario is +// preserved: a QR that is still waiting (not yet scanned) and is past the reuse window +// is re-minted with a fresh get_bot_qrcode, and the cancelled old poll never clobbers +// the new session's state with "failed". +func TestStartLogin_WaitingPastWindowReMints(t *testing.T) { + t.Parallel() + rec := &reqRecorder{} + mintCalls := 0 + srv := newJSONServer(t, rec, func(req recordedReq) handlerResult { + switch req.path { + case "/ilink/bot/get_bot_qrcode": + mintCalls++ + return handlerResult{body: jsonBody(map[string]any{ + "qrcode": fmt.Sprintf("qr-w%d", mintCalls), + "qrcode_img_content": fmt.Sprintf("https://img/w%d", mintCalls), + })} + case "/ilink/bot/get_qrcode_status": + return handlerResult{body: jsonBody(map[string]any{"status": "wait"})} + } + return handlerResult{status: 404} + }) + + cfg := Config{BaseURL: srv.URL, LoginInterval: time.Millisecond, LoginTimeout: 5 * time.Second} + ad := newAdapter(t, cfg, srv) + first, err := ad.StartLogin(context.Background()) + if err != nil { + t.Fatalf("first StartLogin: %v", err) + } + + waitFor(t, func() bool { + ad.loginMu.Lock() + defer ad.loginMu.Unlock() + return ad.loginSession != nil && ad.loginSession.currentPhase() == "wait" + }) + + ad.loginMu.Lock() + if ad.loginSession != nil { + ad.loginSession.startedAt = time.Now().Add(-(qrReuseWindow + time.Second)) + } + ad.loginMu.Unlock() + + second, err := ad.StartLogin(context.Background()) + if err != nil { + t.Fatalf("second StartLogin: %v", err) + } + if second.Qrcode == first.Qrcode { + t.Fatalf("waiting session past reuse window reused stale QR %q, want a fresh code", first.Qrcode) + } + if got := len(rec.find(func(q recordedReq) bool { return q.path == "/ilink/bot/get_bot_qrcode" })); got != 2 { + t.Fatalf("get_bot_qrcode called %d times, want 2 (past-window waiting refresh re-mints)", got) + } + // The cancelled old poll must not clobber the freshly-minted waiting state. + if status, _ := ad.LoginStatus(context.Background()); status != LoginStatusWaiting { + t.Fatalf("LoginStatus after re-mint = %q, want waiting (superceded session must not set failed)", status) + } +} + +// TestLogin_LogRedaction verifies the scan-login path logs only redacted identifiers: +// the renderable QR URL and the bot id are present, but the raw qrcode identifier, the +// bot_token, and the owner user_id are never written. +func TestLogin_LogRedaction(t *testing.T) { + t.Parallel() + var buf bytes.Buffer + statusCalls := 0 + srv := newJSONServer(t, nil, func(req recordedReq) handlerResult { + switch req.path { + case "/ilink/bot/get_bot_qrcode": + return handlerResult{body: jsonBody(map[string]any{ + "qrcode": "qr-redact", "qrcode_img_content": "https://img/redact", + })} + case "/ilink/bot/get_qrcode_status": + statusCalls++ + if statusCalls == 1 { + return handlerResult{body: jsonBody(map[string]any{"status": "scaned"})} + } + return handlerResult{body: jsonBody(map[string]any{ + "status": "confirmed", "bot_token": "tok-secret", + "ilink_bot_id": "bot-redact", "ilink_user_id": "o-redact", + "baseurl": "https://ilinkai.weixin.qq.com", + })} + } + return handlerResult{status: 404} + }) + + cfg := Config{BaseURL: srv.URL, LoginInterval: time.Millisecond, LoginTimeout: 5 * time.Second} + ad, err := New(cfg, srv.Client(), slog.New(slog.NewTextHandler(&buf, nil))) + if err != nil { + t.Fatalf("New: %v", err) + } + if _, err := ad.StartLogin(context.Background()); err != nil { + t.Fatalf("StartLogin: %v", err) + } + waitFor(t, func() bool { return ad.IsConnected() }) + + logs := buf.String() + for _, want := range []string{ + "get_bot_qrcode ok", + "https://img/redact", // sanitized renderable URL + "login confirmed", + "bot-redact", // bot id is non-sensitive + } { + if !strings.Contains(logs, want) { + t.Fatalf("logs missing %q:\n%s", want, logs) + } + } + for _, secret := range []string{"qr-redact", "tok-secret", "o-redact", "qrcode=qr-redact"} { + if strings.Contains(logs, secret) { + t.Fatalf("logs leaked secret %q:\n%s", secret, logs) + } + } +}