Openwhisk: Healthcheck Protocol Bug / Edge Case when Unhealthy or Unresponsive

[bdoyle0182]

We're facing an issue where the Invoker becomes Unhealthy (not processing activations), but it is still sending pings to the controller. This works as intended that the controller marks it as unhealthy or unresponsive. However, it is still sending healthcheck messages on the invoker topic which are not being read when the invoker is in this state. Coincidentally the other eager marking as healthy bug that was identified this week probably isn't helping too. The problem then starts on the restart of the invoker which brings the invoker back to a healthy state:

1. There is a huge backlog of healthcheck messages on the invoker topic (say it took days before the invoker restart)
2. After the invoker restarts, it starts processing these healthchecks finally.
3. Invoker tells the controller it's healthy from the first healthcheck messages processing.
4. Controller starts sending activations onto an invoker topic with a huge healthcheck backlog
5. These activations ultimately timeout, which results in the host unresponsive.
6. Then more healthchecks are completed from the backlog and back to healthy.
7. Sends more activations. Controller flaps the invoker between unresponsive and healthy until the backlog completes.

The easiest solution I thought for this would be to just when the invoker consumes an activation from kafka and it is a healthcheck to drop the message if it is older than a few minutes. This should be fine since once the controller views it as unhealthy or unresponsive, it sends a new healthcheck once a minute. The one potential issue with this is time drift. If the controller internal clock is behind the invoker by more than the threshold, than the invoker will drop every healthcheck and never become healthy. This might be edge casey enough though that we don't care.

As to why things are no longer being read off kafka, I'm not sure yet. I think there might be some edge case bugs with container management in the ContainerPool and ContainerProxy fsm logic. My theory is that there is a dead lock with requesting more activation messages from the feed when the invoker is under heavy load.

I have my eyes on this commit right now when the processBufferOrFeed function was introduced for reading messages from the feed since it's somewhat recent; looking for something, but haven't been able to identify anything yet. I'll update this issue as I find anything of concern in the code.

https://github.com/apache/openwhisk/commit/a7482ca22694eee9b578c1003cd2c847953273e8

[bdoyle0182]

My question is really with the removal of this line. Processing from the buffer or event feed is now strictly event based rather than if nothing is available in the container pool to run it. That function has to be called based on some event now (a container freeing up for example) to reprocess the message rather than before it would just continually try to re-run that message on a loop. I don't have an edge case yet, but I would think this method of pulling from the buffer or message feed would be prone to edge cases especially when the invoker is under load.

https://github.com/apache/openwhisk/commit/a7482ca22694eee9b578c1003cd2c847953273e8#diff-907fea4f2800af33d571845b19ddc9a24a44d481994305f344c23d33310d471aL205

[rabbah]

The backlog is generally not a good symptom - but iirc there is a low expiration on the topic which should retire messages. Thanks for the details explanation, will give it a 👀 also.

[bdoyle0182]

Do you mean that the suggestion of dropping healthcheck messages on the invoker side that are too old is not a good idea? The retention period is two days for the invoker topics. Ours have seven day retention since we use a shared kafka fleet, but that's an us problem. But for reference it took us about three hours to run through five days of consistently sent healthchecks that built up. So would have still taken about an hour for us to catch up if we were using the correct retention period on our hardware.

[rabbah]

No, I mean that there is a backlog on the health topic is a bad symptom. I thought the retention was much much shorter for this topic (compared to the activation topic).

[bdoyle0182]

This is where I got two days from. The other topics seem to be one hour.
https://github.com/apache/openwhisk/blob/master/common/scala/src/main/resources/application.conf#L187

[rabbah]

That's overkill - I don't see a reason these need to be more than a few minutes! Checking history, I don't know why these are so high for a health topic.

[bdoyle0182]

Well the invoker* topics aren't just for the healthcheck messages right? They receive all activations that are sent to that invoker. Healthcheck activations get mixed in.

Even so the controller times out activations after a few minutes so they're kind of pointless to retain regardless. I think our controller views an activation as timed out after three minutes.

[style95]

IMHO, this can also happen when an invoker is failed under heavy loads.
If an invoker is failed while there are many activations in Kafka and it takes a couple of hours to restore it.
If you restart the invoker, then it would start processing 2 hours-old activations first.

In our case, a similar thing happened when a scheduler component had failed while there were a lot of messages piled up in Kafka.
Upon restoring the component, it started reading all messages from Kafka and it generated a colossal request wave which caused too many container creations.
Since most of them were "stale" messages, we ended up with not processing them.
We introduced a threshold and if any messages older than the threshold come, we just complete the activation with an error.
I think this is a kind of tradeoff between the timeout and execution and we concluded if an activation is too old, we should consider it as an already-failed activation.

[bdoyle0182]

@style95 that was exactly our idea on how to fix this. Just drop the activation if it is too old which should be a very easy change.

[rabbah]

that was exactly our idea on how to fix this. Just drop the activation if it is too old which should be a very easy change.

@ddragosd mentioned this in the case of blocking invokes on the dev list too.

[bdoyle0182]

that was exactly our idea on how to fix this. Just drop the activation if it is too old which should be a very easy change.

@ddragosd mentioned this in the case of blocking invokes on the dev list too.

would there be any reason it would be specific to blocking invokes and not just all? The controller times out the activation after a few minutes. As far as I know I don't think it retries after the controller times it out.

To start I'm probably just going to do a check on the healthcheck since I can do that in a couple lines and that's the most critical aspect