Log any FQDN lookup errors and fallback to OS-reported hostname #34946

ycombinator · 2023-03-28T00:24:42Z

What does this PR do?

This PR fixes a bug wherein a Beat would fail to start if the FQDN lookup failed.

Why is it important?

FQDN lookup is "best effort". As such, if the lookup fails for some reason, we should not fail to start a Beat or halt execution otherwise. Instead, we should fallback to the OS-provided hostname and continue execution.

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.~~

How to test this PR locally

Build Filebeat (or any other Beat) with this PR.
```
cd beats/filebeat
mage clean build
```
Set hostname to something that wouldn't resolve via DNS. On MacOS this can be done via:
```
orig_hostname=$(hostname -f)
sudo scutil --set HostName cowchicken
```
Run filebeat version. This command should report the version as usual and NOT fail with an FQDN-related error (as reported in Cannot start Beats - fails with error: could not get FQDN #34910)
```
./filebeat version
```
```
filebeat version 8.8.0 (arm64), libbeat 8.8.0 [528128f44ee870cedca830d8acbf63d8ee35ae26 built 2023-03-28 16:45:09 +0000 UTC]
```

Create a configuration file for the Beat that enables the add_host_metadata processor and also enables the FQDN feature flag.

cat <<EOF >filebeat.test.yml
filebeat.inputs:
- type: stdin

processors:
- add_host_metadata: ~

features.fqdn.enabled: true
output.console.enabled: true
EOF

Start the Beat with the above configuration and look for log entries mentioning FQDN. You should see two log entries in all, one from Beat initialization and one from the add_host_metadata processor.

./filebeat -c ./filebeat.test.yml -e 2>&1 | grep -i fqdn

{"log.level":"warn","@timestamp":"2023-03-28T11:38:17.639-0700","log.origin":{"file.name":"instance/beat.go","file.line":802},"message":"unable to lookup FQDN: could not get FQDN, all methods failed: failed looking up CNAME: lookup cowchicken: no such host: failed looking up IP: lookup cowchicken: no such host, using hostname = cowchicken as FQDN","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"warn","@timestamp":"2023-03-28T11:38:17.642-0700","log.logger":"add_host_metadata","log.origin":{"file.name":"add_host_metadata/add_host_metadata.go","file.line":152},"message":"unable to lookup FQDN: could not get FQDN, all methods failed: failed looking up CNAME: lookup cowchicken: no such host: failed looking up IP: lookup cowchicken: no such host, using hostname = cowchicken as FQDN","service.name":"filebeat","ecs.version":"1.6.0"}

Reset hostname at the end of the test. On MacOS this can be done via:
```
sudo scutil --set HostName $orig_hostname
```

Related issues

Closes Cannot start Beats - fails with error: could not get FQDN #34910
Follow up to Report FQDN on host.name enabled by a feature flag #34456

Use cases

Screenshots

Logs

elasticmachine · 2023-03-28T01:27:55Z

💚 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-03-30T00:17:36.901+0000
Duration: 56 min 48 sec

❕ Flaky test report

No test was executed to be analysed.

🤖 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/processors/add_host_metadata/add_host_metadata.go

libbeat/cmd/instance/beat.go

elasticmachine · 2023-03-28T19:11:30Z

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

cmacknz · 2023-03-28T19:26:17Z

libbeat/processors/add_host_metadata/add_host_metadata.go

+		if err != nil {
+			// FQDN lookup is "best effort".  We log the error, fallback to
+			// the OS-reported hostname, and move on.
+			p.logger.Warnf("unable to lookup FQDN: %s, using hostname = %s as FQDN", err.Error(), hostname)


How often would this be logged? We may want to lower this to Debug to avoid unnecessarily spamming the logs when this fails.

It feels like we would be better off with a metrics counter for how often this resolution has failed.

That would tell us it's failing without worrying about log spam, and we could then turn on debug logging to see exactly what is happening.

How often would this be logged? We may want to lower this to Debug to avoid unnecessarily spamming the logs when this fails.

Whenever the add_host_metadata cache expires. By default, that's every 5 minutes. That's quite frequent, so agreed on lowering the log level here to debug.

It feels like we would be better off with a metrics counter for how often this resolution has failed.

That would tell us it's failing without worrying about log spam, and we could then turn on debug logging to see exactly what is happening.

Makes sense. Let me look into implementing a metrics counter.

cmacknz · 2023-03-28T19:29:06Z

I assume writing a regression test for this is challenging because it requires us to modify the hostname of the system running the tests to one that doesn't resolve via DNS?

cmacknz · 2023-03-28T19:33:51Z

Also your test steps are excellent, thank you! I followed them exactly and the lack of fqdn logs caught that my attempt to switch branches failed because I had local file modifications to discard first :p

ycombinator · 2023-03-28T19:41:02Z

I assume writing a regression test for this is challenging because it requires us to modify the hostname of the system running the tests to one that doesn't resolve via DNS?

Yes. Perhaps we can do something with a Docker testcontainer, though. Let me look into that.

leehinman · 2023-03-28T19:46:47Z

I assume writing a regression test for this is challenging because it requires us to modify the hostname of the system running the tests to one that doesn't resolve via DNS?

Yes. Perhaps we can do something with a Docker testcontainer, though. Let me look into that.

maybe https://github.com/foxcpp/go-mockdns ?

ycombinator · 2023-03-29T09:56:32Z

Thanks to @leehinman's suggestion about https://github.com/foxcpp/go-mockdns, I was able to implement a couple of unit test cases - one where the FQDN lookup will succeed and one where it will fail. I've also implemented the metrics counter and dropped the log level for the FQDN lookup failure in the add_host_metadata processor to debug, as suggested by @cmacknz.

This PR is ready for review again.

cmacknz · 2023-03-29T19:30:00Z

libbeat/processors/add_host_metadata/add_host_metadata.go

 // New constructs a new add_host_metadata processor.
 func New(cfg *config.C) (processors.Processor, error) {
 	c := defaultConfig()
 	if err := cfg.Unpack(&c); err != nil {
 		return nil, fmt.Errorf("fail to unpack the %v configuration: %w", processorName, err)
 	}

+	// Logging and metrics (each processor instance has a unique ID).
+	var (
+		id     = int(instanceID.Inc())


First time I've seen this way of getting around the namespace collision issue. CC @fearful-symmetry, this could help the version of this problem you have in the shipper.

huh, interesting!

libbeat/processors/add_host_metadata/add_host_metadata.go

cmacknz

Looks good. My comment about the processors stats being per instance of the processor is more of a nit.

Thanks for finding a way to test this!

… monitoring

ycombinator · 2023-03-30T00:17:24Z

/test

* Log any FQDN lookup errors, fallback to OS hostname, and move on. * Implement fallback logic * Bumping up go-sysinfo dependency version * Update call to host.ReportInfo * Better log message * Bumping up version on elastic-agent-system-metrics dependency * Updating NOTICE.txt * Log FQDN lookup failure as warning * Move FQDN initialization to after logging has been configured * Better log message * Add metric + test * Update NOTICE.txt * Use a single namespace for all add_host_metadata processor instances' monitoring * Fixing imports * Create monitoring registry only once * Check errors (cherry picked from commit 895505c) # Conflicts: # NOTICE.txt # go.mod # go.sum # libbeat/cmd/instance/beat.go # libbeat/processors/add_host_metadata/add_host_metadata.go # libbeat/processors/add_host_metadata/add_host_metadata_test.go

* Log any FQDN lookup errors, fallback to OS hostname, and move on. * Implement fallback logic * Bumping up go-sysinfo dependency version * Update call to host.ReportInfo * Better log message * Bumping up version on elastic-agent-system-metrics dependency * Updating NOTICE.txt * Log FQDN lookup failure as warning * Move FQDN initialization to after logging has been configured * Better log message * Add metric + test * Update NOTICE.txt * Use a single namespace for all add_host_metadata processor instances' monitoring * Fixing imports * Create monitoring registry only once * Check errors (cherry picked from commit 895505c)

…reported hostname (#34971) * Log any FQDN lookup errors and fallback to OS-reported hostname (#34946) * Log any FQDN lookup errors, fallback to OS hostname, and move on. * Implement fallback logic * Bumping up go-sysinfo dependency version * Update call to host.ReportInfo * Better log message * Bumping up version on elastic-agent-system-metrics dependency * Updating NOTICE.txt * Log FQDN lookup failure as warning * Move FQDN initialization to after logging has been configured * Better log message * Add metric + test * Update NOTICE.txt * Use a single namespace for all add_host_metadata processor instances' monitoring * Fixing imports * Create monitoring registry only once * Check errors (cherry picked from commit 895505c) * Making changes lost in rebase * Fixing conflicts * Reordering imports --------- Co-authored-by: Shaunak Kashyap <ycombinator@gmail.com>

* Log any FQDN lookup errors, fallback to OS hostname, and move on. * Implement fallback logic * Bumping up go-sysinfo dependency version * Update call to host.ReportInfo * Better log message * Bumping up version on elastic-agent-system-metrics dependency * Updating NOTICE.txt * Log FQDN lookup failure as warning * Move FQDN initialization to after logging has been configured * Better log message * Add metric + test * Update NOTICE.txt * Use a single namespace for all add_host_metadata processor instances' monitoring * Fixing imports * Create monitoring registry only once * Check errors

ycombinator added bug Team:Elastic-Agent Label for the Agent team backport-v8.7.0 Automated backport with mergify labels Mar 28, 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 Mar 28, 2023

mergify bot assigned ycombinator Mar 28, 2023

ycombinator mentioned this pull request Mar 28, 2023

Update host functions with go-sysinfo API changes elastic/elastic-agent-system-metrics#81

Merged

4 tasks

ycombinator commented Mar 28, 2023

View reviewed changes

libbeat/processors/add_host_metadata/add_host_metadata.go Show resolved Hide resolved

ycombinator commented Mar 28, 2023

View reviewed changes

libbeat/cmd/instance/beat.go Show resolved Hide resolved

ycombinator commented Mar 28, 2023

View reviewed changes

libbeat/cmd/instance/beat.go Outdated Show resolved Hide resolved

ycombinator commented Mar 28, 2023

View reviewed changes

libbeat/cmd/instance/beat.go Show resolved Hide resolved

ycombinator mentioned this pull request Mar 28, 2023

Report FQDN on host.name as opt-in, enabled by feature flag elastic/elastic-agent#2218

Merged

6 tasks

ycombinator marked this pull request as ready for review March 28, 2023 19:11

ycombinator requested a review from a team as a code owner March 28, 2023 19:11

ycombinator requested review from rdner and faec and removed request for a team March 28, 2023 19:11

ycombinator requested a review from andrewkroh March 28, 2023 19:11

cmacknz reviewed Mar 28, 2023

View reviewed changes

ycombinator requested a review from cmacknz March 29, 2023 09:57

cmacknz reviewed Mar 29, 2023

View reviewed changes

libbeat/processors/add_host_metadata/add_host_metadata.go Outdated Show resolved Hide resolved

cmacknz approved these changes Mar 29, 2023

View reviewed changes

ycombinator added 16 commits March 29, 2023 12:59

Log any FQDN lookup errors, fallback to OS hostname, and move on.

53f039a

Implement fallback logic

4a84108

Bumping up go-sysinfo dependency version

eef3d9d

Update call to host.ReportInfo

2130096

Better log message

cdb125b

Bumping up version on elastic-agent-system-metrics dependency

47e4bc7

Updating NOTICE.txt

c34a698

Log FQDN lookup failure as warning

a6a7f84

Move FQDN initialization to after logging has been configured

1adccc6

Better log message

75b8989

Add metric + test

8f723c5

Update NOTICE.txt

ae45940

Use a single namespace for all add_host_metadata processor instances'…

6e7c22f

… monitoring

Fixing imports

0eef50a

Create monitoring registry only once

508a4a9

Check errors

58d4a07

ycombinator merged commit 895505c into elastic:main Mar 30, 2023

ycombinator deleted the fqdn-lookup-errors branch March 30, 2023 01:13

mergify bot mentioned this pull request Mar 30, 2023

[8.7](backport #34946) Log any FQDN lookup errors and fallback to OS-reported hostname #34971

Merged

ycombinator mentioned this pull request Mar 30, 2023

Update allow_older_versions when running under Elastic Agent #34964

Merged

4 tasks

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Log any FQDN lookup errors and fallback to OS-reported hostname #34946

Log any FQDN lookup errors and fallback to OS-reported hostname #34946

ycombinator commented Mar 28, 2023 •

edited

Loading

elasticmachine commented Mar 28, 2023 •

edited by jenkins-beats-ci bot

Loading

Build stats

elasticmachine commented Mar 28, 2023

cmacknz Mar 28, 2023

cmacknz Mar 28, 2023

ycombinator Mar 28, 2023

ycombinator Mar 28, 2023

cmacknz commented Mar 28, 2023

cmacknz commented Mar 28, 2023

ycombinator commented Mar 28, 2023

leehinman commented Mar 28, 2023

ycombinator commented Mar 29, 2023

cmacknz Mar 29, 2023

fearful-symmetry Mar 30, 2023

cmacknz left a comment

ycombinator commented Mar 30, 2023

Log any FQDN lookup errors and fallback to OS-reported hostname #34946

Log any FQDN lookup errors and fallback to OS-reported hostname #34946

Conversation

ycombinator commented Mar 28, 2023 • edited Loading

What does this PR do?

Why is it important?

Checklist

How to test this PR locally

Related issues

Use cases

Screenshots

Logs

elasticmachine commented Mar 28, 2023 • edited by jenkins-beats-ci bot Loading

💚 Build Succeeded

Build stats

❕ Flaky test report

🤖 GitHub comments

elasticmachine commented Mar 28, 2023

cmacknz Mar 28, 2023

Choose a reason for hiding this comment

cmacknz Mar 28, 2023

Choose a reason for hiding this comment

ycombinator Mar 28, 2023

Choose a reason for hiding this comment

ycombinator Mar 28, 2023

Choose a reason for hiding this comment

cmacknz commented Mar 28, 2023

cmacknz commented Mar 28, 2023

ycombinator commented Mar 28, 2023

leehinman commented Mar 28, 2023

ycombinator commented Mar 29, 2023

cmacknz Mar 29, 2023

Choose a reason for hiding this comment

fearful-symmetry Mar 30, 2023

Choose a reason for hiding this comment

cmacknz left a comment

Choose a reason for hiding this comment

ycombinator commented Mar 30, 2023

ycombinator commented Mar 28, 2023 •

edited

Loading

elasticmachine commented Mar 28, 2023 •

edited by jenkins-beats-ci bot

Loading