Log messages like "Cannot index events" are not detected anymore in system tests

[mrodm]

In #1188, it was added support into elastic-package to check Elastic Agent logs at the end of each system test. Depending on the contents of those logs/messages (taking into account some patterns), those system tests were marked as failure. For instance, if there were messages like: "Cannot index event publisher.Event` (see #1256).

Testing locally some packages with the latest Elastic stack versions, those messages were no longer detected.

It looks like it is related to this PR elastic/elastic-agent#4549

Now messages related to dropping events are written to local files like: state/data/logs/events/elastic-agent-event-log-20250619.ndjson , and they are not shown any more as part of the docker-compose logs.

Example of the message:

{"log.level":"warn","@timestamp":"2025-06-19T10:50:37.228Z","message":"Cannot index event '{...}' (status=400): {\"type\":\"document_parsing_exception\",\"reason\":\"[1:1321] failed to parse field [event.dataset] of type [constant_keyword] in document with id 'dI_Ph5cBatrs-YPd4VMm'. Preview of field's value: 'nginx.access_tf'\",\"caused_by\":{\"type\":\"illegal_argument_exception\",\"reason\":\"[constant_keyword] field [event.dataset] only accepts values that are equal to the value defined in the mappings [nginx.access], but got [nginx.access_tf]\"}}, dropping event!","component":{"binary":"filebeat","dataset":"elastic_agent.filebeat","id":"log-default","type":"log"},"log":{"source":"log-default"},"log.origin":{"file.line":519,"file.name":"elasticsearch/client.go","function":"github.com/elastic/beats/v7/libbeat/outputs/elasticsearch.(*Client).applyItemStatus"},"service.name":"filebeat","log.type":"event","ecs.version":"1.6.0","log.logger":"elasticsearch.elasticsearch","ecs.version":"1.6.0"}

Would those errors detected by the Failure Store ? Those checks were removed in #2553 since there were some problems and that feature was in technical preview yet.

Relates:

• Docs about the change in elastic-agent Add Elastic-Agent event log documentation ingest-docs#1053

[jsoriano]

with the latest Elastic stack versions

Do you know since what version this is not logged anymore?

[cmacknz]

You should be able to configure the event log to write to stderr to catch this if that is the convenient thing to do: https://github.com/elastic/elastic-agent/blob/8803a02d3538b2e2f2741c103aab025d1852a491/internal/pkg/agent/cmd/container.go#L148

• Elastic-Agent event logging
  If EVENTS_TO_STDERR is set to true log entries containing event data or whole raw events will be logged to stderr alongside
  all other log entries. If unset or set to false, the events will be logged to a separate file that is not collected alongside
  the monitoring logs, however they will be present in diagnostics.

The ES output still logs event without this, just not in a way that includes the event content. It tells you to look at the event log so failures are detectable but the reason isn't https://github.com/elastic/beats/blob/875af7d9e99d8b6ea7acc850cf3b290e87d35a6c/libbeat/outputs/elasticsearch/client.go#L519

[mrodm]

with the latest Elastic stack versions

Do you know since what version this is not logged anymore?

Tested updating the value of the constant_keyword for event.dataset in the fields definition to force failure for indexing documents.

--- test/packages/parallel/nginx_multiple_services/data_stream/access/fields/base-fields.yml
+++ test/packages/parallel/nginx_multiple_services/data_stream/access/fields/base-fields.yml
@@ -17,4 +17,4 @@
 - name: event.dataset
   type: constant_keyword
   description: Event dataset
-  value: nginx.access
+  value: nginx.access2

In 8.14.3, the behavior is the same (error appear in the Elastic Agent log):

{"log.level":"debug","@timestamp":"2025-06-20T10:16:27.359Z","message":"Cannot index event publisher.Event{Content:beat.Event{Timestamp:time.Date(1, time.January, 1, 0, 0, 0, 0, time.UTC), Meta:null, Fields:null, Private:interface {}(nil), TimeSeries:false}, Flags:0x1, Cache:publisher.EventCache{m:mapstr.M(nil)}, EncodedEvent:(*elasticsearch.encodedEvent)(0xc001fa0b00)} (status=400): {\"type\":\"document_parsing_exception\",\"reason\":\"[1:1405] failed to parse field [event.dataset] of type [constant_keyword] in document with id 'weDWjJcBeWYo6b4x9Qjd'. Preview of field's value: 'nginx.access'\",\"caused_by\":{\"type\":\"illegal_argument_exception\",\"reason\":\"[constant_keyword] field [event.dataset] only accepts values that are equal to the value defined in the mappings [nginx.access2], but got [nginx.access]\"}}, dropping event!","component":{"binary":"filebeat","dataset":"elastic_agent.filebeat","id":"log-default","type":"log"},"log":{"source":"log-default"},"log.logger":"elasticsearch","log.origin":{"file.line":430,"file.name":"elasticsearch/client.go","function":"github.com/elastic/beats/v7/libbeat/outputs/elasticsearch.(*Client).bulkCollectPublishFails"},"service.name":"filebeat","ecs.version":"1.6.0","ecs.version":"1.6.0"}

In 8.15.0 and 8.15.4 and this message is shown that does not match the regex set in the system tester:

{"log.level":"warn","@timestamp":"2025-06-20T09:58:20.576Z","message":"Cannot index event (status=400): dropping event! Look at the event log to view the event and cause.","component":{"binary":"filebeat","dataset":"elastic_agent.filebeat","id":"log-default","type":"log"},"log":{"source":"log-default"},"log.logger":"elasticsearch","log.origin":{"file.line":488,"file.name":"elasticsearch/client.go","function":"github.com/elastic/beats/v7/libbeat/outputs/elasticsearch.(*Client).applyItemStatus"},"service.name":"filebeat","ecs.version":"1.6.0","ecs.version":"1.6.0"}

In 8.16.0, 8.17.0 and 8.18.0 those messages are not shown in logs from the container (docker-compose).

[mrodm]

Tested adding EVENTS_TO_STDERR environment variable as true for each Elastic Agent container started in system tests, and those logs messages are back. Thanks @cmacknz !

--- internal/agentdeployer/_static/docker-agent-base.yml.tmpl
+++ internal/agentdeployer/_static/docker-agent-base.yml.tmpl
@@ -48,6 +48,7 @@ services:
       {{ else }}
       - FLEET_ENROLLMENT_TOKEN={{ $enrollment_token }}
       {{ end }}
+      - EVENTS_TO_STDERR=true
     volumes:
       - type: bind
         source: ${LOCAL_CA_CERT}

A new pattern should be added or updated the existing one to catch these logs:

{"log.level":"warn","@timestamp":"2025-06-20T11:48:02.179Z","message":"Cannot index event '{...}' (status=400): {\"type\":\"document_parsing_exception\",\"reason\":\"[1:1321] failed to parse field [event.dataset] of type [constant_keyword] in document with id 'D1QqjZcBiVgITaYhzrEB'. Preview of field's value: 'nginx.access'\",\"caused_by\":{\"type\":\"illegal_argument_exception\",\"reason\":\"[constant_keyword] field [event.dataset] only accepts values that are equal to the value defined in the mappings [nginx.access2], but got [nginx.access]\"}}, dropping event!","component":{"binary":"filebeat","dataset":"elastic_agent.filebeat","id":"log-default","type":"log"},"log":{"source":"log-default"},"service.name":"filebeat","log.type":"event","ecs.version":"1.6.0","log.logger":"elasticsearch","log.origin":{"file.line":517,"file.name":"elasticsearch/client.go","function":"github.com/elastic/beats/v7/libbeat/outputs/elasticsearch.(*Client).applyItemStatus"},"ecs.version":"1.6.0"}

But as suggested by the Elastic Agent PR, probably those full messages should not be shown by Elastic Agents as they could contain sensitive data , am I right ?

[mrodm]

Related to this, I've noticed that if there are no hits found during the system test, elastic-package does not check for errors in Elastic Agent logs and it just reports that there were not found the expected hits.

This check about Elastic Agent logs could be added if the hits found are not the expected ones to help debugging.
If so, probably it would be better to create a different issue for that. WDYT ?

Errors in logs about dropping events would not appear because of the issue described here, but there could be other errors like transitions to DEGRADED or FAILED.

[jsoriano]

This check about Elastic Agent logs could be added if the hits found are not the expected ones to help debugging.
If so, probably it would be better to create a different issue for that. WDYT ?

Sounds good, as a separate issue, yes.

[mrodm]

This check about Elastic Agent logs could be added if the hits found are not the expected ones to help debugging.
If so, probably it would be better to create a different issue for that. WDYT ?

Sounds good, as a separate issue, yes.

Created a new issue for this: #2682