EventHub plugin reports strange values periodically

[ilya-scale]

Report

I have connected KEDA to event hub

      spec:
        minReplicaCount: 2
        maxReplicaCount: 8
      triggers:
      - type: azure-eventhub
        metadata:
          storageAccountName: myaccount
          blobContainer: checkpoints
          eventHubNamespace: mynamespace
          eventHubName: myhub
          consumerGroup: myconsumer
          checkpointStrategy: blobMetadata
          unprocessedEventThreshold: "5000"

There seem to be a number of issues with the connection:

1. The connection seems to work but I often get very strange values. I monitor them via grafana and prometheus monitor.
   The value is negative and extremely low:

2. I also get these logs every 10 seconds or even more often:

2023-02-17T11:58:41Z INFO Reconciling ScaledObject {"controller": "scaledobject", "controllerGroup": "keda.sh", "controllerKind": "ScaledObject", "ScaledObject": {"name":"xxx","namespace":"xxx"}, "namespace": "xxx", "name": "data-ingest-iot", "reconcileID": "e272cdaa-8474-421e-9ca4-9fae7bda42f4"}

Which is probably strange since the default check period is every 30 seconds. I have a service bus trigger on another ScaledObject and neither of these things happen (no logs for reconciling, no "off" values either)

3. It seems that the value of the metric is capped at unprocessedEventThreshold * maxReplicaCount as very often I get value 40000 which is quite strange. So I think the value should not be capped. The value itself seems to be off as well, somewhat like in the point 1. but I cannot see it since it is capped.

Expected Behavior

1. There should not be any values that are "off"
2. There probably should not be reconciling every 10 seconds in the log (not sure about that)
3. There should not be any "cap" on the metric value

Actual Behavior

1. Strange values appear periodically
2. Logs indicate that probably something is wrong
3. The value of the metric is capped

Steps to Reproduce the Problem

1. Create an eventhub with some messages coming through
2. Register trigger with the details posted above
3. Run for some time and observe this behaviour

P.S. The negative value does not seem to happen in every environment where I run k8s.

Logs from KEDA operator

example

KEDA Version

2.9.3

Kubernetes Version

1.24

Platform

Microsoft Azure

Scaler Details

EventHubs

Anything else?

No response

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed in 7 days if no further activity occurs. Thank you for your contributions.

[JorTurFer]

Does this behavior still happen in v2.10?

[ilya-scale]

I am running in a development environment the upgraded version (2.10.1) and it actually does not seem to happen anymore. I need some more time to verify that this is indeed the case and upgrade production before I can tell for sure.

Was there something that was fixed in 2.10 to make that happen?

[JorTurFer]

If I'm not wrong (and I can be), we upgraded the dep azure-amqp-common-go from v3 to v4

[ilya-scale]

It seems it did not help after all:

The 0 on the chart is not the 0, it is some real value (around 200), but as you see sometimes it goes to a completely weird value (-9223372036854776)

[JorTurFer]

If you check the values using prometheus directly, do you see the same? I have had some renderization issues with grafana some times

[ilya-scale]

I am not using a dashboard, but a raw Metric from explore:

Would that be enough, or you think it can still render wrong? (The picture here does not have the error as it does not happen every time)

[JorTurFer]

I still think that it can be a render error, I have faced with them sometimes in grafana :/
The problem is that value doesn't make sense :( maybe you could try with different time windows when you see the error to ensure that the negative peaks are at the same time. I mean, if you have the last 3 hours and you see an error 20 minutes ago, try again with the last hour and check if the error is at the same time (if the peak is at the same time with 2 different visualizations, looks like metric problem)

[ilya-scale]

I have some issues with persistence, so I cannot go back in time to check unfortunately, but let me wait until it pops up again, and I can check raw prometheus data from prometheus pod to double check

[ilya-scale]

Here is the result from raw prometheus data (grafana is not involved):

So I guess that proves the issue is with the raw data?

[JorTurFer]

So, definitively KEDA is who is exposing that value :/
Do you have any idea about why this could be happening @v-shenoy @tomkerkhove ?

[ilya-scale]

I can also add that my setup is 2 - 8 replicas, since I have 8 partitions in a hub. Usually it runs with 2 pods, each listening to 4 partitions each.

Azure.Messaging.EventHubs.Processor 5.7.5, Azure Premium Storage Account.

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed in 7 days if no further activity occurs. Thank you for your contributions.

[stale]

This issue has been automatically closed due to inactivity.

[ilya-scale]

I suppose the issue was not really fixed, just closed? Can we reopen it?

[JorTurFer]

sure!
One question, how often does it happen? we have recently released a product that uses EventHub, it's just to check it looking for this weird values

[ilya-scale]

I have now turned the whole setup off since it is not possible to use with this issue, but as far as I remember it happened relatively often, more than once a day.

[JorTurFer]

I'll check it tomorrow morning

[JorTurFer]

In KEDA v2.10.1 still happens:

Do you have any idea about the root cause @tomkerkhove @v-shenoy . I guess that it's related with the circular buffer of the EventHub, but I'm not sure

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed in 7 days if no further activity occurs. Thank you for your contributions.

[ilya-scale]

I think this is still an active issue that should not be closed

[JorTurFer]

@tomkerkhove , do you think that we could get a revision from anyone with knowledge about the eventhub SDK?
Maybe we are doing something wrong, or it's something wrong at some point. I do confirm that this happens (I see it also in my own products)

[tomkerkhove]

Can you summarize the issue please?

[JorTurFer]

The OP is using evenhub scaler and they monitor the exposed value during the time through KEDA's prometheus metrics. The problem is that periodically, KEDA is reporting a weird value:

I have seen the same weird behavior in our own clusters (SCRM) and I have the suspicious that it's because we are doing something wrong calculating the lag.
I'm not an expert in how event hub works, so maybe the issue is in any other place, but if someone who knows about event hub and the golang SDK could take a look and give us some feedback, it'd be nice :)