Forwarder and Http metrics consumers produce incorrect values when used together

[esardaya]

Describe the bug

When adding both an IMetricsConsumer for HttpMetrics and one for ForwarderMetrics, the previous or current metric values can contain incorrect values.

This is because apparently when using EventListeners for event counters (event ID -1), the filtering on event source is not applied and all listeners get all event counter events for all enabled sources. See: dotnet/runtime#31500

The specific issue with forwarder and HTTP metrics has to do with the fact that both of these event sources define counters with the same names, like requests-started.

Both ForwarderEventListenerService and HttpEventListenerService will receive all EventCounters events due to the filtering issue, and since requests-started is considered a valid counter name in both, then the values set on the metrics objects that are passed to OnMetrics will be coming from either source and can be invalid depending on the order of the received events.

One easy solution would be to always (or when event name is EventCounters) filter on the event source name in OnEventWritten here: https://github.com/microsoft/reverse-proxy/blob/main/src/TelemetryConsumption/EventListenerService.cs

To Reproduce

1. Add both an IMetricsConsumer for HttpMetrics and one for ForwarderMetrics.
2. Log the values for previous and current metrics.
3. Make sure that you have some load that will cause the number of started requests from the forwarder to be different than the number of started HTTP requests so that you can see the difference.

Expected:
For each consumer, in the case of requests started (as an example), current should always be higher than previous, and each new previous should be the value of the last current.

Actual:
This is the output we see in our telemetry coming from the forwarder metrics consumer when both consumers are enabled:
2023-04-17T14:38:56.583459Z ForwarderRequestsStarted - Previous: 955, Current: 1151, Value: 196
2023-04-17T14:38:56.786638Z ForwarderRequestsStarted - Previous: 1151, Current: 955, Value: -196
2023-04-17T14:38:57.583489Z ForwarderRequestsStarted - Previous: 955, Current: 1152, Value: 197
2023-04-17T14:38:57.786649Z ForwarderRequestsStarted - Previous: 1152, Current: 956, Value: -196
2023-04-17T14:38:58.583575Z ForwarderRequestsStarted - Previous: 956, Current: 1153, Value: 197
2023-04-17T14:38:58.786836Z ForwarderRequestsStarted - Previous: 1153, Current: 957, Value: -196
2023-04-17T14:38:59.583638Z ForwarderRequestsStarted - Previous: 957, Current: 1155, Value: 198
2023-04-17T14:38:59.786577Z ForwarderRequestsStarted - Previous: 1155, Current: 959, Value: -196

Further technical details

• Package versions: 2.0.0
• Platform: Windows

[MihaZupan]

Thanks for reporting this, I was not aware of the EventListener bug :/
We should work around it in YARP.