"[when debugging] If you see hoof prints think horses, not zebras".
Hunt and Thomas, in The Pragmatic Programmer
Developing in the brave new world of managed memory and garbage collection we, in most cases, don't have to worry about the details of memory allocation and clean-up. However, when our application starts having memory issues, we can easily have a tendency to fall into one of two camps:
- Assuming all memory issues are memory leaks (i.e. objects not being disposed of properly)
- Assuming that garbage collection is not working as stated.
Both of these assumptions are flawed in one common way: they narrow our focus to a limited set of possibilities and that affects the way we approach the problem. Sparing you the cutesy saying about what happens when we ass-u-me, it is fair to say that assumptions cripple any debugging effort. Once we assume we lose control over the "scientific" process of debugging a problem. In this case we had a utility application consuming egregious amounts of data, 1 to 1.5 gb of memory just to process a queue. I immediately assumed a traditional memory leak, as we were dealing with MSMQ, MessageEnumerators, Messages, SqlConnections, SqlCommands etc, I figured something was not getting disposed of or was still gcroot-ed somewhere in the code.
Problem scenario: In a console application we are iterating thru 85,000 messages in a "dead-letter" queue to see if we can salvage the data that never made it to its destination, the database. As we iterate thru the queue we pass off each message to a handler designed for that particular type of message using a factory. The handler de-serializes the message body back into the original object, generates a SQL insert based on the message contents and inserts a row in the database. As each handler returns a result, messages are removed from or left on the MessageQueue. Rinse, repeat.
If we remove the call to the datalayer component that is writing the new rows in the DB, the memory issue goes away. So clearly we have some SqlProvider objects not getting disposed of, right? Wrong. In surgically adding back in the datalayer functionality one method at a time it becomes clear that just opening a connection to the database once is all it takes to create the issue. Comment out the line that creates the connection, no memory issue, add it back in the death spiral returns.
To see if I could reproduce that scenario with fresh code, I reproduce the functionality from the ground up in a Windows Form application to make debugging more friendly. I set up a few different scenarios and, just to make the experience more lively, I add some counters to the forms so I can see how many messages have been processed etc. I take all the same steps as described above and..... no memory issue. I start reviewing the code method by method to see what I am doing differently. I find nothing, everything is exactly the same.....except.....in the windows form I am publishing messages to the GUI using a quick and dirty "DoEvents" call in the loop, who wants to stare at a frozen form? Then it hits me, I remove the DoEvents and the memory issue is back. Now that I have, not an assumption, but the real problem description it doesn't take long to find the answer as the links below will point you to.
Maoni Article on Finalizers
Microsoft Whitepaper
Google Groups Thread
The short answer proved to be this: In console apps the Main() form is launched by default on a Single Threaded Apartment Thread (STA). The same is true of a Windows form app and it's GUI thread. The STA model keeps that thread safe from multi-threading issues, especially when using COM objects that are acting like they are all alone in the world. So, when a COM component is created, used and released on an STA thread, it needs to be finalized. The finalizer thread has to wait until it is "invited to the party" in order to finalize that object. If the STA thread is in a long running loop, and is not publishing messages (ala DoEvents, Thread.Join() etc) then the finalizer is blocked until the loop is done and the STA thread takes a breath. This explains how one database connection could kill this app. The connection was ready to be finalized, the finalizer queues up to process that but is blocked waiting for the STA thread to take a breath. Meanwhile the STA thread is cranking thru a huge Queue and leaving an Exxon Valdez size slick of managed objects who are waiting on guess who, the finalizer thread.
The suggested solution: add an MTAThread() attribute to the entry point of your application (Sub Main() ) to prompt the runtime to load your main thread in Multi Thread Apartment (MTA) mode, now the finalizer can sneak in and do its clean up even though the main loop is not making any effort to share.
So, it wansn't quite horses, but not full-bred zebras either. Either way it was a fun ride.
Back in school my teacher was not much on the formal aspects of the course he was teaching.He was instead, as I describe him, the kind of guy you could imagine living in his room with his PC, hacking away, his mom pushing crackers under the door and begging "You really should go out and get some friends dear." Perhaps because of that we spent less time in the text book and more time digging into just what the IDE, along with COM and MTS at the time, were doing underneath the hood to be "helpful". He often said that memorizing the text book would help you pass but that knowing what was really happening based on your code would give you a better ability to figure things out when debugging "weirdness". For some reason I thought of him just today. :-)
The "weirdness" in this case was that my IDE was doing strange stuff in debug mode, or so I thought at the time. I was trying to see why my property based on a config setting was never getting populated with the correct value. So I did the natural thing, I set a break point on the property get and fired it up. The basic code of the getter was this
Get
Dim prop As Boolean = False
Dim configVal As String = System.Configuration.ConfigurationSettings.AppSettings.Item("MyConfigKey")
If Not configval Is Nothing Then
prop = CBool(configVal)
End If
Return prop
End Get
Nothing fancy, but when debugging I found that the If statement never seemed to evaluate to true, and the if block never executed. The debugger would always jump to End If no matter what I set the value of configVal to in the command window. Somebody wiser than me once said something along the lines of "always look for the stupidest solution first", however with this "weirdness" I immediately launched into the "weirdness countermeasures". These included restarting the IDE, rebuilding the solution, bleaching the temp files in case I was somehow stuck with an old version of the file from a previous life, rebooting, rinse repeat. All of the maneuvers that have served well in the past when bizarre things happen in the IDE. No dice, still same issue every time.
Now it's time for last resort "I have no idea, but I'll try this" measures. In the past I have had lines of code that would not compile with no apparent error and only way to resolve the issue was to retype the line, visually identical to the "bad" line, and all-of-a-sudden the IDE was happy again and we moved on. Whatever! So I figured I would give that a try. As I was re-typing the code I found a bug, seemed stupid and meaningless at first, but it then hit me that it had been the issue all along. In my getter the actual code looked like this
Get
Dim prop As Boolean = False
Dim configVal As String = System.Configuration.ConfigurationSettings.AppSettings.Item("MyConfigKey")
If Not configval Is Nothing Then
prop = CBool(prop)
End If
Return prop
End Get
I was setting the prop variable to the result of CBool(prop) as boolean of itself, which would always mean no change to the variable. Then the lights in my dark and scary brain started to go on! The compiler was helping me! I compiled the code again and looked at the disassembly, first with the bug
If Not configval Is Nothing Then
00000036 test ebx,ebx
00000038 je 0000003A
End If
and then without
If Not configval Is Nothing Then
00000036 test esi,esi
00000038 je 0000004E
prop = CBool(configVal)
0000003a mov ecx,esi
0000003c call FFB91FD0
00000041 movzx edi,al
00000044 mov eax,edi
00000046 and eax,0FFh
0000004b mov dword ptr [ebp-8],eax
End If
The compile decided that the stupid line of code was irrelevant and simply removed it. So in debugging, since we are actually stepping through the debug symbols, not the code, there was no line of code to hit in that If block. So the supposed "weirdness" just turned out to be a bad cut and paste. Doh! If the compiler had left it in I would have seen the line execute with no change to the value of prop and found the bug right away. Instead I get all commando.
Anyway, I just had to share my brain cramp. When things seem "weird" don't forget:
a) the "always look for the stupidest solution first" rule still applies
b) don't forget what might be trying to "help" you under the hood.
Wanted to drop a quick post for two reasons: 1) To prove I have not died, been abducted by aliens, or been confined to a room with soft, cushy walls and a nerf PC for my own "protection". 2) To give a plug for someone I had an opportunity to work with this past week.
Our shop was in need of some SQL Server performance tuning. Not having the expertise in house we called in an outside consultant. Not having had the best experiences with outside "experts" in the past, I was skeptical. However, Ray Rankins and his Gotham Consulting seem to be the real deal. Not living in the SQL world day in and day out, I tend to leave the "deeper thoughts" to the DBA's and worry about the procs doing what I need when I need it. However, when it does come down to a proc that is dogging our application down, it would be nice to really understand why one syntax or set of indexes works so much better than another. Usually the approach to tuning a long running proc from a developer standpoint is "Well, that sucks, let's try something else" and "Wow, that sucks a lot less, let's do that!" Speaking with Ray this past week I found a man who knows, and seems to care, about what is happening under the hood in SQL Server as much as I do about the inner workings of the CLR. The longer I work in this field the more I realize that this kind of person is hard to find. In one ten minute conversation I now have a really good idea what a Clustered vs. a Non-Clustered index is, why it matters, what situations you would want to use either of them etc. Ray has written "the book" on SQL Server and is just making the final edits on the SQL 2005 edition. I think I will add it to my ever growing stack of books to read one rainy day.
As a new approach to some meaningful blogging, as I work on debugging some new bug/issue, the info I collect and my deductions I record right in my LiveWriter window so that I can save any links, code snippets etc. This way, with little effort, at the end of the day I can do some quick editing and post something "useful" (you may choose to retain your own definition of that word). A fringe benefit is that I can find this info again the next time I need it.
So here was the situation:
An ASP.NET application that leverages FormsAuthentication. The timeout is set in the web.config to 20 minutes in the authentication tag something like this:
Users were reporting intermittent timeouts that were significantly less than the 20 minutes. In testing we were unable to duplicate this scenario.
The other important detail, that we have omitted until now, is that we are "rolling our own" authentication ticket in order to have more control over what that ticket contains etc. So in code the default ticket timeout value (set as a constant) was 20 minutes.
So, now onto the mistaken assumptions. I had assumed that the web.config setting would come into effect the first time the ticket was updated. Being that it is a sliding expiration I had thought that the ticket would be updated to the web.config timeout the next time a page was requested. Since the user is redirected from the login page as a matter of course it was assumed (doh!) that the hard-coded timeout value would not last longer than a second or two. So, the first thing I did was set the web.config timeout to be 1 minute so that I could test without waiting 20 minutes. Waited a minute .... posted back ... no dice, still logged in. No matter what I set that value to I could not get kicked out if I tried. Only when I changed to constant to 1 in the code and recompiled was I able to get kicked out as expected. Ok, bad assumption, no big deal, we'll just change the code to read the config value when it sets the original ticket and then all will be in sync, right? Not so easy.
First of all, the values in that section of the config are protected, even from the guy writing the application. The normal system.configuration approach does not expose these values and the FormsAuthentication classes do not expose what you would think is a fairly useful property. So how do you make sure you are in sync with the config file? Doing some googling we find that Scott Hanselman ran into the same thing years ago, no surprise. Scott details his thought process in solving the same issue.
Scott addresses the pain of accessing the config setting from code so that the first creation of the ticket can match the desired setting from the web config. He considers the approach of creating an additional, accessible, config setting that would require being set in two places or creating an invalid situation. (i.e. one setting says expire in 20 minutes, one says 10 etc). He considers reflection, but deems it too ugly. Finally he settles on dynamically "discovering" the web.config, loading into a DOM and xpathing his way to the setting and storing in cache so he only has to do it once. Basically there is no clean work-around so you have to settle for a lesser of the evils approach.
So, armed with that information we start testing with our new found knowledge. We had written a test page to dump out the contents of the ticket to a text box so that we could see what expiration was actually being set. We set the original ticket being written by the code to a nice small value of 4 minutes and started to post the page back. Here comes the strangeness. As we post the page back the expiration time of the ticket does not change. We keep posting the page back every 15 seconds or so and eventually it decided it was time to update the ticket with a new expiration time. Now were really confused, this was, after all, a sliding expiration wasn't it? Every time the page posts back it was supposed to update the time to give another n minutes before it would be timed out. So back to digging, this time we pull up the MSDN documentation on the tag and the element. MSDN documentation on element attributes.
The msdn docs indicate that a sliding expiration does not really slide as you might imagine, and certainly may expire when you do not expect it to. Here is a priceless, if not a bit contradictory bit of MS wisdom: "If the SlidingExpiration attribute is true, the timeout attribute is a sliding value, expiring at the specified number of minutes after the time the last request was received. To prevent compromised performance, and to avoid multiple browser warnings for users that have cookie warnings turned on, the cookie is updated when more than half the specified time has elapsed. This might result in a loss of precision..", I guess! A "loss of precision"? Is that what we call a sliding expiration that doesn't slide and results in an effective timeout of only half what you think you set it to? So, because some people are afraid of the big bad cookie monster we are going to totally hose the well understood concept of a sliding expiration, with no "override this stupid default behavior" attribute in sight? That is insane. Now it's time to pull out Reflector and look for a clever workaround.
Inside the FormsAuthentication class we find the method that does just as described, renews the ticket only if the time left till expiration is greater than the time since the current ticket was issued.
Public Shared Function RenewTicketIfOld(ByVal tOld As FormsAuthenticationTicket) As FormsAuthenticationTicket
If (tOld Is Nothing) Then
Return Nothing
End If
Dim time1 As DateTime = DateTime.Now
Dim span1 As TimeSpan = DirectCast((time1 - tOld.IssueDate), TimeSpan)
Dim span2 As TimeSpan = DirectCast((tOld.Expiration - time1), TimeSpan)
If (span2 > span1) Then
Return tOld
End If
Return New FormsAuthenticationTicket(tOld.Version, tOld.Name, time1, (time1 + (tOld.Expiration - tOld.IssueDate)), tOld.IsPersistent, tOld.UserData, tOld.CookiePath)
End Function
Unfortunately the method is completely self contained and is not using any other settings to determine its results. It bases the decision on whether or not to update the ticket completely on the lifespan of the current ticket and the current time. If more then half the time has elapsed then you get a new one, period. So no work-around presents itself.
Something else we learn from this code is that, if you are manually setting the original ticket, the setting in the web.config, if different, never comes into play, since the renew method is basing its renew length on the originally set length of the ticket not your silly little timeout setting. This setting just gets more useless as we go on!
Now, if you use the out-of-the-box authorization that is provided in the framework and set your ticket using the FormsAuthentication.SetAuthCookie(username,isPersistent,cookiePath) method, the config setting will hold true when the ticket is created for you, however the non-sliding expiration issue still holds true.
So, enough pain for one day, how are we going to "fix" this so that the user has the result they expect, a 20 minute timeout? First we have to sync up our code creation of the first ticket with the web.config value. I wasn't fond of Scott's xml loading solution, although it would work. Since we found that, in our case, the web.config setting was moot anyway We opt for adding a new value to the web.config to explicitly set the value the code would use, afterward the framework would continue to re-apply this value as it refreshed the cookie. This does not provide any actual conflict, but it may provide some confusion as the app is deployed and maintained. The nice thing, for once, is that the timeout attribute on the element is optional and defaults to 30 minutes. Since it is never going to be applied, what do we care? So we remove the attribute and thus remove the apparent conflict in settings.
Now, what can we do about the non-sliding expiration? Well, it's been a long enough day, so we opt for the easy: "Just double it stupid" approach. This could, if we were relying completely on the forms authentication for timeouts, allow users, in some cases, to get anywhere from 20 to 40 minutes timeout, which would be considered a problem as well. However, since we are also requiring a fresh login when the session times out, we are covered. We set the config timeout to twice what the session timeout is and we are good. The shortest the ticket will live is 20 minutes between clicks, and if it lives longer than that the session will tank and all is well.
Now you may have a more elegant solution, so feel free to share...
Had to pass this along when I saw it here at
sitepoint, VirtualPC is now available for free!
Virtually unheard of! Here is link to the download for
VirtualPC 2004 SP1.
There is nothing sweet about spending hours, days, evenings and weekends chasing "ghosts" in your code. In this context "ghosts" mean compile or runtime errors that are not constant, only dreadfully persistent. Perhaps you also have been faced with the intermittent errors that look something along the lines of this:
Could not load type Foospace.FooWebService.FooWS.FooInfo from assembly mscorlib, Version=1.0.5000.0, Culture=neutral, PublicKeyToken=b77a5c561934e089
or
Could not load type 'FooSpace.Global'.
Now, huge caveat here, these types of error could be caused by a plethora of things, even perhaps a plethora of pinatas, but most would provide constant errors on every build or execution. I have found a surprising dearth of information on this scenario, its cause and resolution. So the situation I am about to describe may not match yours, but if it does I hope it helps.
Note first of all that the type I am failing to load is a type defined in a Web Service that my project is calling into. We can imagine that the FooWebService returns a type of FooInfo from a method called GetFoo. (What would we doo without foo?) This is a standalone service and as such does not share any references with our main application so that is enough info about that. Our main application, to start will just have one project: FooApp, it has a Web Reference defined pointing to FooWS and uses that to get and display FooInfo properties on the page when it loads. So far so good.
Now we start to build our application into a solution that we expect to get quite large so we start using Namespaces to categorize our projects. So now we go to our project properties and change the Root Namespace from the default FooApp to FooSpace. When we do this now our project won't run because our global.asax and our webform.aspx files have statements like this: Inherits="FooApp.WebForm1" that need to be changed to read Inherits="FooSpace.WebForm1". At this point something should be telling us that namespaces are more than just a way to organize our code and get pretty little intellisense dropdowns when we are defining our objects. Anyway, we shake off the annoyance and move on, once again our project loads and we are good. We also do the same for the FooWebService Project, as the first segment of the namespace is often a company or overall product name, this makes sense.
Now we add the ever essential FooLibrary project to our solution. To keep in form we change its root namespace to match our new structure, "Foospace". Notice the typo? the "S" is not the same case as our FooApp Root Namespace. Now Visual Basic is case insensitive, so it shouldn't care, right? Wrong, way wrong. In fact, it seems, the compiler can't tell the two apart so sometimes when it is looking for a resource to load it will use the correct namespace, other times it will not. To prove it to yourself, add a reference in your FooApp web project to the new FooLibrary. You don't even need to call anything, or add any import statements. You should start having issues right away. I was going to try to document all the different variations you might see based on your setup but here are a few.
So the basic point of this post is: A Namespace is case sensitive! Whatever .NET language you call home. Our shop ran into this well over a year ago. Just recently it came back into our solution by way of some new project namespacing that had been done and its "avatar" was completely different. On the first go-round we mostly had the issues loading global.asax, still intermittently build by build. On the latest flare up we had the error calling a Web Service well down in the application, once again random build to build. Because the evidence was so different we chased some ghosts before we, once again, identify the culprit. To be fair, I did find one blog that did mention this issue quite some time ago, so I will link to it here. Scroll down the page and look for the header: "VB & C# Casing Issues with VS.NET "
The recent project list on the start page of the Visual Studio IDE seems like such a cool thing at first glance. However, very quickly it degrades into the "How many times do I have to be reminded that I called my test project 'Son of Foo'" list. We end up with junk in there that is just plain annoying. Recently our shop made a move to Subversion for source control, finally giving Visual Source Safe the merciful lethal injection that it so deserved. In the process I cleaned up and moved my local working copy of code to a new folder. So now I not only was reminded of every time I created a test project named "WebApplication1" in the past month, but I also was faced with duplicate entries of "My Solution" in the list, one real one just a mirage. Needless to say I clicked on the mirage enough times to be motivated to google on how to clean up the recent project list. In doing so I found this very light-weight, and useful, util here. Thanks to Josh Beach (whoever you are) and the guys at CodeProject for this useful little number. It truly made my day.
Just a quick note on the quality level you can achieve when, out of an insane desire to have "a life", you throw together a blog after working till 2AM one night. Thanks to Johnny , not only for plugging my blog, but also for the heads up on the typo in my blog subtitle. No I don't have any "ovservations" to share with you today, but perhaps, some day soon an "observation" or two might show up. :-)
Most of my personal (read: "for fun") programming time lately has been involved with web design. Being much more comfortable hiding behind a nice solid business object, this is largely uncharted territory for me and, as such, provides the comfortable, nearly vertical, learning curve that we know and love. I decided up front that I was going to "do it right" and not fall back on the old <table> method of laying out the page contents. I had read, and heard, about the advantages of CSS based page layout, but had not had any direct exposure. In my research of what is available on the web I have collected a short list of valuable CSS resources that I wanted to share. So here goes...
The site that will make you a believer: CSS Zen Garden
Practical layout tips and tutorials: A List Apart
glish.com
I would say that, hands down, the AListApart site has been the most valuable so far, especially this article on how to use negative margin values along with column defining background images to define your 2 or 3 column layout all in CSS and have it degrade nicely. Sweet!
I have wanted to blog for about two years now. With all of the blog sites out there what held me back you ask? Two big questions: Where and What. The where was answered for me when Donny Mack responded to my request to blog here at DotNetJunkies. I can only imagine that he is not making an abundance, if any, profit from this venture so I appreciate very much the opportunity he is giving me to enter into the world of blogging on this site.
Some bloggers that I have worked with that are worthy of mention. Scott Stewart a mentor and friend who not only helped me get my first job programming in .NET but also helped me with the unavoidable learning curve coming from VB 6.0. Also, a brief encounter with Johnny Papa has left me with appreciation for, not only his prolific blogging skills, but also his project management abilities. Not many men come along that can walk the tightrope as effectively as he can.
Now for some bloggers that I wish I had worked with: Rocky, Scott Hanselman, Joel, Don Box just to name a few. Makes you wonder if some day "Andreas" will be enough to identify my blog, that's when I will know that I have really made it!
So, now that the "where" of my blogging aspirations has been addressed, the "what" comes to bear. As my blog theme indicates, I favor an object oriented approach to software development. I have come to appreciate, over time, that the "quick and easy" solutions are never really quick and are often less than easy to maintain. A true object model has saved me many an hour "hacking" what I would have built otherwise. I don't consider myself a purist by any means, but I will assert that most "programmers" that I have interacted with just do not get it. Somehow there seems to be a bit switch somewhere in the VB.Net (and beyond?) programing world; either you are a "just barely above Access" programmer who has heart palpitations whenever the "drag and drop" method doesn't work and you actually have to (shudder) edit the actual code, or you are an astronaut who is too intellectual to actually write code that works, you are far too busy discussing SOA, and other mystical Design Patterns. Not that design patterns are bad but let's be real; words mean things. If we are going to say we are "Object Oriented" let's actually do it, or if our decision is to be "Service Oriented"; that's OK, just be "Service Oriented".
That is all I have to say, for now. If you want more you will just have to wait along with all of the rest of the desperate masses. ;-)