Spike: Investigating Mediator Timeout Issue -- server side

[swcurran]

As reported, we are getting intermittent mediator timeouts in the BC Wallet that result in Wallet issues #812, #987, #988.

Investigations have pointed to a possible problem with ACA-Py, Python Threading and Linux Scheduling and OpenShift/Kubernetes CPU settings. See this ACA-Py Issue #2157 for a deeper discussion on that.

We need to investigate the issues further, and intend to track the issue here. See the first couple of comments for some background and initial steps to be taken.

The goals:

• Find a way to reproduce the timeouts easily in a Dev or Test environment.
• See what is happening on the mediator side -- we know the wallet is getting a timeout, but what is happening on the mediator side?
• Make adjustments as appropriate -- code, OpenShift parameters, etc.

Ultimately, we are deciding:

• Is there an inherent problem with using ACA-Py on OpenShift?
• Can we find a temporary solution for now using ACA-Py?
• What do we want as the long term, fully scalable solution?

Tasks

• [ ] bcgov/bc-wallet-mobile#992

[swcurran]

Notes from meeting on the Mediator from 2023.03.20, with Clecio, Akiff, and Andrew.

• Despite bump in CPU settings on Mediator Prod (limits: CPU: 800m, memory: 256Mi; requests: CPU: 800m, 96Mi), timeouts on the Wallet side are still happening intermittently. AFAWK -- with these settings the throttling has dropped considerably, such that one would not expect timeouts. E.g. there has not been a 1-1 throttling to timeout relationship.
• The issue should not be a race condition, as AFJ (the Wallet) serializes the mediation before responding to the other Agent. The other agent should never be able to send a message before the Mediator is ready to handle it.
• We should work to understand the ACA-Py Mediator issue, vs. trying to replace ACA-Py with AFJ in the mediator (yet). Why?
  • We need to understand the server side of the issue regardless.
  • If there is an inherent problem with ACA-Py on OpenShift, we need to know that independent of the Mediator use case.
  • We are much further away from an HA Mediator based on AFJ than with ACA-Py, and it may be best not to use either.
  • Switching out the mediator has a high complexity cost and we don't want to do that lightly. Either:
    • We must break all existing Wallet to Issuer Service connections, losing at least the "revocation notification" feature.
    • We run with both mediators, using the old one for existing connections, and creating new connections with the new mediator.
  • We would be much better off switching only when we know what mediator we want to use in the long term.
• We want to investigate without the overhead of releasing a special version of the BC Wallet that uses a different mediator for experimenting. As such, our first focus is replicating the issue on the Dev or Test Mediator with a script that @jleach created (https://github.com/fullboar/mediator-test-script) and then looking at the server side to see what is happening.

Agreed at the end of the meeting that we want to investigate and understand the issue with ACA-Py as the mediator implementation, and not go down the AFJ as mediator path at all (yet!). We can continue to increase the resources on the Prod mediator we have to try to limit the impact on existing users. Longer term we will look into the what a fully scalable mediator is and what we want to use.

[WadeBarnes]

There are three parts to an aca-py mediator. The aca-py agent, the wallet (postgres), and the proxy (Caddy). I just had a look at the proxy mediator after we adjusted the agent's resources to limits: CPU: 1000m, memory: 512Mi; requests: CPU: 1000m, memory: 256Mi. The proxy is not being throttled much at all even though it's resource have been set fairly low; <1%. The wallet on the other hand is being throttled about 50% of the time. I also noticed the agent is using an indy wallet which could be contributing to some of the issues.

[WadeBarnes]

Talking with @cvarjao, we're going to adjust the resources on the wallet too. I've found in the past the agent and the wallet need to be adjusted together when there are performance issues.

Edit: The wallet's recourses have been updated to limits: CPU: 800m, memory: 512Mi; requests: CPU: 800m, memory: 192Mi

[swcurran]

@WadeBarnes -- what are you calling "the wallet"? Caught me off guard at first, but I'm assuming you mean the "secure storage" for the Mediator? If so -- please use that term. In our world "wallet" means the Mobile Wallet App -- aka BC Wallet and it's very confusing if it used for something else.

[WadeBarnes]

Yes, I am referring to the secure storage for the mediator; the mediator agent's wallet database. I'll be sure to use the term secure storage in this context.

[swcurran]

First specific task (high level):

• Use Jason's script (or something else?) to simulate the BC Wallet and try to recreate the timeout problem against the Dev Mediator instance.
• Collaborate with the SRE Team as needed to adjust the Dev Mediator resources to make the problem more likely.
• Access the logs for the Mediator and correlate the timeouts you are seeing on the simulated wallet with what is happening with the Mediator.
• If necessary, set the logging higher (e.g. DEBUG) and/or use a customized (forked) ACA-Py Mediator that instruments the instance to produce more useful information from the Mediator.
• If at all possible (without publishing a custom wallet app) try to confirm that a real wallet triggers the same behaviour as the simulated wallet, to make sure we are seeing the same problem.

Once we have the issue reproduced consider how to address it:

• Is there a race condition or problem in the Mediator itself that is resulting in the timeout?
• Are messages being lost without a way to retry sending them?
  • ACA-Py 0.8.0 (not yet deployed) has a fix for this type of issue.
• What is the impact of adjusting the resource settings on the ease of creating timeouts?

After that, we'll think more about next steps.

[WadeBarnes]

I've updated the WebSocket heartbeat and timeout intervals for dev, test, and prod and set them all to ACAPY_WS_HEARTBEAT_INTERVAL=15 and ACAPY_WS_TIMEOUT_INTERVAL=60 as discussed here. Previously we had only updates test to do some performance testing.

[WadeBarnes]

Throttling stats since the config updates: Agent: <1% Throttled Database: <1% Throttled Proxy: <1% Throttled

[swcurran]

I’m interested in us getting the 0.8.0 ACA-Py deployed into this, as it explicitly has a fix for this issue. That might be sufficient to eliminate the timeouts. Hopefully our testing in the lower environments will see if this might eliminate the timeouts without the increased limits.

[swcurran]

@WadeBarnes — can we lower the resource usage on Dev and Test to be in the range we had it before when we were having trouble? We’re starting to do too many changes at a time, and so we don’t know what the impacts of the individual changes are having. The main one to understand — does the fix in 0.8.0 reduce the resource requirements without causing timeouts?

[jleach]

@WadeBarnes @swcurran Is this issue still a thing?

[WadeBarnes]

@jleach, @swcurran, Do we want to reduce the resource allocation in dev and/or test to see if the upgrade to ACA-Py 0.8.1 had any affect on some of the issues?

To answer @jleach, since the upgrade and "over provisioning" of the services we only see the occasional timeout when doing load testing.

[swcurran]

I’d say we should only lower the resources if we are going to do some testing on dev and test — e.g. before and after apples to apples tests. I’m sure we’re not causing anyone grief by leaving things where the are, so the only value in changing is to see if it makes a difference by deliberately testing. Given the minimal use of those mediator, unless we are specific, we’ll never see a problem.

[jeffaudette]

Closing issue, we have not seen any recent timeouts