Sunday, November 2, 2014

Security Analysis of a Glacier Backup tool for Windows

Ok, so my career has shifted more to mobile app development and security. I've been looking into ways to backup personal stuff on my personal, non-work laptop, and I like the idea of using Amazon Glacier. It's cheap, and reasonably available (if you can wait half a day while they fetch your archives, that is). No problem. Just what I was looking for!

I found a great Windows client for Amazon Glacier. It has all the features I need, but in this day and age, one has to be increasingly suspicious of apps that might also contain malware. So, in this post, I want to talk about some skills I've picked up in the last 10 years at my previous job that are paying dividends in checking software to determine whether I trust it or not.

Note that this is fairly high level, except for the parts pertaining to reverse engineering .NET code.

First step in malware analysis. Search online! Has anyone already done this? No? Ok, step 2...

Download the app. You need to setup a virtual machine to run it in so that you can isolate your "real" computer from any potential malware infection. There are numerous ways to do this, and I'll mention a few and let you research what works for you. If you can install a copy of Windows inside a virtual machine, then you can play with it there (using Hyper-V, VMWare, VirtualBox, etc). You can also spin up a Windows copy in the cloud (using Windows Azure, Amazon AWS, Rackspace, etc). That will cost some money, but is a simple way to get Windows if you don't have a license to activate a local copy in a VM. If you work for a software engineering firm, you can almost certainly get a Windows key through your MSDN subscription. Ask around in your IT department. Students, same goes for you at many universities. Also, look into the DreamSpark program.

Now, install the app on your isolated environment. If it's an MSI file, you can open that and inspect the various tables of custom actions, install files, registry changes, etc using a tool called "Orca" from Microsoft. If you have Visual Studio and/or the Windows SDK installed, you can probably find an MSI file for Orca already on your hard drive.

If the installer is not MSI based (or even if it is and you want to be paranoid or don't know enough about MSI technologies to benefit from pre-install static analysis), then fire up SysInternals' ProcMon. You can log all registry, file, and TCP/IP activity for any process on your system. If you run that while the installer does its work, you'll have a good idea of whether it's REALLY doing what it says it is doing. Plus, you'll know where on the system to find the installed app (it may not just be in Program Files, for example) to begin studying further.

At this point, my particular app was discovered to be a .NET windows desktop application (get a good PE information utility to look at your file, and you can tell that way...or also if you open ILDASM and attempt to disassemble the code, it will inform you when it is not a .NET DLL/EXE file). So, I immediately opened ILDASM and tried to convert it from a binary to MSIL source code. I got this cryptic message saying "Protected module -- cannot disassemble". What?!? That was a new one to me. After some googling, I discovered you can set an attribute in your .NET assemblies that tells ILDASM not to disassemble it. Well...that keeps away the newbs, but all you have to do is undo that attribute and you'll be able to disassemble. Use some kind of PE file editor to zero out the attribute as described here.

With the disassembly, you'll likely notice that the code was obfuscated. This means that, during the build process, a tool was used to take the nice meaningful names that classes, methods, fields etc have in .NET and mangle them into 1 and 2 letter long cryptic names. In other words, the .NET metadata is obscured so as not to let you infer meaning from a class named "InstallMalwareOnBackGroundThread". :) Instead it will be named "nca" or "pbe2" or something!

In addition to this, many obfuscation tools screw up the MSIL sequence so that instead of just loading a string on the stack, you load an int, call an obscure method that returns a string, and then call the actual method of interest. Plus dozens of other annoying things...

But for us, that's no problem. Although seeing the code would be nice, my main focus is to know what .NET base class libraries the tool interacts with. This is often enough to infer whether you can reasonably trust a program or not.

So, I searched the IL code for "call" and "callvirt" to make a list of functions called within the program. I then further narrowed that list down to things that started with "System." to know what base class libraries are used. I came away with this list:

System.Management (WMI)
System.Net (probably HTTP/TCP stuff mostly, plus transparent SSL support by .NET)
System.IO (file/disk)
Microsoft.Win32 (registry access)
System.Security.Cryptography (encryption used by the app)

Ok, those are all somewhat reasonable things for my Glacier app to do in certain cases. Let's make sure they're being used properly.

So, I launched Sysinternals' ProcMon and began monitoring file/registry/networking for my program (filtering to include processes that start with the program's name). I also opened SysInternals' DebugMon tool in Administrator mode, and listened for Global Win32 messages. I opened the app, and gave code execution control to this new acquaintance of a tool! Shudder...

I then studied what happened at startup before I ever clicked around in the tool. A roaming profile was created, a log file was created, some non-threatening things were stored in the registry, and some polling thread kept looking for a queue.xml file on disk. Ok, whatever. I then attached to the process with WinDbg and ran the command ".dump /ma C:\Dumps\myfile.dmp". Then I shut the tool down, and shut down my monitoring tools.

The app's own log file had some nice helper debug messages for what it was up to, but of course those shouldn't be 100% trusted. I also looked in the queue file, but nothing interesting was there (presumably because I wasn't trying to download or upload to glacier).

Next, I decided a good old fashioned string search on the file might be handy. But this one is obfuscated, so I decided to search the dump file instead. Dump files are disk copies of exactly how memory was in the process at the moment you executed the dump. So, I loaded the dump file in WinDbg, loaded SOS (I knew the app was 64 bit, because it was in Program Files and not Program Files (x86), and I knew it was .NET 2.0 from ILDASM's output) from Framework64\v2.xxxxx\sos.dll. Then, I ran "!DumpHeap -strings". That produces an output of about 2-3 thousand strings, truncated after the first 100 characters of each line or so. Perusing through these led to some interesting insights.

For example:
"Unable to decrypt your Access Keys (wrong password?)"
Hmm...apparently my credentials are protected by password using symmetric cryptography on disk somewhere.

"System.Security.Cryptography.SHA1CryptoServiceProvider"
"System.Security.Cryptography.RC2CryptoServiceProvider"
"System.Security.Cryptography.MD5CryptoServiceProvider"
"System.Security.Cryptography.DESCryptoServiceProvider"
"TripleDES"
Perhaps these algorithms are used to store the Amazon credentials? Kind of funny, because elsewhere in the tool is an options screen where you can encrypt the files going to Glacier as AES 256, which is the best choice. Why use Triple DES I wonder? Or freaking RC2? Really?

"SELECT * From Win32_OperatingSystem"
Obviously a WMI query for what version of Windows you're on...

"SELECT * From Win32_processor"
A WMI query for processor info (maybe used to properly thread and throttle your Glacier access?)

"net.tcp"
May use WCF services...

"Dropbox"
What the heck? This is nowhere in the UI.

"system.data.sqlclient"
Perhaps uses a local SQL DB? Hmm...

I decided that SSL might get in the way of good information gathering, so I opted for making a new file named "myapp.exe.config" that contained the system.net tracing found on this website. This let me log to a file on disk, BEFORE SSL kicks in! Sweet! I could see everything going to/from Glacier and validate it was what I wanted going across the wire.

At this point, I knew what kinds of things I wanted to look for, so I continued to fine tune my ProcMon filters for file/registry/network activity to alert me of unusual things and filter out expected things. Continuing to click throughout the app, I came to the conclusion I could trust this one. Here are my general findings.

The only web URLs it used were directed to Amazon AWS IP's or DNS names.
The log file only sent data I told it to over to Amazon.
My credentials were stored with...adequate, TripleDES crypto.
WMI was used appropriately, changing behavior based on Windows 8 vs 7, or single/multi core.
The local SQL usage was never found. Maybe the app doesn't use a SQL DB? This was a risk point, but one I decided was worth taking.
The app never contacted Dropbox. I have no idea why that string is in the code. I'm sufficiently convinced the app won't upload my keys to his dropbox, so I'm going to let this one go.

So in all, the app passes! And I have some peace of mind now about using it. At least far more than I originally did. I hope this is helpful to you. What RE tools do you use to measure whether you trust an app or not? I'd love to hear your thoughts in the comments!

Saturday, December 7, 2013

Off-topic: Wiping your hard drive

I want to document how I did this in case I need it in the future. This is a good way to wipe an entire drive quickly with any Linux LiveCD or USB stick. It only uses a program called dd.

Most computers, the primary hard drive is /dev/hda. So, to wipe it, issue this command:

dd if=/dev/zero of=/dev/sda bs=32M

Note that 32MB is a good buffer size for most modern drives. I'm getting 100 MB/s speed wiping using this. For a 500GB drive, that's taking me around 1 hour to wipe.

You can optionally check for a status in a separate terminal tab like so:
while true; do kill -USR1 1234; sleep 5; done

Replace "1234" with the PID of dd (which you can get with a "ps -A | grep dd"). When you flip back to the tab where dd is running, you will get a status update every five seconds. It tells you how much data has been copied, as well as your bytes / sec copied.

Enjoy!

Wednesday, July 31, 2013

Off Topic: Supporting Javascript you didn't write

Hi everyone,

Today's topic doesn't deal with .NET / CLR topics at all. This blog tends to focus on that. But since most .NET developers I know tend to use JS/HTML/CSS with .NET (or ASP.NET), this post should be somewhat beneficial to the "usual" reader of this blog.

I am a support engineer. That means I often get asked to fix code I didn't write. If it's .NET code, I usually turn to debugger breakpoints and/or tracepoints (good info about those here if you are not familiar) or occasionally use a .NET profiler. The first goal behind these tools is often to answer the question "where am I in the code base?" By knowing what code at the function or line level is involved, you can narrow down what things might be broken as you troubleshoot.

And honestly, that is the name of the game with all debugging / troubleshooting, regardless of language or environment. We have a product with a fairly large javascript code base that is difficult for me to keep up with, because I only find myself troubleshooting problems related to it once every 3-6 months. As a result, I often have a large "learning curve" at the beginning of my support issue, as I find out what has changed and what has stayed the same in the code base. Tools like Firebug for Firefox or Chrome's JS debugger are certainly helpful, but sometimes it takes a lot of effort just to figure out what parts of the code base are involved when you click a button, or go to page xyz. You can always view the HTML and see what JS is running, but if the product is designed with a lot of architectural "fluff", you have a hard time deciphering what exactly is going to happen when you click the button. As an example, maybe the button runs a JS function named processAction() that takes a GUID: processCommand('12345-123-123-1234...');

Well that's just not helpful. :) How do I know what that GUID is related to? In our product, it changes every time you hit the page! Ugh.

Enter, JSCoverage. I recently found a great Chrome plugin that can be used to identify functions (or even lines of code) that execute whenever you navigate somehow in your product. This manual page gives you a rundown of how it works. It essentially boils down to these high level steps:

1) Instrument one or more .js source files. These are output in a folder of your choosing.
2) Make sure your output folder is hosted by a web server (such as IIS, aka mapped to a virtual directory, or in a subdir of a virtual directcory).
3) Navigate to the generated jscoverage.html file.
4) Use the Browser tab to launch your app in a separate window or tab.
5) The jscoverage.html tab lets you view live information about coverage as you perform actions in the app launched in step 4.

The architecture is fairly simple. There is a global object named _$jscoverage that contains counters for various JS source code files and different blocks within those files.

_$jscoverage['my-source-file.js'][123]

All of the counters start at 0 and go up from there. The great thing about this architecture is that you can exploit it in a way that the original author may or may not have intended! The _$jscoverage object is only initialized once. Subsequent loads of the page or JS actions/functions that execute just accumulate more hit counts on the counters. They don't clear out. QA people who are interested in *total* code coverage probably like this, but a support developer may be more interested in precise coverage of one or two behaviors instead of all behaviors performed in the web browsing session. So, we can use Chrome's Console to execute some ad-hoc javascript that clears the counters, like so:

for(var propName in _$jscoverage['my-source-file.js']) {
_$jscoverage['my-source-file.js'][propName] = 0;
}

Using this technique, we can clear the counters immediately prior to performing our action of interest. Then, once the action completes, switch back to the jscoverage pane to view coverage data for just that action. You may need to navigate off and back onto the Summary tab to see the results update.

For me, this technique greatly simplifies the support process. Now after reproducing my issue, I know that the problem lies within 10 functions instead of 1000 potential functions! That's a money maker, folks. Now, I know where to place breakpoints via Chrome's JS debugger to get the most mileage out of my support discovery process! Some days I just love my job. :)

Many thanks to the developers of JSCoverage.

Thursday, July 18, 2013

System.Xml ImportNode and the .NET Heap(s)

If you work with XML in .NET a lot, you have probably bumped into a scenario a few times in your career where you need to move or copy some XML fragment out of one document and into another. The typical coding sequence for that might look something like this:

XmlDocument source = new XmlDocument();
source.LoadXml("");

XmlDocument dest = new XmlDocument();
dest.LoadXml("");

//move from source to dest
XmlNode n = source.SelectSingleNode("/source/myxml");
XmlNode nImported = dest.ImportNode(n, true);
XmlNode nAppended = dest.DocumentElement.AppendChild(nImported);

I have often wondered (but, until today, been too lazy to investigate) why ImportNode() and AppendChild() return XmlNode objects, and what one is supposed to do with them? Are they the same? Clones of the same? Etc.

Well, IronPython happens to have this nice feature where it shows you the memory address of the .NET object you reference in an expression via the ipy console.

Excerpt from an IronPython Console session

Wednesday, August 1, 2012

RedGate activation blues

So, my company makes use of the RedGate SQL Compare SDK tools. And let me just say, if you haven't bought these yet...totally worth doing. If you've ever wished for SQL functionality related to diff, merge, etc on your schema structures or your data itself, RedGate can do it. Period. I drink their kool-aid.

But this week, I hit a snag as I upgraded to a new developer laptop. It came time to re-activate my RedGate DLLs so that I could use them in development projects in Visual Studio. Typically, you simply compile the project, and a little dialog box asking you to activate your trial install of RedGate pops up while Visual Studio builds. Our projects wouldn't popup the dialog box. Instead, we received a build error in the Error List window:

Error      2             Exception occurred creating type 'RedGate.SQLDataCompare.Engine.ComparisonSession, RedGate.SQLDataCompare.Engine, Version=10.0.1.69, Culture=neutral, PublicKeyToken=7f465a1c156d4d57' System.IO.FileNotFoundException: Could not load file or assembly 'file:///C:\Src\...\Bin\RedGate.Licensing.Client.UI.resources.dll' or one of its dependencies. The system cannot find the file specified.               C:\Src\...\licenses.licx     2


("Real" paths omitted to protect what I work on)


So, I searched for this satellite assembly on my entire hard drive. It was nowhere to be found! Now what do I do?


I had never used RedGate support before, so I decided to give it a try. I e-mailed licensing@red-gate.com, and explained my predicament. Within 24 hours, I received a response from their internal support team.


"Thanks for contacting Red Gate. The issue you've run into is that the Windows Form that asks for a serial number was written against .NET v2 and therefore needs to be invoked using a .NET v2 resource reader. There is no satellite DLL that is missing.
To make a long story short, create a new VS project and ensure the target Framework version is 2. Then add in a sample application and build it. The serial number dialog should pop up and ask for your serial number. Once you have activated successfully, you can then go back and compile your .NET 4 projects, since the licence has been created and there is no more need to ask for the serial number again."


Sure enough, my code was based on .NET 4 and therefore was not allowing RedGate's licensing mechanism to work properly. As suggested, I used a .NET v2 project to activate the copy. Another coworker pointed out that their installer places some samples at this path:


C:\Program Files (x86)\Red Gate\SQL Comparison SDK 10\Samples\Automating SQL Compare


So, I opened one of those, built, was prompted for my license, activated, and the sample built successfully.  I then opened my original project (.NET v4), and compiled it successfully! Yes!


So, I was unable to find much online about this issue. I wanted to blog so that others might experience less pain. This is for RedGate v 10.x, and possibly other versions.

Wednesday, July 13, 2011

ScintillaNET starter kit



I have searched long and hard across the Internet for a simple "hello world" style example of using ScintillaNET's control. This thing has it all. You name the language, and it will give you a textbox that can syntax highlight for that language, plus dozens of other features like code folding and so forth.
But how to use it? For those of us without much "unmanaged code" experience, the Scintilla web site's documentation can be very initimidating. ScintillaNET's documentation (at least at this point in time) is fairly thin. It simply says "for the details, look at Scintilla's documentation". Today I discovered the reason for that--it's actually surprisingly easy to use the ScintillaNET control! With a very flexible licensing agreement, it's a wonder this thing hasn't gone mainstream in the .NET community. Perhaps with this simple example, I can get that started.

I used Visual Studio 2010 to do this, but any version for .NET 2.0 or higher should suffice.

Step 1): Get the source code, build ScintillaNET, and reference ScintillaNET.dll from a Windows Forms project. (Note: WPF may or may not work with the WindowsFormHost XAML tag allowing Windows Forms controls to be loaded into the XAML structure. I haven't tried that.)

Step 2): Go to your visual designer, and look in the toolbox. There is a control named "Scintilla". Drag that to your form.


Step 3): You'll need to tell it what language to use for syntax highlighting. Scintilla supports a TON of languages: http://scintillanet.codeplex.com/wikipage?title=HowToSyntax&referringTitle=Documentation
In my case, I was making an XML editing control, so I chose to set the language to "xml" in my form's onload event (note, in this code snippet, scnMain is the name of the Scintilla control I dragged onto the form):
private void ctlScintillaNETXml_Load(object sender, EventArgs e)
{
scnMain.ConfigurationManager.Language = "xml";
}


Step 4): Set or get scnMain.Text as appropriate to get a string of code (or in my case, XML markup). That's it! Fire it up and watch the awesomeness that is Scintilla. How easy was that? Enjoy.

Friday, December 3, 2010

Powershell Functions - Evil Calling Convention Problem

In powershell, one might think that calling a function would look like this:

FindReplaceMany_Directory($SubDir, $fileType, $recursive, $findArray, $replaceArray)

given a function like this:
#Find replace files of a certain file type in a given directory.
#$recursive = true to parse sub-dirs as well
#$fileType = ""*.*"", ""*.txt"", etc.
function FindReplaceMany_Directory($dir, $fileType, $recursive, $findArray, $replaceArray)
{
... (omitted) ...
}

This is not the correct syntax. But surprisingly, it still works and ONLY the first parameter gets a proper value. Everything else gets a null.

To properly call this function, do this:
FindReplaceMany_Directory $SubDir $fileType $recursive $findArray $replaceArray

Wednesday, December 1, 2010

Mass Rename files

Here is a script I wrote to rename a bunch of pictures I had on my computer. It lets me put a prefix on the front, so that I can tell what it is by the title in the taskbar at the bottom of the computer when the picture previewer is minimized. This script could easily be tweaked for many other mass renaming jobs without much programming knowledge. Enjoy!

=========(Begin File...just name it something.ps1)========================

Write-Host "Tell me a prefix to put on the front of all *.jpg files in this folder:"
$Prefix = (Get-Host).UI.ReadLine()

if($Prefix.Length -gt 0)
{
$Files = Get-ChildItem *.jpg

foreach($File in $Files)
{
$NewName = $Prefix + $File.Name

Write-Host "Renaming $File to $NewName"

Rename-Item $File $NewName
}
}
else
{
Write-Host "No prefix. Doing nothing."
}

Write-Host "Press any key..."
(Get-Host).UI.ReadLine()

=========(End File)========================

Saturday, October 23, 2010

Why haven't I learned PowerShell sooner?

Powershell is awesome. Thanks to anyone involved in dreaming that up at Microsoft!

Case in point, read about everything you can do w/ a plain ole' delete command replacement. Wow.
http://technet.microsoft.com/en-us/library/ee176938.aspx

Powershell would make such a great build script or installer language...especially if you could pass it name/value pairs of global properties like you can Nant! I think I see a hobby coming on...

Friday, October 22, 2010

Debugging my debugger - ICorDebug and the ramifications of thread suspension

Thanks

First of all, with this post I feel like I've come of age as a debugger. I have to thank Tess (http://blogs.msdn.com/tess) and various other WinDbg bloggers for starting me down this path in first place. Also, thanks to Mike Stall and the other ICorDebug gurus for such great blogging info. Thanks everyone!

The Need
Now, when I troubleshoot production systems in my job, I often find myself doing the same one debugging task over and over again:
1) attach to process with visual studio
2) set it to break on all CLR exceptions
3) wait
4) catch one, look at the call stack, look at the value of local variables and arguments
5) detach
6) fix something and go back to step 1

This is rather mundane, and one day I decided to see if I could automate this. I did. :) I call it "FirstChanceExceptionWatcher". Here's a rundown of the feature set:

The Solution
=============================================================================
FirstChanceExceptionWatcher project
=============================================================================

Usage:
This windows service captures all exceptions that happen in an IIS process,
and writes them to an XML file, along with a configurable amount of context
(call stack, value of strings in call stack, etc.)


Features:
- Runs as windows service
- Resilient and automated debugging
- Automatic re-attach after app pool recycles
- Automatic re-attach after IISReset
- Automatic re-attach after task manager kill of w3wp or aspnet_wp

- log4net rolling append (keeps x days worth of data, and deletes anything
older automatically)

- Logs to a "log" subfolder, next to FirstChanceExceptionWatcher.exe

- Capture first chance Exception. Write results of .ToString()

- Configurable capture of call stack, with parameter types and values (values only for string
or something with a .ToString() method)

- Configurable capture of local variables within methods that are on the call stack (values
only for string or something with a .ToString() method)


Setup:
- Build .sln in VS 2010
- Copy the contents of bin/Release onto a machine running an ASP.NET application.
- Tip: Make sure the drive has free space for logging. One day of logging
might be a negligible amount of logging (KB's) or a ton of logging (1 GB)
(depending on frequency of exceptions in application)
- Run install.bat
- Start service and stop service as desired
- Monitor log files to learn new information

Configuration:
- REQUIRED: Specify name of IIS app pool to attach to in
FirstChanceExceptionWatcher.config
()
- OPTIONAL: Adjust other settings in FirstChanceExceptionWatcher.config
(descriptions are in .config file)
- OPTIONAL: Adjust log4net rolling append or verbosity in
FirstChanceExceptionWatcher.exe.log4net
(Read about configuring log4net ver 1.2.10.x online for details)

Log files:
MainSvc.xml - Information about windows service (attaching/detaching from processes, OS and environment info, startup/shutdown, etc)
Events.xml - Captures debug information when exceptions occur.
Instr.xml - Writes timing information to measure how much the debugger is impacting the performance of
the system. How long are we in the callback methods doing work?

=============================================================================

Cool! Let's put it to use!

The First "Real" Test
So I installed it on a system where I was experiencing a bizarre threading issue. 1 in 10 times that I ran a certain piece of code, it would fail, all based on how busy the system was. The failure was some sort of a silent exception of an asynchronous long running thread. "If I could just see the exception", I thought to myself, "I could probably fix this in no time".

Well, let's just say the public use of the debugger did not go as planned.

The Adventure (aka WinDbg debugging)
Problem:
After a few minutes of debugging, the ASP.NET web site would hang and stop serving any requests for the users. If I turn off the debugging service, the site would begin to function normally again. If I turn it on, the same thing happens within a few moments. Obviously my debugger was causing some kind of a problem!

Other symptoms:
Perfmon showed typical request execution times for the web site (0-4 seconds). Then, suddenly, while hanging, would go to "---------".

The process ID is taking 40-50% CPU as it sits there and "hangs".

Troubleshooting:
I decided to resort back to my good friend WinDbg to debug my debugger. I took two hang dumps about 8 minutes apart to see what I could learn.

cscript adplus.vbs -hang -quiet -p 1239

I found a thread of particular interest in both dumps:

Taken at 12:17 PM:
OS Thread Id: 0x151c (25)
ESP EIP
199bc574 7c82860c [HelperMethodFrame: 199bc574]
199bc5cc 792e0e30 System.String.ConcatArray(System.String[], Int32)
199bc5e4 7928a99c System.String.Concat(System.String[])
199bc600 799cc6d2 System.Exception.ToString()
199bc614 799cc67c System.Exception.ToString()
199bc8ac 79e71b4c [GCFrame: 199bc8ac]
199bc8c8 79e71b4c [GCFrame: 199bc8c8]
199bcb40 79e71b4c [GCFrame: 199bcb40]
199bcb08 79e71b4c [GCFrame: 199bcb08]
199bcb24 79e71b4c [GCFrame: 199bcb24]
199bcda8 79e71b4c [FuncEvalFrame: 199bcda8]

Taken at 12:25 PM:
OS Thread Id: 0x151c (23)
ESP EIP
199bc574 7c82860c [HelperMethodFrame: 199bc574]
199bc5cc 792e0e30 System.String.ConcatArray(System.String[], Int32)
199bc5e4 7928a99c System.String.Concat(System.String[])
199bc600 799cc6d2 System.Exception.ToString()
199bc614 799cc67c System.Exception.ToString()
199bc8ac 79e71b4c [GCFrame: 199bc8ac]
199bc8c8 79e71b4c [GCFrame: 199bc8c8]
199bcb40 79e71b4c [GCFrame: 199bcb40]
199bcb08 79e71b4c [GCFrame: 199bcb08]
199bcb24 79e71b4c [GCFrame: 199bcb24]
199bcda8 79e71b4c [FuncEvalFrame: 199bcda8]

There are several things to notice about this call stack.

First, the managed thread ID changes (23 vs 25). I have never seen this before and am not sure what causes this, but it is interesting because the underlying operating system thread ID (ox151c) remains the same. So be warned, you should watch both.

Second, I actually know what this call stack is, because of the code I wrote into my debugger. When an exception occurs in my ICorDebug based debugger, it takes the exception object and sets up a function evaluation call on the current thread, calling System.Exception.ToString(). Also notice the phrase "FuncEvalFrame" at the base of the call stack in WinDbg.

Third, I know this is not another ToString() call on a different exception, because the OS thread ID and the address of the exception object itself stays the same (799cc67c).

Observations:
OK, so we know that an exception ToString() call is taking minutes to complete...but why? And why is that chewing the CPU?

Troubleshooting:
I ran !runaway to see what threads have been working the hardest:

Taken at 12:17 PM:
0:000> !runaway
User Mode Time
Thread Time
12:ce4 0 days 0:03:48.062
10:218 0 days 0:03:43.328
13:1194 0 days 0:01:36.562
25:151c 0 days 0:00:14.234
11:ea4 0 days 0:00:00.734
14:82c 0 days 0:00:00.578
2:a5c 0 days 0:00:00.078
4:1614 0 days 0:00:00.046
0:b94 0 days 0:00:00.046
5:164c 0 days 0:00:00.031

Taken at 12:25 PM:
0:000> !runaway
User Mode Time
Thread Time
12:ce4 0 days 0:07:14.031
10:218 0 days 0:03:43.328
13:1194 0 days 0:01:36.562
23:151c 0 days 0:00:14.234
11:ea4 0 days 0:00:00.734
14:82c 0 days 0:00:00.578
2:a5c 0 days 0:00:00.078
4:1614 0 days 0:00:00.046
0:b94 0 days 0:00:00.046
5:164c 0 days 0:00:00.031

Whoa! Thread 12 is obviously working while everyone else sits around. Who's thread 12?

!clrstack shows nothing. It's not a managed thread. So, I run !threads -special:

0:012> !threads -special
ThreadCount: 12
UnstartedThread: 0
BackgroundThread: 9
PendingThread: 0
DeadThread: 1
Hosted Runtime: no
PreEmptive GC Alloc Lock
ID OSID ThreadOBJ State GC Context Domain Count APT Exception
10 1 218 000d02c0 1808228 Enabled 274061c4:27408194 000d7040 0 MTA (Threadpool Worker)
14 2 82c 000ddd70 b228 Enabled 00000000:00000000 000d7040 0 MTA (Finalizer)
15 3 17d8 000f6920 80a228 Enabled 00000000:00000000 000d7040 0 MTA (Threadpool Completion Port)
16 4 10f4 000fa748 1228 Enabled 00000000:00000000 000d7040 0 Ukn
8 5 d90 000ff758 880a228 Enabled 00000000:00000000 000d7040 0 MTA (Threadpool Completion Port)
17 7 14b8 00149350 200b028 Enabled 00000000:00000000 000fae88 0 MTA
18 8 44c 0014c2e0 b028 Enabled 00000000:00000000 000fae88 0 MTA
XXXX c 0 1109d4c0 9820 Enabled 00000000:00000000 000d7040 0 Ukn
25 6 151c 110af340 180b220 Enabled 18cccab0:18cce0f8 000fae88 1 MTA (Threadpool Worker) System.Exception (28098c44) (nested exceptions)
26 b 1774 001365f0 8b228 Enabled 00000000:00000000 000fae88 1 MTA
27 9 1044 00136220 880b228 Enabled 00000000:00000000 000d7040 0 MTA (Threadpool Completion Port)
28 a 56c 3a2bb0e0 880b228 Enabled 00000000:00000000 000d7040 0 MTA (Threadpool Completion Port)

OSID Special thread type
8 d90 IOCompletion
9 9b8 Gate
10 218 ThreadpoolWorker
11 ea4 DbgHelper
12 ce4 GC
13 1194 GC
14 82c Finalizer
15 17d8 Timer
16 10f4 ADUnloadHelper
25 151c ThreadpoolWorker
27 1044 IOCompletion
28 56c IOCompletion

Garbage collection is taking up my CPU. Why can't other threads work?

Because I'm doing this in my code!

(just prior to setting up the func eval and letting it run...)
pController.SetAllThreadsDebugState(CorDebugThreadState.THREAD_SUSPEND, pThread);

(once the eval completes...)
pProcess.SetAllThreadsDebugState(CorDebugThreadState.THREAD_RUN, pThread);

So, until the func eval completes, nothing else (apparently even garbage collection) can complete. Ok, so how do I know that my ToString() call probably needs / triggered GC? Memory allocation. Notice the System.String.Concat method on the call stack.

So, at this moment, I finally fully appreciate and understand what Mike Stall means when he says this:

(Taken from http://blogs.msdn.com/b/jmstall/archive/2006/03/05/writing-funceval-in-a-debugger.aspx )

2) You need to make some policy decisions.
a) Other debug events may come in the meantime and you need to decide how to handle those. For eg, if you hit a breakpoint, do you want to silently ignore it finish the eval, or do you want to enter a nested break state? It's your debugger and you get to decide what policy you want.
b) Also, do you suspend other threads? If no, they will move on you when you eval and thus your eval becomes even more invasive. If yes, you may get deadlocks.

Smoking gun! I think we have it. My debugger is running .ToString(), while blocking all other threads. The .ToString() needs to allocate memory, which triggers a GC (sometimes, not all the time), and that causes .ToString() call to never complete, which means no one else can complete either. And so the GC thread is apparently spinning off doing something unproductive for the rest of eternity.

So, I will be reworking my code to allow other threads to continue on while func evals occur, and find a way to correlate the information in the log file, since the .ToString() result and the logging of the first chance exception may not be near each other in the log file.

Hopefully that will correct the issue.

But it didn't. :(

I found some abort related functions on the eval objects, and tried running those after a certain timeout threshold, but that didn't unlock whatever deadlock state my internals of .NET were in.

So, I eventually involved Microsoft Support, and discovered that there is an undocumented requirement in the ICorDebug interfaces that you can only do one eval per debugger break. So, I reworked my logic to keep a list of all parameters and locals for a given exception, eval the first one, and continue. Once the eval completes, I setup an eval for the next. Then that eval completes, and I set up another, and so on, until all evals are ran for the exception. On that last eval complete event, I simply let the debugger resume, and the code goes about its business of running.

This thing is so stinking cool and useful now! I can attach it anytime I'm at a customer and don't have a debugger handy, but need to gather info about how to reproduce something in a non-prod environment. I love it.

Happy Coding!

Tuesday, August 31, 2010

Region-ify your C# code

There are some fancy tools/add-ons for Visual Studio that are huge productivity boosters. But for the poor man, purchasing an add-on is sometimes not an option.

Often, I review others' code (or perhaps my own code from a few years back), and think "What a newb! This junk is spaghetti code!". It is in situations like this where I find myself dying for the ability to collapse if blocks, while statements, etc. in C#.

As I mentioned there add ons that solve this quite eloquently. But, if you're just looking for a quick and dirty way to collapse those curly brackets, I have a macro for you! :)

In visual studio press the ALT key, followed by F8. This opens the macro pane. Most likely, there is already a macro project named my macros. Right click the module underneath that in the tree, and select "Edit". Now, blast this code into the editor:

'Add regions, by curly brackets. Put cursor on the first curly bracket of a pair, and run the macro.
Sub Regionify()
'region-ify
DTE.ActiveDocument.Selection.EndOfLine()
DTE.ActiveDocument.Selection.NewLine()
DTE.ActiveDocument.Selection.Text = "#region"
DTE.ActiveDocument.Selection.LineUp()
DTE.ExecuteCommand("Edit.GotoBrace")
DTE.ActiveDocument.Selection.LineUp()
DTE.ActiveDocument.Selection.EndOfLine()
DTE.ActiveDocument.Selection.NewLine()
DTE.ActiveDocument.Selection.Text = "#endregion"

'return to where I was
DTE.ActiveDocument.Selection.LineDown()
DTE.ExecuteCommand("Edit.GotoBrace")
End Sub

Another developer named Roland has a great post on how to assign hot keys to macros like this one. You can read about that here:

http://weblogs.asp.net/rweigelt/archive/2006/05/15/446536.aspx

Wednesday, March 24, 2010

Sorting any XML

I wrote this because I deal with a tool that treats XML as unsorted data. At the same time, it generates an XSD schema that enforces order. So, to solve the problem, I wrote a transform to take XML and alphabetize it by element name. This will work for any XML without namespaces, and will probably work for XML with namespaces by putting a declaration at the top of the transform.

<?xml version="1.0" encoding="utf-8"?>
<xsl:stylesheet version="1.0" xmlns:xsl="http://www.w3.org/1999/XSL/Transform"
xmlns:msxsl="urn:schemas-microsoft-com:xslt" exclude-result-prefixes="msxsl"
>
<xsl:output method="xml" indent="yes"/>

<xsl:template match="/">
<xsl:apply-templates select="*" mode="Sorting">
<xsl:sort select="local-name()" />
</xsl:apply-templates>
</xsl:template>

<xsl:template match="*" mode="Sorting">
<xsl:copy>
<xsl:choose>
<xsl:when test="./*">
<xsl:apply-templates select="@*" mode="AttSorting" />
<xsl:apply-templates select="./*" mode="Sorting">
<xsl:sort select="local-name()" />
</xsl:apply-templates>
</xsl:when>
<xsl:otherwise>
<xsl:apply-templates select="@*" mode="AttSorting" />
<xsl:value-of select="." />
</xsl:otherwise>
</xsl:choose>
</xsl:copy>
</xsl:template>

<xsl:template match="@*" mode="AttSorting">
<xsl:copy>
</xsl:copy>
</xsl:template>

</xsl:stylesheet>

Monday, January 12, 2009

Assembly Resolution - How AppDomains Change from Desktop to Web

So, for our build wizard, I needed to load some DLLs into a child app domain that could orchestrate all of our build script work, then unload the domain. Freeing up the .NET Assemblies in this way lets us always run off the latest/greatest of the DLL without the need to reset IIS.

I put some significant effort into getting the child AppDomain code to work from a mock command line app before plunging into the web world. This was my first exposure to a non-academic use of AppDomains, so I wanted to have a playground to get comfortable and prototype some code. It didn't take long to get something that was working. So, I imported the classes from my command line app into my web app I had been working on.

In the command line app, I had been initializing the AppDomain like so:

//setup a child appdomain
string appDomainUniqueNamePerUser = string.Format("WF Child Domain", Guid.NewGuid().ToString("D"));
AppDomain childAD = AppDomain.CreateDomain(appDomainUniqueNamePerUser);
assemblyResolvePath = appDomainBaseDir + @"\BuildScripts";
childAD.AssemblyResolve += new ResolveEventHandler(childAD_AssemblyResolve);

//get my proxy class for crossing the appdomain boundary
WFWP remoteWorker =
(WFWP)childAD.CreateInstanceAndUnwrap(Assembly.GetExecutingAssembly().FullName, "FE.BuildControl.WFWP");

Suddently, I was getting strange error "Type is not resolved for member 'FE.BuildControl.WFWP'". What?! The exact same code just worked from the command line.

After much painful troubleshooting, I discovered this error is more of a red herring than anything. It points to assembly loading problems (imagine that!). So, I discovered through the Fusion log and FileMon that my assembly resolution for the WFWP class was interrogating my C:\windows\Microsoft.NET\Framework\v2.0.... folder. "Why there?", you ask....

Well, it turns out that AppDomains by default will assume the same base directory as the .exe they are running from. Yes...the .EXE they are running from. :) So, when I was running as a command line app, it was probing for assemblies in the same folder I was executing from. Naturally, my referenced DLLs existed there and all was well. When in a web app, your .EXE is aspnet_wp.exe (Windows XP) or W3WP.exe (Win 2003). So, those reside in the .NET 2.0 framework folder, mentioned above. So, it was doing exactly what I told it to do, but that's not what I meant.

Enter the AppDomainSetup class:

string appDomainUniqueNamePerUser = string.Format("WF Child Domain", Guid.NewGuid().ToString("D"));
AppDomainSetup ads = new AppDomainSetup();
ads.ApplicationBase = appDomainBaseDir;
ads.DisallowBindingRedirects = false;
ads.DisallowCodeDownload = true;
ads.PrivateBinPath = "Bin";
AppDomain childAD = AppDomain.CreateDomain(appDomainUniqueNamePerUser, null, ads);

By specifying my physical folder that I'm using as a virtual directory in IIS as my "ApplicationBase" above, I can cause the assembly resolution logic in .NET to look for my DLLs there instead. The "PrivateBinPath" just helps it along and says, "DLLs in this application will be in this folder". Now, my child appdomain executes like a champ!

Moral of the story: .NET simplifies/standardizes a lot of things compared to prior languages, but one cannot assume that a class will behave identically when put in a different context (such as another hosted process).

That's all for now. Take care,