Steve Wellens

Programming in the .Net environment

Sponsors

Links

February 2009 - Posts

Rock the Cache Bar, Rock the Cache Bar

It's possible you may develop dozens of web sites without ever doing any data caching. However, if you are trying to increase performance, data caching can be a key tool. The Asp.Net Cache object is remarkably easy to use, but it has many settings which makes it extremely powerful.

The only way to learn and get a good understanding of the Cache object's features is to experiment. To keep my experiment from being too tedious, I use short times.

In the Web.Config file, I set the Session timeout to be 2 minutes:

<system.web>
  <sessionState timeout="2">  </sessionState>
</system.web>

Stepping through the code with the debugger will interfere with timings...so trace statements are used. In order to get timestamps in the trace statements, I used a function in a static utility class I have:  ODS stands for Output Debug String:

static public class MiscUtilities
{ 
    /// ---- ODS ---------------------------------------
    /// <summary>
    /// Output Debug String with time stamp.
    /// </summary>
 
    public static void ODS(string Msg)
    {
        String Out = String.Format("{0}  {1}",
            DateTime.Now.ToString("hh:mm:ss.ff"), Msg);
        System.Diagnostics.Debug.WriteLine(Out);
    }

I was interested in how the Cache interacted with normal page events. In the Global.asax file, I trace the events with my utility function:

<%@ Application Language="C#" %>
 
<script RunAt="server">
 
    void Application_Start(object sender, EventArgs e)
    {
        MiscUtilities.ODS("****ApplicationStart");
    }        
    void Application_BeginRequest(object sender, EventArgs e) 
    {
        MiscUtilities.ODS("Application_BeginRequest");
    }
    void Application_EndRequest(object sender, EventArgs e)
    {
        MiscUtilities.ODS("Application_EndRequest");
    }
    void Session_Start(object sender, EventArgs e)
    {
        MiscUtilities.ODS("Session_Start");
    }
    void Application_End(object sender, EventArgs e)
    {
        MiscUtilities.ODS("Application_End");
    }
    void Application_Error(object sender, EventArgs e)
    {
        MiscUtilities.ODS("Application_Error " + Server.GetLastError().Message);
    }
    void Session_End(object sender, EventArgs e)
    {
        MiscUtilities.ODS("Session_End");
    }
</script>
 

To explain the test we need to know what Sliding Expiration is. When you tell a Cache to use Sliding Expiration and give it a TimeSpan of 5 minutes, it may never time out. Every time the cache object is accessed, the timer is reset. This is great, if a cached object is used a lot, it will remain cached. Rarely used cached objects will be released.

If we use Absolute Expiration, then we use a DateTime to supply a specific time to release the cached object. If you know a database will be updated at 1:00 AM, you may want to have a cached item released and reset at 2:00 AM.

Side Note: You can also set a Cached object to expired when a file has changed. I didn't test this but I can see how it would be useful to allow nontechnical people to update the text content on a web page.

One of the most intriguing features of the Cache object is that you can have a function called when a Cache object expires. This is the feature I was most interested in.

Since the cache going to be set in two places, I created a function so all the settings would be in one place. For this test I used a string, but any serializable object can be placed in the Cache. I set the Cached object to expire 5 seconds in the future. A delegate is created for the callback function.

private void InsertToCache(String Key, String Item)
{
    Item = Item + "+";   // append a char to the cached object
 
    MiscUtilities.ODS("Cache Inserted:  " + Key + "  " + Item);
 
    CacheItemRemovedCallback RemoveCallBack = new CacheItemRemovedCallback(onCacheRemove);
 
    Cache.Insert(Key, 
                 Item, 
                 null,
                 System.DateTime.Now.AddSeconds(5),
                 System.Web.Caching.Cache.NoSlidingExpiration,
                 System.Web.Caching.CacheItemPriority.Default,
                 RemoveCallBack);   
}

I set the callback function to re-insert the item into the Cache:

// ---- onCacheRemove --------------------
//
// Fires when an item is removed from the cache
 
private void onCacheRemove(string Key, object Item, CacheItemRemovedReason Reason)
{
    MiscUtilities.ODS("onCacheRemove: " + Key + "  " + Reason.ToString());
 
    // re-insert the item back into the cache
    InsertToCache(Key, Item.ToString());
}
 

And finally, here is how I kicked it of:

protected void Page_Load(object sender, EventArgs e)
{
    if (!IsPostBack)
    {
        InsertToCache("Key", "+");
    }      
}

Here is the output:

04:42:30.93  ****ApplicationStart
04:42:30.94  Application_BeginRequest
04:42:32.40  Session_Start
04:42:32.46  Cache Inserted:  Key  ++
04:42:32.64  Application_EndRequest
04:42:32.67  Application_BeginRequest
04:42:32.68  Application_EndRequest
04:42:40.01  onCacheRemove: Key  Expired
04:42:40.01  Cache Inserted:  Key  +++
04:43:00.01  onCacheRemove: Key  Expired
04:43:00.01  Cache Inserted:  Key  ++++
04:43:20.01  onCacheRemove: Key  Expired
04:43:20.01  Cache Inserted:  Key  +++++
04:43:40.01  onCacheRemove: Key  Expired
04:43:40.01  Cache Inserted:  Key  ++++++
04:44:00.01  onCacheRemove: Key  Expired
04:44:00.01  Cache Inserted:  Key  +++++++
04:44:20.01  onCacheRemove: Key  Expired
04:44:20.01  Cache Inserted:  Key  ++++++++
04:44:40.01  onCacheRemove: Key  Expired
04:44:40.01  Cache Inserted:  Key  +++++++++
04:44:40.01  Session_End
04:45:00.01  onCacheRemove: Key  Expired
04:45:00.01  Cache Inserted:  Key  ++++++++++
04:45:20.01  onCacheRemove: Key  Expired
04:45:20.01  Cache Inserted:  Key  +++++++++++

Interesting Note 1:

Cached objects are independent of sessions. After the session that created the Cache object expired, the object lived on. Cached objects are shared across sessions and last for the duration of the application. If you have one hundred simultaneous users and they all need a static customer list from the database, you can save a boatload of database calls by caching the list.

Interesting Note 2:

I set the expiration date to be 5 seconds in the future but the Cached object expired every 20 seconds. What's that all about? I experimented with different time values:

Time to Expire (secs)

Time Actually Expired (secs)

3

20

5

20

20

40

30

40

50

60

70

80

Ahhh, there must be a thread that checks every 20 seconds for expired objects.

Interesting Note 3:

Two of the parameters of the Cache Insert function are

DateTime absoluteExpiration,
TimeSpan slidingExpiration

They are used like this:

Cache.Insert(Key, 
             Item, 
             null,
             System.DateTime.Now.AddSeconds(5),
             System.Web.Caching.Cache.NoSlidingExpiration,
             System.Web.Caching.CacheItemPriority.Default,
             RemoveCallBack);   

Or like this:

Cache.Insert(Key,
             Item,
             null,
             System.Web.Caching.Cache.NoAbsoluteExpiration,
             new TimeSpan(0, 0, 30),
             System.Web.Caching.CacheItemPriority.Default,
             RemoveCallBack);

The person who designed this used a trick. He created dummy variables with the correct type and gave them "Flag Names".

namespace System.Web.Caching
{
    public sealed class Cache : IEnumerable
    {
        public static readonly DateTime NoAbsoluteExpiration;
        public static readonly TimeSpan NoSlidingExpiration;

This allows the "flags" to be passed where a DateTime or TimeSpan is expected. While I admire the cleverness, I would have used an enum.

I hope someone finds this useful, or at least interesting.

Steve Wellens

ILDasm Helpful Hack

I do not want to learn "yet another programming language", especially a low-level one like Microsoft's Intermediate Language (IL). And yet, sometimes it's useful to look under the hood and see what in tarnation is going on. And that means knowing something about IL.

I was answering a question on optimization (the root cause of a lot of unmaintainable code) and found it useful to generate the IL to show which of two algorithms was quicker. With modern operating systems having dozens of background threads running, simple timing can lead to misleading results. Is the algorithm slow, or was System Restore creating a restore point when we measured?

In order to examine code in IL, it's helpful to delimit sections. But we can't use comments, they are stripped out. So, here is a cheesy way to delimit sections of code. Note the variables assigned to MyInt:

namespace ConsoleApplication1
{
    class Program
    {
        static void Main(string[] args)
        {                      
            string MyString = string.Empty;
            int MyInt;
 
            MyInt = 0xAAAAAAA; // ---- Marker: algorithm A
 
            if (MyString == String.Empty)
                MyInt = 1;
            else
                MyInt = 2;
 
            MyInt = 0xBBBBBBB;  // ---- Marker: algorithm B
 
            MyInt = MyString == String.Empty ? 1 : 2;
 
            MyInt = 0xCCCCCCC;  // ---- Marker: end test.
        }
    }

When you create the IL with ILDasm, you can easily see where the markers are. In this case I bolded and underlined them:

  .method private hidebysig static void  Main(string[] args) cil managed
  {
    .entrypoint
    // Code size       68 (0x44)
    .maxstack  2
    .locals init ([0] string MyString,
             [1] int32 MyInt,
             [2] bool CS$4$0000)
    IL_0000:  nop
    IL_0001:  ldsfld     string [mscorlib]System.String::Empty
    IL_0006:  stloc.0
    IL_0007:  ldc.i4     0xaaaaaaa
    IL_000c:  stloc.1
    IL_000d:  ldloc.0
    IL_000e:  ldsfld     string [mscorlib]System.String::Empty
    IL_0013:  call       bool [mscorlib]System.String::op_Equality(string,string)
    IL_0018:  ldc.i4.0
    IL_0019:  ceq
    IL_001b:  stloc.2
    IL_001c:  ldloc.2
    IL_001d:  brtrue.s   IL_0023
    IL_001f:  ldc.i4.1
    IL_0020:  stloc.1
    IL_0021:  br.s       IL_0025
    IL_0023:  ldc.i4.2
    IL_0024:  stloc.1
    IL_0025:  ldc.i4     0xbbbbbbb
    IL_002a:  stloc.1
    IL_002b:  ldloc.0
    IL_002c:  ldsfld     string [mscorlib]System.String::Empty
    IL_0031:  call       bool [mscorlib]System.String::op_Equality(string, string)
    IL_0036:  brtrue.s   IL_003b
    IL_0038:  ldc.i4.2
    IL_0039:  br.s       IL_003c
    IL_003b:  ldc.i4.1
    IL_003c:  stloc.1
    IL_003d:  ldc.i4     0xccccccc
    IL_0042:  stloc.1
    IL_0043:  ret
  } // end of method Program::Main
 

A quick look at the IL code should tell you which algorithm is fastest…and you don't even have to be a rocket surgeon.

But, of course, as any seasoned developer will tell you: "It's the maintenance stupid!"

I hope you find this helpful.

Steve Wellens

[Update]

My friend Svante pointed out to me that it is the JIT that does the final optimization and you can’t really go by IL to determine which algorithms are quicker.  He is correct.

To look at the JIT output…

Go to Tools->Options->Debugging->General and unclick "Suppress JIT optimization on module load."  You want the optimization.
Add a breakpoint to the code. Run the program, when the breakpoint hits, right-click the source code and select "Go to Disassembly."   I removed the "markers" because they are no longer needed.

JIT Output (edited):

                if (MyString == String.Empty)
    00000050  mov         edx,dword ptr ds:[02CC102Ch]
    00000056  mov         ecx,dword ptr [ebp-40h]
    00000059  call        6A625FB8
    0000005e  mov         dword ptr [ebp-4Ch],eax
    00000061  cmp         dword ptr [ebp-4Ch],0
    00000065  sete        al  
    00000068  movzx       eax,al
    0000006b  mov         dword ptr [ebp-48h],eax
    0000006e  cmp         dword ptr [ebp-48h],0
    00000072  jne         0000007E
                    MyInt = 1;
    00000074  mov         dword ptr [ebp-44h],1
    0000007b  nop             
    0000007c  jmp         00000085
                else
                    MyInt = 2;
    0000007e  mov         dword ptr [ebp-44h],2

 

                MyInt = MyString == String.Empty ? 1 : 2;
    0000008c  mov         edx,dword ptr ds:[02CC102Ch]
    00000092  mov         ecx,dword ptr [ebp-40h]
    00000095  call        6A625FB8
    0000009a  mov         dword ptr [ebp-50h],eax
    0000009d  cmp         dword ptr [ebp-50h],0
    000000a1  jne         000000AD
    000000a3  nop             
    000000a4  mov         dword ptr [ebp-54h],2
    000000ab  jmp         000000B4
    000000ad  mov         dword ptr [ebp-54h],1
    000000b4  mov         eax,dword ptr [ebp-54h]
    000000b7  mov         dword ptr [ebp-44h],eax

I hope this extra information is helpful to someone.

C# Nullable Types…Subtlety

While moderating posts over on the Asp.Net forums, I ran into a thread containing questions about using Nullable types.

Nullable types are a simple concept: Allow value types to have the value of null. Typically, an integer or float cannot be null: When in scope, they always exist and therefore must have a numeric value (zero is not null, it is a numeric value).

Here is the subtlety (or in technical terms, a really ooky statement):

Nullable types with the value of null are not really null.

Look at this code:

    int    Test1 = 0;       // standard value type
    int?   Test2 = null;    // nullable value type         
    Object Test3 = null;    // reference type
 
    Response.Write("Test1: " + Test1.ToString() + "<br />");
    Response.Write("Test2: " + Test2.ToString() + "<br />");
    //Response.Write("Test3: " + Test3.ToString() + "<br />");
 
    // Output:
    //
    // Test1: 0   // correct
    // Test2:     // no exception, what? but it's null!
    //
    // If Test3 is allowed to run, we get:
    //   "Object reference not set to an instance of an object."

 It is odd that we can access Test2 when its value is null but we get no output string.

Microsoft's web site correctly describes nullable types (http://msdn.microsoft.com/en-us/library/1t3y8s4s.aspx):

"A nullable type can represent the correct range of values for its underlying value type, plus an additional null value."

But most of us gloss over descriptions like that and until you see it demonstrated, you may not truly understand.

I hope someone finds this useful, Steve Wellens.

Debugging a Deployed Site

"It works on my machine."

How many times have we heard that?  Getting something to work on other machines, after deployment, can be the final challenge in a successful project.  The worst case scenario is having to go to the problem machine (hopefully it isn't in the remote reaches of Siberia) installing the IDE, patches, source code, third party libraries, compiling and then debugging.  It's not a pleasant task.

An often overlooked but useful tool is:  System.Diagnostics.Debug.WriteLine(...)

Here are some sample lines in global.asax:

<%@ Application Language="C#" %>
 
<script RunAt="server">
 
    void Application_Start(object sender, EventArgs e)
    {
        System.Diagnostics.Debug.WriteLine("****ApplicationStart");
    }
    void Application_BeginRequest(object sender, EventArgs e) 
    {
        System.Diagnostics.Debug.WriteLine("Application_BeginRequest");
    }
    void Application_EndRequest(object sender, EventArgs e)
    {
        System.Diagnostics.Debug.WriteLine("Application_EndRequest");
    }
    void Session_Start(object sender, EventArgs e)
    {
        System.Diagnostics.Debug.WriteLine("Session_Start");
    }

Here is what the outputs look like in Visual Studio: Debug->Windows->Output. I turned off the Module Load messages to keep the output cleaner. An interesting thing to note is that the first Application_BeginRequest triggers the Session_Start event. Clicking a button a few times generates the other Application_BeginRequest events.

   

So far so good, but how does this help debugging on a deployed machine? The answer is by using a free tool called DebugView from Sysinternals.  Microsoft has acquired Sysinternals so you can search Microsoft's web site to download it.

Here is the same output captured by DebugView. The extra lines are caused by a Sound Card device driver on the host machine (the developers may have made a mistake).

   

Notes:

1)  Depending on the operating system, you may need to turn on global capturing of events in DebugView:

Capture->Capture Global Win32

2)  Debugging strings are turned off when compilation debug is false in web.config. To get the debug strings to work, debug must be "true"

<compilation debug="true" strict="false" explicit="true">

3)  If you run the site in Visual Studio, you will not see the strings in DebugView. 

I hope you find this information useful.

Steve Wellens

More Posts