a/badguardhome
1
0
Fork 0
Code Issues Pull Requests Projects Releases Wiki Activity

Pull request: fix querylog bug

Browse Source 
Merge in DNS/adguard-home from 2345-querylog-bug-fix to master

Closes #2345.

Squashed commit of the following:

commit 3ebd13e059242b041f3c4d77583a077f9e619b48
Author: Eugene Burkov <e.burkov@adguard.com>
Date:   Fri Nov 27 12:14:49 2020 +0300

    all: make changelog more humanly readable.

commit 3c9bb1be6aec113ebebdb40c976dbdb821f75638
Author: Eugene Burkov <e.burkov@adguard.com>
Date:   Thu Nov 26 14:43:14 2020 +0300

    all: log changes

commit 08c67da926aa085fabdec31c092285a351eb0e08
Merge: 650d2241e 96e83a133
Author: Eugene Burkov <e.burkov@adguard.com>
Date:   Thu Nov 26 14:42:18 2020 +0300

    Merge branch 'master' into 2345-querylog-bug-fix

commit 650d2241e02cf54a7e1f7a611199e770fd119953
Author: Eugene Burkov <e.burkov@adguard.com>
Date:   Thu Nov 26 14:02:57 2020 +0300

    querylog: fix json parsing bug
This commit is contained in:
Eugene Burkov 2020-11-27 12:33:25 +03:00
parent 96e83a133f
commit f9e4e7b024
3 changed files with 87 additions and 22 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
CHANGELOG.md
View File

@ -37,9 +37,11 @@ and this project adheres to
### Fixed ### Fixed
- A JSON parsing error in query log [#2345].
- Incorrect detection of the IPv6 address of an interface as well as another - Incorrect detection of the IPv6 address of an interface as well as another
infinite loop in the `/dhcp/find_active_dhcp` HTTP API [#2355]. infinite loop in the `/dhcp/find_active_dhcp` HTTP API [#2355].
[#2345]: https://github.com/AdguardTeam/AdGuardHome/issues/2345
[#2355]: https://github.com/AdguardTeam/AdGuardHome/issues/2355 [#2355]: https://github.com/AdguardTeam/AdGuardHome/issues/2355

41
internal/querylog/decode.go
View File

@ -3,7 +3,7 @@ package querylog
import ( import (
"encoding/base64" "encoding/base64"
"encoding/json" "encoding/json"
"strconv" "io"
"strings" "strings"
"time" "time"
@ -84,15 +84,11 @@ var logEntryHandlers = map[string](func(t json.Token, ent *logEntry) error){
return err return err
}, },
"IsFiltered": func(t json.Token, ent *logEntry) error { "IsFiltered": func(t json.Token, ent *logEntry) error {
v, ok := t.(string) v, ok := t.(bool)
if !ok { if !ok {
return nil return nil
} }
b, err := strconv.ParseBool(v) ent.Result.IsFiltered = v
if err != nil {
return err
}
ent.Result.IsFiltered = b
return nil return nil
}, },
"Rule": func(t json.Token, ent *logEntry) error { "Rule": func(t json.Token, ent *logEntry) error {
@ -104,23 +100,23 @@ var logEntryHandlers = map[string](func(t json.Token, ent *logEntry) error){
return nil return nil
}, },
"FilterID": func(t json.Token, ent *logEntry) error { "FilterID": func(t json.Token, ent *logEntry) error {
v, ok := t.(string) v, ok := t.(json.Number)
if !ok { if !ok {
return nil return nil
} }
i, err := strconv.Atoi(v) i, err := v.Int64()
if err != nil { if err != nil {
return err return err
} }
ent.Result.FilterID = int64(i) ent.Result.FilterID = i
return nil return nil
}, },
"Reason": func(t json.Token, ent *logEntry) error { "Reason": func(t json.Token, ent *logEntry) error {
v, ok := t.(string) v, ok := t.(json.Number)
if !ok { if !ok {
return nil return nil
} }
i, err := strconv.Atoi(v) i, err := v.Int64()
if err != nil { if err != nil {
return err return err
} }
@ -144,17 +140,20 @@ var logEntryHandlers = map[string](func(t json.Token, ent *logEntry) error){
return nil return nil
}, },
"Elapsed": func(t json.Token, ent *logEntry) error { "Elapsed": func(t json.Token, ent *logEntry) error {
v, ok := t.(string) v, ok := t.(json.Number)
if !ok { if !ok {
return nil return nil
} }
i, err := strconv.Atoi(v) i, err := v.Int64()
if err != nil { if err != nil {
return err return err
} }
ent.Elapsed = time.Duration(i) ent.Elapsed = time.Duration(i)
return nil return nil
}, },
"Result": func(json.Token, *logEntry) error {
return nil
},
"Question": func(t json.Token, ent *logEntry) error { "Question": func(t json.Token, ent *logEntry) error {
v, ok := t.(string) v, ok := t.(string)
if !ok { if !ok {
@ -192,10 +191,13 @@ var logEntryHandlers = map[string](func(t json.Token, ent *logEntry) error){
func decodeLogEntry(ent *logEntry, str string) { func decodeLogEntry(ent *logEntry, str string) {
dec := json.NewDecoder(strings.NewReader(str)) dec := json.NewDecoder(strings.NewReader(str))
for dec.More() { dec.UseNumber()
for {
keyToken, err := dec.Token() keyToken, err := dec.Token()
if err != nil { if err != nil {
if err != io.EOF {
log.Debug("decodeLogEntry err: %s", err) log.Debug("decodeLogEntry err: %s", err)
}
return return
} }
if _, ok := keyToken.(json.Delim); ok { if _, ok := keyToken.(json.Delim); ok {
@ -203,17 +205,18 @@ func decodeLogEntry(ent *logEntry, str string) {
} }
key := keyToken.(string) key := keyToken.(string)
handler, ok := logEntryHandlers[key] handler, ok := logEntryHandlers[key]
value, err := dec.Token() if !ok {
continue
}
val, err := dec.Token()
if err != nil { if err != nil {
return return
} }
if ok { if err := handler(val, ent); err != nil {
if err := handler(value, ent); err != nil {
log.Debug("decodeLogEntry err: %s", err) log.Debug("decodeLogEntry err: %s", err)
return return
} }
} }
}
} }
// Get value from "key":"value" // Get value from "key":"value"

60
internal/querylog/decode_test.go
View File

@ -32,6 +32,66 @@ func TestDecode_decodeQueryLog(t *testing.T) {
name: "back_compatibility_bad_decoding", name: "back_compatibility_bad_decoding",
log: `{"Question":"LgBAAABAAAAAAAAC2FkZ3VhcmR0ZWFtBmdpdGh1YgJpbwAAHAAB","Answer":"ULiBgAABAAAAAQAAC2FkZ3VhcmR0ZWFtBmdpdGh1YgJpbwAAHAABwBgABgABAAADQgBLB25zLTE2MjIJYXdzZG5zLTEwAmNvAnVrABFhd3NkbnMtaG9zdG1hc3RlcgZhbWF6b24DY29tAAAAAAEAABwgAAADhAASdQAAAVGA","Result":{},"Time":"2020-11-13T12:41:25.970861+03:00","Elapsed":244066501,"IP":"127.0.0.1","Upstream":"https://1.1.1.1:443/dns-query"}`, log: `{"Question":"LgBAAABAAAAAAAAC2FkZ3VhcmR0ZWFtBmdpdGh1YgJpbwAAHAAB","Answer":"ULiBgAABAAAAAQAAC2FkZ3VhcmR0ZWFtBmdpdGh1YgJpbwAAHAABwBgABgABAAADQgBLB25zLTE2MjIJYXdzZG5zLTEwAmNvAnVrABFhd3NkbnMtaG9zdG1hc3RlcgZhbWF6b24DY29tAAAAAAEAABwgAAADhAASdQAAAVGA","Result":{},"Time":"2020-11-13T12:41:25.970861+03:00","Elapsed":244066501,"IP":"127.0.0.1","Upstream":"https://1.1.1.1:443/dns-query"}`,
want: "decodeLogEntry err: illegal base64 data at input byte 48\n", want: "decodeLogEntry err: illegal base64 data at input byte 48\n",
}, {
name: "modern_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: "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}`,
want: "decodeLogEntry 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}`,
want: "default",
}, {
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",
}, {
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",
}, {
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}`,
want: "decodeLogEntry 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",
}, {
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",
}, {
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",
}, {
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",
}, {
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}`,
want: "decodeLogEntry 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",
}, {
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}`,
want: "decodeLogEntry 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",
}, {
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",
}} }}
for _, tc := range testCases { for _, tc := range testCases {