Memory Cache .Net 4.0 performance test : astonishing result

Question

This performance test is wrong or the system cache is working with exceptional performance?

This is my result :
[13] number of interactions 100000 : 63 milliseconds
[14] number of interactions 100000 : 139 milliseconds
[12] number of interactions 100000 : 47 milliseconds
[15] number of interactions 100000 : 44 milliseconds
End of test.

Hardware : x86 Family 6 Model 23 Stepping GenuineIntel ~2992 Mhz 3.327 MB, 5.1.2600 Service Pack 3

using System;
using System.Collections.Generic;
using System.Runtime.Caching;
using System.Diagnostics;
using System.Threading;

namespace CacheNet40
{
    public class CacheTest
    {
        private ObjectCache cache;

        public CacheTest()
        {
            cache = MemoryCache.Default;
        }

        public void AddItem(CacheItem item, double span)
        {
            CacheItemPolicy cp = new CacheItemPolicy();
            cp.SlidingExpiration.Add(TimeSpan.FromMinutes(span));

            cache.Add(item, cp);
        }
        public Object GetItem(string key)
        {
            return cache.Get(key);
        }
    }

    class Program
    {        
        private static CacheTest Cache = new CacheTest();
        private static string allowedChars = "abcdefghijkmnopqrstuvwxyzABCDEFGHJKLMNOPQRSTUVWXYZ0123456789!@$?_-";
        private static int counter = 0;
        private static readonly object locker = new object();

        static string CreateRandomString(int passwordLength, int idx)
        {            
            char[] chars = new char[passwordLength];
            Random rd = new Random((int)DateTime.Now.Ticks + idx);

            for (int i = 0; i < passwordLength; i++)
            {
                chars[i] = allowedChars[rd.Next(0, allowedChars.Length)];
            }
            return new string(chars);
        }

        private static void CacheAccessTes()
        {
            int span = 5;
            string key;
            string data;
            int itens = 1000;
            int interactions = 100000;
            int cont = 0;
            int index = 0;
            List<string> keys = new List<string>();

            lock (locker)
            {
                counter++;
            }

            cont = itens;

            //populates it with data in the cache
            do
            {                
                key = CreateRandomString(127, Thread.CurrentThread.ManagedThreadId + cont);
                keys.Add(key);

                data = CreateRandomString(156000, Thread.CurrentThread.ManagedThreadId + cont + 1);

                CacheItem ci = new CacheItem(key, data);
                Cache.AddItem(ci, span);

                cont--;
            }
            while (cont > 0);

            cont = interactions;
            index = 0;

            //test readings
            Stopwatch stopWatch = new Stopwatch();
            stopWatch.Start();            
            do
            {
                Object ci = Cache.GetItem(keys[index]);

                ci = null;
                index++;
                if (index == itens)
                {
                    index = 0;
                }

                cont--;
            }
            while (cont > 0);
            stopWatch.Stop();

            lock (locker)
            {
                counter--;
            }

            string outstring = String.Format("[{0}] number of interactions {1} : {2} milliseconds", Thread.CurrentThread.ManagedThreadId, interactions, stopWatch.ElapsedMilliseconds );
            Console.WriteLine(outstring);
        }

        static void Main(string[] args)
        {
            for (int threads = 0; threads < 4; threads++)
            {
                Thread thread = new Thread(new ThreadStart(CacheAccessTes));
                thread.Start();
            }

            Thread.Sleep(1000);

            while (true)
            {
                lock (locker)
                {
                    if (counter == 0) break;
                }
                Thread.Sleep(100);
            }

            Console.WriteLine("End of test.");
            Console.ReadLine();
        }
    }
}

Answer 1

I've just searched the net for information on MemoryCache performance and stumbled upon this SO question. I asked myself why a proper benchmark library wasn't used, so I've ended up cooking my own benchmark by being very lazy (as all good programmers should :-) and used the incredible BenchmarkDotNet library to check how well (or not) this class behaves.

First the results

BenchmarkDotNet=v0.11.5, OS=Windows 10.0.17134.706 (1803/April2018Update/Redstone4)
Intel Core i5-8250U CPU 1.60GHz (Kaby Lake R), 1 CPU, 8 logical and 4 physical cores
Frequency=1757813 Hz, Resolution=568.8887 ns, Timer=TSC
  [Host]     : .NET Framework 4.7.2 (CLR 4.0.30319.42000), 64bit RyuJIT-v4.7.3394.0
  DefaultJob : .NET Framework 4.7.2 (CLR 4.0.30319.42000), 64bit RyuJIT-v4.7.3394.0



|                         Method |     N |      Mean |     Error |    StdDev |
|------------------------------- |------ |----------:|----------:|----------:|
|            FindDadosEmpInCache | 30000 | 231.40 ns | 0.4435 ns | 0.3703 ns |
|               FindDataAtTheEnd | 30000 | 429.90 ns | 1.1490 ns | 1.0186 ns |
|           FindDataInDictionary | 30000 |  24.09 ns | 0.2244 ns | 0.2099 ns |
| FindDataInConcurrentDictionary | 30000 |  29.66 ns | 0.0990 ns | 0.0926 ns |
|              FindDataInHashset | 30000 |  16.25 ns | 0.0077 ns | 0.0065 ns |

Now some explaining...

I was mostly interested in seeing how fast MemoryCache would compare to hashed lists (Dictionary, Hashset...) with thousands of entries and also to a worst case linear search over such "long" list. So I've added some additional tests and realized that while MemoryCache is not as fast as the simple or concurrent lists, the speed still lies at the nanosecond scale. Not even a single millisecond is taken to retrieve an item in a 30,000 long list of cached items.

To be fair MemoryCache does a LOT more than those simple lists as it must control concurrency, item expiration/eviction, etc. I believe it is fast enough for all kinds of workloads, but if you don't need its added features, like eviction policies, you should better stick with the simpler hashed lists implementations.

On the other hand, since it's an order a magnitude "slower" than a hash lookup, there may be room for improvement. I guess the designers thought it is just good enough as it is, and who am I to disagree with the DOTNET engineers? :-)

Here is the source code for the benchmark program:

using BenchmarkDotNet.Attributes;
using BenchmarkDotNet.Running;
using System;
using System.Collections.Concurrent;
using System.Collections.Generic;
using System.Linq;
using System.Runtime.Caching;

namespace TestListPerformance
{
    class Program
    {
        static void Main(string[] args) {
            var summary = BenchmarkRunner.Run<BenchmarkMemoryCache>();
        }
    }

    public class BenchmarkMemoryCache
    {
        [Params(30000)]
        public int N { get; set; }
        public string FindStr;
        private IList<DadosEmp> data;
        private Dictionary<string, DadosEmp> dict;
        private ConcurrentDictionary<string, DadosEmp> concurrentDict;
        private HashSet<DadosEmp> hashset;
        private DadosEmp last;

        [GlobalSetup]
        public void BuildData() {
            FindStr = N.ToString();
            data = new List<DadosEmp>(N);
            dict = new Dictionary<string, DadosEmp>(N);
            concurrentDict = new ConcurrentDictionary<string, DadosEmp>();
            hashset = new HashSet<DadosEmp>();
            for (int i = 0; i <= N; i++) {
                DadosEmp d;
                data.Add(d = new DadosEmp {
                    Identificacao = i,
                    Pis = i * 100,
                    NumCartao = i * 1000,
                    Nome = "Nome " + i.ToString(),
                });
                MemoryCache.Default.Add(i.ToString(), d, 
                    new CacheItemPolicy { SlidingExpiration = TimeSpan.FromMinutes(30) });
                dict.Add(i.ToString(), d);
                concurrentDict.TryAdd(i.ToString(), d);
                hashset.Add(d);
                last = d;
            }
        }
        [Benchmark]
        public DadosEmp FindDadosEmpInCache() {
            var f = (DadosEmp)MemoryCache.Default.Get(FindStr);
            return f;
        }
        [Benchmark]
        public DadosEmp FindDataAtTheEnd() {
            var f = data.FirstOrDefault(e => e.NumCartao == N || e.Pis == N || e.Identificacao == N);
            return f;
        }
        [Benchmark]
        public DadosEmp FindDataInDictionary() {
            var f = dict[FindStr];
            return f;
        }
        [Benchmark]
        public DadosEmp FindDataInConcurrentDictionary() {
            var f = concurrentDict[FindStr];
            return f;
        }
        [Benchmark]
        public bool FindDataInHashset() {
            return hashset.Contains(last);
        }

    }

    public class DadosEmp : IEquatable<DadosEmp> 
    {
        public const string BIO_EXCLUSAO = "xbio";

        public DadosEmp() {
            Biometrias = new List<string>();
        }
        public long Identificacao { get; set; }
        public long Pis { get; set; }
        public long NumCartao { get; set; }
        public string Nome { get; set; }
        public int VersaoBio { get; set; }
        public string Unidade { get; set; }
        public IList<string> Biometrias { get; set; }
        public string Biometria { get; set; } 
        public bool ExcluirBiometria { get { return Biometria == BIO_EXCLUSAO; } }
        public DateTime DataEnvioRep { get; set; } 
        public string SenhaTeclado { get; set; }
        public bool ExigeAutorizacaoSaida { get; set; }
        public bool BioRepPendente { get; set; }
        public override bool Equals(object obj) {
            DadosEmp e = obj as DadosEmp;
            if (ReferenceEquals(e, null))
                return false;
            return Equals(e);
        }
        public bool Equals(DadosEmp e) {
            if (ReferenceEquals(e, null))
                return false;
            return e.Pis == this.Pis;
        }
        public override int GetHashCode() {
            return Pis.GetHashCode();
        }
        public override string ToString() {
            return string.Format("{0} ({1} - {2})", Nome, Pis, Identificacao);
        }
    }
}

Answer 2

Looks good. Although timings below a second are not very reliable; you might have run into a garbage collect, your PC might do something else for a short while, first time JIT compile etc.

So increase the count. Which should also make the results for each thread end up closer together.

Some test I did last week made it to eight million iterations per second (doing not a lot, but still) singlethreaded. So yes, PC's are fast these days ;-)

Answer 3

The problem is the StopWatch class which can't be used on multi-core machines! (I'm assuming you have a multi-core CPU) Something to do with how the BIOS handles that counter when a thread moves from one core to another (even a single threaded application jumps cores!).

Edit:
Check out - http://msdn.microsoft.com/en-us/library/windows/desktop/ms644904(v=vs.85).aspx - specifically the remarks section. There is a stackoverflow post as well - Multicore and thread aware .Net stopwatch?. End Edit

I have searched high and low for the best method to measure app performance and the most reliable I have come up with is DateTime.UtcNow. Get the start and end time and then take the difference between them. You have to loop your code enough to get past the low precision, but no other method I have come across gives more reliable accuracy.

Answer 4

On my machine, it's about 40 ms, or 400 ns per GetItem call.

I traced the calls under debugger, it's about 2000 instructions per GetItem on my I7 machine. That is more than I would expect.