Only log publish event messages in trace log level under elastic-agent #34391

blakerouse · 2023-01-25T15:36:09Z

What does this PR do?

Changes the behavior of the publishing pipeline to only log the Publish event: messages when the Elastic Agent is running in trace mode.

This change has no effect on beats not running under the Elastic Agent.

Why is it important?

When this was enabled in debug mode it make it impossible to read the debug logs. This change only shows these messages when running with trace enabled.

Checklist

My code follows the style guidelines of this project
I have commented my code, particularly in hard-to-understand areas
~~[ ] I have made corresponding changes to the documentation~~
~~[ ] I have made corresponding change to the default configuration files~~
~~[ ] I have added tests that prove my fix is effective or that my feature works~~
I have added an entry in CHANGELOG.next.asciidoc or CHANGELOG-developer.next.asciidoc.

Related issues

Closes elastic/elastic-agent #1955

mergify · 2023-01-25T15:36:44Z

This pull request does not have a backport label.
If this is a bug or security fix, could you label this PR @blakerouse? 🙏.
For such, you'll need to label your PR with:

The upcoming major version of the Elastic Stack
The upcoming minor version of the Elastic Stack (if you're not pushing a breaking change)

To fixup this pull request, you need to add the backport labels for the needed
branches, such as:

backport-v8./d.0 is the label to automatically backport to the 8./d branch. /d is the digit

elasticmachine · 2023-01-25T15:37:58Z

Pinging @elastic/elastic-agent (Team:Elastic-Agent)

elasticmachine · 2023-01-25T15:42:50Z

💚 Build Succeeded

the below badges are clickable and redirect to their specific view in the CI or DOCS

Expand to view the summary

Build stats

Start Time: 2023-01-26T16:04:45.142+0000
Duration: 67 min 40 sec

Test stats 🧪

Test	Results
Failed	0
Passed	25215
Skipped	1962
Total	27177

💚 Flaky test report

Tests succeeded.

🤖 GitHub comments

Expand to view the GitHub comments

To re-run your PR in the CI, just comment with:

/test : Re-trigger the build.
/package : Generate the packages and run the E2E tests.
/beats-tester : Run the installation tests with beats-tester.
run elasticsearch-ci/docs : Re-trigger the docs validation. (use unformatted text in the comment!)

libbeat/publisher/processing/processing.go

cmacknz · 2023-01-26T02:18:06Z

libbeat/publisher/processing/processors.go

+		agent := underAgent.Load()
+		if agent {
+			trace := underAgentTrace.Load()
+			if !trace {


I think we should also apply this to any debug level log lines in processors, since they can/will happen for every event in the pipeline.

For example I've seen this one be printed for every log line processed (an example is also in the description of elastic/elastic-agent#1955):

beats/libbeat/processors/actions/copy_fields.go

Lines 81 to 82 in 5337e63

errMsg := fmt.Errorf("Failed to copy fields in copy_fields processor: %s", err)

f.logger.Debug(errMsg.Error())

Searching for instances of Debug in libbeat/processors shows there aren't that many instances of this to handle, so we may as well deal with them now before somebody forgets to set ignore_missing on a drop_fields processor and makes debug logging unusable again.

I am torn on that. I agree that when it happens it floods the logs, but it really is an issue and maybe we should log it at debug.

The reason for not logging Publish event: at debug is that it logs when it is successful, not only on failure.

Until we have a way to set the log level per integration in Fleet my concern is that processor errors will prevent us from seeing the debug logs of the agent itself.

I think fundamentally I agree the processor errors are true errors, but I also think that with the current log level configuration mechanism in Fleet we should move them to trace to protect ourselves from not being able to debug the agent itself.

Okay I have added that logic to the processors as well.

mergify · 2023-01-26T13:25:43Z

This pull request is now in conflicts. Could you fix it? 🙏
To fixup this pull request, you can check out it locally. See documentation: https://help.github.com/articles/checking-out-pull-requests-locally/

git fetch upstream
git checkout -b agent-v2-trace upstream/agent-v2-trace
git merge upstream/main
git push upstream agent-v2-trace

mergify · 2023-01-26T16:02:35Z

This pull request is now in conflicts. Could you fix it? 🙏
To fixup this pull request, you can check out it locally. See documentation: https://help.github.com/articles/checking-out-pull-requests-locally/

git fetch upstream
git checkout -b agent-v2-trace upstream/agent-v2-trace
git merge upstream/main
git push upstream agent-v2-trace

cmacknz

Looks good, we can keep iterating on this as we find noise.

I don't believe this will fully resolve the problem though, because Fleet doesn't expose the trace level yet. We need to deal with that to fully close the issue, otherwise we've just hidden these log lines entirely for Fleet managed agents.

elastic/elastic-agent#1955 (comment)

libbeat/publisher/processing/default.go

#34391) * Only log publish event messages in trace log level under elastic-agent. * Add changelog entry. * Fix changelog. * Add same logic to processors. (cherry picked from commit 15ff7d1) # Conflicts: # libbeat/processors/actions/append.go

…evel under elastic-agent (#34434) * Only log publish event messages in trace log level under elastic-agent (#34391) * Only log publish event messages in trace log level under elastic-agent. * Add changelog entry. * Fix changelog. * Add same logic to processors. (cherry picked from commit 15ff7d1) # Conflicts: # libbeat/processors/actions/append.go * Remove append processor. --------- Co-authored-by: Blake Rouse <blake.rouse@elastic.co>

#34391) * Only log publish event messages in trace log level under elastic-agent. * Add changelog entry. * Fix changelog. * Add same logic to processors.

Only log publish event messages in trace log level under elastic-agent.

f7db313

blakerouse added the Team:Elastic-Agent Label for the Agent team label Jan 25, 2023

blakerouse self-assigned this Jan 25, 2023

botelastic bot added needs_team Indicates that the issue/PR needs a Team:* label and removed needs_team Indicates that the issue/PR needs a Team:* label labels Jan 25, 2023

Add changelog entry.

09080ed

blakerouse added the backport-v8.6.0 Automated backport with mergify label Jan 25, 2023

Merge branch 'main' into agent-v2-trace

53b988c

blakerouse marked this pull request as ready for review January 25, 2023 15:37

blakerouse requested a review from a team as a code owner January 25, 2023 15:37

blakerouse requested review from cmacknz and leehinman and removed request for a team January 25, 2023 15:37

cmacknz reviewed Jan 26, 2023

View reviewed changes

libbeat/publisher/processing/processing.go Outdated Show resolved Hide resolved

cmacknz reviewed Jan 26, 2023

View reviewed changes

blakerouse added 3 commits January 26, 2023 10:04

Merge branch 'main' into agent-v2-trace

75a7aa3

Fix changelog.

f99d48a

Add same logic to processors.

937947a

Merge branch 'main' into agent-v2-trace

2f92b52

cmacknz mentioned this pull request Jan 26, 2023

V2: Agent debug logs are not visible in diagnostics because logs are flooded with Beat debug log messages elastic/elastic-agent#1955

Closed

cmacknz approved these changes Jan 26, 2023

View reviewed changes

libbeat/publisher/processing/default.go Show resolved Hide resolved

blakerouse merged commit 15ff7d1 into elastic:main Jan 31, 2023

blakerouse deleted the agent-v2-trace branch January 31, 2023 18:23

mergify bot mentioned this pull request Jan 31, 2023

[8.6](backport #34391) Only log publish event messages in trace log level under elastic-agent #34434

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Only log publish event messages in trace log level under elastic-agent #34391

Only log publish event messages in trace log level under elastic-agent #34391

blakerouse commented Jan 25, 2023 •

edited

Loading

mergify bot commented Jan 25, 2023

elasticmachine commented Jan 25, 2023

elasticmachine commented Jan 25, 2023 •

edited by jenkins-beats-ci bot

Loading

Build stats

Test stats 🧪

cmacknz Jan 26, 2023 •

edited

Loading

blakerouse Jan 26, 2023

cmacknz Jan 26, 2023

blakerouse Jan 26, 2023

mergify bot commented Jan 26, 2023

mergify bot commented Jan 26, 2023

cmacknz left a comment

	errMsg := fmt.Errorf("Failed to copy fields in copy_fields processor: %s", err)
	f.logger.Debug(errMsg.Error())

Only log publish event messages in trace log level under elastic-agent #34391

Only log publish event messages in trace log level under elastic-agent #34391

Conversation

blakerouse commented Jan 25, 2023 • edited Loading

What does this PR do?

Why is it important?

Checklist

Related issues

mergify bot commented Jan 25, 2023

elasticmachine commented Jan 25, 2023

elasticmachine commented Jan 25, 2023 • edited by jenkins-beats-ci bot Loading

💚 Build Succeeded

Build stats

Test stats 🧪

💚 Flaky test report

🤖 GitHub comments

cmacknz Jan 26, 2023 • edited Loading

Choose a reason for hiding this comment

blakerouse Jan 26, 2023

Choose a reason for hiding this comment

cmacknz Jan 26, 2023

Choose a reason for hiding this comment

blakerouse Jan 26, 2023

Choose a reason for hiding this comment

mergify bot commented Jan 26, 2023

mergify bot commented Jan 26, 2023

cmacknz left a comment

Choose a reason for hiding this comment

blakerouse commented Jan 25, 2023 •

edited

Loading

elasticmachine commented Jan 25, 2023 •

edited by jenkins-beats-ci bot

Loading

cmacknz Jan 26, 2023 •

edited

Loading