Pull request: querylog: resort buffers

Merge in DNS/adguard-home from 2293-log-sort to master

Updates #2293.

Squashed commit of the following:

commit f8961e5
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Sat Nov 28 17:19:15 2020 +0300

    all: document changes

commit c92c533
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Sat Nov 28 16:44:01 2020 +0300

    querylog: resort buffers

CHANGELOG.md

@@ -40,10 +40,13 @@ and this project adheres to
 
 ### Fixed
 
+- A mitigation against records being shown in the wrong order on the query log
+  page [#2293].
 - A JSON parsing error in query log [#2345].
 - Incorrect detection of the IPv6 address of an interface as well as another
   infinite loop in the `/dhcp/find_active_dhcp` HTTP API [#2355].
 
+[#2293]: https://github.com/AdguardTeam/AdGuardHome/issues/2293
 [#2345]: https://github.com/AdguardTeam/AdGuardHome/issues/2345
 [#2355]: https://github.com/AdguardTeam/AdGuardHome/issues/2355
 

internal/querylog/qlog_http.go → internal/querylog/http.go

@@ -47,7 +47,7 @@ func (l *queryLog) handleQueryLog(w http.ResponseWriter, r *http.Request) {
 	entries, oldest := l.search(params)
 
 	// convert log entries to JSON
-	var data = l.entriesToJSON(entries, oldest)
+	data := l.entriesToJSON(entries, oldest)
 
 	jsonVal, err := json.Marshal(data)
 	if err != nil {

internal/querylog/json.go

@@ -32,7 +32,7 @@ func (l *queryLog) getClientIP(clientIP string) string {
 // entriesToJSON - converts log entries to JSON
 func (l *queryLog) entriesToJSON(entries []*logEntry, oldest time.Time) map[string]interface{} {
 	// init the response object
-	var data = []map[string]interface{}{}
+	data := []map[string]interface{}{}
 
 	// the elements order is already reversed (from newer to older)
 	for i := 0; i < len(entries); i++ {
@@ -41,7 +41,7 @@ func (l *queryLog) entriesToJSON(entries []*logEntry, oldest time.Time) map[stri
 		data = append(data, jsonEntry)
 	}
 
-	var result = map[string]interface{}{}
+	result := map[string]interface{}{}
 	result["oldest"] = ""
 	if !oldest.IsZero() {
 		result["oldest"] = oldest.Format(time.RFC3339Nano)
@@ -123,7 +123,7 @@ func answerToMap(a *dns.Msg) []map[string]interface{} {
 		return nil
 	}
 
-	var answers = []map[string]interface{}{}
+	answers := []map[string]interface{}{}
 	for _, k := range a.Answer {
 		header := k.Header()
 		answer := map[string]interface{}{

internal/querylog/qlog_test.go

@@ -1,9 +1,12 @@
 package querylog
 
 import (
+	"math/rand"
 	"net"
 	"os"
+	"sort"
 	"testing"
+	"time"
 
 	"github.com/AdguardTeam/dnsproxy/proxyutil"
 
@@ -20,7 +23,7 @@ func TestMain(m *testing.M) {
 func prepareTestDir() string {
 	const dir = "./agh-test"
 	_ = os.RemoveAll(dir)
-	_ = os.MkdirAll(dir, 0755)
+	_ = os.MkdirAll(dir, 0o755)
 	return dir
 }
 
@@ -263,3 +266,72 @@ func assertLogEntry(t *testing.T, entry *logEntry, host, answer, client string)
 	assert.Equal(t, answer, ip.String())
 	return true
 }
+
+func testEntries() (entries []*logEntry) {
+	rsrc := rand.NewSource(time.Now().UnixNano())
+	rgen := rand.New(rsrc)
+
+	entries = make([]*logEntry, 1000)
+	for i := range entries {
+		min := rgen.Intn(60)
+		sec := rgen.Intn(60)
+		entries[i] = &logEntry{
+			Time: time.Date(2020, 1, 1, 0, min, sec, 0, time.UTC),
+		}
+	}
+
+	return entries
+}
+
+// logEntriesByTimeDesc is a wrapper over []*logEntry for sorting.
+//
+// NOTE(a.garipov): Weirdly enough, on my machine this gets consistently
+// outperformed by sort.Slice, see the benchmark below.  I'm leaving this
+// implementation here, in tests, in case we want to make sure it outperforms on
+// most machines, but for now this is unused in the actual code.
+type logEntriesByTimeDesc []*logEntry
+
+// Len implements the sort.Interface interface for logEntriesByTimeDesc.
+func (les logEntriesByTimeDesc) Len() (n int) { return len(les) }
+
+// Less implements the sort.Interface interface for logEntriesByTimeDesc.
+func (les logEntriesByTimeDesc) Less(i, j int) (less bool) {
+	return les[i].Time.After(les[j].Time)
+}
+
+// Swap implements the sort.Interface interface for logEntriesByTimeDesc.
+func (les logEntriesByTimeDesc) Swap(i, j int) { les[i], les[j] = les[j], les[i] }
+
+func BenchmarkLogEntry_sort(b *testing.B) {
+	b.Run("methods", func(b *testing.B) {
+		for i := 0; i < b.N; i++ {
+			b.StopTimer()
+			entries := testEntries()
+			b.StartTimer()
+
+			sort.Stable(logEntriesByTimeDesc(entries))
+		}
+	})
+
+	b.Run("reflect", func(b *testing.B) {
+		for i := 0; i < b.N; i++ {
+			b.StopTimer()
+			entries := testEntries()
+			b.StartTimer()
+
+			sort.SliceStable(entries, func(i, j int) (less bool) {
+				return entries[i].Time.After(entries[j].Time)
+			})
+		}
+	})
+}
+
+func TestLogEntriesByTime_sort(t *testing.T) {
+	entries := testEntries()
+	sort.Sort(logEntriesByTimeDesc(entries))
+
+	for i := 1; i < len(entries); i++ {
+		assert.False(t, entries[i].Time.After(entries[i-1].Time),
+			"%s %s", entries[i].Time, entries[i-1].Time)
+	}
+}

internal/querylog/querylog_file.go

@@ -65,7 +65,7 @@ func (l *queryLog) flushToFile(buffer []*logEntry) error {
 
 	l.fileWriteLock.Lock()
 	defer l.fileWriteLock.Unlock()
-	f, err := os.OpenFile(filename, os.O_WRONLY|os.O_CREATE|os.O_APPEND, 0644)
+	f, err := os.OpenFile(filename, os.O_WRONLY|os.O_CREATE|os.O_APPEND, 0o644)
 	if err != nil {
 		log.Error("failed to create file \"%s\": %s", filename, err)
 		return err

internal/querylog/querylog_search.go → internal/querylog/search.go

@@ -2,6 +2,7 @@ package querylog
 
 import (
 	"io"
+	"sort"
 	"time"
 
 	"github.com/AdguardTeam/AdGuardHome/internal/util"
@@ -46,6 +47,14 @@ func (l *queryLog) search(params *searchParams) ([]*logEntry, time.Time) {
 		entries = entries[:totalLimit]
 	}
 
+	// Resort entries on start time to partially mitigate query log looking
+	// weird on the frontend.
+	//
+	// See https://github.com/AdguardTeam/AdGuardHome/issues/2293.
+	sort.SliceStable(entries, func(i, j int) (less bool) {
+		return entries[i].Time.After(entries[j].Time)
+	})
+
 	if params.offset > 0 {
 		if len(entries) > params.offset {
 			entries = entries[params.offset:]

internal/querylog/search_criteria.go

@@ -58,7 +58,7 @@ func (c *searchCriteria) quickMatch(line string) bool {
 }
 
 // quickMatchJSONValue - helper used by quickMatch
-func (c *searchCriteria) quickMatchJSONValue(line string, propertyName string) bool {
+func (c *searchCriteria) quickMatchJSONValue(line, propertyName string) bool {
 	val := readJSONValue(line, propertyName)
 	if len(val) == 0 {
 		return false