-
Notifications
You must be signed in to change notification settings - Fork 608
Add logging for dns lookups with timestamps #3631
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
base: master
Are you sure you want to change the base?
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
Original file line number | Diff line number | Diff line change |
---|---|---|
|
@@ -20,6 +20,7 @@ import ( | |
"flag" | ||
"fmt" | ||
"log" | ||
"log/slog" | ||
"net" | ||
"net/http" | ||
"os" | ||
|
@@ -39,10 +40,10 @@ import ( | |
const clusterDomain = "cluster.local" | ||
|
||
type Config struct { | ||
qps int | ||
testDuration, idleDuration, queryTimeout time.Duration | ||
hostnameFile string | ||
queryClusterNames, logQueries bool | ||
qps int | ||
testDuration, idleDuration, queryTimeout time.Duration | ||
hostnameFile string | ||
queryClusterNames, logQueries, enableLatencyLogging bool | ||
} | ||
|
||
type dnsClient struct { | ||
|
@@ -59,6 +60,13 @@ type dnsClient struct { | |
|
||
type LookupFunc func(string) ([]string, error) | ||
|
||
var ( | ||
// infoLogger writes to stdout, initialized if flag is set. | ||
infoLogger *slog.Logger | ||
// errorLogger writes to stderr, initialized if flag is set. | ||
errorLogger *slog.Logger | ||
) | ||
|
||
func main() { | ||
config := Config{} | ||
flag.IntVar(&config.qps, "qps", 10, "The number of DNS queries per second to issue") | ||
|
@@ -68,8 +76,12 @@ func main() { | |
flag.StringVar(&config.hostnameFile, "inputfile", "", "Path to the file containing hostnames to lookup. Hostnames should be newline-separated.") | ||
flag.BoolVar(&config.queryClusterNames, "query-cluster-names", false, "Indicates whether the query names should be the service names in the cluster.") | ||
flag.BoolVar(&config.logQueries, "log-queries", false, "Indicates whether each query should be logged.") | ||
|
||
flag.BoolVar(&config.enableLatencyLogging, "enable-latency-logging", false, "Indicate whether to enable structured logging for each DNS lookup latency.") | ||
flag.Parse() | ||
if config.enableLatencyLogging { | ||
infoLogger = slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{Level: slog.LevelInfo})) | ||
} | ||
errorLogger = slog.New(slog.NewJSONHandler(os.Stderr, &slog.HandlerOptions{Level: slog.LevelError})) | ||
log.Printf("Starting dnstest with config parameters - %+v", config) | ||
client := &dnsClient{config: &config, stopChan: make(chan os.Signal, 1)} | ||
signal.Notify(client.stopChan, syscall.SIGTERM) | ||
|
@@ -223,6 +235,12 @@ func (c *dnsClient) runQuery(name string, timeout time.Duration, lookupFunc Look | |
startTime := time.Now() | ||
_, err := lookupFunc(name) | ||
latency := time.Since(startTime) | ||
if infoLogger != nil && err == nil { | ||
infoLogger.Info("DNS lookup successful, latency recorded", | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. suggest: infoLogger("lookup", "name", name, "latency_ms", latency.Milliseconds(), "err", err) Latency we want in milliseconds |
||
"hostname", name, | ||
"latency_seconds", latency.Seconds(), | ||
) | ||
} | ||
dnsLatency.Observe(latency.Seconds()) | ||
resultChan <- err | ||
}(resultChan) | ||
|
@@ -235,7 +253,11 @@ func (c *dnsClient) runQuery(name string, timeout time.Duration, lookupFunc Look | |
log.Printf("DNS lookup of name %q, err - %v\n", name, err) | ||
} | ||
if err != nil { | ||
log.Printf("Failed DNS lookup of name %q, err - %v\n", name, err) | ||
errorLogger.Error("Failed DNS lookup", | ||
"hostname", name, | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. make it easier to maintain -- "name", name |
||
"error", err.Error(), | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Do you need to call Error? Isn't it extraneous? |
||
"timed_out", timedOut, | ||
) | ||
} | ||
c.updateResults(timedOut, err) | ||
}() | ||
|
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
why not route the infoLogger to a dummy logger that doesn't output instead of having
if
statements?There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I also recommend logging for all lookups, irrespective of err == nil or not.