Metricbeat generates large and repetitive permission error logs

[cmacknz]

Here is an example:

{"log.level":"error","@timestamp":"2024-12-03T20:27:50.168Z","log.origin":{"function":"github.com/elastic/beats/v7/metricbeat/mb/module.(*metricSetWrapper).fetch","file.name":"module/wrapper.go","file.line":266},"message":"Error fetching data for metricset system.process: Not enough privileges to fetch information: Not enough privileges to fetch information: non fatal error fetching PID some info for 1, metrics are valid, but partial: non-fatal error fetching PID metrics for 1, metrics are valid, but partial: Not enough privileges to fetch information: /io unavailable; if running inside a container, use SYS_PTRACE: error fetching IO metrics: read /hostfs/proc/1/io: permission denied\nnon fatal error fetching PID some info for 2, metrics are valid, but partial: non-fatal error fetching PID metrics for 2, metrics are valid, but partial: Not enough privileges to fetch information: /io unavailable; if running inside a container, use SYS_PTRACE: error fetching IO metrics: read /hostfs/proc/2/io: permission denied\nnon fatal error fetching PID some info for 3, metrics are valid, but partial: non-fatal error fetching PID metrics for 3, metrics are valid, but partial: Not enough privileges to fetch information: /io unavailable; if running inside a container, use SYS_PTRACE: error fetching IO metrics: read /hostfs/proc/3/io: permission denied\nnon fatal error fetching PID some info for 4, metrics are valid, but partial: non-fatal error fetching PID......

Here is an additional screenshot indicating that these errors can become ludicrously large in some circumstances:

It looks like we might be reporting the same error for every single PID on the system. We need to report the general error a single time instead.

[elasticmachine]

Pinging @elastic/elastic-agent-data-plane (Team:Elastic-Agent-Data-Plane)

[fearful-symmetry]

Here, in wrapper.go:

			reporter.V2().Error(err)
			if errors.As(err, &mb.PartialMetricsError{}) {
				// mark module as running if metrics are partially available and display the error message
				msw.module.UpdateStatus(status.Running, fmt.Sprintf("Error fetching data for metricset %s.%s: %v", msw.module.Name(), msw.MetricSet.Name(), err))
			} else {
				// mark it as degraded for any other issue encountered
				msw.module.UpdateStatus(status.Degraded, fmt.Sprintf("Error fetching data for metricset %s.%s: %v", msw.module.Name(), msw.MetricSet.Name(), err))
			}
			logp.Err("Error fetching data for metricset %s.%s: %s", msw.module.Name(), msw.Name(), err)

I'm guessing that should be logp.Debug, and not logp.Err

[VihasMakwana]

I agree.

If we're having partial metrics, log it a debug level.
Or else, log it at error level.

[VihasMakwana]

Even if we're logging at a debug level, the log is huge. I'll work on narrowing it down. Maybe something like:

Failed to fetch all metrics for processes: [1,2,3,...]

[cmacknz]

It is always possible for that error to be every PID on the machine. So maybe something like Failed to fetch all metrics for PID X and N other PIDs if there was more than one.

[VihasMakwana]

logs looks like this now

{"log.level":"error","@timestamp":"2024-12-12T13:59:11.076+0530","log.origin":{"function":"github.com/elastic/beats/v7/metricbeat/mb/module.(*metricSetWrapper).handleFetchError","file.name":"module/wrapper.go","file.line":324},"message":"Error fetching data for metricset system.process_summary: non fatal error; reporting partial metrics: error fetching PID metrics for 316 processes, most likely a \"permission denied\" error. Enable debug logging to determine the exact cause.","service.name":"metricbeat","ecs.version":"1.6.0"}
{"log.level":"error","@timestamp":"2024-12-12T13:59:16.308+0530","log.origin":{"function":"github.com/elastic/beats/v7/metricbeat/mb/module.(*metricSetWrapper).handleFetchError","file.name":"module/wrapper.go","file.line":324},"message":"Error fetching data for metricset system.process: non fatal error; reporting partial metrics: error fetching PID metrics for 316 processes, most likely a \"permission denied\" error. Enable debug logging to determine the exact cause.","service.name":"metricbeat","ecs.version":"1.6.0"}

[yavor-ivanov-covantis]

Elastic agents versions 8.17 and 8.16 are all affected.

[cmacknz]

@VihasMakwana was the elastic-agent-system-metrics package updated in main+8.17+8.16 with this? If not, we should re-open the issue until that is done. Merging the PR into the system metrics package doesn't fix this by itself.

[VihasMakwana]

@cmacknz I was waiting for this backport PR's #42024 CI to get green. I'll reopen this until we verify it's fixed.

[jlind23]

Backport PR are still opened:

• [8.16](backport #41965) [system/cpu][system/core] - New config for using performance counters #42067
• [8.17](backport #41965) [system/cpu][system/core] - New config for using performance counters #42068

[VihasMakwana]

Backports are now merged.

[VihasMakwana]

Closing this as the elastic-agent-system-metrics is updated on main+8.16+8.17