[chore][comp/forwarder/defaultforwarder] Lower level of 'successfully posted payload' messages to debug

[mx-psi]

What does this PR do?

Lowers log level of "successfully posted payload" messages to debug level. These have been reported as spammy by OpenTelemetry Collector Datadog exporter users (see issue linked below).

Motivation

open-telemetry/opentelemetry-collector-contrib/issues/43594

[carlosroman]

This actually breaks our observability in the Agent so we do not want to make this change. It doesn't spam the Agent because we have a nicer way to handle these useful log messages as mentioned in the issue you linked to.

[agent-platform-auto-pr]

Static quality checks

✅ Please find below the results from static quality gates
Comparison made with ancestor b1026eb

Successful checks

Info

	Quality gate	Delta	On disk size (MiB)	Delta	On wire size (MiB)
✅	agent_deb_amd64	$${0}$$	$${674.78}$$ < $${702.15}$$	$${+0.01}$$	$${164.66}$$ < $${177.79}$$
✅	agent_deb_amd64_fips	$${0}$$	$${669.28}$$ < $${696.65}$$	$${-0.03}$$	$${163.81}$$ < $${176.53}$$
✅	agent_heroku_amd64	$${0}$$	$${336.54}$$ < $${340.18}$$	$${+0}$$	$${89.83}$$ < $${91.08}$$
✅	agent_msi	$${0}$$	$${1013.54}$$ < $${1015.38}$$	$${+0.01}$$	$${148.42}$$ < $${150.78}$$
✅	agent_rpm_amd64	$${0}$$	$${674.77}$$ < $${702.14}$$	$${-0.02}$$	$${166.98}$$ < $${180.53}$$
✅	agent_rpm_amd64_fips	$${0}$$	$${669.27}$$ < $${696.64}$$	$${+0.03}$$	$${165.52}$$ < $${178.79}$$
✅	agent_rpm_arm64	$${0}$$	$${664.29}$$ < $${686.31}$$	$${-0}$$	$${153.2}$$ < $${161.22}$$
✅	agent_rpm_arm64_fips	$${0}$$	$${659.8}$$ < $${681.84}$$	$${-0}$$	$${152.68}$$ < $${160.18}$$
✅	agent_suse_amd64	$${0}$$	$${674.77}$$ < $${702.14}$$	$${-0.02}$$	$${166.98}$$ < $${180.53}$$
✅	agent_suse_amd64_fips	$${0}$$	$${669.27}$$ < $${696.64}$$	$${+0.03}$$	$${165.52}$$ < $${178.79}$$
✅	agent_suse_arm64	$${0}$$	$${664.29}$$ < $${686.31}$$	$${-0}$$	$${153.2}$$ < $${161.22}$$
✅	agent_suse_arm64_fips	$${0}$$	$${659.8}$$ < $${681.84}$$	$${-0}$$	$${152.68}$$ < $${160.18}$$
✅	docker_agent_amd64	$${+0}$$	$${746.2}$$ < $${773.59}$$	$${-0}$$	$${251.8}$$ < $${266.06}$$
✅	docker_agent_arm64	$${-0}$$	$${759.68}$$ < $${781.7}$$	$${+0}$$	$${242.41}$$ < $${251.85}$$
✅	docker_agent_jmx_amd64	$${+0}$$	$${937.07}$$ < $${964.45}$$	$${-0}$$	$${320.43}$$ < $${334.68}$$
✅	docker_agent_jmx_arm64	$${-0}$$	$${939.14}$$ < $${961.17}$$	$${+0}$$	$${307.01}$$ < $${316.44}$$
✅	docker_cluster_agent_amd64	$${-0}$$	$${213.01}$$ < $${213.74}$$	$${-0}$$	$${72.26}$$ < $${73.14}$$
✅	docker_cluster_agent_arm64	$${+0}$$	$${228.92}$$ < $${229.68}$$	$${-0}$$	$${68.53}$$ < $${69.41}$$
✅	docker_cws_instrumentation_amd64	$${0}$$	$${7.07}$$ < $${7.12}$$	$${+0}$$	$${2.95}$$ < $${3.29}$$
✅	docker_cws_instrumentation_arm64	$${0}$$	$${6.69}$$ < $${6.92}$$	$${+0}$$	$${2.7}$$ < $${3.07}$$
✅	docker_dogstatsd_amd64	$${-0}$$	$${38.44}$$ < $${39.3}$$	$${+0}$$	$${14.84}$$ < $${15.76}$$
✅	docker_dogstatsd_arm64	$${0}$$	$${37.13}$$ < $${37.94}$$	$${+0}$$	$${14.29}$$ < $${14.83}$$
✅	dogstatsd_deb_amd64	$${0}$$	$${29.66}$$ < $${30.53}$$	$${-0}$$	$${7.82}$$ < $${8.75}$$
✅	dogstatsd_deb_arm64	$${0}$$	$${28.24}$$ < $${29.11}$$	$${+0}$$	$${6.77}$$ < $${7.71}$$
✅	dogstatsd_rpm_amd64	$${0}$$	$${29.66}$$ < $${30.53}$$	$${+0}$$	$${7.83}$$ < $${8.76}$$
✅	dogstatsd_suse_amd64	$${0}$$	$${29.66}$$ < $${30.53}$$	$${+0}$$	$${7.83}$$ < $${8.76}$$
✅	iot_agent_deb_amd64	$${0}$$	$${41.88}$$ < $${54.97}$$	$${+0}$$	$${10.9}$$ < $${14.45}$$
✅	iot_agent_deb_arm64	$${0}$$	$${39.7}$$ < $${51.9}$$	$${-0}$$	$${9.41}$$ < $${12.63}$$
✅	iot_agent_deb_armhf	$${0}$$	$${39.57}$$ < $${51.84}$$	$${+0}$$	$${9.49}$$ < $${12.74}$$
✅	iot_agent_rpm_amd64	$${0}$$	$${41.88}$$ < $${54.97}$$	$${-0}$$	$${10.91}$$ < $${14.47}$$
✅	iot_agent_suse_amd64	$${0}$$	$${41.88}$$ < $${54.97}$$	$${-0}$$	$${10.91}$$ < $${14.47}$$

[cit-pr-commenter]

Regression Detector

Regression Detector Results

Metrics dashboard
Target profiles
Run ID: c9328544-d202-414b-a417-d0a7839f5499

Baseline: b1026eb
Comparison: c6c9c9b
Diff

Optimization Goals: ✅ Improvement(s) detected

perf	experiment	goal	Δ mean %	Δ mean % CI	trials	links
✅	docker_containers_memory	memory utilization	-12.39	[-12.83, -11.95]	1	Logs

Experiments ignored for regressions

Regressions in experiments with settings containing erratic: true are ignored.

perf	experiment	goal	Δ mean %	Δ mean % CI	trials	links
❌	docker_containers_cpu	% cpu utilization	+56.48	[+53.91, +59.05]	1	Logs

Fine details of change detection per experiment

perf	experiment	goal	Δ mean %	Δ mean % CI	trials	links
❌	docker_containers_cpu	% cpu utilization	+56.48	[+53.91, +59.05]	1	Logs
➖	ddot_logs	memory utilization	+0.50	[+0.44, +0.55]	1	Logs
➖	ddot_metrics_sum_cumulativetodelta_exporter	memory utilization	+0.17	[-0.02, +0.37]	1	Logs
➖	ddot_metrics_sum_delta	memory utilization	+0.05	[-0.11, +0.22]	1	Logs
➖	quality_gate_idle_all_features	memory utilization	+0.05	[+0.01, +0.09]	1	Logs bounds checks dashboard
➖	file_to_blackhole_100ms_latency	egress throughput	+0.04	[-0.56, +0.64]	1	Logs
➖	uds_dogstatsd_20mb_12k_contexts_20_senders	memory utilization	+0.03	[-0.01, +0.08]	1	Logs
➖	tcp_dd_logs_filter_exclude	ingress throughput	+0.00	[-0.01, +0.01]	1	Logs
➖	uds_dogstatsd_to_api	ingress throughput	-0.00	[-0.24, +0.23]	1	Logs
➖	file_to_blackhole_0ms_latency	egress throughput	-0.01	[-0.61, +0.59]	1	Logs
➖	file_to_blackhole_1000ms_latency	egress throughput	-0.05	[-0.67, +0.56]	1	Logs
➖	ddot_metrics_sum_cumulative	memory utilization	-0.09	[-0.21, +0.02]	1	Logs
➖	quality_gate_logs	% cpu utilization	-0.10	[-2.88, +2.67]	1	Logs bounds checks dashboard
➖	otlp_ingest_logs	memory utilization	-0.14	[-0.27, -0.01]	1	Logs
➖	file_to_blackhole_500ms_latency	egress throughput	-0.14	[-0.75, +0.47]	1	Logs
➖	quality_gate_idle	memory utilization	-0.15	[-0.18, -0.11]	1	Logs bounds checks dashboard
➖	tcp_syslog_to_blackhole	ingress throughput	-0.24	[-0.31, -0.16]	1	Logs
➖	quality_gate_metrics_logs	memory utilization	-0.29	[-0.48, -0.11]	1	Logs bounds checks dashboard
➖	otlp_ingest_metrics	memory utilization	-0.36	[-0.48, -0.23]	1	Logs
➖	ddot_metrics	memory utilization	-0.45	[-0.62, -0.28]	1	Logs
➖	file_tree	memory utilization	-0.64	[-0.67, -0.60]	1	Logs
✅	docker_containers_memory	memory utilization	-12.39	[-12.83, -11.95]	1	Logs

Bounds Checks: ✅ Passed

perf	experiment	bounds_check_name	replicates_passed	links
✅	docker_containers_cpu	simple_check_run	10/10
✅	docker_containers_memory	memory_usage	10/10
✅	docker_containers_memory	simple_check_run	10/10
✅	file_to_blackhole_0ms_latency	lost_bytes	10/10
✅	file_to_blackhole_0ms_latency	memory_usage	10/10
✅	file_to_blackhole_1000ms_latency	memory_usage	10/10
✅	file_to_blackhole_100ms_latency	lost_bytes	10/10
✅	file_to_blackhole_100ms_latency	memory_usage	10/10
✅	file_to_blackhole_500ms_latency	lost_bytes	10/10
✅	file_to_blackhole_500ms_latency	memory_usage	10/10
✅	quality_gate_idle	intake_connections	10/10	bounds checks dashboard
✅	quality_gate_idle	memory_usage	10/10	bounds checks dashboard
✅	quality_gate_idle_all_features	intake_connections	10/10	bounds checks dashboard
✅	quality_gate_idle_all_features	memory_usage	10/10	bounds checks dashboard
✅	quality_gate_logs	intake_connections	10/10	bounds checks dashboard
✅	quality_gate_logs	lost_bytes	10/10	bounds checks dashboard
✅	quality_gate_logs	memory_usage	10/10	bounds checks dashboard
✅	quality_gate_metrics_logs	cpu_usage	10/10	bounds checks dashboard
✅	quality_gate_metrics_logs	intake_connections	10/10	bounds checks dashboard
✅	quality_gate_metrics_logs	lost_bytes	10/10	bounds checks dashboard
✅	quality_gate_metrics_logs	memory_usage	10/10	bounds checks dashboard

Explanation

Confidence level: 90.00%
Effect size tolerance: |Δ mean %| ≥ 5.00%

Performance changes are noted in the perf column of each table:

• ✅ = significantly better comparison variant performance
• ❌ = significantly worse comparison variant performance
• ➖ = no significant change in performance

A regression test is an A/B test of target performance in a repeatable rig, where "performance" is measured as "comparison variant minus baseline variant" for an optimization goal (e.g., ingress throughput). Due to intrinsic variability in measuring that goal, we can only estimate its mean value for each experiment; we report uncertainty in that value as a 90.00% confidence interval denoted "Δ mean % CI".

For each experiment, we decide whether a change in performance is a "regression" -- a change worth investigating further -- if all of the following criteria are true:

1. Its estimated |Δ mean %| ≥ 5.00%, indicating the change is big enough to merit a closer look.

2. Its 90.00% confidence interval "Δ mean % CI" does not contain zero, indicating that if our statistical model is accurate, there is at least a 90.00% chance there is a difference in performance between baseline and comparison variants.

3. Its configuration does not mark it "erratic".

CI Pass/Fail Decision

✅ Passed. All Quality Gates passed.

• quality_gate_metrics_logs, bounds check intake_connections: 10/10 replicas passed. Gate passed.
• quality_gate_metrics_logs, bounds check lost_bytes: 10/10 replicas passed. Gate passed.
• quality_gate_metrics_logs, bounds check memory_usage: 10/10 replicas passed. Gate passed.
• quality_gate_metrics_logs, bounds check cpu_usage: 10/10 replicas passed. Gate passed.
• quality_gate_idle_all_features, bounds check memory_usage: 10/10 replicas passed. Gate passed.
• quality_gate_idle_all_features, bounds check intake_connections: 10/10 replicas passed. Gate passed.
• quality_gate_logs, bounds check intake_connections: 10/10 replicas passed. Gate passed.
• quality_gate_logs, bounds check memory_usage: 10/10 replicas passed. Gate passed.
• quality_gate_logs, bounds check lost_bytes: 10/10 replicas passed. Gate passed.
• quality_gate_idle, bounds check intake_connections: 10/10 replicas passed. Gate passed.
• quality_gate_idle, bounds check memory_usage: 10/10 replicas passed. Gate passed.

[mx-psi]

This actually breaks our observability in the Agent so we do not want to make this change. It doesn't spam the Agent because we have a nicer way to handle these useful log messages as mentioned in the issue you linked to.

Could you expand as to how this breaks the observability in the Agent?

[jackgopack4]

@carlosroman how about a way to select verbosity of the forwarder on instantiation that is by default Info level but could be set to debug

[carlosroman]

This actually breaks our observability in the Agent so we do not want to make this change. It doesn't spam the Agent because we have a nicer way to handle these useful log messages as mentioned in the issue you linked to.

Could you expand as to how this breaks the observability in the Agent?

This log line is crucial for both us and our customers. It confirms the Agent's successful payload submissions upon startup and enables us to track these events in the logs. When addressing support cases, these log lines from flare files provide valuable insights into the Agent's behavior. Removing or lowering the log level would compromise our ability to observe the Agent's operations. We should not alter these log lines simply because the OTel collector or other services using our code as a library cannot control their logging frequency.

A potential solution involves updating the Datadog log library imported into the OTel collector. This approach would enable centralized control over all logs generated by Datadog Agent dependencies.

The original poster of the issue even understands why it might not be possible to do so:

If it's not possible (and I could understand), I would like to be able to modify the logging frequency of this log, as it seems to be possible in the Datadog Agent.

[tobz]

@carlosroman how about a way to select verbosity of the forwarder on instantiation that is by default Info level but could be set to debug

Are you suggesting a way to configure which verbosity level the individual calls would choose to log at, passed as an option during instantiation? If so, then no, we wouldn't want to do that: that would be additional complexity that is tangential to the component itself solely to solve a problem occurring in an off-label usage of the code.

[mx-psi]

This log line is crucial for both us and our customers. It confirms the Agent's successful payload submissions upon startup and enables us to track these events in the logs. When addressing support cases, these log lines from flare files provide valuable insights into the Agent's behavior.

Flare files should still have debug level logs if enabled, shouldn't them? This may be a bold claim, but I think most client libraries do not have these kinds of info-level "everything went fine" logs and people are still able to debug them.

We should not alter these log lines simply because the OTel collector or other services using our code as a library cannot control their logging frequency.

The Collector is able to adjust the logging frequency of these and any other repeated logs: there is sampling for all Collector logs enabled by default, see https://github.com/open-telemetry/opentelemetry-collector/blob/58b71431b36f62a7797a02d661547584cf15222a/service/telemetry/otelconftelemetry/factory.go#L48-L53

Despite this, our users complain about these logs as not being useful and being spammy, so I don't think the problem is any lack of capabilities from the Collector side, but rather a more fundamental problem with these logs.

We can tell the original reporter to adjust the sampling frequency but given that, already after sampling, these logs seem to be spammy, I think this points to an issue in the Agent.

[mx-psi]

Superseded by #42268