AppFabric OutOfMemoryException as soon as the locally cached item expires

Question

I added quite a large xml file to the cache. The cache cluster timeout for stored objects is set to 120 seconds. The local cache is set to hold data for only 20 seconds. Now if I run my simple test application the "get" requests to my DataCache within the first 20 seconds succeed. Afterwards there's an awkward OutOfMemoryException.

Added 001 to cache with a retention time of 120 seconds.
DateTime: 10.07.2012 16:58:44, Retrieval took 00:00:00.0054096
DateTime: 10.07.2012 16:58:45, Retrieval took 00:00:00.0001192
DateTime: 10.07.2012 16:58:46, Retrieval took 00:00:00.0000575
DateTime: 10.07.2012 16:58:47, Retrieval took 00:00:00.0000581
DateTime: 10.07.2012 16:58:48, Retrieval took 00:00:00.0000600
DateTime: 10.07.2012 16:58:49, Retrieval took 00:00:00.0000715
DateTime: 10.07.2012 16:58:50, Retrieval took 00:00:00.0000597
DateTime: 10.07.2012 16:58:51, Retrieval took 00:00:00.0000656
DateTime: 10.07.2012 16:58:52, Retrieval took 00:00:00.0000586
DateTime: 10.07.2012 16:58:53, Retrieval took 00:00:00.0000748
DateTime: 10.07.2012 16:58:54, Retrieval took 00:00:00.0000636
DateTime: 10.07.2012 16:58:55, Retrieval took 00:00:00.0000709
DateTime: 10.07.2012 16:58:56, Retrieval took 00:00:00.0000583
DateTime: 10.07.2012 16:58:57, Retrieval took 00:00:00.0000709
DateTime: 10.07.2012 16:58:58, Retrieval took 00:00:00.0000662
DateTime: 10.07.2012 16:58:59, Retrieval took 00:00:00.0000609
DateTime: 10.07.2012 16:59:00, Retrieval took 00:00:00.0000603
DateTime: 10.07.2012 16:59:01, Retrieval took 00:00:00.0000611
DateTime: 10.07.2012 16:59:02, Retrieval took 00:00:00.0000575
DateTime: 10.07.2012 16:59:03, Retrieval took 00:00:00.0001092

Unhandled Exception: OutOfMemoryException.
Press any key to continue . . .


It's the client running out of memory - for no obvious reason. As you can see after 20s the local cache expires and the first request to the cache cluster fails with an OutOfMemoryException. And there is for free (and more than enough) memory available - I checked with procxp.

Any idea? Also some appfabric debugging information would be handsome.. e.g. I want to know if an object came from the local cache or over the wire.

Answer 1

You can figure out whether object is returned from Local cache or fetched from cluster from the cache client logs.

Are you using Appfabric 1.0 or 1.1 ? What is the xml size that you are trying to store ?

Answer 2

I am using AppFabric 1.1.
I provided multiple XML files for appfabric to chew on with the tiniest one being 5MB and the largest one being ~140MB. I already adjusted the MaxBufferSize on the client and server side. The file size is more of a theoretical nature... unfortunately I cannot rule out that at some point a file this big will actually be added to the cache.

factoryConfig.TransportProperties.MaxBufferSize = 104857600; // 100MB
factoryConfig.TransportProperties.MaxBufferPoolSize = 104857600 * 8;

It does work with my 20MB test xml file:

Added 001 to cache with a retention of 120 seconds.
DateTime: 16.07.2012 08:55:34, Retrieval took 00:00:00.0048349
DateTime: 16.07.2012 08:55:35, Retrieval took 00:00:00.0001206
DateTime: 16.07.2012 08:55:36, Retrieval took 00:00:00.0000583
DateTime: 16.07.2012 08:55:37, Retrieval took 00:00:00.0000581
DateTime: 16.07.2012 08:55:38, Retrieval took 00:00:00.0000586
DateTime: 16.07.2012 08:55:39, Retrieval took 00:00:00.0000578
DateTime: 16.07.2012 08:55:40, Retrieval took 00:00:00.0000575
DateTime: 16.07.2012 08:55:41, Retrieval took 00:00:00.0000578
DateTime: 16.07.2012 08:55:42, Retrieval took 00:00:00.0000684
DateTime: 16.07.2012 08:55:43, Retrieval took 00:00:00.0000575
DateTime: 16.07.2012 08:55:45, Retrieval took 00:00:00.8020041
DateTime: 16.07.2012 08:55:47, Retrieval took 00:00:00.7578474
DateTime: 16.07.2012 08:55:48, Retrieval took 00:00:00.0000603
DateTime: 16.07.2012 08:55:49, Retrieval took 00:00:00.0000740
DateTime: 16.07.2012 08:55:50, Retrieval took 00:00:00.0000597
DateTime: 16.07.2012 08:55:51, Retrieval took 00:00:00.0000743
DateTime: 16.07.2012 08:55:52, Retrieval took 00:00:00.0000595
DateTime: 16.07.2012 08:55:53, Retrieval took 00:00:00.0000583
DateTime: 16.07.2012 08:55:54, Retrieval took 00:00:00.0000782
DateTime: 16.07.2012 08:55:55, Retrieval took 00:00:00.0000589
DateTime: 16.07.2012 08:55:56, Retrieval took 00:00:00.0000589
DateTime: 16.07.2012 08:55:57, Retrieval took 00:00:00.0000620
DateTime: 16.07.2012 08:55:59, Retrieval took 00:00:01.2998903
DateTime: 16.07.2012 08:56:01, Retrieval took 00:00:00.7789897
DateTime: 16.07.2012 08:56:02, Retrieval took 00:00:00.0000597
DateTime: 16.07.2012 08:56:03, Retrieval took 00:00:00.0000804
DateTime: 16.07.2012 08:56:04, Retrieval took 00:00:00.0000592
DateTime: 16.07.2012 08:56:05, Retrieval took 00:00:00.0000592
DateTime: 16.07.2012 08:56:06, Retrieval took 00:00:00.0000826
DateTime: 16.07.2012 08:56:07, Retrieval took 00:00:00.0000969
DateTime: 16.07.2012 08:56:08, Retrieval took 00:00:00.0000854
DateTime: 16.07.2012 08:56:09, Retrieval took 00:00:00.0000824
DateTime: 16.07.2012 08:56:10, Retrieval took 00:00:00.0000628
DateTime: 16.07.2012 08:56:11, Retrieval took 00:00:00.0000603
DateTime: 16.07.2012 08:56:13, Retrieval took 00:00:01.2681243
DateTime: 16.07.2012 08:56:15, Retrieval took 00:00:00.7870086
DateTime: 16.07.2012 08:56:16, Retrieval took 00:00:00.0000676
DateTime: 16.07.2012 08:56:17, Retrieval took 00:00:00.0000606
Press any key to continue . . .

As you can see every 10s there's a spike. That's when AppFabric needs to get the file from the cluster rather than the local cache. (I wonder why it takes 2 requests before it is retrieved from the local cache again.)

My 71MB test file runs into the OutOfMemoryException.

I'll look into cache client logs. I know it uses ETW. That's what kept me from doing it until now. I don't like reading tons of event log messages. I'd prefer to have a flat trace log file. 

Answer 3

"why it takes 2 requests before it is retrieved from the local cache again .."  - this could be related to a Local Cache issue we fixed in a 1.1 QFE. Can you try installing the below update and see if this issue and the OutOfMemory problem get resolved.

http://support.microsoft.com/kb/2716015/en-US

Answer 4

I installed the "CU2" update. The setup process never completed on my (only) cache host. Reinstalling AppFabic from scratch helped.

There appear to be some powershell module signing issues here:

Do you want to run software from this untrusted publisher?
File C:\Program
Files\AppFabric\PowershellModules\DistributedCacheAdministration\Microsoft.Appl
icationServer.Caching.ManagementPS.format.ps1xml is published by CN=Microsoft
Corporation, OU=MOPR, O=Microsoft Corporation, L=Redmond, S=Washington, C=US
and is not trusted on your system. Only run scripts from trusted publishers.
[V] Never run  [D] Do not run  [R] Run once  [A] Always run  [?] Help
(default is "D"):R

Do you want to run software from this untrusted publisher?
File C:\Program
Files\AppFabric\PowershellModules\DistributedCacheAdministration\DistributedCac
heAdministration.psm1 is published by CN=Microsoft Corporation, OU=MOPR,
O=Microsoft Corporation, L=Redmond, S=Washington, C=US and is not trusted on
your system. Only run scripts from trusted publishers.
[V] Never run  [D] Do not run  [R] Run once  [A] Always run  [?] Help
(default is "D"):R

Anyway.. the second spike disappeared - good job there:

Added xmlfile (20MB) to cache with a retention of 120 seconds.
DateTime: 17.07.2012 08:52:52, Retrieval took 00:00:00.0049623
DateTime: 17.07.2012 08:52:53, Retrieval took 00:00:00.0001251
DateTime: 17.07.2012 08:52:54, Retrieval took 00:00:00.0000578
DateTime: 17.07.2012 08:52:55, Retrieval took 00:00:00.0000578
DateTime: 17.07.2012 08:52:56, Retrieval took 00:00:00.0000600
DateTime: 17.07.2012 08:52:57, Retrieval took 00:00:00.0000595
DateTime: 17.07.2012 08:52:58, Retrieval took 00:00:00.0000628
DateTime: 17.07.2012 08:52:59, Retrieval took 00:00:00.0000684
DateTime: 17.07.2012 08:53:00, Retrieval took 00:00:00.0000695
DateTime: 17.07.2012 08:53:01, Retrieval took 00:00:00.0000734
DateTime: 17.07.2012 08:53:03, Retrieval took 00:00:00.9190112
DateTime: 17.07.2012 08:53:04, Retrieval took 00:00:00.0000743
DateTime: 17.07.2012 08:53:05, Retrieval took 00:00:00.0000779
DateTime: 17.07.2012 08:53:06, Retrieval took 00:00:00.0000611
DateTime: 17.07.2012 08:53:07, Retrieval took 00:00:00.0000595
DateTime: 17.07.2012 08:53:08, Retrieval took 00:00:00.0000586
DateTime: 17.07.2012 08:53:09, Retrieval took 00:00:00.0001019
DateTime: 17.07.2012 08:53:10, Retrieval took 00:00:00.0000578
DateTime: 17.07.2012 08:53:11, Retrieval took 00:00:00.0000600
DateTime: 17.07.2012 08:53:12, Retrieval took 00:00:00.0000603
DateTime: 17.07.2012 08:53:14, Retrieval took 00:00:00.8378603
DateTime: 17.07.2012 08:53:15, Retrieval took 00:00:00.0000785
DateTime: 17.07.2012 08:53:16, Retrieval took 00:00:00.0000603
DateTime: 17.07.2012 08:53:17, Retrieval took 00:00:00.0000676
DateTime: 17.07.2012 08:53:18, Retrieval took 00:00:00.0000754
DateTime: 17.07.2012 08:53:19, Retrieval took 00:00:00.0000636
DateTime: 17.07.2012 08:53:20, Retrieval took 00:00:00.0000600
DateTime: 17.07.2012 08:53:21, Retrieval took 00:00:00.0000673
DateTime: 17.07.2012 08:53:22, Retrieval took 00:00:00.0000595
DateTime: 17.07.2012 08:53:23, Retrieval took 00:00:00.0000639
DateTime: 17.07.2012 08:53:25, Retrieval took 00:00:01.2882466
DateTime: 17.07.2012 08:53:26, Retrieval took 00:00:00.0000734

With my medium sized XML file (~70MB) the cache client still runs into an OutOfMemoryException when the file has been removed from the local cache and has to be retrieved from the cache cluster. For this test I set the buffersize on both the client and the cache host to 71 * 1024 * 1024 and pool size to 71 * 1024 * 1024 * 8. That should do, right?

Added xmlfile (71MB) to cache with a retention of 120 seconds.
DateTime: 17.07.2012 08:58:55, Retrieval took 00:00:00.0054794
DateTime: 17.07.2012 08:58:56, Retrieval took 00:00:00.0001449
DateTime: 17.07.2012 08:58:57, Retrieval took 00:00:00.0000972
DateTime: 17.07.2012 08:58:58, Retrieval took 00:00:00.0000595
DateTime: 17.07.2012 08:58:59, Retrieval took 00:00:00.0000664
DateTime: 17.07.2012 08:59:00, Retrieval took 00:00:00.0000595
DateTime: 17.07.2012 08:59:01, Retrieval took 00:00:00.0000625
DateTime: 17.07.2012 08:59:02, Retrieval took 00:00:00.0000597
DateTime: 17.07.2012 08:59:03, Retrieval took 00:00:00.0000776
DateTime: 17.07.2012 08:59:04, Retrieval took 00:00:00.0000636

Unhandled Exception: OutOfMemoryException.

Increasing the BufferSize to twice the file size doesn't help either.

Answer 5

Before caching please serialize and compress data while accessing , deserialize and decomress data

public static byte[] SerializeBinary(object obj)
        //{
        //    using (MemoryStream ms = new MemoryStream())
        //    {
        //        BinaryFormatter serializer; serializer = new BinaryFormatter();
        //        ms.Position = 0;

        //        serializer.Serialize(ms, obj);
        //        ms.Flush();
        //        return ms.ToArray();
        //    }
        //}
        //public static object DeSerializeBinary(MemoryStream ms)
        //{
        //    //using (MemoryStream ms = new MemoryStream())
        //    //{
        //    BinaryFormatter serializer; serializer = new BinaryFormatter();
        //    ms.Position = 0;
        //    object obj = serializer.Deserialize(ms);
        //    return obj;
        //    //}
        //}


        //public static byte[] CompressData(object obj)
        //{
        //    byte[] inb = SerializeBinary(obj);
        //    byte[] outb;
        //    using (MemoryStream ostream = new MemoryStream())
        //    {
        //        using (DeflateStream df = new DeflateStream(ostream, CompressionMode.Compress, true))
        //        {
        //            df.Write(inb, 0, inb.Length);
        //        } outb = ostream.ToArray();
        //    } return outb;
        //}

        //public static object DecompressData(byte[] inb)
        //{
        //    byte[] outb;
        //    using (MemoryStream istream = new MemoryStream(inb))
        //    {
        //        using (MemoryStream ostream = new MemoryStream())
        //        {
        //            using (System.IO.Compression.DeflateStream sr =
        //                new System.IO.Compression.DeflateStream(istream, System.IO.Compression.CompressionMode.Decompress))
        //            {
        //                sr.CopyTo(ostream);
        //            } outb = ostream.ToArray();
        //            return DeSerializeBinary(ostream);
        //        }
        //    }
        //}

Answer 6

Sorry for the late answer.

Is this some kind of work around? Doesn't AppFabric serialize data itself? I understand why you want to compress the data and it does work with an xml file, but not everything compresses as good as plain text. Is the size a general problem with appfabric?