package weixin_ilink // 入站媒体取证日志(inbound_debug.go)的自证测试。断言分三类: // - **记全了结构**:取证要看的那几个字段一个不少(否则日志等于白留); // - **一个凭据/地址都没记**:查询串、`aes_key`、正文、完整 URL 都不得出现; // - **级别留在 DEBUG**:默认 INFO 下不得出现。 // // 断言的落点是**渲染后的日志串**(TextHandler 真输出),不是属性表:「没往某个属性里 // 写」离「日志里没有」还差一步 —— 凭据只要混进任何一个属性,只有看渲染结果才抓得到。 // // 末尾还有一条**交叉验证**:`mediaRefOrigin` 是 `mediaRefOf` 的取证投影,两者对同一 // item 必须给出「有引用/没引用」一致的答案,否则日志会说谎。 import ( "bytes" "context" "encoding/json" "log/slog" "net" "net/http" "strconv" "strings" "testing" ) // debugCapture 返回渲染目标与一条把 DEBUG 也打出来的日志器(被测日志级别固定 DEBUG)。 func debugCapture() (*bytes.Buffer, *slog.Logger) { buf := &bytes.Buffer{} return buf, slog.New(slog.NewTextHandler(buf, &slog.HandlerOptions{Level: slog.LevelDebug})) } // debugLines 摘出渲染后**消息等于 msg** 的日志行。 func debugLines(buf *bytes.Buffer, msg string) []string { var out []string for _, line := range strings.Split(buf.String(), "\n") { if strings.Contains(line, `msg="`+msg+`"`) { out = append(out, line) } } return out } // newDebugAdapter 装配一个日志被捕获的适配器(client 可为 nil,本次只用转换/取回路径)。 func newDebugAdapter(t *testing.T, cfg Config, log *slog.Logger, client *http.Client) *Adapter { t.Helper() a, err := New(cfg, client, log) if err != nil { t.Fatalf("New: %v", err) } return a } // TestInboundMediaShapeLogIsStructuralOnly 用一条真机形状的入站消息(文本 + 图片 item, // 引用在 `media.encrypt_query_param`)走转换路径:日志必须说清「几个 item、各是什么类型、 // 引用来自哪个字段、host 是谁」,而查询串、`aes_key` 与正文一个都不许出现。 func TestInboundMediaShapeLogIsStructuralOnly(t *testing.T) { t.Parallel() const ( body = "BODY-SENTINEL-9137" query = "QUERY-SENTINEL-9137" aesKey = "AESKEY-SENTINEL-9137" cdnOrigin = "novac2c.cdn.weixin.qq.com" ) raw, err := json.Marshal(map[string]any{ "client_id": "c-dbg", "from_user_id": "u-dbg", "message_type": msgTypeUser, "item_list": []any{ map[string]any{"type": itemText, "text_item": map[string]any{"text": body}}, map[string]any{"type": itemImage, "image_item": map[string]any{ "media": map[string]any{"encrypt_query_param": query, "aes_key": aesKey}, }}, }, }) if err != nil { t.Fatalf("marshal fixture: %v", err) } buf, log := debugCapture() a := newDebugAdapter(t, Config{BaseURL: "https://ilink.invalid", CDNBaseURL: "https://" + cdnOrigin + "/c2c"}, log, nil) if _, m := a.convertMessage(raw); m == nil { t.Fatal("convertMessage 没有解析出消息") } lines := debugLines(buf, "inbound media shape") if len(lines) != 1 { t.Fatalf("入站媒体形状日志行数 = %d, want 1\n全量日志:\n%s", len(lines), buf.String()) } line := lines[0] t.Logf("渲染后的形状行: %s", line) for _, want := range []string{ "level=DEBUG", "source=plugins/channels/weixin_ilink", "message_type=1", "items=2", `item_types="[text image]"`, "ref=media.encrypt_query_param", "host=" + cdnOrigin, "truncated=false", } { if !strings.Contains(line, want) { t.Errorf("入站媒体形状日志缺少结构字段 %q\n实际: %s", want, line) } } for _, forbidden := range []string{body, query, aesKey, "https://", "encrypted_query_param", "download?"} { if strings.Contains(line, forbidden) { t.Errorf("入站媒体形状日志泄露了 %q\n实际: %s", forbidden, line) } } if all := buf.String(); strings.Contains(all, query) || strings.Contains(all, aesKey) || strings.Contains(all, body) { t.Errorf("正文或凭据出现在日志里:\n%s", all) } } // TestInboundMediaFetchLogsOutcomeWithoutURL 走完整的取回路径(假 CDN 命中一次):成功行 // 只记类型/host/字节数/嗅探 mime,绝不记查询串与完整地址。 func TestInboundMediaFetchLogsOutcomeWithoutURL(t *testing.T) { t.Parallel() key := keyOf(0x61) s := newIlinkAssetServer(t, encrypted(t, key, pngBytes)) buf, log := debugCapture() a := newDebugAdapter(t, Config{BaseURL: s.srv.URL, CDNBaseURL: s.srv.URL, BotToken: encodeToken(key)}, log, s.srv.Client()) _, m := a.convertMessage(imageItemRaw(t, map[string]any{ "media": map[string]any{"encrypt_query_param": "QUERY-SENTINEL-9137"}, })) a.deliver(context.Background(), *m, nil) if s.hits.Load() != 1 { t.Fatalf("CDN 命中 = %d, want 1", s.hits.Load()) } lines := debugLines(buf, "inbound media fetch ok") if len(lines) != 1 { t.Fatalf("取回结局日志行数 = %d, want 1\n全量日志:\n%s", len(lines), buf.String()) } line := lines[0] for _, want := range []string{"level=DEBUG", "kind=image", "host=127.0.0.1", "bytes=" + strconv.Itoa(len(pngBytes)), "mime=image/png"} { if !strings.Contains(line, want) { t.Errorf("取回结局日志缺少字段 %q\n实际: %s", want, line) } } for _, forbidden := range []string{"QUERY-SENTINEL-9137", "encrypted_query_param", s.srv.URL, "http://"} { if strings.Contains(line, forbidden) { t.Errorf("取回结局日志泄露了 %q\n实际: %s", forbidden, line) } } // 形状行同样只记 host,不记查询串。 shapes := debugLines(buf, "inbound media shape") if len(shapes) != 1 || !strings.Contains(shapes[0], "ref=media.encrypt_query_param host=127.0.0.1") { t.Errorf("形状行未记下平台字段与 host:\n%s", strings.Join(shapes, "\n")) } } // TestInboundMediaFetchFailureLogsHostAndCategory 复现事故形状:取回的主机解析不了 // (DNS)。日志必须给出**试过哪台主机**与**是哪一类失败**,且不带完整地址 ——「模型编的 // 地址」正是靠「这个 host 在我们自己的形状行里出现过没有」来排除的。 // // 夹具刻意用事故里那个字面量主机;这里它由**我们自己配置的 CDN 根**给出,从而走完 // 「形状行 + 取回失败行」两行日志,正是取证要看到的样子。 func TestInboundMediaFetchFailureLogsHostAndCategory(t *testing.T) { t.Parallel() const accidentHost = "wechat-image.ilink.example" key := keyOf(0x62) buf, log := debugCapture() a := newDebugAdapter(t, Config{ BaseURL: "https://ilink.invalid", CDNBaseURL: "https://" + accidentHost + "/c2c", BotToken: encodeToken(key), }, log, dnsFailClient(accidentHost)) _, m := a.convertMessage(imageItemRaw(t, map[string]any{ "media": map[string]any{"encrypt_query_param": "QUERY-SENTINEL-9137"}, })) a.deliver(context.Background(), *m, nil) lines := debugLines(buf, "inbound media fetch failed") if len(lines) != 1 { t.Fatalf("取回失败日志行数 = %d, want 1\n全量日志:\n%s", len(lines), buf.String()) } line := lines[0] for _, want := range []string{"level=DEBUG", "kind=image", "host=" + accidentHost, "err_kind=dns"} { if !strings.Contains(line, want) { t.Errorf("取回失败日志缺少字段 %q\n实际: %s", want, line) } } for _, forbidden := range []string{"QUERY-SENTINEL-9137", "encrypted_query_param", "https://", "download?"} { if strings.Contains(line, forbidden) { t.Errorf("取回失败日志泄露了 %q\n实际: %s", forbidden, line) } } } // TestInboundMediaLogsStayAtDebugLevel 这两条日志必须留在 DEBUG:默认 INFO 下不得出现, // 免得给正常运行加上每条消息一行的噪声(要取证时把日志级别调到 debug)。 func TestInboundMediaLogsStayAtDebugLevel(t *testing.T) { t.Parallel() buf := &bytes.Buffer{} a, err := New(Config{BaseURL: "https://ilink.invalid"}, nil, slog.New(slog.NewTextHandler(buf, nil))) if err != nil { t.Fatalf("New: %v", err) } a.convertMessage(imageItemRaw(t, map[string]any{"media": map[string]any{"encrypt_query_param": "ENC"}})) if got := buf.String(); strings.Contains(got, "inbound media shape") { t.Errorf("默认级别下不应出现入站媒体取证日志:\n%s", got) } } // TestInboundShapeLogCoversNonUserMessages 覆盖「非消息事件」的替代口径:该渠道没有 // OneBot 那样的 heartbeat/meta_event 流,但 `message_type != 1` 的非用户消息此前会被 // 静默丢弃 —— 取证行因此排在类型判定**之前**,把「推了但不是主人消息」也留痕。 func TestInboundShapeLogCoversNonUserMessages(t *testing.T) { t.Parallel() raw := jsonBody(map[string]any{ "client_id": "c-bot", "from_user_id": "bot-1", "message_type": msgTypeUser + 1, "item_list": []any{map[string]any{"type": itemText, "text_item": map[string]any{"text": "BODY-SENTINEL-9137"}}}, }) buf, log := debugCapture() a := newDebugAdapter(t, Config{BaseURL: "https://ilink.invalid"}, log, nil) if _, m := a.convertMessage(raw); m != nil { t.Fatal("非用户消息不该被转换成 UnifiedMessage") } lines := debugLines(buf, "inbound media shape") if len(lines) != 1 || !strings.Contains(lines[0], "message_type=2") { t.Fatalf("非用户消息没有留下取证行:\n%s", buf.String()) } if strings.Contains(lines[0], "BODY-SENTINEL-9137") { t.Errorf("非用户消息的正文进了日志:\n%s", lines[0]) } } // TestInboundShapeLogCapsItemList 钉住逐项展开的上限:item_list 由对端构造,不能让它 // 把一条日志撑成几万项;超出部分只体现在计数与 truncated 标记里。 func TestInboundShapeLogCapsItemList(t *testing.T) { t.Parallel() items := make([]any, 0, inboundDebugMaxItems+3) for i := 0; i < inboundDebugMaxItems+3; i++ { items = append(items, map[string]any{"type": itemText, "text_item": map[string]any{"text": "x"}}) } raw, err := json.Marshal(map[string]any{ "client_id": "c-cap", "from_user_id": "u-cap", "message_type": msgTypeUser, "item_list": items, }) if err != nil { t.Fatalf("marshal fixture: %v", err) } buf, log := debugCapture() a := newDebugAdapter(t, Config{BaseURL: "https://ilink.invalid"}, log, nil) a.convertMessage(raw) lines := debugLines(buf, "inbound media shape") if len(lines) != 1 { t.Fatalf("入站媒体形状日志行数 = %d, want 1\n全量日志:\n%s", len(lines), buf.String()) } if !strings.Contains(lines[0], "items="+strconv.Itoa(inboundDebugMaxItems+3)) { t.Errorf("计数应为真实项数\n实际: %s", lines[0]) } if !strings.Contains(lines[0], "truncated=true") { t.Errorf("超限时应标 truncated=true\n实际: %s", lines[0]) } if got := strings.Count(lines[0], "text"); got != inboundDebugMaxItems { t.Errorf("逐项展开的条数 = %d, want %d\n实际: %s", got, inboundDebugMaxItems, lines[0]) } } // TestMediaRefOriginMatchesMediaRefOf 交叉验证「取证投影」与「取回用的真身」:两者对同一 // item 必须对「有没有引用」给出一致的答案。少了这条,mediaRefOrigin 一旦与 mediaRefOf // 漂移,日志就会开始说谎,而故障现场恰恰只有它可看。 func TestMediaRefOriginMatchesMediaRefOf(t *testing.T) { t.Parallel() cases := []struct { name string item map[string]any }{ {"无引用", map[string]any{"type": itemText}}, {"media.full_url", map[string]any{"type": itemImage, "image_item": map[string]any{"media": map[string]any{"full_url": "https://cdn.invalid/x.png"}}}}, {"media.encrypt_query_param", map[string]any{"type": itemImage, "image_item": map[string]any{"media": map[string]any{"encrypt_query_param": "E"}}}}, {"平铺 url", map[string]any{"type": itemImage, "url": "https://cdn.invalid/y.png"}}, {"嵌套 cdn_ref", map[string]any{"type": itemFile, "file_item": map[string]any{"cdn_ref": "r"}}}, {"平铺 download_url", map[string]any{"type": itemVideo, "download_url": "d"}}, } for _, tc := range cases { tc := tc t.Run(tc.name, func(t *testing.T) { t.Parallel() ref := mediaRefOf(tc.item) origin := mediaRefOrigin(tc.item) if (ref != "") != (origin != refNone) { t.Fatalf("mediaRefOf = %q 但 mediaRefOrigin = %q(两者已经漂移)", ref, origin) } }) } } // roundTripFunc 让测试用一个函数冒充 RoundTripper(不触网)。 type roundTripFunc func(*http.Request) (*http.Response, error) func (f roundTripFunc) RoundTrip(r *http.Request) (*http.Response, error) { return f(r) } // dnsFailClient 返回一个把每次请求都判成 DNS 解析失败的客户端:解析器给出的失败在 // net/http 里正是 `*net.DNSError`,与真机上「解析主机失败」走出同一条错误链。 func dnsFailClient(host string) *http.Client { return &http.Client{Transport: roundTripFunc(func(*http.Request) (*http.Response, error) { return nil, &net.DNSError{Err: "no such host", Name: host, IsNotFound: true} })} }