From 54a3c3ba3faa137be56c99534c485e8ce12a6631 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?=C5=81ukasz=20Mierzwa?= <l.mierzwa@gmail.com>
Date: Thu, 14 Jul 2022 10:34:15 +0100
Subject: [PATCH] Print query that caused a panic (#10995)
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

We print the stacktrace of a panic when query causes one, but there's no
information about the query itself, which makes it harder to debug and
reproduce the issue.
This adds the 'expr' string to the logged panic.

Signed-off-by: Łukasz Mierzwa <l.mierzwa@gmail.com>
---
 promql/engine.go      |  6 +++---
 promql/engine_test.go | 22 ++++++++++++++++------
 2 files changed, 19 insertions(+), 9 deletions(-)

diff --git a/promql/engine.go b/promql/engine.go
index 3cb1c95683..a6b3cc7234 100644
--- a/promql/engine.go
+++ b/promql/engine.go
@@ -937,7 +937,7 @@ func (ev *evaluator) error(err error) {
 }
 
 // recover is the handler that turns panics into returns from the top level of evaluation.
-func (ev *evaluator) recover(ws *storage.Warnings, errp *error) {
+func (ev *evaluator) recover(expr parser.Expr, ws *storage.Warnings, errp *error) {
 	e := recover()
 	if e == nil {
 		return
@@ -949,7 +949,7 @@ func (ev *evaluator) recover(ws *storage.Warnings, errp *error) {
 		buf := make([]byte, 64<<10)
 		buf = buf[:runtime.Stack(buf, false)]
 
-		level.Error(ev.logger).Log("msg", "runtime panic in parser", "err", e, "stacktrace", string(buf))
+		level.Error(ev.logger).Log("msg", "runtime panic in parser", "expr", expr.String(), "err", e, "stacktrace", string(buf))
 		*errp = fmt.Errorf("unexpected error: %w", err)
 	case errWithWarnings:
 		*errp = err.err
@@ -960,7 +960,7 @@ func (ev *evaluator) recover(ws *storage.Warnings, errp *error) {
 }
 
 func (ev *evaluator) Eval(expr parser.Expr) (v parser.Value, ws storage.Warnings, err error) {
-	defer ev.recover(&ws, &err)
+	defer ev.recover(expr, &ws, &err)
 
 	v, ws = ev.eval(expr)
 	return v, ws, nil
diff --git a/promql/engine_test.go b/promql/engine_test.go
index 201676b433..e71f7a7a99 100644
--- a/promql/engine_test.go
+++ b/promql/engine_test.go
@@ -1641,17 +1641,27 @@ load 1ms
 }
 
 func TestRecoverEvaluatorRuntime(t *testing.T) {
-	ev := &evaluator{logger: log.NewNopLogger()}
+	var output []interface{}
+	logger := log.Logger(log.LoggerFunc(func(keyvals ...interface{}) error {
+		output = append(output, keyvals...)
+		return nil
+	}))
+	ev := &evaluator{logger: logger}
+
+	expr, _ := parser.ParseExpr("sum(up)")
 
 	var err error
-	defer ev.recover(nil, &err)
+
+	defer func() {
+		require.EqualError(t, err, "unexpected error: runtime error: index out of range [123] with length 0")
+		require.Contains(t, output, "sum(up)")
+	}()
+	defer ev.recover(expr, nil, &err)
 
 	// Cause a runtime panic.
 	var a []int
 	//nolint:govet
 	a[123] = 1
-
-	require.EqualError(t, err, "unexpected error")
 }
 
 func TestRecoverEvaluatorError(t *testing.T) {
@@ -1663,7 +1673,7 @@ func TestRecoverEvaluatorError(t *testing.T) {
 	defer func() {
 		require.EqualError(t, err, e.Error())
 	}()
-	defer ev.recover(nil, &err)
+	defer ev.recover(nil, nil, &err)
 
 	panic(e)
 }
@@ -1683,7 +1693,7 @@ func TestRecoverEvaluatorErrorWithWarnings(t *testing.T) {
 		require.EqualError(t, err, e.Error())
 		require.Equal(t, warnings, ws, "wrong warning message")
 	}()
-	defer ev.recover(&ws, &err)
+	defer ev.recover(nil, &ws, &err)
 
 	panic(e)
 }