fix(weixin_ilink): 已扫待确认不重新取码 + scaned 状态暴露 + 扫码链路日志
StartLogin 换码保护: 当 runLogin 观测到 wire 状态已进入 scaned/scaned_but_redirect/need_verifycode(confirmingPhase)时, 复用当前 loginSession 的 QR 而不重新 fetchQRCode/cancel 旧 poll, 避免 45s 自动刷新/恢复前台把已扫未确认的会话砍掉导致微信 confirm 丢失。 仍保留 qrReuseWindow: 未扫描(等待中)且超窗口才重取, 保留显式刷新二维码要新码。 runLogin 补 case scaned: setLoginState(LoginStatusWaiting, loginScannedDetail), 沿用 Waiting 不新增破坏性状态; 顺带在会话上记录 wire phase 供 StartLogin 判别。 可观测性: fetchQRCode 取码成功记 get_bot_qrcode ok(url 脱敏, 不含 qrcode), pollQRStatus 状态变化才记 get_qrcode_status(status), completeLogin/failLogin/ completeBindedRedirect 记结果; 均不落 qrcode/bot_token/user_id。 failLogin 修正: 被 re-mint superseded 的旧会话不再 clobber 新会话状态(不置 failed)。 新增测试: scaned 暴露到 LoginStatus; scaned 超窗口复用 QR 不重取; 等待中超窗口 重取; 日志脱敏断言。
This commit is contained in:
1 parent
4223f5a19a
commit
c515de28bf
3 files changed
+293
-10
No files matched your search
@@ -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
|
||||
}
|
||||
|
||||
|
||||
@@ -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
|
||||
|
||||
@@ -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)
|
||||
}
|
||||
}
|
||||
}
|
||||
Reference in new issue
Block a user