StackExchange / StackExchange.Redis

General purpose redis client
https://stackexchange.github.io/StackExchange.Redis/
Other
5.85k stars 1.5k forks source link

Performance Issues #2644

Open elinun opened 5 months ago

elinun commented 5 months ago

I am currently using StackExchange.Redis version 2.1.58 (but my problem persists even after upgrading to 2.7.17), and I am having issues with SDK calls taking a long time to execute (1-5 seconds). I have added logging and have found that the lines taking a long time to execute are the call to IDatabase.KeyExistsAsync(string key) and call to Multiplexer.GetDatabase(). Using Wireshark, I noticed that even though the redis server responded near instantaneously, the KeyExistsAsync call still took over 1 second to complete. I have increased my min thread count to 300. My Slowlog is empty.

Here is my RedisCache class:

public class RedisCache : IRedisCache
    {
        private static Lazy<ConnectionMultiplexer> lazyConnection = null;
        private TelemetryClient telemetryClient = new TelemetryClient();

        public ConnectionMultiplexer Connection
        {
            get
            {
                return lazyConnection?.Value;
            }
        }

        public RedisCache(RedisConfig config)
        {
            InitRedis(config.ConnectionString);
        }

        public RedisCache(string connectionString)
        {
            InitRedis(connectionString);
        }

        public void InitRedis(string connectionString)
        {
            var startTime = DateTime.Now;
            if (lazyConnection == null)
            {
                var timer = Stopwatch.StartNew();
                telemetryClient.InstrumentationKey = ConfigurationManager.AppSettings.Get("AppInsightsKey");
                var deltaBackOffInMilliseconds = (int)TimeSpan.FromSeconds(5).TotalMilliseconds;
                var maxDeltaBackOffInMilliseconds = (int)TimeSpan.FromSeconds(20).TotalMilliseconds;

                lazyConnection = new Lazy<ConnectionMultiplexer>(() =>
                {
                    ConfigurationOptions configOptions = ConfigurationOptions.Parse(connectionString);
                    configOptions.AbortOnConnectFail = false;
                    configOptions.ConnectRetry = 5;
                    configOptions.ReconnectRetryPolicy = new ExponentialRetry(deltaBackOffInMilliseconds, maxDeltaBackOffInMilliseconds);
                    configOptions.ConnectTimeout = 30000;

                    var multiplexer = ConnectionMultiplexer.Connect(configOptions);

                    multiplexer.InternalError += (sender, args) =>
                    {
                        telemetryClient.TrackException(args.Exception);
                    };

                    multiplexer.ConnectionFailed += (sender, args) =>
                    {
                        telemetryClient.TrackException(args.Exception);
                    };

                    multiplexer.ConnectionRestored += (sender, args) =>
                    {
                        telemetryClient.TrackTrace($"Redis.ConnectionRestored: {args.EndPoint}");
                    };

                    multiplexer.ErrorMessage += (sender, args) =>
                    {
                        telemetryClient.TrackTrace($"Redis.ErrorMessage: {args.Message}");
                    };

                    return multiplexer;
                });

                timer.Stop();
                telemetryClient.TrackDependency(new DependencyTelemetry
                {
                    Data = "Init Redis - Create Multiplexer",
                    Duration = timer.Elapsed,
                    Timestamp = startTime,
                    Name = "Init Redis"
                });
            }
           else
           {
                telemetryClient.TrackDependency(new DependencyTelemetry
                {
                    Data = "Init Redis - Multiplexer Already Created",
                    Timestamp = startTime,
                    Name = "Init Redis"
                });
            }
        }

        private IDatabase OpenDB()
        {
            var startTime = DateTime.Now;
            var timer = Stopwatch.StartNew();

            int retryCounter = 5;
            IDatabase cache = null;
            int i = retryCounter;
            for (; i > 0; i--)
            {
                cache = Connection.GetDatabase(); // Retrieves, a light-weight, pass through object.
                if (cache != null)
                {
                    break;
                }
            }

            timer.Stop();
            var telemetry = new DependencyTelemetry
            {
                Data = "Redis - OpenDB",
                Duration = timer.Elapsed,
                Timestamp = startTime,
                Name = "Redis - OpenDB"
            };
            telemetry.Properties["Tries"] = (6 - i).ToString();
            telemetryClient.TrackDependency(telemetry);
            if (cache == null)
            {
                throw new Exception("Could not open Redis cache database.");
            }

            return cache;
        }

        public async Task<bool> StringSetAsync(string key, string value, TimeSpan expiration)
        {
            IDatabase cache = OpenDB();
            return await cache.StringSetAsync(key, value, expiration).ConfigureAwait(false);
        }

        public async Task<string> StringGetAsync(string key)
        {
            IDatabase cache = OpenDB();
            return await cache.StringGetAsync(key).ConfigureAwait(false);
        }

        public async Task KeyDeleteAsync(string key)
        {
            try
            {
                IDatabase cache = OpenDB();
                await cache.KeyDeleteAsync(key);
            }
            catch { /* Don't care */ }
        }

        public async Task<bool> KeyExistsAsync(string key)
        {
            try
            {
                IDatabase cache = OpenDB();
                return await cache.KeyExistsAsync(key).ConfigureAwait(false);
            }
            catch
            {
                return false;
            }
        }
  }

Then I am calling this class with the following code:

var redis = new RedisCache(connectionString);
bool exists = await redis.KeyExistsAsync(key);

These are the options specified in my connection string: ssl=True,sslprotocols=tls12,abortConnect=False

NickCraver commented 5 months ago

There's a lot more going on here because there's a full AppInsights in your get database path (all we do is return a ref btw - you can simply cache the database. That telemetry client is adding a lot of overhead comparing to anything we're doing. You'll want to try a base approach without any of that and build back up to see where your performance is tanking.