mirrors/AdGuardHome
1
0
Fork 0
mirror of https://github.com/AdguardTeam/AdGuardHome.git synced 2024-11-23 13:35:38 +03:00
Code Issues Projects Releases Packages Wiki Activity

all: imp code

Browse source
This commit is contained in:
Stanislav Chzhen 2024-11-18 20:57:15 +03:00
parent ef715c58cb
commit fbe728c9aa
4 changed files with 46 additions and 35 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

4
internal/home/dns.go
View file

@ -531,7 +531,7 @@ func closeDNSServer() {
if Context.stats != nil { if Context.stats != nil {
err := Context.stats.Close() err := Context.stats.Close()
if err != nil { if err != nil {
log.Debug("closing stats: %s", err) log.Error("closing stats: %s", err)
} }
} }
@ -539,7 +539,7 @@ func closeDNSServer() {
// TODO(s.chzhen): Pass context. // TODO(s.chzhen): Pass context.
err := Context.queryLog.Shutdown(context.TODO()) err := Context.queryLog.Shutdown(context.TODO())
if err != nil { if err != nil {
log.Debug("closing query log: %s", err) log.Error("closing query log: %s", err)
} }
} }

61
internal/querylog/decode.go
View file

@ -223,7 +223,12 @@ func (l *queryLog) decodeVTokenAndAddRule(
vToken, err := dec.Token() vToken, err := dec.Token()
if err != nil { if err != nil {
if err != io.EOF { if err != io.EOF {
l.logger.DebugContext(ctx, "decodeResultRuleKey", "key", key, slogutil.KeyError, err) l.logger.DebugContext(
ctx,
"decoding result rule key",
"key", key,
slogutil.KeyError, err,
)
} }
return newRules, nil return newRules, nil
@ -239,11 +244,13 @@ func (l *queryLog) decodeVTokenAndAddRule(
// decodeResultRules parses the dec's tokens into logEntry ent interpreting it // decodeResultRules parses the dec's tokens into logEntry ent interpreting it
// as a slice of the result rules. // as a slice of the result rules.
func (l *queryLog) decodeResultRules(ctx context.Context, dec *json.Decoder, ent *logEntry) { func (l *queryLog) decodeResultRules(ctx context.Context, dec *json.Decoder, ent *logEntry) {
const msgPrefix = "decoding result rules"
for { for {
delimToken, err := dec.Token() delimToken, err := dec.Token()
if err != nil { if err != nil {
if err != io.EOF { if err != io.EOF {
l.logger.DebugContext(ctx, "decodeResultRules", slogutil.KeyError, err) l.logger.DebugContext(ctx, msgPrefix+"; token", slogutil.KeyError, err)
} }
return return
@ -254,7 +261,7 @@ func (l *queryLog) decodeResultRules(ctx context.Context, dec *json.Decoder, ent
} else if d != '[' { } else if d != '[' {
l.logger.DebugContext( l.logger.DebugContext(
ctx, ctx,
"decodeResultRules", msgPrefix,
slogutil.KeyError, unexpectedDelimiterError(d), slogutil.KeyError, unexpectedDelimiterError(d),
) )
} }
@ -262,7 +269,7 @@ func (l *queryLog) decodeResultRules(ctx context.Context, dec *json.Decoder, ent
err = l.decodeResultRuleToken(ctx, dec, ent) err = l.decodeResultRuleToken(ctx, dec, ent)
if err != nil { if err != nil {
if err != io.EOF && !errors.Is(err, ErrEndOfToken) { if err != io.EOF && !errors.Is(err, ErrEndOfToken) {
l.logger.DebugContext(ctx, "decodeResultRules", slogutil.KeyError, err) l.logger.DebugContext(ctx, msgPrefix+"; rule token", slogutil.KeyError, err)
} }
return return
@ -313,11 +320,13 @@ func (l *queryLog) decodeResultRuleToken(
// rewrites currently has the highest priority along the entire filtering // rewrites currently has the highest priority along the entire filtering
// pipeline. // pipeline.
func (l *queryLog) decodeResultReverseHosts(ctx context.Context, dec *json.Decoder, ent *logEntry) { func (l *queryLog) decodeResultReverseHosts(ctx context.Context, dec *json.Decoder, ent *logEntry) {
const msgPrefix = "decoding result reverse hosts"
for { for {
itemToken, err := dec.Token() itemToken, err := dec.Token()
if err != nil { if err != nil {
if err != io.EOF { if err != io.EOF {
l.logger.DebugContext(ctx, "decodeResultReverseHosts", slogutil.KeyError, err) l.logger.DebugContext(ctx, msgPrefix+"; token", slogutil.KeyError, err)
} }
return return
@ -333,7 +342,7 @@ func (l *queryLog) decodeResultReverseHosts(ctx context.Context, dec *json.Decod
l.logger.DebugContext( l.logger.DebugContext(
ctx, ctx,
"decodeResultReverseHosts", msgPrefix,
slogutil.KeyError, unexpectedDelimiterError(v), slogutil.KeyError, unexpectedDelimiterError(v),
) )
@ -367,11 +376,13 @@ func (l *queryLog) decodeResultReverseHosts(ctx context.Context, dec *json.Decod
// decodeResultIPList parses the dec's tokens into logEntry ent interpreting it // decodeResultIPList parses the dec's tokens into logEntry ent interpreting it
// as the result IP addresses list. // as the result IP addresses list.
func (l *queryLog) decodeResultIPList(ctx context.Context, dec *json.Decoder, ent *logEntry) { func (l *queryLog) decodeResultIPList(ctx context.Context, dec *json.Decoder, ent *logEntry) {
const msgPrefix = "decoding result ip list"
for { for {
itemToken, err := dec.Token() itemToken, err := dec.Token()
if err != nil { if err != nil {
if err != io.EOF { if err != io.EOF {
l.logger.DebugContext(ctx, "decodeResultIPList", slogutil.KeyError, err) l.logger.DebugContext(ctx, msgPrefix+"; token", slogutil.KeyError, err)
} }
return return
@ -387,7 +398,7 @@ func (l *queryLog) decodeResultIPList(ctx context.Context, dec *json.Decoder, en
l.logger.DebugContext( l.logger.DebugContext(
ctx, ctx,
"decodeResultIPList", msgPrefix,
slogutil.KeyError, unexpectedDelimiterError(v), slogutil.KeyError, unexpectedDelimiterError(v),
) )
@ -412,6 +423,8 @@ func (l *queryLog) decodeResultDNSRewriteResultKey(
dec *json.Decoder, dec *json.Decoder,
ent *logEntry, ent *logEntry,
) { ) {
const msgPrefix = "decoding result dns rewrite result key"
var err error var err error
switch key { switch key {
@ -420,11 +433,7 @@ func (l *queryLog) decodeResultDNSRewriteResultKey(
vToken, err = dec.Token() vToken, err = dec.Token()
if err != nil { if err != nil {
if err != io.EOF { if err != io.EOF {
l.logger.DebugContext( l.logger.DebugContext(ctx, msgPrefix+"; token", slogutil.KeyError, err)
ctx,
"decodeResultDNSRewriteResultKey",
slogutil.KeyError, err,
)
} }
return return
@ -452,11 +461,7 @@ func (l *queryLog) decodeResultDNSRewriteResultKey(
// decoding and correct the values. // decoding and correct the values.
err = dec.Decode(&ent.Result.DNSRewriteResult.Response) err = dec.Decode(&ent.Result.DNSRewriteResult.Response)
if err != nil { if err != nil {
l.logger.DebugContext( l.logger.DebugContext(ctx, msgPrefix+"; response", slogutil.KeyError, err)
ctx,
"decodeResultDNSRewriteResultKey response",
slogutil.KeyError, err,
)
} }
ent.parseDNSRewriteResultIPs() ent.parseDNSRewriteResultIPs()
@ -472,11 +477,13 @@ func (l *queryLog) decodeResultDNSRewriteResult(
dec *json.Decoder, dec *json.Decoder,
ent *logEntry, ent *logEntry,
) { ) {
const msgPrefix = "decoding result dns rewrite result"
for { for {
key, err := parseKeyToken(dec) key, err := parseKeyToken(dec)
if err != nil { if err != nil {
if err != io.EOF && !errors.Is(err, ErrEndOfToken) { if err != io.EOF && !errors.Is(err, ErrEndOfToken) {
l.logger.DebugContext(ctx, "decodeResultDNSRewriteResult", slogutil.KeyError, err) l.logger.DebugContext(ctx, msgPrefix+"; token", slogutil.KeyError, err)
} }
return return
@ -550,13 +557,15 @@ func parseKeyToken(dec *json.Decoder) (key string, err error) {
// decodeResult decodes a token of "Result" type to logEntry struct. // decodeResult decodes a token of "Result" type to logEntry struct.
func (l *queryLog) decodeResult(ctx context.Context, dec *json.Decoder, ent *logEntry) { func (l *queryLog) decodeResult(ctx context.Context, dec *json.Decoder, ent *logEntry) {
const msgPrefix = "decoding result"
defer translateResult(ent) defer translateResult(ent)
for { for {
key, err := parseKeyToken(dec) key, err := parseKeyToken(dec)
if err != nil { if err != nil {
if err != io.EOF && !errors.Is(err, ErrEndOfToken) { if err != io.EOF && !errors.Is(err, ErrEndOfToken) {
l.logger.DebugContext(ctx, "decodeResult", slogutil.KeyError, err) l.logger.DebugContext(ctx, msgPrefix+"; token", slogutil.KeyError, err)
} }
return return
@ -582,7 +591,7 @@ func (l *queryLog) decodeResult(ctx context.Context, dec *json.Decoder, ent *log
} }
if err = handler(val, ent); err != nil { if err = handler(val, ent); err != nil {
l.logger.DebugContext(ctx, "decodeResult handler", slogutil.KeyError, err) l.logger.DebugContext(ctx, msgPrefix+"; handler", slogutil.KeyError, err)
return return
} }
@ -701,6 +710,8 @@ func (l *queryLog) resultDecHandler(
// decodeLogEntry decodes string str to logEntry ent. // decodeLogEntry decodes string str to logEntry ent.
func (l *queryLog) decodeLogEntry(ctx context.Context, ent *logEntry, str string) { func (l *queryLog) decodeLogEntry(ctx context.Context, ent *logEntry, str string) {
const msgPrefix = "decoding log entry"
dec := json.NewDecoder(strings.NewReader(str)) dec := json.NewDecoder(strings.NewReader(str))
dec.UseNumber() dec.UseNumber()
@ -708,7 +719,7 @@ func (l *queryLog) decodeLogEntry(ctx context.Context, ent *logEntry, str string
keyToken, err := dec.Token() keyToken, err := dec.Token()
if err != nil { if err != nil {
if err != io.EOF { if err != io.EOF {
l.logger.DebugContext(ctx, "decodeLogEntry err", slogutil.KeyError, err) l.logger.DebugContext(ctx, msgPrefix+"; token", slogutil.KeyError, err)
} }
return return
@ -720,8 +731,8 @@ func (l *queryLog) decodeLogEntry(ctx context.Context, ent *logEntry, str string
key, ok := keyToken.(string) key, ok := keyToken.(string)
if !ok { if !ok {
err = fmt.Errorf("decodeLogEntry: keyToken is %T (%[1]v) and not string", keyToken) err = fmt.Errorf("%s: keyToken is %T (%[2]v) and not string", msgPrefix, keyToken)
l.logger.DebugContext(ctx, "decodeLogEntry", slogutil.KeyError, err) l.logger.DebugContext(ctx, msgPrefix, slogutil.KeyError, err)
return return
} }
@ -743,7 +754,7 @@ func (l *queryLog) decodeLogEntry(ctx context.Context, ent *logEntry, str string
} }
if err = handler(val, ent); err != nil { if err = handler(val, ent); err != nil {
l.logger.DebugContext(ctx, "decodeLogEntry handler", slogutil.KeyError, err) l.logger.DebugContext(ctx, msgPrefix+"; handler", slogutil.KeyError, err)
return return
} }

14
internal/querylog/decode_test.go
View file

@ -121,11 +121,11 @@ func TestDecodeLogEntry(t *testing.T) {
}, { }, {
name: "bad_filter_id_old_rule", 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}`, 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: `level=DEBUG msg="decodeResult handler" err="strconv.ParseInt: parsing \"1.5\": invalid syntax"`, want: `level=DEBUG msg="decoding result; handler" err="strconv.ParseInt: parsing \"1.5\": invalid syntax"`,
}, { }, {
name: "bad_is_filtered", 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},"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: `level=DEBUG msg="decodeLogEntry err" err="invalid character 'o' in literal true (expecting 'u')"`, want: `level=DEBUG msg="decoding log entry; token" err="invalid character 'o' in literal true (expecting 'u')"`,
}, { }, {
name: "bad_elapsed", 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},"Elapsed":-1}`, 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}`,
@ -137,7 +137,7 @@ func TestDecodeLogEntry(t *testing.T) {
}, { }, {
name: "bad_time", 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},"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: `level=DEBUG msg="decodeLogEntry handler" err="parsing time \"12/09/1998T15:00:00.000000+05:00\" as \"2006-01-02T15:04:05Z07:00\": cannot parse \"12/09/1998T15:00:00.000000+05:00\" as \"2006\""`, want: `level=DEBUG msg="decoding log entry; handler" err="parsing time \"12/09/1998T15:00:00.000000+05:00\" as \"2006-01-02T15:04:05Z07:00\": cannot parse \"12/09/1998T15:00:00.000000+05:00\" as \"2006\""`,
}, { }, {
name: "bad_host", 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},"Elapsed":837429}`, 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}`,
@ -157,7 +157,7 @@ func TestDecodeLogEntry(t *testing.T) {
}, { }, {
name: "very_bad_client_proto", 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},"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: `level=DEBUG msg="decodeLogEntry handler" err="invalid client proto: \"dog\""`, want: `level=DEBUG msg="decoding log entry; handler" err="invalid client proto: \"dog\""`,
}, { }, {
name: "bad_answer", 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},"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":0.9,"Result":{"IsFiltered":true,"Reason":3},"Elapsed":837429}`,
@ -165,7 +165,7 @@ func TestDecodeLogEntry(t *testing.T) {
}, { }, {
name: "very_bad_answer", 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},"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: `level=DEBUG msg="decodeLogEntry handler" err="illegal base64 data at input byte 61"`, want: `level=DEBUG msg="decoding log entry; handler" err="illegal base64 data at input byte 61"`,
}, { }, {
name: "bad_rule", 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},"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":true,"Reason":3,"Rule":false},"Elapsed":837429}`,
@ -177,11 +177,11 @@ func TestDecodeLogEntry(t *testing.T) {
}, { }, {
name: "bad_reverse_hosts", 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}`, 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: `level=DEBUG msg=decodeResultReverseHosts err="unexpected delimiter: \"{\""`, want: `level=DEBUG msg="decoding result reverse hosts" err="unexpected delimiter: \"{\""`,
}, { }, {
name: "bad_ip_list", 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}`, 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: `level=DEBUG msg=decodeResultIPList err="unexpected delimiter: \"{\""`, want: `level=DEBUG msg="decoding result ip list" err="unexpected delimiter: \"{\""`,
}} }}
for _, tc := range testCases { for _, tc := range testCases {

2
internal/querylog/search.go
View file

@ -75,7 +75,7 @@ func (l *queryLog) searchMemory(
l.logger.ErrorContext( l.logger.ErrorContext(
ctx, ctx,
"enriching memory record", "enriching memory record",
"time", e.Time, "at", e.Time,
"client_ip", e.IP, "client_ip", e.IP,
"client_id", e.ClientID, "client_id", e.ClientID,
slogutil.KeyError, err, slogutil.KeyError, err,