Search code examples
.net-corestackexchange.redisheroku-redis

Receiving a timeout error when trying to use Heroku Data Redis with Stackexchange.Redis


Receiving the following error when trying to retrieve data from Heroku Data Redis on a .Net Core app hosted on Heroku using Docker, the cache works locally but I'm getting this error message when deployed to Heroku:

StackExchange.Redis.RedisTimeoutException: The timeout was reached before the message could be written to the output buffer, and it was not sent, command=HMGET, timeout: 60000, inst: 0, qu: 1, qs: 0, aw: False, bw: CheckingForTimeout, serverEndpoint: [amazon aws host:port], mc: 1/1/0, mgr: 10 of 10 available, clientName: d3d51ae0-3bd0-4434-8767-2028ec9f6c41(SE.Redis-v2.6.66.47313), IOCP: (Busy=0,Free=1000,Min=10,Max=1000), WORKER: (Busy=0,Free=32767,Min=10,Max=32767), POOL: (Threads=5,QueuedItems=0,CompletedItems=986), v: 2.6.66.47313 (Please take a look at this article for some common client-side issues that can cause timeouts: https://stackexchange.github.io/StackExchange.Redis/Timeouts)

Stack Trace:

2023-01-30T16:49:20.014624+00:00 app[web.1]: Stack Trace:
2023-01-30T16:49:20.014625+00:00 app[web.1]:
2023-01-30T16:49:20.014625+00:00 app[web.1]: at Microsoft.Extensions.Caching.StackExchangeRedis.RedisExtensions.HashMemberGetAsync(IDatabase cache, String key, String[] members)
2023-01-30T16:49:20.014626+00:00 app[web.1]: at Microsoft.Extensions.Caching.StackExchangeRedis.RedisCache.GetAndRefreshAsync(String key, Boolean getData, CancellationToken token)
2023-01-30T16:49:20.014626+00:00 app[web.1]: at Microsoft.Extensions.Caching.StackExchangeRedis.RedisCache.GetAsync(String key, CancellationToken token)
2023-01-30T16:49:20.014626+00:00 app[web.1]: at SudokuCollective.Cache.CacheService.GetByUserNameWithCacheAsync(IUsersRepository`1 repo, IDistributedCache cache, String cacheKey, DateTime expiration, ICacheKeys keys, String username, String license, IResult result) in /src/SudokuCollective.Api/SudokuCollective.Cache/CacheService.cs:line 1029
2023-01-30T16:49:20.014627+00:00 app[web.1]: at SudokuCollective.Data.Services.AuthenticateService.AuthenticateAsync(ILoginRequest request) in /src/SudokuCollective.Api/SudokuCollective.Data/Services/AuthenticateService.cs:line 89
2023-01-30T16:49:20.014627+00:00 app[web.1]: at SudokuCollective.Api.Controllers.V1.LoginController.PostAsync(LoginRequest request) in /src/SudokuCollective.Api/SudokuCollective.Api/Controllers/V1/LoginController.cs:line 80, License: , AppId: 0, RequestorId: 0
2023-01-30T16:49:20.014638+00:00 app[web.1]: StackExchange.Redis.RedisTimeoutException: The timeout was reached before the message could be written to the output buffer, and it was not sent, command=HMGET, timeout: 60000, inst: 0, qu: 0, qs: 0, aw: False, bw: CheckingForTimeout, serverEndpoint: ec2-3-221-27-134.compute-1.amazonaws.com:19570, mc: 1/1/0, mgr: 10 of 10 available, clientName: d3d51ae0-3bd0-4434-8767-2028ec9f6c41(SE.Redis-v2.6.66.47313), IOCP: (Busy=0,Free=1000,Min=10,Max=1000), WORKER: (Busy=1,Free=32766,Min=10,Max=32767), POOL: (Threads=5,QueuedItems=0,CompletedItems=1277), v: 2.6.66.47313 (Please take a look at this article for some common client-side issues that can cause timeouts: https://stackexchange.github.io/StackExchange.Redis/Timeouts)
2023-01-30T16:49:20.014638+00:00 app[web.1]: at Microsoft.Extensions.Caching.StackExchangeRedis.RedisExtensions.HashMemberGetAsync(IDatabase cache, String key, String[] members)
2023-01-30T16:49:20.014640+00:00 app[web.1]: at Microsoft.Extensions.Caching.StackExchangeRedis.RedisCache.GetAndRefreshAsync(String key, Boolean getData, CancellationToken token)
2023-01-30T16:49:20.014642+00:00 app[web.1]: at Microsoft.Extensions.Caching.StackExchangeRedis.RedisCache.GetAsync(String key, CancellationToken token)
2023-01-30T16:49:20.014643+00:00 app[web.1]: at SudokuCollective.Cache.CacheService.GetByUserNameWithCacheAsync(IUsersRepository`1 repo, IDistributedCache cache, String cacheKey, DateTime expiration, ICacheKeys keys, String username, String license, IResult result) in /src/SudokuCollective.Api/SudokuCollective.Cache/CacheService.cs:line 1029
2023-01-30T16:49:20.014644+00:00 app[web.1]: at SudokuCollective.Data.Services.AuthenticateService.AuthenticateAsync(ILoginRequest request) in /src/SudokuCollective.Api/SudokuCollective.Data/Services/AuthenticateService.cs:line 89
2023-01-30T16:49:20.014655+00:00 app[web.1]: at SudokuCollective.Api.Controllers.V1.LoginController.PostAsync(LoginRequest request) in /src/SudokuCollective.Api/SudokuCollective.Api/Controllers/V1/LoginController.cs:line 80

The cache is configured as follows in the Startup.cs file:

string cacheConnectionString = "";

ConfigurationOptions options;

if (!_environment.IsStaging())
{
    cacheConnectionString = Configuration.GetConnectionString("CacheConnection");

    options = ConfigurationOptions.Parse(Configuration.GetConnectionString("CacheConnection"));
}
else
{
    options = GetHerokuRedisConfigurationOptions();

    cacheConnectionString = options.ToString();
}

services.AddStackExchangeRedisCache(redisOptions => {
    redisOptions.Configuration = cacheConnectionString;
    redisOptions.ConfigurationOptions = options;
});

The GetHerokuRedisConfigurationOptions method configures the options as follows:

private static ConfigurationOptions GetHerokuRedisConfigurationOptions()
{
    // Get the connection string from the ENV variables
    var redisUrlString = Environment.GetEnvironmentVariable("REDIS_URL");

    // parse the connection string
    var redisUri = new Uri(redisUrlString);
    var userInfo = redisUri.UserInfo.Split(':');

    var config = new ConfigurationOptions
    {
        EndPoints = { { redisUri.Host, redisUri.Port } },
        Password = userInfo[1],
        AbortOnConnectFail = false,
        ConnectRetry = 3,
        ConnectTimeout = 60000,
        SyncTimeout = 60000,
        AsyncTimeout = 60000,
        Ssl = true,
        SslProtocols = System.Security.Authentication.SslProtocols.Tls12,
    };

    // Add the tls certificate
    config.CertificateSelection += delegate
    {
        var cert = new X509Certificate2("[path to pfx file]");
        return cert;
    };

    return config;
}

I suspected this could be a timeout issue so in the GetHerokuRedisConfigurationOptions method I set the timeouts to 60000 milliseconds but the issue persists. How can I register the IDistributedCache service so it can successfully retrieve data without the above timeout?


Solution

  • I was able to solve the issue. I believe docker wasn't saving the pfx certificate because I was getting authorization errors connecting to the ssl connection for Heroku Data Redis. I wasn't able to review the file system that Docker produced on Heroku but I logged information confirming the pfx file wasn't found. I think this is a security feature in Docker as you would want to limit dissemination of such files.

    In either case, since it is a self signed certificate you just need to disable peer verification. You can review the Heroku documentation as to how you do this for supported languages, in this case since we're running .Net Core through docker this is how I configured it:

    In Startup.cs:

    ConfigurationOptions options;
    
    string cacheConnectionString = "";
    
    if (!_environment.IsStaging())
    {
        options = ConfigurationOptions.Parse(Configuration.GetConnectionString("CacheConnection"));
    
        cacheConnectionString = Configuration.GetConnectionString("CacheConnection");
    }
    else
    {
        options = GetHerokuRedisConfigurationOptions();
    
        cacheConnectionString = options.ToString();
    }
    
    services.AddSingleton<Lazy<IConnectionMultiplexer>>(sp => 
        new Lazy<IConnectionMultiplexer>(() => 
        {
            return ConnectionMultiplexer.Connect(options);
        }));
    
    services.AddStackExchangeRedisCache(redisOptions => {
        redisOptions.InstanceName = "SudokuCollective";
        redisOptions.Configuration = cacheConnectionString;
        redisOptions.ConfigurationOptions = options;
        redisOptions.ConnectionMultiplexerFactory = () =>
        {
            var serviceProvider = services.BuildServiceProvider();
            Lazy<IConnectionMultiplexer> connection = serviceProvider.GetService<Lazy<IConnectionMultiplexer>>();
            return Task.FromResult(connection.Value);
        };
    });
    

    Then within Startup.cs I define a static method to initialize Heroku Redis configuration options:

    private static ConfigurationOptions GetHerokuRedisConfigurationOptions()
    {
        // Get the connection string from the ENV variables
        var redisUrlString = Environment.GetEnvironmentVariable("REDIS_URL");
    
        // parse the connection string
        var redisUri = new Uri(redisUrlString);
        var userInfo = redisUri.UserInfo.Split(':');
    
        var config = new ConfigurationOptions
        {
            EndPoints = { { redisUri.Host, redisUri.Port } },
            Password = userInfo[1],
            AbortOnConnectFail = true,
            ConnectRetry = 3,
            Ssl = true,
            SslProtocols = System.Security.Authentication.SslProtocols.Tls12,
        };
    
        // Disable peer certificate verification
        config.CertificateValidation += delegate { return true; };
    
        return config;
    }
    

    I believe that this line:

    config.CertificateValidation += delegate { return true; };
    

    Is the equivalent of the following Java documentation provided by Heroku:

    @Configuration
    class AppConfig {
    
        @Bean
        public LettuceClientConfigurationBuilderCustomizer lettuceClientConfigurationBuilderCustomizer() {
            return clientConfigurationBuilder -> {
                if (clientConfigurationBuilder.build().isUseSsl()) {
                    clientConfigurationBuilder.useSsl().disablePeerVerification();
                }
            };
        }
    }
    

    It basically disables certification verification. It now runs as expected.