Files
AskaEth e1bd7c3009
CI / Backend (build / vet / test / cross-compile) (push) Has been cancelled
CI / Frontend (tsc + vite build) (push) Has been cancelled
fix(channels): 探活失败不再静默 + 回执信封校验(杜绝把失败谎报成账号离线)+ echo 唯一化
2026-10-05 12:29:34 +08:00

541 lines
19 KiB
Go
Raw Permalink Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
package qq_obv11
// 本文件是 `get_status` 主动探活(probe.go)的端到端自证:用**本地假 OneBot 实现**
// (WS 反连 / HTTP API)真的收一次 get_status 请求、真的回一次响应,断言
// - 账号在线/离线被如实检测到(含 offline 判定),且 AccountStatus 可区分「未探到」;
// - 状态**只在变化时**记一条日志(用测试 handler 捕获渲染后的日志串来数行数);
// - 请求失败 / 超时不伪造状态,也不产生状态日志;
// - 后台探活循环在 Disconnect 后干净退出(不再发请求)。
//
// 绝不用真实 QQ:全部走本机 httptest 假服务端。
import (
"bytes"
"context"
"encoding/json"
"errors"
"log/slog"
"net/http"
"net/http/httptest"
"strings"
"sync"
"sync/atomic"
"testing"
"time"
)
// fakeStatusWS 是本地假的 OneBot WS 实现:只认 get_status 请求,并按当前 online/good
// 回一条带 echo 的标准响应信封。reply=false 时故意不回(模拟对端挂死 / 超时)。
// raw 非空时完全接管回执内容(构造 retcode!=0 / data 为 null 等异常信封)。
type fakeStatusWS struct {
online atomic.Bool
good atomic.Bool
reply atomic.Bool
raw atomic.Value // func(echo string) []byte
mu sync.Mutex
probes int
}
func (f *fakeStatusWS) count() int {
f.mu.Lock()
defer f.mu.Unlock()
return f.probes
}
func (f *fakeStatusWS) handler() http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
conn, err := upgradeWS(w, r)
if err != nil {
return
}
defer func() { _ = conn.Close() }()
for {
_, payload, err := conn.ReadMessage()
if err != nil {
return
}
var req struct {
Action string `json:"action"`
Echo string `json:"echo"`
}
if err := json.Unmarshal(payload, &req); err != nil || req.Action != actionGetStatus {
continue
}
f.mu.Lock()
f.probes++
f.mu.Unlock()
if !f.reply.Load() {
continue
}
if fn, ok := f.raw.Load().(func(string) []byte); ok {
_ = conn.WriteMessage(opText, fn(req.Echo))
continue
}
body, _ := json.Marshal(map[string]any{
"status": "ok",
"retcode": 0,
"data": map[string]any{"online": f.online.Load(), "good": f.good.Load()},
"echo": req.Echo,
})
_ = conn.WriteMessage(opText, body)
}
})
}
// countLogLines 数渲染后日志里包含 sub 的行数(用于断言「只记一次」)。
func countLogLines(buf *bytes.Buffer, sub string) int {
return countLogText(buf.String(), sub)
}
// countLogText 与 countLogLines 同口径,但接受并发安全缓冲拿到的文本快照。
func countLogText(text, sub string) int {
n := 0
for _, line := range strings.Split(text, "\n") {
if strings.Contains(line, sub) {
n++
}
}
return n
}
// syncLogWriter 是并发安全的日志写入端:探活循环在后台写、测试在主协程读,
// 直接共用裸 bytes.Buffer 会构成 data race。
type syncLogWriter struct {
mu sync.Mutex
buf bytes.Buffer
}
func (w *syncLogWriter) Write(p []byte) (int, error) {
w.mu.Lock()
defer w.mu.Unlock()
return w.buf.Write(p)
}
func (w *syncLogWriter) text() string {
w.mu.Lock()
defer w.mu.Unlock()
return w.buf.String()
}
// logCaptureSync 与 logCapture 同级别同格式,但写入端并发安全。
func logCaptureSync() (*syncLogWriter, *slog.Logger) {
w := &syncLogWriter{}
return w, slog.New(slog.NewTextHandler(w, &slog.HandlerOptions{Level: slog.LevelDebug}))
}
// TestProbeDetectsAccountTransitionsOnceWS 覆盖 WS 端:真的发 get_status、真的收回执,
// 在线→离线被检测到,且每次状态变化**只记一条**日志(good 也带上)。
func TestProbeDetectsAccountTransitionsOnceWS(t *testing.T) {
t.Parallel()
buf, log := logCapture()
f := &fakeStatusWS{}
f.reply.Store(true)
f.good.Store(true)
srv := httptest.NewServer(f.handler())
defer srv.Close()
url := "ws://" + strings.TrimPrefix(srv.URL, "http://")
a := NewAdapter(Config{Mode: modeClient, RemoteURL: url, Logger: log})
if err := a.Connect(context.Background()); err != nil {
t.Fatalf("Connect error: %v", err)
}
defer func() { _ = a.Disconnect(context.Background()) }()
ctx := context.Background()
probe := func() {
t.Helper()
if err := a.probeStatus(ctx); err != nil {
t.Fatalf("probeStatus error: %v", err)
}
}
f.online.Store(true)
probe() // 首次确立:在线 → 记一条
probe() // 状态未变 → 不记
if online, known := a.AccountStatus(); !known || !online {
t.Fatalf("AccountStatus() = (%v,%v), want (true,true) after online probe", online, known)
}
f.online.Store(false)
probe() // 在线→离线 → 记一条
probe() // 状态未变 → 不记
if online, known := a.AccountStatus(); !known || online {
t.Fatalf("AccountStatus() = (%v,%v), want (false,true) after offline probe", online, known)
}
if n := countLogLines(buf, "onebot account online"); n != 1 {
t.Errorf("「account online」日志行数 = %d, want 1\n%s", n, buf.String())
}
if n := countLogLines(buf, "onebot account offline"); n != 1 {
t.Errorf("「account offline」日志行数 = %d, want 1\n%s", n, buf.String())
}
if !strings.Contains(buf.String(), "good=true") {
t.Errorf("状态日志缺少 OneBot 返回的 good\n%s", buf.String())
}
if !strings.Contains(buf.String(), "source=plugins/channels/qq_obv11") {
t.Errorf("状态日志缺少 source\n%s", buf.String())
}
}
// TestProbeOverHTTPTransport 覆盖 HTTP 端:get_status 走既有 obHTTPClient,同样能检测
// 离线→在线;证明两条传输共用同一套探活逻辑。
func TestProbeOverHTTPTransport(t *testing.T) {
t.Parallel()
buf, log := logCapture()
var online atomic.Bool
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
w.Header().Set("Content-Type", "application/json")
_ = json.NewEncoder(w).Encode(map[string]any{
"status": "ok",
"retcode": 0,
"data": map[string]any{"online": online.Load(), "good": true},
})
}))
defer srv.Close()
a := NewAdapter(Config{
Transport: transportHTTP,
Mode: modeClient,
APIBaseURL: srv.URL,
Logger: log,
})
if err := a.Connect(context.Background()); err != nil {
t.Fatalf("Connect error: %v", err)
}
defer func() { _ = a.Disconnect(context.Background()) }()
ctx := context.Background()
online.Store(false)
if err := a.probeStatus(ctx); err != nil {
t.Fatalf("probeStatus error: %v", err)
}
if got, known := a.AccountStatus(); !known || got {
t.Fatalf("AccountStatus() = (%v,%v), want (false,true)", got, known)
}
online.Store(true)
if err := a.probeStatus(ctx); err != nil {
t.Fatalf("probeStatus error: %v", err)
}
if got, known := a.AccountStatus(); !known || !got {
t.Fatalf("AccountStatus() = (%v,%v), want (true,true)", got, known)
}
if n := countLogLines(buf, "onebot account offline"); n != 1 {
t.Errorf("「account offline」日志行数 = %d, want 1\n%s", n, buf.String())
}
if n := countLogLines(buf, "onebot account online"); n != 1 {
t.Errorf("「account online」日志行数 = %d, want 1\n%s", n, buf.String())
}
}
// TestProbeTimeoutWithoutReply 覆盖失败路径:对端收下请求却不回执 ⇒ 探活超时返回错误,
// 账号状态保持「未探到」,绝不伪造在线/离线,也不产生状态日志。
func TestProbeTimeoutWithoutReply(t *testing.T) {
t.Parallel()
buf, log := logCapture()
f := &fakeStatusWS{} // reply=false:只计数不回执
f.reply.Store(false)
srv := httptest.NewServer(f.handler())
defer srv.Close()
url := "ws://" + strings.TrimPrefix(srv.URL, "http://")
a := NewAdapter(Config{Mode: modeClient, RemoteURL: url, Logger: log})
a.probeTimeout = 150 * time.Millisecond
if err := a.Connect(context.Background()); err != nil {
t.Fatalf("Connect error: %v", err)
}
defer func() { _ = a.Disconnect(context.Background()) }()
err := a.probeStatus(context.Background())
if err == nil {
t.Fatal("probeStatus() = nil, want timeout error")
}
if !errors.Is(err, context.DeadlineExceeded) {
t.Errorf("probeStatus error = %v, want context.DeadlineExceeded", err)
}
if _, known := a.AccountStatus(); known {
t.Error("AccountStatus known = true after failed probe, want false (未探到)")
}
if n := countLogLines(buf, "onebot account"); n != 0 {
t.Errorf("失败探活不应产生状态日志,实得 %d 行\n%s", n, buf.String())
}
if f.count() == 0 {
t.Error("假服务端从未收到 get_status 请求,探活根本没走既有通道")
}
}
// TestProbeHTTPRetcodeFailure 覆盖 HTTP 端失败判定:OneBot 回 retcode!=0 时探活报错,
// 状态不更新。
func TestProbeHTTPRetcodeFailure(t *testing.T) {
t.Parallel()
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
w.Header().Set("Content-Type", "application/json")
_ = json.NewEncoder(w).Encode(map[string]any{"status": "failed", "retcode": 100, "msg": "nope"})
}))
defer srv.Close()
a := NewAdapter(Config{Transport: transportHTTP, Mode: modeClient, APIBaseURL: srv.URL})
if err := a.Connect(context.Background()); err != nil {
t.Fatalf("Connect error: %v", err)
}
defer func() { _ = a.Disconnect(context.Background()) }()
if err := a.probeStatus(context.Background()); err == nil {
t.Fatal("probeStatus() = nil, want the OneBot retcode failure surfaced")
}
if _, known := a.AccountStatus(); known {
t.Error("AccountStatus known = true after failed probe, want false")
}
}
// TestProbeLoopStopsOnDisconnect 覆盖后台探活循环:按 probeEvery 周期真的发请求,且
// Disconnect 后干净退出(不再有新请求),不泄漏 goroutine。
func TestProbeLoopStopsOnDisconnect(t *testing.T) {
t.Parallel()
_, log := logCapture()
f := &fakeStatusWS{}
f.reply.Store(true)
f.online.Store(true)
srv := httptest.NewServer(f.handler())
defer srv.Close()
url := "ws://" + strings.TrimPrefix(srv.URL, "http://")
a := NewAdapter(Config{Mode: modeClient, RemoteURL: url, Logger: log})
a.probeEvery = 5 * time.Millisecond
if err := a.Connect(context.Background()); err != nil {
t.Fatalf("Connect error: %v", err)
}
if !waitUntil(3*time.Second, func() bool { return f.count() >= 2 }) {
t.Fatalf("后台探活循环未发出请求(probes=%d)", f.count())
}
if err := a.Disconnect(context.Background()); err != nil {
t.Fatalf("Disconnect error: %v", err)
}
after := f.count()
time.Sleep(80 * time.Millisecond) // ~16 个 probeEvery
if final := f.count(); final != after {
t.Errorf("Disconnect 后探活仍在继续:%d → %d", after, final)
}
}
// TestProbeStartLogOnConnect 断言 Connect 会**主动汇报**探活状态:启用时给出间隔、超时与
// 端。没有这一行,「探活没跑」与「跑了但一直失败」在日志里长得一模一样(都是没有)。
func TestProbeStartLogOnConnect(t *testing.T) {
t.Parallel()
writer, log := logCaptureSync()
f := &fakeStatusWS{}
f.reply.Store(true)
srv := httptest.NewServer(f.handler())
defer srv.Close()
a := NewAdapter(Config{Mode: modeClient, RemoteURL: wsURL(srv), Logger: log})
if err := a.Connect(context.Background()); err != nil {
t.Fatalf("Connect error: %v", err)
}
defer func() { _ = a.Disconnect(context.Background()) }()
text := writer.text()
if n := countLogText(text, "onebot get_status probe enabled"); n != 1 {
t.Fatalf("探活启用行行数 = %d, want 1\n%s", n, text)
}
if !strings.Contains(text, "interval=") || !strings.Contains(text, "timeout=") {
t.Errorf("启用行缺少 interval/timeout,看不出探活节奏:\n%s", text)
}
if !strings.Contains(text, "source=plugins/channels/qq_obv11") {
t.Errorf("启用行缺少 source:\n%s", text)
}
}
// TestProbeStartLogReportsDisabled 断言探活不可用时也有一行,且带原因——排障时
// 「为什么没跑」必须能从日志里读出来,而不是猜。
func TestProbeStartLogReportsDisabled(t *testing.T) {
t.Parallel()
buf, log := logCapture()
a := NewAdapter(Config{Transport: transportHTTP, Mode: modeServer, Logger: log})
a.logProbeStart()
if n := countLogLines(buf, "onebot get_status probe disabled"); n != 1 {
t.Fatalf("探活禁用行行数 = %d, want 1\n%s", n, buf.String())
}
if !strings.Contains(buf.String(), "reason=") {
t.Errorf("禁用行缺少 reason:\n%s", buf.String())
}
}
// TestProbeFailureLogsWarnOnceThenThrottles 是失败日志口径的确定性单元测试:连续失败里
// 第 1 次必 WARN、每隔 probeWarnEvery 次再 WARN 一次、其余降 DEBUG——**每次都留痕**但
// 绝不刷屏。
func TestProbeFailureLogsWarnOnceThenThrottles(t *testing.T) {
t.Parallel()
buf, log := logCapture()
a := NewAdapter(Config{Mode: modeClient, Logger: log})
probeErr := errors.New("qq-obv11: get_status probe: test failure")
for n := 1; n <= probeWarnEvery; n++ {
a.logProbeFailure(probeErr, n)
}
text := buf.String()
if n := countLogLines(buf, "onebot get_status probe failed"); n != probeWarnEvery-1 {
t.Errorf("「首次失败」文案行数 = %d, want %d\n%s", n, probeWarnEvery-1, text)
}
if n := countLogLines(buf, "onebot get_status probe still failing"); n != 1 {
t.Errorf("节流 WARN 行数 = %d, want 1(第 %d 次失败)\n%s", n, probeWarnEvery, text)
}
if n := countLogLines(buf, "level=WARN"); n != 2 {
t.Errorf("连续 %d 次失败共 %d 行 WARN, want 2(首败 + 节流)\n%s", probeWarnEvery, n, text)
}
if n := countLogLines(buf, "level=DEBUG"); n != probeWarnEvery-2 {
t.Errorf("DEBUG 行数 = %d, want %d\n%s", n, probeWarnEvery-2, text)
}
if !strings.Contains(text, "err=") || !strings.Contains(text, "failures=") || !strings.Contains(text, "retryIn=") {
t.Errorf("失败日志缺少 err/failures/retryIn:\n%s", text)
}
}
// TestProbeLoopLogsFailureThenRecovery 是失败日志的循环级自证:假 OneBot 收下请求却不
// 回执 ⇒ 后台循环必须留下 WARN(绝不静默);对端恢复回执后必须留下「recovered」,
// 并把账号状态重新确立为在线。
func TestProbeLoopLogsFailureThenRecovery(t *testing.T) {
t.Parallel()
f := &fakeStatusWS{} // reply=false:只计数不回执 ⇒ 每次探活超时
f.online.Store(true)
f.good.Store(true)
srv := httptest.NewServer(f.handler())
defer srv.Close()
writer, log := logCaptureSync()
a := NewAdapter(Config{Mode: modeClient, RemoteURL: wsURL(srv), Logger: log})
a.probeEvery = 5 * time.Millisecond
a.probeTimeout = 30 * time.Millisecond
// 失败退避拉到 200ms 固定:首败 WARN 之后不会在同一瞬间堆出第二次失败,
// 「此处只能有一行 WARN」才是确定性的断言。
a.policy = slowTestProbePolicy()
if err := a.Connect(context.Background()); err != nil {
t.Fatalf("Connect error: %v", err)
}
defer func() { _ = a.Disconnect(context.Background()) }()
if !waitUntil(5*time.Second, func() bool {
return strings.Contains(writer.text(), "onebot get_status probe failed")
}) {
t.Fatalf("探活连续失败却一条日志都没有(静默失败):\n%s", writer.text())
}
if n := countLogText(writer.text(), "level=WARN"); n != 1 {
t.Errorf("首次失败期间 WARN 行数 = %d, want 1(连续失败不刷屏)\n%s", n, writer.text())
}
f.reply.Store(true)
if !waitUntil(5*time.Second, func() bool {
return strings.Contains(writer.text(), "onebot get_status probe recovered")
}) {
t.Fatalf("探活恢复后没有留下恢复日志:\n%s", writer.text())
}
if online, known := a.AccountStatus(); !known || !online {
t.Errorf("AccountStatus() = (%v,%v), want (true,true) after recovery", online, known)
}
}
// TestProbeEnvelopeFailuresNeverFakeOffline 覆盖 WS 端的信封异常(WS 上没有 http_client
// 的 retcode 校验):retcode!=0、status=failed、data 为 null / 缺失,一律判为**失败**。
// 若这里被判成「成功」,解析出的零值会把「探活失败」谎报成「账号离线」——比不报更危险。
func TestProbeEnvelopeFailuresNeverFakeOffline(t *testing.T) {
t.Parallel()
cases := []struct{ name, raw string }{
{"retcode non-zero with null data", `{"status":"failed","retcode":1404,"data":null}`},
{"retcode non-zero without data", `{"status":"failed","retcode":1404}`},
{"status failed with ok retcode", `{"status":"failed","retcode":0,"data":{"online":true,"good":true}}`},
{"data missing", `{"status":"ok","retcode":0}`},
{"data null", `{"status":"ok","retcode":0,"data":null}`},
}
for _, tc := range cases {
tc := tc
t.Run(tc.name, func(t *testing.T) {
t.Parallel()
buf, log := logCapture()
f := &fakeStatusWS{}
f.reply.Store(true)
f.raw.Store(func(echo string) []byte {
var m map[string]any
_ = json.Unmarshal([]byte(tc.raw), &m)
m["echo"] = echo
b, _ := json.Marshal(m)
return b
})
srv := httptest.NewServer(f.handler())
defer srv.Close()
a := NewAdapter(Config{Mode: modeClient, RemoteURL: wsURL(srv), Logger: log})
a.probeTimeout = 500 * time.Millisecond
if err := a.Connect(context.Background()); err != nil {
t.Fatalf("Connect error: %v", err)
}
defer func() { _ = a.Disconnect(context.Background()) }()
if err := a.probeStatus(context.Background()); err == nil {
t.Fatal("probeStatus() = nil, want the malformed envelope surfaced as an error")
}
if _, known := a.AccountStatus(); known {
t.Error("AccountStatus known = true after a malformed envelope, want false(未探到)")
}
if n := countLogLines(buf, "onebot account"); n != 0 {
t.Errorf("信封异常不得产生账号状态日志,实得 %d 行\n%s", n, buf.String())
}
})
}
}
// TestProbeEchoIsUnique 断言回执关联键(echo)在同一次运行里唯一:唯一性不能靠时钟
// 精度(Windows 时钟粒度粗时相邻两次取值的 UnixNano 可能相同,后一次登记会覆盖前一次的
// 等待通道,先登记的那个只能等到超时)。
func TestProbeEchoIsUnique(t *testing.T) {
t.Parallel()
a := NewAdapter(Config{})
seen := make(map[string]bool, 1000)
for i := 0; i < 1000; i++ {
echo := a.nextProbeEcho()
if !strings.HasPrefix(echo, probeEchoPrefix) {
t.Fatalf("echo %q 缺少探活前缀 %q(会与 send_msg 的 echo_* 混淆)", echo, probeEchoPrefix)
}
if seen[echo] {
t.Fatalf("echo 重复:%q", echo)
}
seen[echo] = true
}
}
// wsURL 把 httptest 服务的 http:// 基址换成 ws://(本包自带 WS 编解码,测试同样走真帧)。
func wsURL(srv *httptest.Server) string {
return "ws://" + strings.TrimPrefix(srv.URL, "http://")
}
// slowTestProbePolicy 是固定 200ms 的探活退避策略:让「首败之后短时间内不再有第二次
// 失败」成为确定性事实,测试主协程读日志时才不会与后台写日志赛跑。
func slowTestProbePolicy() reconnectPolicy {
return reconnectPolicy{
baseDelay: 200 * time.Millisecond,
maxDelay: 200 * time.Millisecond,
factor: reconnectBackoffFactor,
maxDoublings: reconnectMaxDoublings,
jitterRatio: 0,
}
}