Andy Hopper's Blog

Windows 2008 + MacBook Pro == Happy Andy

ahopper — Tue, 03 Jun 2008 00:07:00 GMT

I have now been running Windows 2008 on a MacBook Pro for over a month, and I have to report that it's the only way to fly. This thing is ever so shiny, light, and FAST. I'm running the x64 flavor of 2008, and it truly is Vista the way Vista should have been.

However, being a dev, I can't just leave it at that; I must complain about something! While Boot Camp has done a great job at providing drivers for the hardware, there are some notable hiccups; the Bluetooth drivers appear to be out of date (I've checked; the hardware IDs for my MBP's hardware look to be from a newer version of the hardware than the drivers know to look for), tap to click is AWOL, and S3 sleep sometimes decides to fail (the machine refuses to sleep and the screen blacks out - and will remain so until a hard reboot). All that being said, I still highly recommend it.

Now, if I can just find a way to replace that glowing Apple logo on the back of the LCD with a Windows logo...

Fantastic news from the development tools front!

ahopper — Thu, 29 May 2008 11:52:00 GMT

When I left Microsoft, I felt pretty sad. Not only would I leave a bunch of great friends behind (and REALLY good benefits) - I was leaving my beloved Toolbox behind! (Toolbox is an internal site that has TONS of tools and apps written by Microsoft employees) So, imagine my intense happiness when some of my favorite tools finally surfaced for public consumption!

Microsoft Source Analysis for C# - This was called StyleCop inside the walls of Microsoft. What is it? It's a source-code analysis tool that you can use to ensure that everybody in your org is adhering to your coding guidelines. It can be a bit (ok, VERY) pedantic sometimes, but you can dial down the level of nitpick.

Deployment Tools Foundation - At MSFT, whenever I needed to do something in managed code during setup, I'd reach for this great internal tool for creating managed custom actions. It worked fairly well, even if it did hit many of the issues Rob Mensching had enumerated for why WiX had no roadmap for managed custom actions a year or so ago. Well, Jason's a smart fellow, and he addressed those issues in the latest version, which has become DTF.

Lastly, Bob Arnson has released a great WiX extension for creating exceptions in Windows Firewall by adding a couple of new elements to your WiX code.

Instrumentation, Your App, and You - Part II: Eventing

ahopper — Tue, 29 Apr 2008 00:19:00 GMT

This is a continuation of my inaugural blog series on instrumentation (see part one here).

Eventing is one of those features in the .NET Framework that is incredibly useful, especially if you are an Enterprise or Internet-facing application developer. Proper eventing instrumentation can make the difference between an operable application and something your IT guys would never allow in the datacenter. Unfortunately, it is also really easy to abuse.

OK, this is where I don my Pedantic Instrumentation Guy hat. Yes, I'm going to be an annoying PIG that asks you to do a bit of work in order to have good instrumentation so you don't have to pay some ex-green-beret a lot of money to wade through mini-dumps. (Not that we mind the income, mind you!)

All too often, developers will use the event log as a poor man's trace log - they'll dump informational messages into the Application log or, worse yet, perform full stack dumps into the log when an exception is caught. In addition, it's just too easy to configure programmatically, which can set you up for embarrasing crashes.

You see, the event log was not intended to act as a log file; instead, it is intended to be a place where you can go to see a comprehensive view of important things happening on your system. There are two magic words in there I want to emphasize: comprehensive and important. You must understand that you are not the only application writing to the event log. In fact, there's a phenomenon known as an "event storm" where a poorly written application can flood a computer's event log with so much useless or redundant data that other things that are really useful to see like warnings from SQL or disk I/O errors get missed. This logically brings us to event importance. You really should only be logging significant events. Things like startup, shutdown, catastrophic failures but most importantly, recoverable errors.

Ahhh, recoverable errors. PIG hat still on? Ah, good. This topic could (and probably will) merit a whole series of posts dedicated to knowing/learning how your applications may fail. Here's a Golden Rule of eventing: Do not log an error if all your poor sysadmin can do is see that the application has logged an error. Trust me; he's not going to appreciate the event message for its innate beauty. If there is no possible recovery action documented for a particular error event ID (or even better, included in the event's message), then all your app is doing is indicating to the sysadmin that he should seriously consider uninstalling your application. Consider this: you see the following error event:

Log Name:      Application
Source:        MyApplication
Date:          5/8/2008 7:00:00 AM
Event ID:      0
Task Category: (0)
Level:         Error
Keywords:
User:          N/A
Computer:      datacenter1
Description:
Object not set to an instance of an object.

Did this tell you anything about how you can prevent this error in the future? If not, why is it in the event log? If it doesn't provide me with a way to help my system be happy again, it's just noise. The best I can do is to attach a debugger and snap a minidump when I hit a NullReferenceException, and this is not something to consider lightly when you've got an Internet-facing application (Or tight purse-strings. Do you know how much it costs to hire ex-green-berets these days?).

No, a much better error event would be:

Log Name:      Application
Source:        MyApplication
Date:          5/8/2008 7:00:00 AM
Event ID:      1033
Task Category: (3)
Level:         Error
Keywords:
User:          N/A
Computer:      datacenter1
Description:
Unable to retrieve customer information from the database. Please verify that the 'customer' database at server 'database2' is accessible.

So, what's the difference here? Well, there's the obvious difference and the hidden one. The obvious difference is that the event gives you a pretty good indication of what's going on. In addition, it gave you some things to go check to help your app get back on its feet: is the database server up and running? If so, is the database available? The hidden difference is that the developer anticipated that he may not get a valid object from the call to retrieve an object from the server and wrote error-handling code to capture the information needed to troubleshoot the problem and to write the above entry. I'm not going to lie and say that it's easy to write code that anticipates failure. It's actually pretty hard to know all of the ways in which some component can fail, especially if you didn't write it yourself. Some of this will come from experience and testing, and there are also static analysis tools that can analyze your code's call stacks for exceptions that aren't handled but if you're really lucky, the developers who wrote the component will have included things like <exception> information in their XML documentation. With all of the above and some grunt-work on the developers' part, you should be able to tell your sysadmin what is wrong with your app. So what if you encounter a truly exceptional exception? Well, that falls under the category of catastrophic failure. For obvious reasons, it's your responsibility to try to minimize the scenarios where one of these can occur, but if it were to happen this is where all of the helpful advice I provided in the tracing article (you DID read that, right?) comes in.

Oh, one other thing you may notice in my "new and improved" log message is that there was an event ID. This is also a pretty important concept: once you've spent the time to analyze the manner in which your application can fail, try to assign event IDs to the cause of failures you are logging. For example: an inability to connect to the database server is 1033, an access denied to a configuration file may be 2021, and so on. If you do your homework here you can not only make it easier for a human being to find and correct the issue preventing your application from functioning but you can facilitate the development of auto-recovery actions in monitoring packages like System Center Operations Manager. Spending the time to itemize your event messages also allows you to leverage the string formatting and localization capabilities of the Message Compiler (mc.exe) utility. I'll dedicate a separate post to how one can use MC.exe to generate message files and how you can register and use event sources that use message files.

Finally, let's talk about event source registration. Again, this is one of those areas where things were made a wee bit too easy. A pattern you see too often in managed code is:

if (!EventLog.SourceExists("Foo"))
{
EventLog.CreateEventSource("Foo", "Application");
}
EventLog.WriteEntry("Foo", "Some event", EventLogEntryType.Information);

In fact, I was apalled to discover this code in a Microsoft certification exam! You should never ship code like the above for a couple of reasons, but the most obvious one is that it requires elevated permissions to create an event source. If an unprivileged user account attempts to run the above you will get a SecurityException. Instead, have your installation package leverage Windows Installer's support for registering event message files and use the WriteEvent overload instead - that way, you can create an EventInstance object that contains the event message ID and supply format strings that get plugged into the appropriate place in the message.

Well, there you have it. A whirlwind tour of the philosophy behind proper* event logging in your application.

Whew. Now I can take this stupid thing off.

* "Proper" is in the eye of the beholder. Feel free to ignore any and all of my advice. Tax, tag and title not included in the advertised sale price.

Instrumentation, Your App, and You - Part I: Tracing

ahopper — Mon, 28 Apr 2008 23:38:00 GMT

It's been a while since I've blogged about anything technical, and since I'm here in my new home at Wintellect I decided that I need to begin anew. So, without further ado...

I wish I could find a way to make instrumentation sexy; every time I try to explain to someone about why they should invest in instrumentation, I see them get the “deer in the headlights” look and try to find a way to get away from this crazy bald man. It’s just so BORING… and invaluable.

Basically, my philosophy is that attaching a debugger is well and good, but there are only a few scenarios where that’s going to be possible or acceptable. With Enterprise-facing Web or LOB applications, you have a lot of leeway – they can afford to have you (or one of their technical resources) go to a machine and attach WinDBG or CDB – but I hold Internet-facing sites and client-side code to a much higher bar. With a live Internet-facing site, you can’t just hit a breakpoint and dig around as it brings the app to a screeching halt. Even scripting a breakpoint that snaps a minidump and resumes is no good as it still blocks the app for an indeterminate (although admittedly pretty short) amount of time. With a client-side application, you simply cannot ask a customer to install a debugger and get that minidump to you.

So, how can you instrument your application? Well, there are three primary ways and one interesting way. You can use trace logging (which will be the core focus of this post), event logging, performance counters, and finally, WMI.

There are plenty of times where that hard-won minidump simply isn’t enough; after all, not only is it rocket science to most developers, but all you’ll see stack traces and current values for members – not HOW you got to this point. A lot of the art debugging is intuiting what path the app took to get to this crashing stack, and a good trace log can let the app do a lot of that detective work for you. Even minimal stack tracing (entry/exit) gives you a great deal of behavioral information, and this can be invaluable when you’re trying to figure out WHY you’re waiting on that Mutex again.

Tracing undeniably has a non-zero overhead associated with it, and this overhead takes two forms. First, there’s the behavioral/code overhead that goes with getting people in the mindset of leaving post-it notes in their code for the unfortunate soul who has to troubleshoot their misbehaving app. Second, there’s the performance overhead that goes along with adding more calls to the application. The first is manageable, and the second is fixable.

On the behavioral front, it’s very much an evangelism issue and it’s kinda like selling insurance for your career. Once you have an app out in the field with zero instrumentation and some high-profile customer is screaming for your head because you STILL don’t know why your app is hitting this exception, you gain a deep appreciation for how much you would have loved to know what the response from that SOAP call was. As for the amount of work it requires from the developer, it all depends upon the class of application; there’s a dial you’ll want to turn for the amount of tracing code you write. When I’m wearing my hard hat I want tracing at every decision block, every exception handler to dump the exception and logging the parameters to methods at “verbose” levels. When I’m wearing my “warm fuzzy” hat for simple LOB applications, I want tracing before and after major events in the code like network/IO calls. But in practice, it’s going to be up to the dev to understand how their code might misbehave and to leave a trail of tracing breadcrumbs to help some poor soul noodle out why some button didn’t get enabled.

Now on to the performance overhead. Most developers don’t stop to think about the cost associated with constructing the call stack for a trace call, and when they see that their application’s runtime performance suffers because they have a bazillion trace calls that call ToString or box up a bunch of integers, they’re quick to blame tracing in general and yank it altogether (seen it happen first-hand, that). There’s no reason it has to be this expensive, though. If tracing isn’t enabled, it should just get out of the way – it’s only when we’re debugging that we want that overhead, and then we won’t care as much if we take a hit. It’s an unfortunate reality that all of the wonderful work the driver guys did on TraceWPP is lost in the managed world; there’s no (publicly available, that is) tool for preprocessing managed code and wrapping trace calls with runtime-evaluated conditionals to shortcut the construction of the call stack if tracing is not enabled.

So, if we can't use TraceWPP, what can we do, then? Well, for the time being (hint, hint), we're stuck with hand-generating conditional blocks to detect whether tracing is enabled for a particular trace level. However, I hope to remedy that situation here in this blog: we'll walk through the implementation of a preprocessor in the style of TraceWPP and use it for our managed apps.

Well, this post has become long enough for now. We'll take a look at the other ways your application can help you debug itself later.