From d9448ddca6d4ef3635d767e3e496e44c35d3fc6e Mon Sep 17 00:00:00 2001 From: Ainar Garipov Date: Mon, 21 Dec 2020 15:44:54 +0300 Subject: [PATCH] querylog: support dnsrewrite rules --- internal/querylog/decode.go | 300 ++++++++++++++++++++++++++++++- internal/querylog/decode_test.go | 150 ++++++++++++---- 2 files changed, 416 insertions(+), 34 deletions(-) diff --git a/internal/querylog/decode.go b/internal/querylog/decode.go index f59377811e6..ed7214893de 100644 --- a/internal/querylog/decode.go +++ b/internal/querylog/decode.go @@ -4,11 +4,14 @@ import ( "encoding/base64" "encoding/json" "io" + "net" "strings" "time" "github.com/AdguardTeam/AdGuardHome/internal/dnsfilter" "github.com/AdguardTeam/golibs/log" + "github.com/AdguardTeam/urlfilter/rules" + "github.com/miekg/dns" ) type logEntryHandler (func(t json.Token, ent *logEntry) error) @@ -165,13 +168,285 @@ var resultHandlers = map[string]logEntryHandler{ return nil }, "ServiceName": func(t json.Token, ent *logEntry) error { - v, ok := t.(string) + s, ok := t.(string) if !ok { return nil } - ent.Result.ServiceName = v + + ent.Result.ServiceName = s + return nil }, + "CanonName": func(t json.Token, ent *logEntry) error { + s, ok := t.(string) + if !ok { + return nil + } + + ent.Result.CanonName = s + + return nil + }, +} + +func decodeResultRuleKey(key string, i int, dec *json.Decoder, ent *logEntry) { + switch key { + case "FilterListID": + vToken, err := dec.Token() + if err != nil { + if err != io.EOF { + log.Debug("decodeResultRuleKey %s err: %s", key, err) + } + + return + } + + if len(ent.Result.Rules) < i+1 { + ent.Result.Rules = append(ent.Result.Rules, &dnsfilter.ResultRule{}) + } + + if n, ok := vToken.(json.Number); ok { + ent.Result.Rules[i].FilterListID, _ = n.Int64() + } + case "IP": + vToken, err := dec.Token() + if err != nil { + if err != io.EOF { + log.Debug("decodeResultRuleKey %s err: %s", key, err) + } + + return + } + + if len(ent.Result.Rules) < i+1 { + ent.Result.Rules = append(ent.Result.Rules, &dnsfilter.ResultRule{}) + } + + if ipStr, ok := vToken.(string); ok { + ent.Result.Rules[i].IP = net.ParseIP(ipStr) + } + case "Text": + vToken, err := dec.Token() + if err != nil { + if err != io.EOF { + log.Debug("decodeResultRuleKey %s err: %s", key, err) + } + + return + } + + if len(ent.Result.Rules) < i+1 { + ent.Result.Rules = append(ent.Result.Rules, &dnsfilter.ResultRule{}) + } + + if s, ok := vToken.(string); ok { + ent.Result.Rules[i].Text = s + } + default: + // Go on. + } +} + +func decodeResultRules(dec *json.Decoder, ent *logEntry) { + for { + delimToken, err := dec.Token() + if err != nil { + if err != io.EOF { + log.Debug("decodeResultRules err: %s", err) + } + + return + } + + if d, ok := delimToken.(json.Delim); ok { + if d != '[' { + log.Debug("decodeResultRules: unexpected delim %q", d) + } + } else { + return + } + + i := 0 + for { + keyToken, err := dec.Token() + if err != nil { + if err != io.EOF { + log.Debug("decodeResultRules err: %s", err) + } + + return + } + + if d, ok := keyToken.(json.Delim); ok { + if d == '}' { + i++ + } else if d == ']' { + return + } + + continue + } + + key, ok := keyToken.(string) + if !ok { + log.Debug("decodeResultRules: keyToken is %T (%[1]v) and not string", keyToken) + + return + } + + decodeResultRuleKey(key, i, dec, ent) + } + } +} + +func decodeResultReverseHosts(dec *json.Decoder, ent *logEntry) { + for { + itemToken, err := dec.Token() + if err != nil { + if err != io.EOF { + log.Debug("decodeResultReverseHosts err: %s", err) + } + + return + } + + switch v := itemToken.(type) { + case json.Delim: + if v == '[' { + continue + } else if v == ']' { + return + } + + log.Debug("decodeResultReverseHosts: unexpected delim %q", v) + + return + case string: + ent.Result.ReverseHosts = append(ent.Result.ReverseHosts, v) + default: + continue + } + } +} + +func decodeResultIPList(dec *json.Decoder, ent *logEntry) { + for { + itemToken, err := dec.Token() + if err != nil { + if err != io.EOF { + log.Debug("decodeResultIPList err: %s", err) + } + + return + } + + switch v := itemToken.(type) { + case json.Delim: + if v == '[' { + continue + } else if v == ']' { + return + } + + log.Debug("decodeResultIPList: unexpected delim %q", v) + + return + case string: + ip := net.ParseIP(v) + if ip != nil { + ent.Result.IPList = append(ent.Result.IPList, ip) + } + default: + continue + } + } +} + +func decodeResultDNSRewriteResult(dec *json.Decoder, ent *logEntry) { + for { + keyToken, err := dec.Token() + if err != nil { + if err != io.EOF { + log.Debug("decodeResultDNSRewriteResult err: %s", err) + } + + return + } + + if d, ok := keyToken.(json.Delim); ok { + if d == '}' { + return + } + + continue + } + + key, ok := keyToken.(string) + if !ok { + log.Debug("decodeResultDNSRewriteResult: keyToken is %T (%[1]v) and not string", keyToken) + + return + } + + // TODO(a.garipov): Refactor this into a separate + // function à la decodeResultRuleKey if we keep this + // code for a longer time than planned. + switch key { + case "RCode": + vToken, err := dec.Token() + if err != nil { + if err != io.EOF { + log.Debug("decodeResultDNSRewriteResult err: %s", err) + } + + return + } + + if ent.Result.DNSRewriteResult == nil { + ent.Result.DNSRewriteResult = &dnsfilter.DNSRewriteResult{} + } + + if n, ok := vToken.(json.Number); ok { + rcode64, _ := n.Int64() + ent.Result.DNSRewriteResult.RCode = rules.RCode(rcode64) + } + + continue + case "Response": + if ent.Result.DNSRewriteResult == nil { + ent.Result.DNSRewriteResult = &dnsfilter.DNSRewriteResult{} + } + + if ent.Result.DNSRewriteResult.Response == nil { + ent.Result.DNSRewriteResult.Response = dnsfilter.DNSRewriteResultResponse{} + } + + // TODO(a.garipov): I give up. This whole file + // is a mess. Luckily, we can assume that this + // field is relatively rare and just use the + // normal decoding and correct the values. + err = dec.Decode(&ent.Result.DNSRewriteResult.Response) + if err != nil { + log.Debug("decodeResultDNSRewriteResult response err: %s", err) + } + + for rrType, rrValues := range ent.Result.DNSRewriteResult.Response { + switch rrType { + case dns.TypeA, dns.TypeAAAA: + for i, v := range rrValues { + s, _ := v.(string) + rrValues[i] = net.ParseIP(s) + } + default: + // Go on. + } + } + + continue + default: + // Go on. + } + } } func decodeResult(dec *json.Decoder, ent *logEntry) { @@ -200,6 +475,27 @@ func decodeResult(dec *json.Decoder, ent *logEntry) { return } + switch key { + case "ReverseHosts": + decodeResultReverseHosts(dec, ent) + + continue + case "IPList": + decodeResultIPList(dec, ent) + + continue + case "Rules": + decodeResultRules(dec, ent) + + continue + case "DNSRewriteResult": + decodeResultDNSRewriteResult(dec, ent) + + continue + default: + // Go on. + } + handler, ok := resultHandlers[key] if !ok { continue diff --git a/internal/querylog/decode_test.go b/internal/querylog/decode_test.go index d9cbd6002a4..ffcf94dcd69 100644 --- a/internal/querylog/decode_test.go +++ b/internal/querylog/decode_test.go @@ -2,95 +2,181 @@ package querylog import ( "bytes" + "encoding/base64" + "net" "strings" "testing" + "time" + "github.com/AdguardTeam/AdGuardHome/internal/dnsfilter" "github.com/AdguardTeam/AdGuardHome/internal/testutil" "github.com/AdguardTeam/golibs/log" + "github.com/AdguardTeam/urlfilter/rules" + "github.com/miekg/dns" "github.com/stretchr/testify/assert" ) -func TestDecode_decodeQueryLog(t *testing.T) { +func TestDecodeLogEntry(t *testing.T) { logOutput := &bytes.Buffer{} testutil.ReplaceLogWriter(t, logOutput) testutil.ReplaceLogLevel(t, log.DEBUG) + t.Run("success", func(t *testing.T) { + const ansStr = `Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==` + const data = `{"IP":"127.0.0.1",` + + `"T":"2020-11-25T18:55:56.519796+03:00",` + + `"QH":"an.yandex.ru",` + + `"QT":"A",` + + `"QC":"IN",` + + `"CP":"",` + + `"Answer":"` + ansStr + `",` + + `"Result":{` + + `"IsFiltered":true,` + + `"Reason":3,` + + `"ReverseHosts":["example.net"],` + + `"IPList":["127.0.0.2"],` + + `"Rules":[{"FilterListID":42,"Text":"||an.yandex.ru","IP":"127.0.0.2"},` + + `{"FilterListID":43,"Text":"||an2.yandex.ru","IP":"127.0.0.3"}],` + + `"CanonName":"example.com",` + + `"ServiceName":"example.org",` + + `"DNSRewriteResult":{"RCode":0,"Response":{"1":["127.0.0.2"]}}},` + + `"Elapsed":837429}` + + ans, err := base64.StdEncoding.DecodeString(ansStr) + assert.Nil(t, err) + + want := &logEntry{ + IP: "127.0.0.1", + Time: time.Date(2020, 11, 25, 15, 55, 56, 519796000, time.UTC), + QHost: "an.yandex.ru", + QType: "A", + QClass: "IN", + ClientProto: "", + Answer: ans, + Result: dnsfilter.Result{ + IsFiltered: true, + Reason: dnsfilter.FilteredBlockList, + ReverseHosts: []string{"example.net"}, + IPList: []net.IP{net.IPv4(127, 0, 0, 2)}, + Rules: []*dnsfilter.ResultRule{{ + FilterListID: 42, + Text: "||an.yandex.ru", + IP: net.IPv4(127, 0, 0, 2), + }, { + FilterListID: 43, + Text: "||an2.yandex.ru", + IP: net.IPv4(127, 0, 0, 3), + }}, + CanonName: "example.com", + ServiceName: "example.org", + DNSRewriteResult: &dnsfilter.DNSRewriteResult{ + RCode: dns.RcodeSuccess, + Response: dnsfilter.DNSRewriteResultResponse{ + dns.TypeA: []rules.RRValue{net.IPv4(127, 0, 0, 2)}, + }, + }, + }, + Elapsed: 837429, + } + + got := &logEntry{} + decodeLogEntry(got, data) + + s := logOutput.String() + assert.Equal(t, "", s) + + // Correct for time zones. + got.Time = got.Time.UTC() + assert.Equal(t, want, got) + }) + testCases := []struct { name string log string want string }{{ - name: "all_right", - log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":"","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3,"Rule":"||an.yandex.","FilterID":1},"Elapsed":837429}`, - want: "default", + name: "all_right_old_rule", + log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":"","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3,"Rule":"||an.yandex.","FilterID":1,"ReverseHosts":["example.com"],"IPList":["127.0.0.1"]},"Elapsed":837429}`, + want: "", }, { - name: "bad_filter_id", - log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":"","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3,"Rule":"||an.yandex.","FilterID":1.5},"Elapsed":837429}`, + name: "bad_filter_id_old_rule", + log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":"","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3,"FilterID":1.5},"Elapsed":837429}`, want: "decodeResult handler err: strconv.ParseInt: parsing \"1.5\": invalid syntax\n", }, { name: "bad_is_filtered", - log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":"","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":trooe,"Reason":3,"Rule":"||an.yandex.","FilterID":1},"Elapsed":837429}`, + log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":"","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":trooe,"Reason":3},"Elapsed":837429}`, want: "decodeLogEntry err: invalid character 'o' in literal true (expecting 'u')\n", }, { name: "bad_elapsed", - log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":"","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3,"Rule":"||an.yandex.","FilterID":1},"Elapsed":-1}`, - want: "default", + log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":"","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3},"Elapsed":-1}`, + want: "", }, { name: "bad_ip", - log: `{"IP":127001,"T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":"","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3,"Rule":"||an.yandex.","FilterID":1},"Elapsed":837429}`, - want: "default", + log: `{"IP":127001,"T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":"","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3},"Elapsed":837429}`, + want: "", }, { name: "bad_time", - log: `{"IP":"127.0.0.1","T":"12/09/1998T15:00:00.000000+05:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":"","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3,"Rule":"||an.yandex.","FilterID":1},"Elapsed":837429}`, + log: `{"IP":"127.0.0.1","T":"12/09/1998T15:00:00.000000+05:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":"","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3},"Elapsed":837429}`, want: "decodeLogEntry handler err: parsing time \"12/09/1998T15:00:00.000000+05:00\" as \"2006-01-02T15:04:05Z07:00\": cannot parse \"9/1998T15:00:00.000000+05:00\" as \"2006\"\n", }, { name: "bad_host", - log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":6,"QT":"A","QC":"IN","CP":"","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3,"Rule":"||an.yandex.","FilterID":1},"Elapsed":837429}`, - want: "default", + log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":6,"QT":"A","QC":"IN","CP":"","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3},"Elapsed":837429}`, + want: "", }, { name: "bad_type", - log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":true,"QC":"IN","CP":"","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3,"Rule":"||an.yandex.","FilterID":1},"Elapsed":837429}`, - want: "default", + log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":true,"QC":"IN","CP":"","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3},"Elapsed":837429}`, + want: "", }, { name: "bad_class", - log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":false,"CP":"","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3,"Rule":"||an.yandex.","FilterID":1},"Elapsed":837429}`, - want: "default", + log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":false,"CP":"","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3},"Elapsed":837429}`, + want: "", }, { name: "bad_client_proto", - log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":8,"Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3,"Rule":"||an.yandex.","FilterID":1},"Elapsed":837429}`, - want: "default", + log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":8,"Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3},"Elapsed":837429}`, + want: "", }, { name: "very_bad_client_proto", - log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":"dog","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3,"Rule":"||an.yandex.","FilterID":1},"Elapsed":837429}`, + log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":"dog","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3},"Elapsed":837429}`, want: "decodeLogEntry handler err: invalid client proto: \"dog\"\n", }, { name: "bad_answer", - log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":"","Answer":0.9,"Result":{"IsFiltered":true,"Reason":3,"Rule":"||an.yandex.","FilterID":1},"Elapsed":837429}`, - want: "default", + log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":"","Answer":0.9,"Result":{"IsFiltered":true,"Reason":3},"Elapsed":837429}`, + want: "", }, { name: "very_bad_answer", - log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":"","Answer":"Qz+BgAABAAEAAAAAAmuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3,"Rule":"||an.yandex.","FilterID":1},"Elapsed":837429}`, + log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":"","Answer":"Qz+BgAABAAEAAAAAAmuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3},"Elapsed":837429}`, want: "decodeLogEntry handler err: illegal base64 data at input byte 61\n", }, { name: "bad_rule", - log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":"","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3,"Rule":false,"FilterID":1},"Elapsed":837429}`, - want: "default", + log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":"","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3,"Rule":false},"Elapsed":837429}`, + want: "", }, { name: "bad_reason", - log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":"","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":true,"Rule":"||an.yandex.","FilterID":1},"Elapsed":837429}`, - want: "default", + log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":"","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":true},"Elapsed":837429}`, + want: "", + }, { + name: "bad_reverse_hosts", + log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":"","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3,"ReverseHosts":[{}]},"Elapsed":837429}`, + want: "decodeResultReverseHosts: unexpected delim \"{\"\n", + }, { + name: "bad_ip_list", + log: `{"IP":"127.0.0.1","T":"2020-11-25T18:55:56.519796+03:00","QH":"an.yandex.ru","QT":"A","QC":"IN","CP":"","Answer":"Qz+BgAABAAEAAAAAAmFuBnlhbmRleAJydQAAAQABwAwAAQABAAAACgAEAAAAAA==","Result":{"IsFiltered":true,"Reason":3,"ReverseHosts":["example.net"],"IPList":[{}]},"Elapsed":837429}`, + want: "decodeResultIPList: unexpected delim \"{\"\n", }} for _, tc := range testCases { t.Run(tc.name, func(t *testing.T) { - _, err := logOutput.Write([]byte("default")) - assert.Nil(t, err) - l := &logEntry{} decodeLogEntry(l, tc.log) - assert.True(t, strings.HasSuffix(logOutput.String(), tc.want), "%q\ndoes not end with\n%q", logOutput.String(), tc.want) + s := logOutput.String() + if tc.want == "" { + assert.Equal(t, "", s) + } else { + assert.True(t, strings.HasSuffix(s, tc.want), + "got %q", s) + } logOutput.Reset() })