middleware/log: make {size} the length of the request (#449)

* middleware/log: make {size} the length of the request

{size} is the lenght of the request, {rsize} is the length of the
reply.

* Fix test

4 files changed, 10 insertions, 8 deletions

diff --git a/middleware/log/README.md b/middleware/log/README.md
index 1cd3d84e1..812fa20bb 100644
--- a/middleware/log/README.md
+++ b/middleware/log/README.md
@@ -62,19 +62,20 @@ The following place holders are supported:
 * `{proto}`: protocol used (tcp or udp).
 * `{when}`: time of the query.
 * `{remote}`: client's IP address.
+* `{size}`: request size in bytes.
 * `{port}`: client's port.
-* `{rcode}`: response RCODE.
-* `{size}`: response size.
 * `{duration}`: response duration.
-* `{>bufsize}`: the EDNS0 buffer size advertized by the client.
+* `{>bufsize}`: the EDNS0 buffer size advertised.
 * `{>do}`: is the EDNS0 DO (DNSSEC OK) bit set.
 * `{>id}`: query ID
-* `{>opcode}`: query OPCODE
+* `{>opcode}`: query OPCODE.
+* `{rcode}`: response RCODE.
+* `{rsize}`: response size.
 
 The default Common Log Format is:
 
 ~~~ txt
-`{remote} - [{when}] "{type} {class} {name} {proto} {>do} {>bufsize}" {rcode} {size} {duration}`
+`{remote} - [{when}] "{type} {class} {name} {proto} {size} {>do} {>bufsize}" {rcode} {rsize} {duration}`
 ~~~
 
 ## Examples
diff --git a/middleware/log/log.go b/middleware/log/log.go
index e099eced7..ef9e3f51d 100644
--- a/middleware/log/log.go
+++ b/middleware/log/log.go
@@ -80,7 +80,7 @@ const (
 	// DefaultLogFilename is the default log filename.
 	DefaultLogFilename = "query.log"
 	// CommonLogFormat is the common log format.
-	CommonLogFormat = `{remote} ` + CommonLogEmptyValue + ` [{when}] "{type} {class} {name} {proto} {>do} {>bufsize}" {rcode} {size} {duration}`
+	CommonLogFormat = `{remote} ` + CommonLogEmptyValue + ` [{when}] "{type} {class} {name} {proto} {size} {>do} {>bufsize}" {rcode} {rsize} {duration}`
 	// CommonLogEmptyValue is the common empty log value.
 	CommonLogEmptyValue = "-"
 	// CombinedLogFormat is the combined log format.
diff --git a/middleware/log/log_test.go b/middleware/log/log_test.go
index 2f4d8c098..8e6d48418 100644
--- a/middleware/log/log_test.go
+++ b/middleware/log/log_test.go
@@ -39,7 +39,7 @@ func TestLoggedStatus(t *testing.T) {
 	}
 
 	logged := f.String()
-	if !strings.Contains(logged, "A IN example.org. udp false 512") {
+	if !strings.Contains(logged, "A IN example.org. udp 29 false 512") {
 		t.Errorf("Expected it to be logged. Logged string: %s", logged)
 	}
 }
diff --git a/middleware/pkg/replacer/replacer.go b/middleware/pkg/replacer/replacer.go
index 71aa1c1b5..890f0c45f 100644
--- a/middleware/pkg/replacer/replacer.go
+++ b/middleware/pkg/replacer/replacer.go
@@ -42,6 +42,7 @@ func New(r *dns.Msg, rr *dnsrecorder.Recorder, emptyValue string) Replacer {
 			"{when}": func() string {
 				return time.Now().Format(timeFormat)
 			}(),
+			"{size}":   strconv.Itoa(req.Len()),
 			"{remote}": req.IP(),
 			"{port}":   req.Port(),
 		},
@@ -53,7 +54,7 @@ func New(r *dns.Msg, rr *dnsrecorder.Recorder, emptyValue string) Replacer {
 			rcode = strconv.Itoa(rr.Rcode)
 		}
 		rep.replacements["{rcode}"] = rcode
-		rep.replacements["{size}"] = strconv.Itoa(rr.Len)
+		rep.replacements["{rsize}"] = strconv.Itoa(rr.Len)
 		rep.replacements["{duration}"] = time.Since(rr.Start).String()
 	}