From 9ee160f5c60e9ad488f63ca15287d1dde3483eb0 Mon Sep 17 00:00:00 2001 From: Tiago Queiroz Date: Wed, 14 Aug 2024 23:45:07 +0200 Subject: [PATCH 1/2] [ES output] Log event fields in events log file (#40512) The Elasticsearch output, when faced with ingestion errors was logging the raw publisher.Event that had already been encoded, hence no event fields were present in the logs. This commit fixes it by adding a String method to the encodedEvent type and using the encodedEvent in the logs instead of the publisher.Event. (cherry picked from commit e7732c66698ec63eebaefcfd30d0c4703bf2f104) # Conflicts: # libbeat/outputs/elasticsearch/client.go --- CHANGELOG.next.asciidoc | 1 + filebeat/tests/integration/event_log_file_test.go | 2 +- libbeat/outputs/elasticsearch/client.go | 15 +++++++++++++++ libbeat/outputs/elasticsearch/event_encoder.go | 7 +++++++ 4 files changed, 24 insertions(+), 1 deletion(-) diff --git a/CHANGELOG.next.asciidoc b/CHANGELOG.next.asciidoc index 8049ad66f791..77b3fe62507a 100644 --- a/CHANGELOG.next.asciidoc +++ b/CHANGELOG.next.asciidoc @@ -106,6 +106,7 @@ https://github.com/elastic/beats/compare/v8.8.1\...main[Check the HEAD diff] - Fix bug in Okta entity analytics rate limit logic. {issue}40106[40106] {pull}40267[40267] - Fix order of configuration for EntraID entity analytics provider. {pull}40487[40487] - Ensure Entra ID request bodies are not truncated and trace logs are rotated before 100MB. {pull}40494[40494] +- The Elasticsearch output now correctly logs the event fields to the event log file {issue}40509[40509] {pull}40512[40512] *Heartbeat* diff --git a/filebeat/tests/integration/event_log_file_test.go b/filebeat/tests/integration/event_log_file_test.go index 5b2758b40186..316f09f384a4 100644 --- a/filebeat/tests/integration/event_log_file_test.go +++ b/filebeat/tests/integration/event_log_file_test.go @@ -122,7 +122,7 @@ func TestEventsLoggerESOutput(t *testing.T) { } strData := string(data) - eventMsg := "not a number" + eventMsg := `\"int\":\"not a number\"` if !strings.Contains(strData, eventMsg) { t.Errorf("expecting to find '%s' on '%s'", eventMsg, eventsLogFile) t.Errorf("Contents:\n%s", strData) diff --git a/libbeat/outputs/elasticsearch/client.go b/libbeat/outputs/elasticsearch/client.go index 933d04c789ca..1066736d64f6 100644 --- a/libbeat/outputs/elasticsearch/client.go +++ b/libbeat/outputs/elasticsearch/client.go @@ -478,15 +478,25 @@ func (client *Client) applyItemStatus( if encodedEvent.deadLetter { // Fatal error while sending an already-failed event to the dead letter // index, drop. +<<<<<<< HEAD client.log.Errorf("Can't deliver to dead letter index event (status=%v). Look at the event log to view the event and cause.", itemStatus) client.log.Errorw(fmt.Sprintf("Can't deliver to dead letter index event %#v (status=%v): %s", event, itemStatus, itemMessage), logp.TypeKey, logp.EventType) +======= + client.pLogDeadLetter.Add() + client.log.Errorw(fmt.Sprintf("Can't deliver to dead letter index event '%s' (status=%v): %s", encodedEvent, itemStatus, itemMessage), logp.TypeKey, logp.EventType) +>>>>>>> e7732c6669 ([ES output] Log event fields in events log file (#40512)) stats.nonIndexable++ return false } if client.deadLetterIndex == "" { // Fatal error and no dead letter index, drop. +<<<<<<< HEAD client.log.Warnf("Cannot index event (status=%v): dropping event! Look at the event log to view the event and cause.", itemStatus) client.log.Warnw(fmt.Sprintf("Cannot index event %#v (status=%v): %s, dropping event!", event, itemStatus, itemMessage), logp.TypeKey, logp.EventType) +======= + client.pLogIndex.Add() + client.log.Warnw(fmt.Sprintf("Cannot index event '%s' (status=%v): %s, dropping event!", encodedEvent, itemStatus, itemMessage), logp.TypeKey, logp.EventType) +>>>>>>> e7732c6669 ([ES output] Log event fields in events log file (#40512)) stats.nonIndexable++ return false } @@ -494,8 +504,13 @@ func (client *Client) applyItemStatus( // We count this as a "retryable failure", and then if the dead letter // ingestion succeeds it is counted in the "deadLetter" counter // rather than the "acked" counter. +<<<<<<< HEAD client.log.Warnf("Cannot index event (status=%v), trying dead letter index. Look at the event log to view the event and cause.", itemStatus) client.log.Warnw(fmt.Sprintf("Cannot index event %#v (status=%v): %s, trying dead letter index", event, itemStatus, itemMessage), logp.TypeKey, logp.EventType) +======= + client.pLogIndexTryDeadLetter.Add() + client.log.Warnw(fmt.Sprintf("Cannot index event '%s' (status=%v): %s, trying dead letter index", encodedEvent, itemStatus, itemMessage), logp.TypeKey, logp.EventType) +>>>>>>> e7732c6669 ([ES output] Log event fields in events log file (#40512)) encodedEvent.setDeadLetter(client.deadLetterIndex, itemStatus, string(itemMessage)) } diff --git a/libbeat/outputs/elasticsearch/event_encoder.go b/libbeat/outputs/elasticsearch/event_encoder.go index 7d345e2bc5c5..e569ebf3abf3 100644 --- a/libbeat/outputs/elasticsearch/event_encoder.go +++ b/libbeat/outputs/elasticsearch/event_encoder.go @@ -151,3 +151,10 @@ func (e *encodedEvent) setDeadLetter( } e.encoding = []byte(deadLetterReencoding.String()) } + +// String converts e.encoding to string and returns it. +// The goal of this method is to provide an easy way to log +// the event encoded. +func (e *encodedEvent) String() string { + return string(e.encoding) +} From cf89b68067b1a755fe01bfa4ec546f16271a7dab Mon Sep 17 00:00:00 2001 From: Tiago Queiroz Date: Wed, 14 Aug 2024 18:11:59 -0400 Subject: [PATCH 2/2] Fix merge conflicts --- libbeat/outputs/elasticsearch/client.go | 15 --------------- 1 file changed, 15 deletions(-) diff --git a/libbeat/outputs/elasticsearch/client.go b/libbeat/outputs/elasticsearch/client.go index 1066736d64f6..767170b0502a 100644 --- a/libbeat/outputs/elasticsearch/client.go +++ b/libbeat/outputs/elasticsearch/client.go @@ -478,25 +478,15 @@ func (client *Client) applyItemStatus( if encodedEvent.deadLetter { // Fatal error while sending an already-failed event to the dead letter // index, drop. -<<<<<<< HEAD client.log.Errorf("Can't deliver to dead letter index event (status=%v). Look at the event log to view the event and cause.", itemStatus) - client.log.Errorw(fmt.Sprintf("Can't deliver to dead letter index event %#v (status=%v): %s", event, itemStatus, itemMessage), logp.TypeKey, logp.EventType) -======= - client.pLogDeadLetter.Add() client.log.Errorw(fmt.Sprintf("Can't deliver to dead letter index event '%s' (status=%v): %s", encodedEvent, itemStatus, itemMessage), logp.TypeKey, logp.EventType) ->>>>>>> e7732c6669 ([ES output] Log event fields in events log file (#40512)) stats.nonIndexable++ return false } if client.deadLetterIndex == "" { // Fatal error and no dead letter index, drop. -<<<<<<< HEAD client.log.Warnf("Cannot index event (status=%v): dropping event! Look at the event log to view the event and cause.", itemStatus) - client.log.Warnw(fmt.Sprintf("Cannot index event %#v (status=%v): %s, dropping event!", event, itemStatus, itemMessage), logp.TypeKey, logp.EventType) -======= - client.pLogIndex.Add() client.log.Warnw(fmt.Sprintf("Cannot index event '%s' (status=%v): %s, dropping event!", encodedEvent, itemStatus, itemMessage), logp.TypeKey, logp.EventType) ->>>>>>> e7732c6669 ([ES output] Log event fields in events log file (#40512)) stats.nonIndexable++ return false } @@ -504,13 +494,8 @@ func (client *Client) applyItemStatus( // We count this as a "retryable failure", and then if the dead letter // ingestion succeeds it is counted in the "deadLetter" counter // rather than the "acked" counter. -<<<<<<< HEAD client.log.Warnf("Cannot index event (status=%v), trying dead letter index. Look at the event log to view the event and cause.", itemStatus) - client.log.Warnw(fmt.Sprintf("Cannot index event %#v (status=%v): %s, trying dead letter index", event, itemStatus, itemMessage), logp.TypeKey, logp.EventType) -======= - client.pLogIndexTryDeadLetter.Add() client.log.Warnw(fmt.Sprintf("Cannot index event '%s' (status=%v): %s, trying dead letter index", encodedEvent, itemStatus, itemMessage), logp.TypeKey, logp.EventType) ->>>>>>> e7732c6669 ([ES output] Log event fields in events log file (#40512)) encodedEvent.setDeadLetter(client.deadLetterIndex, itemStatus, string(itemMessage)) }