Many Redis requests are timing out and throwing errors

[nathanmarcos]

Describe the bug
After fixing the latest Redis outage (#3509) on version 1.27.0, the application started throwing millions of mget error: Timeout Error: Request timed out.. It seems that this is caused when small changes in latency between Router and Redis requests last longer than the default timeout of 1ms.

To Reproduce
Steps to reproduce the behavior:

1. Run Redis instance
2. Run Router with APQ set up with Redis
3. Submit request with persistedQuery hash in the extensions
4. See errors on router's terminal:

2023-08-21T10:32:44.655911Z  ERROR [trace_id=84abf715700bdc7accbbe5bf7cac366a] mget error: Timeout Error: Request timed out.
2023-08-21T10:32:44.676982Z  ERROR [trace_id=c18fb3e62220025ab1858ee3295446d3] mget error: Timeout Error: Request timed out.
2023-08-21T10:32:44.678350Z  ERROR [trace_id=776705431a03a9d0adda5ac8eb32380c] mget error: Timeout Error: Request timed out.

Expected behavior
Errors should not happen.

[o0Ignition0o]

It looks like the timeout is set to 1ms and not configurable, @Geal do you have any opinions on that?

                default_command_timeout_ms: 1,

[Geal]

That default option is too optimistic. Pergaps that should be configurable too, because it depends a lot on the production environment

[o0Ignition0o]

An other thing that eludes me at the moment is @nathanmarcos didn't see these errors before, is it because redis disconnected and didn't try to reconnect?

[nathanmarcos]

@o0Ignition0o, I think that’s not related since these errors occur when Redis is up and running. When the Router loses its connection to Redis, other errors in the logs become more frequent.

Example when you simply kill Redis when Router is running:

2023-08-22T17:31:36.846418Z  ERROR Client disconnected with error: Redis Error - kind: Canceled, details: Canceled.
2023-08-22T17:31:36.851909Z  ERROR Client disconnected with error: Redis Error - kind: IO, details: Os { code: 61, kind: ConnectionRefused, message: "Connection refused" }

Then when you spin it up again:

2023-08-22T17:33:10.182223Z  INFO Redis client reconnected.

I only copied one of each type of these logs, but actually, there were dozens of them.