test: make promql engine_test use files to exercise query logger

Signed-off-by: TJ Hoplock <t.hoplock@gmail.com>
This commit is contained in:
TJ Hoplock 2024-12-02 09:21:56 -05:00
parent 4d54c304f8
commit 53eb1fe71f

View file

@ -17,9 +17,9 @@ import (
"context"
"errors"
"fmt"
"io"
"log/slog"
"math"
"os"
"path/filepath"
"sort"
"strings"
"sync"
@ -39,6 +39,7 @@ import (
"github.com/prometheus/prometheus/storage"
"github.com/prometheus/prometheus/tsdb/chunkenc"
"github.com/prometheus/prometheus/util/annotations"
"github.com/prometheus/prometheus/util/logging"
"github.com/prometheus/prometheus/util/stats"
"github.com/prometheus/prometheus/util/testutil"
)
@ -2148,65 +2149,17 @@ func TestSubquerySelector(t *testing.T) {
}
}
var _ io.Closer = (*FakeQueryLogger)(nil)
func getLogLines(t *testing.T, name string) []string {
content, err := os.ReadFile(name)
require.NoError(t, err)
var _ slog.Handler = (*FakeQueryLogger)(nil)
type FakeQueryLogger struct {
closed bool
logs []any
attrs []any
}
func NewFakeQueryLogger() *FakeQueryLogger {
return &FakeQueryLogger{
closed: false,
logs: make([]interface{}, 0),
attrs: make([]any, 0),
lines := strings.Split(string(content), "\n")
for i := len(lines) - 1; i >= 0; i-- {
if lines[i] == "" {
lines = append(lines[:i], lines[i+1:]...)
}
}
}
func (f *FakeQueryLogger) Close() error {
f.closed = true
return nil
}
func (f *FakeQueryLogger) Enabled(ctx context.Context, level slog.Level) bool {
return true
}
func (f *FakeQueryLogger) Handle(ctx context.Context, r slog.Record) error {
// Test usage only really cares about existence of keyvals passed in
// via args, just append in the log message before handling the
// provided args and any embedded kvs added via `.With()` on f.attrs.
log := append([]any{r.Message}, f.attrs...)
f.attrs = f.attrs[:0]
r.Attrs(func(a slog.Attr) bool {
log = append(log, a.Key, a.Value.Any())
return true
})
f.logs = append(f.logs, log...)
return nil
}
func (f *FakeQueryLogger) WithAttrs(attrs []slog.Attr) slog.Handler {
attrPairs := []any{}
for _, a := range attrs {
attrPairs = append(attrPairs, a.Key, a.Value.Any())
}
return &FakeQueryLogger{
closed: f.closed,
logs: f.logs,
attrs: append(f.attrs, attrPairs...),
}
}
func (f *FakeQueryLogger) WithGroup(name string) slog.Handler {
// We don't need to support groups for this fake handler in testing.
return f
return lines
}
func TestQueryLogger_basic(t *testing.T) {
@ -2231,32 +2184,45 @@ func TestQueryLogger_basic(t *testing.T) {
// promql.Query works without query log initialized.
queryExec()
f1 := NewFakeQueryLogger()
tmpDir := t.TempDir()
ql1File := filepath.Join(tmpDir, "query1.log")
f1, err := logging.NewJSONFileLogger(ql1File)
require.NoError(t, err)
engine.SetQueryLogger(f1)
queryExec()
require.Contains(t, f1.logs, `params`)
require.Contains(t, f1.logs, map[string]interface{}{"query": "test statement"})
logLines := getLogLines(t, ql1File)
require.Contains(t, logLines[0], "params", map[string]interface{}{"query": "test statement"})
require.Len(t, logLines, 1)
l := len(f1.logs)
l := len(logLines)
queryExec()
require.Len(t, f1.logs, 2*l)
logLines = getLogLines(t, ql1File)
l2 := len(logLines)
require.Equal(t, l2, 2*l)
// Test that we close the query logger when unsetting it.
require.False(t, f1.closed, "expected f1 to be open, got closed")
// Test that we close the query logger when unsetting it. The following
// attempt to close the file should error.
engine.SetQueryLogger(nil)
require.True(t, f1.closed, "expected f1 to be closed, got open")
err = f1.Close()
require.ErrorContains(t, err, "file already closed", "expected f1 to be closed, got open")
queryExec()
// Test that we close the query logger when swapping.
f2 := NewFakeQueryLogger()
f3 := NewFakeQueryLogger()
ql2File := filepath.Join(tmpDir, "query2.log")
f2, err := logging.NewJSONFileLogger(ql2File)
require.NoError(t, err)
ql3File := filepath.Join(tmpDir, "query3.log")
f3, err := logging.NewJSONFileLogger(ql3File)
require.NoError(t, err)
engine.SetQueryLogger(f2)
require.False(t, f2.closed, "expected f2 to be open, got closed")
queryExec()
engine.SetQueryLogger(f3)
require.True(t, f2.closed, "expected f2 to be closed, got open")
require.False(t, f3.closed, "expected f3 to be open, got closed")
err = f2.Close()
require.ErrorContains(t, err, "file already closed", "expected f2 to be closed, got open")
queryExec()
err = f3.Close()
require.NoError(t, err)
}
func TestQueryLogger_fields(t *testing.T) {
@ -2268,7 +2234,14 @@ func TestQueryLogger_fields(t *testing.T) {
}
engine := promqltest.NewTestEngineWithOpts(t, opts)
f1 := NewFakeQueryLogger()
tmpDir := t.TempDir()
ql1File := filepath.Join(tmpDir, "query1.log")
f1, err := logging.NewJSONFileLogger(ql1File)
require.NoError(t, err)
t.Cleanup(func() {
require.NoError(t, f1.Close())
})
engine.SetQueryLogger(f1)
ctx, cancelCtx := context.WithCancel(context.Background())
@ -2281,8 +2254,8 @@ func TestQueryLogger_fields(t *testing.T) {
res := query.Exec(ctx)
require.NoError(t, res.Err)
require.Contains(t, f1.logs, `foo`)
require.Contains(t, f1.logs, `bar`)
logLines := getLogLines(t, ql1File)
require.Contains(t, logLines[0], "foo", "bar")
}
func TestQueryLogger_error(t *testing.T) {
@ -2294,7 +2267,14 @@ func TestQueryLogger_error(t *testing.T) {
}
engine := promqltest.NewTestEngineWithOpts(t, opts)
f1 := NewFakeQueryLogger()
tmpDir := t.TempDir()
ql1File := filepath.Join(tmpDir, "query1.log")
f1, err := logging.NewJSONFileLogger(ql1File)
require.NoError(t, err)
t.Cleanup(func() {
require.NoError(t, f1.Close())
})
engine.SetQueryLogger(f1)
ctx, cancelCtx := context.WithCancel(context.Background())
@ -2308,10 +2288,9 @@ func TestQueryLogger_error(t *testing.T) {
res := query.Exec(ctx)
require.Error(t, res.Err, "query should have failed")
require.Contains(t, f1.logs, `params`)
require.Contains(t, f1.logs, map[string]interface{}{"query": "test statement"})
require.Contains(t, f1.logs, `error`)
require.Contains(t, f1.logs, testErr)
logLines := getLogLines(t, ql1File)
require.Contains(t, logLines[0], "error", testErr)
require.Contains(t, logLines[0], "params", map[string]interface{}{"query": "test statement"})
}
func TestPreprocessAndWrapWithStepInvariantExpr(t *testing.T) {