feat(querylog): define which information should be logged (#765) (#766)

This commit is contained in:
Dimitri Herzog 2022-11-26 22:12:56 +01:00 committed by GitHub
parent 797d71d57c
commit 2b49c2048f
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
15 changed files with 289 additions and 200 deletions

View File

@ -86,6 +86,10 @@ type QueryLogType int16
// ) // )
type StartStrategyType uint16 type StartStrategyType uint16
// QueryLogField data field to be logged
// ENUM(clientIP,clientName,responseReason,responseAnswer,question,duration)
type QueryLogField string
type QType dns.Type type QType dns.Type
func (c QType) String() string { func (c QType) String() string {
@ -567,11 +571,12 @@ type CachingConfig struct {
// QueryLogConfig configuration for the query logging // QueryLogConfig configuration for the query logging
type QueryLogConfig struct { type QueryLogConfig struct {
Target string `yaml:"target"` Target string `yaml:"target"`
Type QueryLogType `yaml:"type"` Type QueryLogType `yaml:"type"`
LogRetentionDays uint64 `yaml:"logRetentionDays"` LogRetentionDays uint64 `yaml:"logRetentionDays"`
CreationAttempts int `yaml:"creationAttempts" default:"3"` CreationAttempts int `yaml:"creationAttempts" default:"3"`
CreationCooldown Duration `yaml:"creationCooldown" default:"2s"` CreationCooldown Duration `yaml:"creationCooldown" default:"2s"`
Fields []QueryLogField `yaml:"fields"`
} }
// RedisConfig configuration for the redis connection // RedisConfig configuration for the redis connection

View File

@ -157,6 +157,82 @@ func (x *NetProtocol) UnmarshalText(text []byte) error {
return nil return nil
} }
const (
// QueryLogFieldClientIP is a QueryLogField of type clientIP.
QueryLogFieldClientIP QueryLogField = "clientIP"
// QueryLogFieldClientName is a QueryLogField of type clientName.
QueryLogFieldClientName QueryLogField = "clientName"
// QueryLogFieldResponseReason is a QueryLogField of type responseReason.
QueryLogFieldResponseReason QueryLogField = "responseReason"
// QueryLogFieldResponseAnswer is a QueryLogField of type responseAnswer.
QueryLogFieldResponseAnswer QueryLogField = "responseAnswer"
// QueryLogFieldQuestion is a QueryLogField of type question.
QueryLogFieldQuestion QueryLogField = "question"
// QueryLogFieldDuration is a QueryLogField of type duration.
QueryLogFieldDuration QueryLogField = "duration"
)
var ErrInvalidQueryLogField = fmt.Errorf("not a valid QueryLogField, try [%s]", strings.Join(_QueryLogFieldNames, ", "))
var _QueryLogFieldNames = []string{
string(QueryLogFieldClientIP),
string(QueryLogFieldClientName),
string(QueryLogFieldResponseReason),
string(QueryLogFieldResponseAnswer),
string(QueryLogFieldQuestion),
string(QueryLogFieldDuration),
}
// QueryLogFieldNames returns a list of possible string values of QueryLogField.
func QueryLogFieldNames() []string {
tmp := make([]string, len(_QueryLogFieldNames))
copy(tmp, _QueryLogFieldNames)
return tmp
}
// String implements the Stringer interface.
func (x QueryLogField) String() string {
return string(x)
}
// String implements the Stringer interface.
func (x QueryLogField) IsValid() bool {
_, err := ParseQueryLogField(string(x))
return err == nil
}
var _QueryLogFieldValue = map[string]QueryLogField{
"clientIP": QueryLogFieldClientIP,
"clientName": QueryLogFieldClientName,
"responseReason": QueryLogFieldResponseReason,
"responseAnswer": QueryLogFieldResponseAnswer,
"question": QueryLogFieldQuestion,
"duration": QueryLogFieldDuration,
}
// ParseQueryLogField attempts to convert a string to a QueryLogField.
func ParseQueryLogField(name string) (QueryLogField, error) {
if x, ok := _QueryLogFieldValue[name]; ok {
return x, nil
}
return QueryLogField(""), fmt.Errorf("%s is %w", name, ErrInvalidQueryLogField)
}
// MarshalText implements the text marshaller method.
func (x QueryLogField) MarshalText() ([]byte, error) {
return []byte(string(x)), nil
}
// UnmarshalText implements the text unmarshaller method.
func (x *QueryLogField) UnmarshalText(text []byte) error {
tmp, err := ParseQueryLogField(string(text))
if err != nil {
return err
}
*x = tmp
return nil
}
const ( const (
// QueryLogTypeConsole is a QueryLogType of type Console. // QueryLogTypeConsole is a QueryLogType of type Console.
// use logger as fallback // use logger as fallback

View File

@ -177,6 +177,10 @@ queryLog:
creationAttempts: 1 creationAttempts: 1
# optional: Time between the creation attempts, default: 2s # optional: Time between the creation attempts, default: 2s
creationCooldown: 2s creationCooldown: 2s
# optional: Which fields should be logged. You can choose one or more from: clientIP, clientName, responseReason, responseAnswer, question, duration. If not defined, it logs all fields
fields:
- clientIP
- duration
# optional: Blocky can synchronize its cache and blocking state between multiple instances through redis. # optional: Blocky can synchronize its cache and blocking state between multiple instances through redis.
redis: redis:

View File

@ -600,22 +600,37 @@ You can select one of following query log types:
- `console` - log into console output - `console` - log into console output
- `none` - do not log any queries - `none` - do not log any queries
### Query log fields
You can choose which information from processed DNS request and response should be logged in the target system. You can define one or more of following fields:
- `clientIP` - origin IP address from the request
- `clientName` - resolved client name(s) from the origins request
- `responseReason` - reason for the response (e.g. from which upstream resolver), response type and code
- `responseAnswer` - returned DNS answer
- `question` - DNS question from the request
- `duration` - request processing time in milliseconds
!!! hint
If not defined, blocky will log all available information
Configuration parameters: Configuration parameters:
| Parameter | Type | Mandatory | Default value | Description | | Parameter | Type | Mandatory | Default value | Description |
|---------------------------|----------------------------------------------------------------------|-----------|---------------|------------------------------------------------------------------------------------| |---------------------------|--------------------------------------------------------------------------------------|-----------|---------------|------------------------------------------------------------------------------------|
| queryLog.type | enum (mysql, postgresql, csv, csv-client, console, none (see above)) | no | | Type of logging target. Console if empty | | queryLog.type | enum (mysql, postgresql, csv, csv-client, console, none (see above)) | no | | Type of logging target. Console if empty |
| queryLog.target | string | no | | directory for writing the logs (for csv) or database url (for mysql or postgresql) | | queryLog.target | string | no | | directory for writing the logs (for csv) or database url (for mysql or postgresql) |
| queryLog.logRetentionDays | int | no | 0 | if > 0, deletes log files/database entries which are older than ... days | | queryLog.logRetentionDays | int | no | 0 | if > 0, deletes log files/database entries which are older than ... days |
| queryLog.creationAttempts | int | no | 3 | Max attempts to create specific query log writer | | queryLog.creationAttempts | int | no | 3 | Max attempts to create specific query log writer |
| queryLog.CreationCooldown | duration format | no | 2 | Time between the creation attempts | | queryLog.CreationCooldown | duration format | no | 2 | Time between the creation attempts |
| queryLog.fields | list enum (clientIP, clientName, responseReason, responseAnswer, question, duration) | no | all | which information should be logged |
!!! hint !!! hint
Please ensure, that the log directory is writable or database exists. If you use docker, please ensure, that the directory is properly Please ensure, that the log directory is writable or database exists. If you use docker, please ensure, that the directory is properly
mounted (e.g. volume) mounted (e.g. volume)
example for CSV format example for CSV format with limited logging information
!!! example !!! example
```yaml ```yaml
@ -623,6 +638,9 @@ example for CSV format
type: csv type: csv
target: /logs target: /logs
logRetentionDays: 7 logRetentionDays: 7
fields:
- clientIP
- duration
``` ```
example for Database example for Database

1
go.mod
View File

@ -36,7 +36,6 @@ require (
) )
require ( require (
github.com/alecthomas/template v0.0.0-20190718012654-fb15b899a751
github.com/docker/go-connections v0.4.0 github.com/docker/go-connections v0.4.0
github.com/dosgo/zigtool v0.0.0-20210923085854-9c6fc1d62198 github.com/dosgo/zigtool v0.0.0-20210923085854-9c6fc1d62198
github.com/testcontainers/testcontainers-go v0.15.0 github.com/testcontainers/testcontainers-go v0.15.0

1
go.sum
View File

@ -90,7 +90,6 @@ github.com/Shopify/logrus-bugsnag v0.0.0-20171204204709-577dee27f20d/go.mod h1:H
github.com/abice/go-enum v0.5.3 h1:Ghq0aWp+tCNZFAb4lFK7UnjzUJQTS1atIMjHkX+Gex4= github.com/abice/go-enum v0.5.3 h1:Ghq0aWp+tCNZFAb4lFK7UnjzUJQTS1atIMjHkX+Gex4=
github.com/abice/go-enum v0.5.3/go.mod h1:jf915DI7NxXZRwk8qDgZJKq2raAtwcPBXJRh9WVgtU0= github.com/abice/go-enum v0.5.3/go.mod h1:jf915DI7NxXZRwk8qDgZJKq2raAtwcPBXJRh9WVgtU0=
github.com/alecthomas/template v0.0.0-20160405071501-a0175ee3bccc/go.mod h1:LOuyumcjzFXgccqObfd/Ljyb9UuFJ6TxHnclSeseNhc= github.com/alecthomas/template v0.0.0-20160405071501-a0175ee3bccc/go.mod h1:LOuyumcjzFXgccqObfd/Ljyb9UuFJ6TxHnclSeseNhc=
github.com/alecthomas/template v0.0.0-20190718012654-fb15b899a751 h1:JYp7IbQjafoB+tBA3gMyHYHrpOtNuDiK/uB5uXxq5wM=
github.com/alecthomas/template v0.0.0-20190718012654-fb15b899a751/go.mod h1:LOuyumcjzFXgccqObfd/Ljyb9UuFJ6TxHnclSeseNhc= github.com/alecthomas/template v0.0.0-20190718012654-fb15b899a751/go.mod h1:LOuyumcjzFXgccqObfd/Ljyb9UuFJ6TxHnclSeseNhc=
github.com/alecthomas/units v0.0.0-20151022065526-2efee857e7cf/go.mod h1:ybxpYRFXyAe+OPACYpWeL0wqObRcbAqCMya13uyzqw0= github.com/alecthomas/units v0.0.0-20151022065526-2efee857e7cf/go.mod h1:ybxpYRFXyAe+OPACYpWeL0wqObRcbAqCMya13uyzqw0=
github.com/alecthomas/units v0.0.0-20190717042225-c3de453c63f4/go.mod h1:ybxpYRFXyAe+OPACYpWeL0wqObRcbAqCMya13uyzqw0= github.com/alecthomas/units v0.0.0-20190717042225-c3de453c63f4/go.mod h1:ybxpYRFXyAe+OPACYpWeL0wqObRcbAqCMya13uyzqw0=

View File

@ -10,9 +10,8 @@ import (
"gorm.io/gorm/logger" "gorm.io/gorm/logger"
"github.com/0xERR0R/blocky/log" "github.com/0xERR0R/blocky/log"
"github.com/0xERR0R/blocky/util" "github.com/0xERR0R/blocky/util"
"github.com/miekg/dns"
"golang.org/x/net/publicsuffix" "golang.org/x/net/publicsuffix"
"gorm.io/driver/mysql" "gorm.io/driver/mysql"
"gorm.io/driver/postgres" "gorm.io/driver/postgres"
@ -126,21 +125,21 @@ func (d *DatabaseWriter) periodicFlush() {
} }
func (d *DatabaseWriter) Write(entry *LogEntry) { func (d *DatabaseWriter) Write(entry *LogEntry) {
domain := util.ExtractDomain(entry.Request.Req.Question[0]) domain := util.ExtractDomainOnly(entry.QuestionName)
eTLD, _ := publicsuffix.EffectiveTLDPlusOne(domain) eTLD, _ := publicsuffix.EffectiveTLDPlusOne(domain)
e := &logEntry{ e := &logEntry{
RequestTS: &entry.Start, RequestTS: &entry.Start,
ClientIP: entry.Request.ClientIP.String(), ClientIP: entry.ClientIP,
ClientName: strings.Join(entry.Request.ClientNames, "; "), ClientName: strings.Join(entry.ClientNames, "; "),
DurationMs: entry.DurationMs, DurationMs: entry.DurationMs,
Reason: entry.Response.Reason, Reason: entry.ResponseReason,
ResponseType: entry.Response.RType.String(), ResponseType: entry.ResponseType,
QuestionType: dns.TypeToString[entry.Request.Req.Question[0].Qtype], QuestionType: entry.QuestionType,
QuestionName: domain, QuestionName: domain,
EffectiveTLDP: eTLD, EffectiveTLDP: eTLD,
Answer: util.AnswerToString(entry.Response.Res.Answer), Answer: entry.Answer,
ResponseCode: dns.RcodeToString[entry.Response.Res.Rcode], ResponseCode: entry.ResponseCode,
Hostname: util.HostnameString(), Hostname: util.HostnameString(),
} }

View File

@ -3,11 +3,6 @@ package querylog
import ( import (
"time" "time"
"github.com/0xERR0R/blocky/log"
"github.com/0xERR0R/blocky/model"
"github.com/0xERR0R/blocky/util"
"github.com/miekg/dns"
"github.com/sirupsen/logrus"
"gorm.io/driver/sqlite" "gorm.io/driver/sqlite"
"gorm.io/gorm" "gorm.io/gorm"
@ -24,16 +19,10 @@ var _ = Describe("DatabaseWriter", func() {
var ( var (
sqliteDB gorm.Dialector sqliteDB gorm.Dialector
writer *DatabaseWriter writer *DatabaseWriter
request *model.Request
) )
BeforeEach(func() { BeforeEach(func() {
sqliteDB = sqlite.Open("file::memory:") sqliteDB = sqlite.Open("file::memory:")
request = &model.Request{
Req: util.NewMsgWithQuestion("google.de.", dns.Type(dns.TypeA)),
Log: logrus.NewEntry(log.Log()),
}
}) })
When("New log entry was created", func() { When("New log entry was created", func() {
@ -43,27 +32,14 @@ var _ = Describe("DatabaseWriter", func() {
}) })
It("should be persisted in the database", func() { It("should be persisted in the database", func() {
res, err := util.NewMsgWithAnswer("example.com", 123, dns.Type(dns.TypeA), "123.124.122.122")
Expect(err).Should(Succeed())
response := &model.Response{
Res: res,
Reason: "Resolved",
RType: model.ResponseTypeRESOLVED,
}
// one entry with now as timestamp // one entry with now as timestamp
writer.Write(&LogEntry{ writer.Write(&LogEntry{
Request: request,
Response: response,
Start: time.Now(), Start: time.Now(),
DurationMs: 20, DurationMs: 20,
}) })
// one entry before 2 days // one entry before 2 days
writer.Write(&LogEntry{ writer.Write(&LogEntry{
Request: request,
Response: response,
Start: time.Now().AddDate(0, 0, -2), Start: time.Now().AddDate(0, 0, -2),
DurationMs: 20, DurationMs: 20,
}) })
@ -102,27 +78,14 @@ var _ = Describe("DatabaseWriter", func() {
}) })
It("these old entries should be deleted", func() { It("these old entries should be deleted", func() {
res, err := util.NewMsgWithAnswer("example.com", 123, dns.Type(dns.TypeA), "123.124.122.122")
Expect(err).Should(Succeed())
response := &model.Response{
Res: res,
Reason: "Resolved",
RType: model.ResponseTypeRESOLVED,
}
// one entry with now as timestamp // one entry with now as timestamp
writer.Write(&LogEntry{ writer.Write(&LogEntry{
Request: request,
Response: response,
Start: time.Now(), Start: time.Now(),
DurationMs: 20, DurationMs: 20,
}) })
// one entry before 2 days -> should be deleted // one entry before 2 days -> should be deleted
writer.Write(&LogEntry{ writer.Write(&LogEntry{
Request: request,
Response: response,
Start: time.Now().AddDate(0, 0, -2), Start: time.Now().AddDate(0, 0, -2),
DurationMs: 20, DurationMs: 20,
}) })

View File

@ -12,7 +12,6 @@ import (
"github.com/0xERR0R/blocky/log" "github.com/0xERR0R/blocky/log"
"github.com/0xERR0R/blocky/util" "github.com/0xERR0R/blocky/util"
"github.com/miekg/dns"
"github.com/sirupsen/logrus" "github.com/sirupsen/logrus"
) )
@ -44,7 +43,7 @@ func (d *FileWriter) Write(entry *LogEntry) {
dateString := entry.Start.Format("2006-01-02") dateString := entry.Start.Format("2006-01-02")
if d.perClient { if d.perClient {
clientPrefix = strings.Join(entry.Request.ClientNames, "-") clientPrefix = strings.Join(entry.ClientNames, "-")
} else { } else {
clientPrefix = "ALL" clientPrefix = "ALL"
} }
@ -102,18 +101,17 @@ func (d *FileWriter) CleanUp() {
} }
func createQueryLogRow(logEntry *LogEntry) []string { func createQueryLogRow(logEntry *LogEntry) []string {
request := logEntry.Request
response := logEntry.Response
return []string{ return []string{
logEntry.Start.Format("2006-01-02 15:04:05"), logEntry.Start.Format("2006-01-02 15:04:05"),
request.ClientIP.String(), logEntry.ClientIP,
strings.Join(request.ClientNames, "; "), strings.Join(logEntry.ClientNames, "; "),
fmt.Sprintf("%d", logEntry.DurationMs), fmt.Sprintf("%d", logEntry.DurationMs),
response.Reason, logEntry.ResponseReason,
util.QuestionToString(request.Req.Question), logEntry.QuestionName,
util.AnswerToString(response.Res.Answer), logEntry.Answer,
dns.RcodeToString[response.Res.Rcode], logEntry.ResponseCode,
logEntry.ResponseType,
logEntry.QuestionType,
util.HostnameString(), util.HostnameString(),
} }
} }

View File

@ -12,9 +12,6 @@ import (
"github.com/0xERR0R/blocky/helpertest" "github.com/0xERR0R/blocky/helpertest"
"github.com/0xERR0R/blocky/log" "github.com/0xERR0R/blocky/log"
"github.com/0xERR0R/blocky/model"
"github.com/0xERR0R/blocky/util"
"github.com/miekg/dns"
. "github.com/onsi/ginkgo/v2" . "github.com/onsi/ginkgo/v2"
. "github.com/onsi/gomega" . "github.com/onsi/gomega"
) )
@ -45,41 +42,19 @@ var _ = Describe("FileWriter", func() {
Expect(err).Should(Succeed()) Expect(err).Should(Succeed())
res, err := util.NewMsgWithAnswer("example.com", 123, dns.Type(dns.TypeA), "123.124.122.122")
Expect(err).Should(Succeed())
By("entry for client 1", func() { By("entry for client 1", func() {
writer.Write(&LogEntry{ writer.Write(&LogEntry{
Request: &model.Request{ ClientNames: []string{"client1"},
ClientNames: []string{"client1"}, Start: time.Now(),
Req: util.NewMsgWithQuestion("google.de.", dns.Type(dns.TypeA)), DurationMs: 20,
RequestTS: time.Time{},
},
Response: &model.Response{
Res: res,
Reason: "Resolved",
RType: model.ResponseTypeRESOLVED,
},
Start: time.Now(),
DurationMs: 20,
}) })
}) })
By("entry for client 2", func() { By("entry for client 2", func() {
writer.Write(&LogEntry{ writer.Write(&LogEntry{
Request: &model.Request{ ClientNames: []string{"client2"},
ClientNames: []string{"client2"}, Start: time.Now(),
Req: util.NewMsgWithQuestion("google.de.", dns.Type(dns.TypeA)), DurationMs: 20,
RequestTS: time.Time{},
},
Response: &model.Response{
Res: res,
Reason: "Resolved",
RType: model.ResponseTypeRESOLVED,
},
Start: time.Now(),
DurationMs: 20,
}) })
}) })
@ -94,41 +69,19 @@ var _ = Describe("FileWriter", func() {
Expect(err).Should(Succeed()) Expect(err).Should(Succeed())
res, err := util.NewMsgWithAnswer("example.com", 123, dns.Type(dns.TypeA), "123.124.122.122")
Expect(err).Should(Succeed())
By("entry for client 1", func() { By("entry for client 1", func() {
writer.Write(&LogEntry{ writer.Write(&LogEntry{
Request: &model.Request{ ClientNames: []string{"client1"},
ClientNames: []string{"client1"}, Start: time.Now(),
Req: util.NewMsgWithQuestion("google.de.", dns.Type(dns.TypeA)), DurationMs: 20,
RequestTS: time.Time{},
},
Response: &model.Response{
Res: res,
Reason: "Resolved",
RType: model.ResponseTypeRESOLVED,
},
Start: time.Now(),
DurationMs: 20,
}) })
}) })
By("entry for client 2", func() { By("entry for client 2", func() {
writer.Write(&LogEntry{ writer.Write(&LogEntry{
Request: &model.Request{ ClientNames: []string{"client2"},
ClientNames: []string{"client2"}, Start: time.Now(),
Req: util.NewMsgWithQuestion("google.de.", dns.Type(dns.TypeA)), DurationMs: 20,
RequestTS: time.Time{},
},
Response: &model.Response{
Res: res,
Reason: "Resolved",
RType: model.ResponseTypeRESOLVED,
},
Start: time.Now(),
DurationMs: 20,
}) })
}) })
@ -150,40 +103,18 @@ var _ = Describe("FileWriter", func() {
Expect(err).Should(Succeed()) Expect(err).Should(Succeed())
res, err := util.NewMsgWithAnswer("example.com", 123, dns.Type(dns.TypeA), "123.124.122.122")
Expect(err).Should(Succeed())
By("entry today", func() { By("entry today", func() {
writer.Write(&LogEntry{ writer.Write(&LogEntry{
Request: &model.Request{ ClientNames: []string{"client1"},
ClientNames: []string{"client1"}, Start: time.Now(),
Req: util.NewMsgWithQuestion("google.de.", dns.Type(dns.TypeA)), DurationMs: 20,
RequestTS: time.Now(),
},
Response: &model.Response{
Res: res,
Reason: "Resolved",
RType: model.ResponseTypeRESOLVED,
},
Start: time.Now(),
DurationMs: 20,
}) })
}) })
By("entry 2 days ago", func() { By("entry 2 days ago", func() {
writer.Write(&LogEntry{ writer.Write(&LogEntry{
Request: &model.Request{ ClientNames: []string{"client1"},
ClientNames: []string{"client1"}, Start: time.Now().AddDate(0, 0, -3),
Req: util.NewMsgWithQuestion("google.de.", dns.Type(dns.TypeA)), DurationMs: 20,
RequestTS: time.Now(),
},
Response: &model.Response{
Res: res,
Reason: "Resolved",
RType: model.ResponseTypeRESOLVED,
},
Start: time.Now().AddDate(0, 0, -3),
DurationMs: 20,
}) })
}) })

View File

@ -5,7 +5,6 @@ import (
"github.com/0xERR0R/blocky/log" "github.com/0xERR0R/blocky/log"
"github.com/0xERR0R/blocky/util" "github.com/0xERR0R/blocky/util"
"github.com/miekg/dns"
"github.com/sirupsen/logrus" "github.com/sirupsen/logrus"
) )
@ -22,12 +21,14 @@ func NewLoggerWriter() *LoggerWriter {
func (d *LoggerWriter) Write(entry *LogEntry) { func (d *LoggerWriter) Write(entry *LogEntry) {
d.logger.WithFields( d.logger.WithFields(
logrus.Fields{ logrus.Fields{
"client_ip": entry.Request.ClientIP, "client_ip": entry.ClientIP,
"client_names": strings.Join(entry.Request.ClientNames, "; "), "client_names": strings.Join(entry.ClientNames, "; "),
"response_reason": entry.Response.Reason, "response_reason": entry.ResponseReason,
"question": util.QuestionToString(entry.Request.Req.Question), "response_type": entry.ResponseType,
"response_code": dns.RcodeToString[entry.Response.Res.Rcode], "response_code": entry.ResponseCode,
"answer": util.AnswerToString(entry.Response.Res.Answer), "question_name": entry.QuestionName,
"question_type": entry.QuestionType,
"answer": entry.Answer,
"duration_ms": entry.DurationMs, "duration_ms": entry.DurationMs,
"hostname": util.HostnameString(), "hostname": util.HostnameString(),
}, },

View File

@ -5,12 +5,7 @@ import (
"github.com/sirupsen/logrus/hooks/test" "github.com/sirupsen/logrus/hooks/test"
"github.com/0xERR0R/blocky/log"
"github.com/0xERR0R/blocky/model"
"github.com/0xERR0R/blocky/util"
"github.com/miekg/dns"
. "github.com/onsi/gomega" . "github.com/onsi/gomega"
"github.com/sirupsen/logrus"
. "github.com/onsi/ginkgo/v2" . "github.com/onsi/ginkgo/v2"
) )
@ -23,21 +18,8 @@ var _ = Describe("LoggerWriter", func() {
writer := NewLoggerWriter() writer := NewLoggerWriter()
logger, hook := test.NewNullLogger() logger, hook := test.NewNullLogger()
writer.logger = logger.WithField("k", "v") writer.logger = logger.WithField("k", "v")
request := &model.Request{
Req: util.NewMsgWithQuestion("google.de.", dns.Type(dns.TypeA)),
Log: logrus.NewEntry(log.Log()),
}
res, err := util.NewMsgWithAnswer("example.com", 123, dns.Type(dns.TypeA), "123.124.122.122")
Expect(err).Should(Succeed())
response := &model.Response{
Res: res,
Reason: "Resolved",
RType: model.ResponseTypeRESOLVED,
}
writer.Write(&LogEntry{ writer.Write(&LogEntry{
Request: request,
Response: response,
Start: time.Now(), Start: time.Now(),
DurationMs: 20, DurationMs: 20,
}) })

View File

@ -2,15 +2,19 @@ package querylog
import ( import (
"time" "time"
"github.com/0xERR0R/blocky/model"
) )
type LogEntry struct { type LogEntry struct {
Request *model.Request Start time.Time
Response *model.Response ClientIP string
Start time.Time ClientNames []string
DurationMs int64 DurationMs int64
ResponseReason string
ResponseType string
ResponseCode string
QuestionType string
QuestionName string
Answer string
} }
type Writer interface { type Writer interface {

View File

@ -7,7 +7,9 @@ import (
"github.com/0xERR0R/blocky/config" "github.com/0xERR0R/blocky/config"
"github.com/0xERR0R/blocky/model" "github.com/0xERR0R/blocky/model"
"github.com/0xERR0R/blocky/querylog" "github.com/0xERR0R/blocky/querylog"
"github.com/0xERR0R/blocky/util"
"github.com/avast/retry-go/v4" "github.com/avast/retry-go/v4"
"github.com/miekg/dns"
) )
const ( const (
@ -25,6 +27,7 @@ type QueryLoggingResolver struct {
logChan chan *querylog.LogEntry logChan chan *querylog.LogEntry
writer querylog.Writer writer querylog.Writer
logType config.QueryLogType logType config.QueryLogType
fields []config.QueryLogField
} }
// NewQueryLoggingResolver returns a new resolver instance // NewQueryLoggingResolver returns a new resolver instance
@ -74,6 +77,7 @@ func NewQueryLoggingResolver(cfg config.QueryLogConfig) ChainedResolver {
logChan: logChan, logChan: logChan,
writer: writer, writer: writer,
logType: logType, logType: logType,
fields: resolveQueryLogFields(cfg),
} }
go resolver.writeLog() go resolver.writeLog()
@ -85,6 +89,24 @@ func NewQueryLoggingResolver(cfg config.QueryLogConfig) ChainedResolver {
return &resolver return &resolver
} }
func resolveQueryLogFields(cfg config.QueryLogConfig) []config.QueryLogField {
var fields []config.QueryLogField
if len(cfg.Fields) == 0 {
// no fields defined, use all fields as fallback
for _, v := range config.QueryLogFieldNames() {
qlt, err := config.ParseQueryLogField(v)
util.LogOnError("ignoring unknown query log field", err)
fields = append(fields, qlt)
}
} else {
fields = cfg.Fields
}
return fields
}
// triggers periodically cleanup of old log files // triggers periodically cleanup of old log files
func (r *QueryLoggingResolver) periodicCleanUp() { func (r *QueryLoggingResolver) periodicCleanUp() {
ticker := time.NewTicker(cleanUpRunPeriod) ticker := time.NewTicker(cleanUpRunPeriod)
@ -112,11 +134,7 @@ func (r *QueryLoggingResolver) Resolve(request *model.Request) (*model.Response,
if err == nil { if err == nil {
select { select {
case r.logChan <- &querylog.LogEntry{ case r.logChan <- r.createLogEntry(request, resp, start, duration):
Request: request,
Response: resp,
Start: start,
DurationMs: duration}:
default: default:
logger.Error("query log writer is too slow, log entry will be dropped") logger.Error("query log writer is too slow, log entry will be dropped")
} }
@ -125,6 +143,42 @@ func (r *QueryLoggingResolver) Resolve(request *model.Request) (*model.Response,
return resp, err return resp, err
} }
func (r *QueryLoggingResolver) createLogEntry(request *model.Request, response *model.Response,
start time.Time, durationMs int64) *querylog.LogEntry {
entry := querylog.LogEntry{
Start: start,
ClientIP: "0.0.0.0",
ClientNames: []string{"none"},
}
for _, f := range r.fields {
switch f {
case config.QueryLogFieldClientIP:
entry.ClientIP = request.ClientIP.String()
case config.QueryLogFieldClientName:
entry.ClientNames = request.ClientNames
case config.QueryLogFieldResponseReason:
entry.ResponseReason = response.Reason
entry.ResponseType = response.RType.String()
entry.ResponseCode = dns.RcodeToString[response.Res.Rcode]
case config.QueryLogFieldResponseAnswer:
entry.Answer = util.AnswerToString(response.Res.Answer)
case config.QueryLogFieldQuestion:
entry.QuestionName = request.Req.Question[0].Name
entry.QuestionType = dns.TypeToString[request.Req.Question[0].Qtype]
case config.QueryLogFieldDuration:
entry.DurationMs = durationMs
}
}
return &entry
}
// write entry: if log directory is configured, write to log file // write entry: if log directory is configured, write to log file
func (r *QueryLoggingResolver) writeLog() { func (r *QueryLoggingResolver) writeLog() {
for logEntry := range r.logChan { for logEntry := range r.logChan {
@ -147,6 +201,7 @@ func (r *QueryLoggingResolver) Configuration() (result []string) {
result = append(result, fmt.Sprintf("type: \"%s\"", r.logType)) result = append(result, fmt.Sprintf("type: \"%s\"", r.logType))
result = append(result, fmt.Sprintf("target: \"%s\"", r.target)) result = append(result, fmt.Sprintf("target: \"%s\"", r.target))
result = append(result, fmt.Sprintf("logRetentionDays: %d", r.logRetentionDays)) result = append(result, fmt.Sprintf("logRetentionDays: %d", r.logRetentionDays))
result = append(result, fmt.Sprintf("fields: %s", r.fields))
return return
} }

View File

@ -110,8 +110,11 @@ var _ = Describe("QueryLoggingResolver", func() {
g.Expect(csvLines[0][1]).Should(Equal("192.168.178.25")) g.Expect(csvLines[0][1]).Should(Equal("192.168.178.25"))
g.Expect(csvLines[0][2]).Should(Equal("client1")) g.Expect(csvLines[0][2]).Should(Equal("client1"))
g.Expect(csvLines[0][4]).Should(Equal("reason")) g.Expect(csvLines[0][4]).Should(Equal("reason"))
g.Expect(csvLines[0][5]).Should(Equal("A (example.com.)")) g.Expect(csvLines[0][5]).Should(Equal("example.com."))
g.Expect(csvLines[0][6]).Should(Equal("A (123.122.121.120)")) g.Expect(csvLines[0][6]).Should(Equal("A (123.122.121.120)"))
g.Expect(csvLines[0][7]).Should(Equal("NOERROR"))
g.Expect(csvLines[0][8]).Should(Equal("RESOLVED"))
g.Expect(csvLines[0][9]).Should(Equal("A"))
}, "1s").Should(Succeed()) }, "1s").Should(Succeed())
}) })
@ -126,8 +129,11 @@ var _ = Describe("QueryLoggingResolver", func() {
g.Expect(csvLines[0][1]).Should(Equal("192.168.178.26")) g.Expect(csvLines[0][1]).Should(Equal("192.168.178.26"))
g.Expect(csvLines[0][2]).Should(Equal("cl/ient2\\$%&test")) g.Expect(csvLines[0][2]).Should(Equal("cl/ient2\\$%&test"))
g.Expect(csvLines[0][4]).Should(Equal("reason")) g.Expect(csvLines[0][4]).Should(Equal("reason"))
g.Expect(csvLines[0][5]).Should(Equal("A (example.com.)")) g.Expect(csvLines[0][5]).Should(Equal("example.com."))
g.Expect(csvLines[0][6]).Should(Equal("A (123.122.121.120)")) g.Expect(csvLines[0][6]).Should(Equal("A (123.122.121.120)"))
g.Expect(csvLines[0][7]).Should(Equal("NOERROR"))
g.Expect(csvLines[0][8]).Should(Equal("RESOLVED"))
g.Expect(csvLines[0][9]).Should(Equal("A"))
}, "1s").Should(Succeed()) }, "1s").Should(Succeed())
}) })
}) })
@ -165,20 +171,69 @@ var _ = Describe("QueryLoggingResolver", func() {
g.Expect(csvLines[0][1]).Should(Equal("192.168.178.25")) g.Expect(csvLines[0][1]).Should(Equal("192.168.178.25"))
g.Expect(csvLines[0][2]).Should(Equal("client1")) g.Expect(csvLines[0][2]).Should(Equal("client1"))
g.Expect(csvLines[0][4]).Should(Equal("reason")) g.Expect(csvLines[0][4]).Should(Equal("reason"))
g.Expect(csvLines[0][5]).Should(Equal("A (example.com.)")) g.Expect(csvLines[0][5]).Should(Equal("example.com."))
g.Expect(csvLines[0][6]).Should(Equal("A (123.122.121.120)")) g.Expect(csvLines[0][6]).Should(Equal("A (123.122.121.120)"))
g.Expect(csvLines[0][7]).Should(Equal("NOERROR"))
g.Expect(csvLines[0][8]).Should(Equal("RESOLVED"))
g.Expect(csvLines[0][9]).Should(Equal("A"))
// client2 -> second line // client2 -> second line
g.Expect(csvLines[1][1]).Should(Equal("192.168.178.26")) g.Expect(csvLines[1][1]).Should(Equal("192.168.178.26"))
g.Expect(csvLines[1][2]).Should(Equal("client2")) g.Expect(csvLines[1][2]).Should(Equal("client2"))
g.Expect(csvLines[1][4]).Should(Equal("reason")) g.Expect(csvLines[1][4]).Should(Equal("reason"))
g.Expect(csvLines[1][5]).Should(Equal("A (example.com.)")) g.Expect(csvLines[1][5]).Should(Equal("example.com."))
g.Expect(csvLines[1][6]).Should(Equal("A (123.122.121.120)")) g.Expect(csvLines[1][6]).Should(Equal("A (123.122.121.120)"))
g.Expect(csvLines[1][7]).Should(Equal("NOERROR"))
g.Expect(csvLines[1][8]).Should(Equal("RESOLVED"))
g.Expect(csvLines[1][9]).Should(Equal("A"))
}, "1s").Should(Succeed()) }, "1s").Should(Succeed())
}) })
}) })
}) })
When("Configuration with specific fields to log", func() {
BeforeEach(func() {
sutConfig = config.QueryLogConfig{
Target: tmpDir.Path,
Type: config.QueryLogTypeCsv,
CreationAttempts: 1,
CreationCooldown: config.Duration(time.Millisecond),
Fields: []config.QueryLogField{config.QueryLogFieldClientIP},
}
mockAnswer, _ = util.NewMsgWithAnswer("example.com.", 300, dns.Type(dns.TypeA), "123.122.121.120")
})
It("should create one log file", func() {
By("request from client 1", func() {
resp, err = sut.Resolve(newRequestWithClient("example.com.", dns.Type(dns.TypeA), "192.168.178.25", "client1"))
Expect(err).Should(Succeed())
})
m.AssertExpectations(GinkgoT())
By("check log", func() {
Eventually(func(g Gomega) {
csvLines, err := readCsv(tmpDir.JoinPath(
fmt.Sprintf("%s_ALL.log", time.Now().Format("2006-01-02"))))
g.Expect(err).Should(Succeed())
g.Expect(csvLines).Should(HaveLen(1))
// ip will be logged
g.Expect(csvLines[0][1]).Should(Equal("192.168.178.25"))
g.Expect(csvLines[0][2]).Should(Equal("none"))
g.Expect(csvLines[0][3]).Should(Equal("0"))
g.Expect(csvLines[0][4]).Should(Equal(""))
g.Expect(csvLines[0][5]).Should(Equal(""))
g.Expect(csvLines[0][6]).Should(Equal(""))
g.Expect(csvLines[0][7]).Should(Equal(""))
g.Expect(csvLines[0][8]).Should(Equal(""))
g.Expect(csvLines[0][9]).Should(Equal(""))
}, "1s").Should(Succeed())
})
})
})
}) })
Describe("Slow writer", func() { Describe("Slow writer", func() {