x-pack/filebeat/input/httpjson: improve template evaluation logging

This adds valuable missing context to the debug logging emitted for template evaluation. Previously, only the final result was printed to the log, which failed to provide the information required to be able to determine why any given template was being executed. So add the target name to the logs.
elastic · Sep 24, 2023 · 38301bb · 38301bb
1 parent ea3b9e3
commit 38301bb
Show file tree

Hide file tree

Showing 7 changed files with 12 additions and 7 deletions.
diff --git a/CHANGELOG.next.asciidoc b/CHANGELOG.next.asciidoc
@@ -218,6 +218,7 @@ https://github.com/elastic/beats/compare/v8.8.1\...main[Check the HEAD diff]
 - Disable warning message about ingest pipeline loading when running under Elastic Agent. {pull}36659[36659]
 - Add input metrics to http_endpoint input. {issue}36402[36402] {pull}36427[36427]
 - Update mito CEL extension library to v1.6.0. {pull}36651[36651]
+- Improve template evaluation logging for HTTPJSON input. {pull}[]
 
 *Auditbeat*
 

diff --git a/x-pack/filebeat/input/httpjson/cursor.go b/x-pack/filebeat/input/httpjson/cursor.go
@@ -50,7 +50,7 @@ func (c *cursor) update(trCtx *transformContext) {
 	}
 
 	for k, cfg := range c.cfg {
-		v, _ := cfg.Value.Execute(trCtx, transformable{}, "", cfg.Default, c.log)
+		v, _ := cfg.Value.Execute(trCtx, transformable{}, k, cfg.Default, c.log)
 		if v != "" || !cfg.mustIgnoreEmptyValue() {
 			_, _ = c.state.Put(k, v)
 			c.log.Debugf("cursor.%s stored with %s", k, v)

diff --git a/x-pack/filebeat/input/httpjson/input_test.go b/x-pack/filebeat/input/httpjson/input_test.go
@@ -1248,6 +1248,8 @@ var testCases = []struct {
 }
 
 func TestInput(t *testing.T) {
+	logp.TestingSetup()
+
 	for _, test := range testCases {
 		t.Run(test.name, func(t *testing.T) {
 			if test.skipReason != "" {

diff --git a/x-pack/filebeat/input/httpjson/rate_limiter.go b/x-pack/filebeat/input/httpjson/rate_limiter.go
@@ -104,7 +104,7 @@ func (r *rateLimiter) getRateLimit(resp *http.Response) (int64, error) {
 	ctx := emptyTransformContext()
 	ctx.updateLastResponse(response{header: resp.Header.Clone()})
 
-	remaining, _ := r.remaining.Execute(ctx, tr, "", nil, r.log)
+	remaining, _ := r.remaining.Execute(ctx, tr, "rate-limit_remaining", nil, r.log)
 	if remaining == "" {
 		return 0, errors.New("remaining value is empty")
 	}
@@ -119,7 +119,7 @@ func (r *rateLimiter) getRateLimit(resp *http.Response) (int64, error) {
 	if r.earlyLimit != nil {
 		earlyLimit := *r.earlyLimit
 		if earlyLimit > 0 && earlyLimit < 1 {
-			limit, _ := r.limit.Execute(ctx, tr, "", nil, r.log)
+			limit, _ := r.limit.Execute(ctx, tr, "early_limit", nil, r.log)
 			if limit != "" {
 				l, err := strconv.ParseInt(limit, 10, 64)
 				if err == nil {
@@ -141,7 +141,7 @@ func (r *rateLimiter) getRateLimit(resp *http.Response) (int64, error) {
 		return 0, nil
 	}
 
-	reset, _ := r.reset.Execute(ctx, tr, "", nil, r.log)
+	reset, _ := r.reset.Execute(ctx, tr, "rate-limit_reset", nil, r.log)
 	if reset == "" {
 		return 0, errors.New("reset value is empty")
 	}

diff --git a/x-pack/filebeat/input/httpjson/request.go b/x-pack/filebeat/input/httpjson/request.go
@@ -385,7 +385,7 @@ func evaluateResponse(expression *valueTpl, data []byte, log *logp.Logger) (bool
 		lastResponse:  &response{body: dataMap},
 	}
 
-	val, err := expression.Execute(paramCtx, tr, "", nil, log)
+	val, err := expression.Execute(paramCtx, tr, "response_evaluation", nil, log)
 	if err != nil {
 		return false, fmt.Errorf("error while evaluating expression: %w", err)
 	}

diff --git a/x-pack/filebeat/input/httpjson/value_tpl.go b/x-pack/filebeat/input/httpjson/value_tpl.go
@@ -142,7 +142,7 @@ func tryDebugTemplateValue(target, val string, log *logp.Logger) {
 	case "Authorization", "Proxy-Authorization":
 		// ignore filtered headers
 	default:
-		log.Debugf("template execution: evaluated template %q", val)
+		log.Debugw("evaluated template", "target", target, "value", val)
 	}
 }
 

diff --git a/x-pack/filebeat/input/httpjson/value_tpl_test.go b/x-pack/filebeat/input/httpjson/value_tpl_test.go
@@ -19,6 +19,8 @@ import (
 )
 
 func TestValueTpl(t *testing.T) {
+	logp.TestingSetup()
+
 	cases := []struct {
 		name          string
 		value         string
@@ -764,7 +766,7 @@ func TestValueTpl(t *testing.T) {
 				assert.NoError(t, defTpl.Unpack(tc.paramDefVal))
 			}
 
-			got, err := tpl.Execute(tc.paramCtx, tc.paramTr, "", defTpl, logp.NewLogger(""))
+			got, err := tpl.Execute(tc.paramCtx, tc.paramTr, tc.name, defTpl, logp.NewLogger(""))
 			assert.Equal(t, tc.expectedVal, got)
 			if tc.expectedError == "" {
 				assert.NoError(t, err)