When I switch modes and work in TeamCity, I miss having that information available, with no extra steps from me. Despite several searches, though, I was never able to find a plugin that duplicated that behavior I liked in the Jenkins plugin. Turns out that TeamCity makes it pretty easy to roll your own, with just a little bit of powershell and some built-in features.

In this post I am going to cover capturing the warnings from an MSBuild build step, adding that warning count to the main dashboard, adding a statistics chart for the warning count over time, adding a condensed list to the end of the build log, adding the formatted list as a build artifact, and adding a custom report tab to report the warnings for each build.

Because who doesn't need five different ways to see their warnings?

Capturing the Build Warnings

Since I am using MSBuild, the build warnings have a consistent pattern and MSBuild itself has an option to log out to a logger. We can add this attribute in either the build step or the Build Parameters. My preference is using the parameters of the build step in case I have multiple MSBuild calls in the build.

Parameter to add to MSBuild: /l:FileLogger,Microsoft.Build.Engine;logfile=%BuildLogFilename%

Adding the MS Build Parameter

Each time MSBuild runs, it will log it's output to the specified file. We can use powershell to extract the warnings from the output, like so:

Once we have the warnings extracted, we can move on to decide how we want them delivered.

Each section below will continue to add on to this script until it contains all the pieces we need to meet the display goals at the beginning.

Condensed Warning List in Build Log

The powershell script that is extracting warnings will need to run as a build step in the appropriate build configuration. This means that displaying a formatted list of warnings at the end of the build log is as simple as outputting that list from the powershell script we are building.

This will output a section at the bottom of the build log that contains our warnings, like so:

Warnings in the Bottom of a Build Log

Which I suppose is fine, but doesn't really add that much value over the ones listed further up the log by MSBuild itself.

Condensed Warning List in Archived Text File

Now that I have formatted warnings, it's pretty easy to create a file with those warnings and archive it. First I'll update the script to take an output parameter and add some file output:

Then I'll configure the project to capture that output file as an artifact:

Artifact Configuration

Et voila, the file shows up in my archived items:

List of archived items from a run

And I have a clean, archived list of my warnings:

Display of archived text file

But, really, we can do better.

Warning count in build status

Part of the goal was to be able to see the warning count change with no extra work, the best place I can think of to meet this is the final build status on each build.

Before:

Build status on dashboard

TeamCity provides support for setting the build status from a build script. By adding some output to the powershell script, like so:

Each successful build will also display the number of warnings that were captured.

Build status on dashboard, with warnings

Better, but what about historical values? And I still don't like that text file artifact.

Warning Count as a Custom Chart

TeamCity also provides the ability to add custom charts based on either built-in or custom statistics. Custom statistics are reported similar to the build status output above:

Adding a custom chart requires us to dig into the configurations of TeamCity. I'm going to add a chart that will be displayed for any build that provides the warning count number above, so I'll open the [teamCity data dir]/config/main-config.xml file and add the following section:

This will add a chart to the Statistics tab of the build. After a few builds this is what I have:

Build Warning Statistics

It probably would look better if I hadn't built with the same number of warnings each time, but you get the point. The mouse hover works just like the built-in charts, linking to the run status for the individual point.

Ok, getting better, but I think we can take it one step further.

Adding a Custom Build Warnings Tab

So far we have improved methods of seeing the warning count and watching how it changes over time, but the actual list still leaves something to be desired. Luckily, TeamCity supports custom report tabs in the Build Results. This gives us an easily accessible place to put the warnings and, since it uses HTML, better formatting options than the text file.

First I need to update the powershell script to output the HTML file. TeamCity will be picking up an entire folder for the report tab, so I could add some external CSS or image files for my report, but I'll leave that for another day.

I've added HTML output to the script with a hardcoded output location that ensures the report directory exists before writing the index.html page. I've hardcoded this value to reduce the amount of thinking 'll need to do as I add this to other projects (keeps it consistent from output name to artifact setting to report tab configuration).

The next step is to configure the project to capture the folder as an artifact:

Artifact configuration

Then the last step is to modify the TeamCity configuration to recognize that when I output archives like that, I want to treat them as a report. To do this I add the following chunk of XML to my [TeamCity data directory]/config/main-config.xml file (per the documentation link above):

And there we go, the custom report tab is available in the build results:

Build Warnings tab in Run Results

Which takes us from no visibility into our warnings, to five different methods of viewing the information.

Wrap-up

From having to Ctrl+F through the build log all the way to plugin-level output in a few easy steps. After setting this up one time, the only pieces that needed to be repeated for additional builds are the addition of the /logger parameter for MSBuild and the powershell build step to extract the results, and capturing the artifact for the HTML page. All of the output is either built in to the script or applies to the whole server and is displayed whenever the statistics or archive are present in a build.

Here is the finished script:

To recap, we started with some warning messages randomly scattered across the build log. We ended with the warning count automatically showing in the build status on the dashboard, a nice chart of the number over time, and three different ways to view the detailed list. I hope this proves useful to others as well, now I have to go and fix the sample warnings I added before I forget about them.

How it works

TeamCity has project and build level custom charting that is driven by settings files. These files and the format of the necessary chart definition are documented. The actual graph XML is pretty straightforward and easy to implement. The files refer to values that are provided by TeamCity (listed on that page), via a special file you drop during your build (teamcity-info.xml), or via service messages.

Graph Definitions

In the Jenkins build I had graphed the following data from the WCAT run:

• Rate Graph - Transactions Per Second, Requests Per Second
• Totals Graph - Total Transaction count, Total Request count, Total Error count
• Response Time to Last Byte Graph - Minimum, Average, 95th Percentile, 99th Percentile, Maximum

To match this in TeamCity I created the project-wide graph settings like so:

Besides the key in each valueType tag, I also include a buildTypeid that is the internal build ID for my automated load test build. I found this in the address bar after clicking the build's link on the dashboard:

Team City - Build URL

Defining the Data

Once I have the definitions roughly the way I want them, I need to make the data available from the WCAT run. WCAT already produces it's results in XML and for Jenkins I created an XSL to transform the results into a new XML file that would be easier to plot in Jenkins. For TeamCity I'll do the same, but this time I decided to use powershell to execute the transformation.

The WCAT results take some work to decode, as they are stored in XML that is halfway to presentation format. Luckily I have already done this once, so creating a new XSL is fairly easy:

(The final XSL is located on bitbucket in the event that I make any future changes).

The powershell command to run the transform is then as easy as:

TeamCity replaces the variables with the correct values and transforms the generated log into the specially named "teamcity-info.xml" file.

Done

I wasn't happy about editing settings file in TeamCity directly, especially given the implications this has in a real environment (how many people would need to be involved to do this in a heavily audited environment?). However that was the only issue I had and I am happy with the results (the build versions are the same because I rebuilt several times so I would have a decent chart):

Team City - Finished Charts

For bonus points, the same functionality you have with the built-in charts is available here. You can change the time period, view averages of the values, and change which points are graphed by checking or unchecking them.

Take it to the cloud, of course.

(Well, and write a bunch of blog posts and a wiki page too)

Azure Setup

The target of this exercise was to get the project deploying automatically to the cloud, and I wasn't particular about where. I decided that the free website feature in Azure would be a good target. Mostly due to the free part but also because I suspected it would be easy.

First up was creating an Azure account, which I did via WindowsAzure.com. The Web Sites feature is still in Preview mode, so I had to go the preview features and enable it.

WindowsAzure.com - Preview Features Option

The Web Sites option is at the bottom and enabled with a button and dialog:

WindowsAzure.com - Preview Features

Once it's enabled, I can go into the portal and when I press the "New" button at the bottom, I'll have options to create a new Web Site instance.

WindowsAzure.com - New Website

After creating the new site, it will provision and show up in my dashboard:

WindowsAzure.com - Dashboard

That's all it takes to have a new Web Site in Windows Azure. Of course it's not doing anything useful at the moment, so lets go back to the build process and fix that.

Build Process Changes

Because I chose to use an Azure Web Site, the build changes are going to be minimal. Microsoft intends us to use the Publish feature in Visual Studio or Web Matrix to deploy our websites, so they give us all the settings we need to run the msdeploy executable from a build step instead.

In the properties dashboard for the new website above, there is a link to download the publish settings for the site and a link to setup credentials. First setup the credentials, then click the download link to download the publish settings. These settings are intended for Visual Studio or Web Matrix, but being XML we can read the file and pluck out the important values.

I made a copy of my final "Deploy to Production" step and modified the msdeploy step to use a new Param file. The Param file is used during the deployment to set the IIS name and connection strings, you can see all of them on BitBucket.

TeamCity Build Steps

MSDeploy Command (TeamCity version):

I then updated the Configuration Parameters to reflect the Azure credentials and URL so the deployment and smoke test would work properly and entered the username and password entered in the Azure Dashboard in the prior step.

TeamCity Configuration Parameters

And that's it, probably the fastest on premises to cloud change. Press the build button in TeamCity and we have a green build to the cloud:

TeamCity Build Successful

And after a similar set of changes in Jenkins, I have a parallel production step that targets Azure as well:

Jenkins Build Pipeline

And of course I had to push the button a few times:

Jenkins Build Success

You can see the site here: http://elismvcmusicstore.azurewebsites.net

Note: It will probably load slowly. It's on a shared node and seems to go to sleep since it gets visited so infrequently. If I felt like paying for it, it's just a toggle button away from running as a reserved instance (and another to scale it up to multiple instances)

That was the easy button version

Despite the fact that I chose the easiest possible target, as long as we can script the deployment we can easily add it into the pipeline and know that our deployment is taking exactly the same steps every time it deploys. Whether we were instead deploying to an Azure web role, deploying EC2 instances, or pushing to another provider, we have the framework to do so consistently and safely.

General Feelings

My general feelings towards TeamCity during this process have been good. I found several places where TeamCity would have been easier to use [than Jenkins], such as parsing test result files and evaluating results. I like the visibility of pending changes for each build step and everything I have implemented has been extremely straightforward (though I haven't taken on custom graphs and code coverage yet). Wiring together dependencies was far easier and clearer then in Jenkins, and the build-level configurations and sharing of build numbers throughout the build was a lot cleaner. Little touches like previews for the artifacts and working directories were also extremely handy.

Not everything was perfect, however. The build chains were as close as I could get to a pipeline visualization and they are busier then the pipeline view in Jenkins. There also wasn't an obvious way to use a build chain view for the dashboard. Rerunning steps in the build would create a whole new chain, rather then being treated as a retry of a prior run of the same snapshot. The plugins don't feel quite as first class in TeamCity as they did in Jenkins, but the built in functionality was quite a bit more extensive, so I think this just comes down to focus and my own experience (or lack) with the tools.

But enough of my feelings, lets do some technical stuff.

Review of the Build Process

The build pipeline is the process the code goes through from committing the code to eventual delivery, automated where possible to minimize the lead time for new features and wire in good practices I want to follow. The code is built and passes through a variety of tests and checks at each step, with only a few configurations changing along the way, ensuring what is released has passed every step as quickly and consistently as possible (smooth is fast).

The current Jenkins build pipeline looks like this (plus lots of static analysis that doesn't fit in the picture):

Continuous Delivery Pipeline with Load Test Step

These are the portion I intend to do in TeamCity:

CI Stage

Monitors main code repository, execute build, run unit tests, deploy to ensure deployable, smoke test deployment

Interface Testing

Monitors interface test code repository, deploys + smoke tests deployment, runs interface tests

Load Testing

Monitors load test code repository, deploys + smoke tests deployment, runs load test

QA Deploy

Manual QA deployment for imaginary QA department

Prod Deploy

Manual production deployment

I will be leaving the load test results graph and static analysis until a later post.

Server Setup

Since my original post I have setup a dedicated Hyper-V server on Windows 2012 RC and moved the original AVL-BUILD-01 and AVL-BETA-01 server to this host, adding an AVL-SQL-01 that serves as a host for environment-specific MSSQL databases. I created the new TeamCity build server (AVL-BUILD-02) to match the original, including same versions of OS, Visual Studio, etc:

Initial Installs:

• Windows 2008 R2 + lots of Windows updates
• Visual Studio 2010 + more updates (SP1, etc)
• ASP.Net MVC3
• TeamCity 7.1
• Mercurial 2.3.0 (only version difference from AVL-BUILD-01)
• Web Deploy 2.1
• WCAT 6.3
• FireFox 146 (or whatever)

As noted, the Firefox and mercurial installs didn't match, version-wise, but everything else I kept the same as the Jenkins build server.

Creating the CI Build

The CI project is probably the most complex one due to the number of steps and fact that it serves the artifacts every later step will use.

1: Create the project
The project serves as the container for the builds, creating one only requires a name and optional description:

Team City - Project Setup

Once the project is named, I can add my first build step (don't worry, I'll only do these screen shots one time):

Team City - Ready to add builds

Here I'll name the build step and define the artifacts I want to store for later use, including the deployment package I intend to make and the folder of environment-specific configurations.

Team City - Adding a Build

Next is the settings for the main site code repository. To create VCS settings for the build we need to create the VCS root (which includes the polling settings) then define the settings that are specific to this build.

Team City - Defining Version Control

At this point I can start adding my build steps. These build steps will duplicate the ones I used in Jenkins. An advantage over the Jenkins setup is that the MSBuild runner already has versions configured and there is a built-in MSTest runner. When entering the command-line calls I used in Jenkins, I'll substitute in TeamCity variables using the small image next to the inputs.

Team City - Build Steps

Below the build steps I have used the report processing feature to process the results of the smoke test script (original post here), which outputs in JUnit format. TeamCity will automatically collect the results from the MSTest step and this step and make them available in the summary and run details.

The second to last steps is to setup a build trigger to run on VCS changes, which is a couple clicks and extremely straightforward.

Team City - Adding a Trigger

Then the last step is to define the build parameters. TeamCity automatically detected the extra unrecognized parameters from my command-line build steps and has added them to the list of build configurations, which I thought was pretty slick. To make it even better, I can reference these parameters from later builds to reduce the number of places I need to define unique settings.

Team City - Build Parameters

Once I have finished setting up this build, I can return to the main dashboard and run it on demand by pressing the "Run" button.

Team City - Dashboard

And we have the first build stage done.

Creating the Interface Testing Build

The interface testing build (original post here) is only a few steps. The first few stages of this build are the same, I create the build, define a VCS root that points to the Interface testing project on BitBucket, then add the build steps. I use an MSBuild step to build the automated interface test project (SpecFlow, Nunit, Selenium), command-line steps to call MSDeploy and the smoke test script, copy in the automated test settings for the tests, then use the built-in Nunit test runner to run the automated test assembly.

Team City - Interface Test Build

Skipping ahead to the Dependencies section, I'll add a snapshot dependency on the CI stage so that builds of the Interface stage use snapshots from the same point in time as it's linked CI build. I'll also add an artifact dependency to pull all of the artifacts from the CI build into a local folder named PriorArtifacts, keeping with the pattern I used in the Jenkins build.

Team City - Dependencies

Next I add a build trigger to run after a successful build of the CI stage and fill the dependencies with references to the values from the CI Build where I can.

Team City - Build Parameters

And the last step is to return to the project screen and define the Artifacts for this stage as "PriorArtifacts/*" so it will pass on all of the artifacts it pulled in from the prior stage.

Running this build reminded me that Firefox has a nasty habit of downloading updates when you least want them, as the interface tests started timing out because they couldn't quit. A quick tweak to the Firefox settings and I have a successful interface test step running, with the test results showing in the summary just like the CI stage.

Team City - Interface Tests

Note: The build number for each build allows you to define your own pattern. By setting it to %dep.bt2.build.number%, each of my builds use the build number I created in the CI stage (which is used again in the smoke tests).

Creating the Load Test, QA, and Prod Builds

At this point I have all the pieces I need to finish out the last 3 stages.

Load Test Build
The Load Test stage (see original here) gets the same build number and artifacts as the Interface Testing stage. I add a new VCS root to pull down the load tests scripts from BitBucket, deploy, smoke test, then run the run.cmd file that runs the WCAT load test. I skipped the challenging part of this, which is turning the results into a chart, but as I mentioned earlier that sounds like it will be a follow-up post of it's own. The dependencies, parameters, and build trigger are set up the same as the Interface testing build.

Deploy QA and Deploy Prod Builds
The last two are rinse and repeats. Take the build number and artifact settings, no VCS settings, add dependencies and leave them to be triggered manually.

The Pipeline

Those 5 builds compromise the core of the pipeline and show up in the TeamCity dashboard like so:

Team City - Full Dashboard

To get to the build chains view, go into the Project page and click the last tab to the right, titled "Build Chains".

Team City - Build Chains

The summary bar lists the final step and status in the chain, the last step that ran, and the date. Expanding it shows the full chain (though there are some scrolling issues).

Last Words

This was an interesting project, as I was able to take a fairly complex build and see how it would work in a completely different engine. The addition of a first class pipeline view is probably the biggest item on my wishlist and I look forward to seeing what they do with it in the future. Even without that, though, it was a great tool to use and offered me none of the teething problems I had with several of the Jenkins plugins.

Sample screenshot from interface

Spoilers: I liked it. A lot.

About Librato Metrics

Unlike the unstructured data logging services in the prior posts, Metrics is all about storing, displaying, and alerting on numeric metric data. This limits how you would use it, for instance you wouldn't be able to dig into a spike in page execution times and see the id's of the users or the type of browser that was in use. On the other hand, the focus on numeric gauges and counters means that Librato can provide a deeper set of tools around graphing, alerting, and dashboards.

Highlights:

Librato's API is extremely full-featured, offering GET/PUT/POST actions for creating, sending, and retrieving metrics, as well as endpoints to interact with other facets of the service, like dashboards. All of this is offered through an interface that is both polished and usable, with none of the lag I ran into on some of the other services. In addition, support for alerting is built into the application.

Input Support: HTTP GET/PUT/POST/DELETE everything (see note below) with JSON
Output Support: Same as above, plus has support for paginating large sets of results
Ease of Setup: Very easy through the interface or by just sending new data metrics, API token is immediately available for use
Searching: This is not a log service, so the searching only covers searching for entities (metrics, dashboards, etc)
Visualization: Great. Though they currently only have support for line graphs, the overall interface is fantastic and there are other graph types in the works

Note: The full list of elements you can interact with via the API includes Metrics, Instruments, Dashboards, Tags, Alerts, Services, and even Users.

General Opinion:

This service is easy to use, provides a really usable interface, and is completely open and extensible through a very rich API. Despite some hinkiness with the dashboard timespans, which I think is due to the small amount of sample data I had and their down-sampling method, this is an excellent service. The services also support sending data aggregated over a time period (multi-sample), so you can buffer and send at longer intervals if the finer detail is an unnecessary drain on your wallet or network.

I suspect that their interface uses the same API that they expose to end users, as I haven't been able to find anything I could do in the interface that wasn't also possible in the API. Exposing the data through the API also means that not only do we have all of the graphic and alerting capabilities that are built in to the service, we can also extend it to do more (something several of the other reviewed services required to even get a simple graph).

Getting the sample application hooked into the service was extremely easy, even taking into account the fact that I had to write a parallel set of methods to send the metric data instead of the log data for the other services.

Running the Sample Site with Metrics

Clone a copy of the sample application from tarwn/InstrumentationSampleCode on github. Go to the metrics.librato.com website and sign up for an account (they have a 30 day free trial).

After signing in to your account, you can access your account information from the "Account Settings" link at the bottom of the screen. Add or edit the sensitive.config file at the root of the .Net solution, substituting your values where appropriate:

sensitive.config

Load up the sample app, click some buttons, then switch over to Metrics to see the results. You should see several new gauges and counters in your Metrics list:

Metrics List

Clicking on one of these metrics will open the metric so you can see it's display settings and a graph of it's recent values:

Metric Details

We could spend a lot more time getting into the details of creating instruments, dashboards, alerts and so on, but at this point you should have everything you need to start playing with those on your own.

I've really enjoyed using Metrics so far, and if you're looking for a metrics tool you should definitely give it a test drive.

My Original Post: Evaluating ORMs for Batch Data Performance
Source Code: My fork of StaticVoid.OrmPerformance

I received a lot of good feedback and suggestions on that post, and implemented all of the additions (except Kermit's, oops). While I am still looking primarily at bulk insert performance, I also implemented the other test operations and Luke has pulled most of the changes back into his project (I am behind on issuing a pull request for NHibernate, sorry). This post is a follow-up on those additions with an updated conclusion, if you hadn't read the previous post, it's probably still worth a read.

The Updated Lineup

The updated lineup for tests now looks like:

• EntityFramework 4.1
  
  • Basic Configuration (No optimizations)
  • AutoDetectChanges Disabled
  • Tuned
• EntityFramework 5.0 beta1
  
  • Basic Configuration (No optimizations)
  • AutoDetectChanges Disabled
  • Proxy Entities
  • Tuned
• Dapper 1.8
  
  • Dapper Rainbow
  • My Best effort at making it go fast
  • Batching inserts/updates using transactions
• LINQ to SQL
  
  • Basic Configuration (No optimizations)
  • Tuned
• NHibernate 3.2.0.4
  
  • Basic implementation
  • Stateless + 200 record batches
  • Stateless + 1000 record batches
• PetaPoco 3.04
  
  • Basic implementation
  • Batching inserts via transaction
• Simple.Data 1.0.0 rc 0
  
  • Basic implementation
  • Batch inserts (built-in, automagical)
• Raw ADO methods
  
  • Basic SQL Command
  • SQL Command w/ Transaction
  • Bulk insert via SqlDataAdapter
  • Bulk insert via SqlBulkCopy and SqlBulkCopy w/ Table Lock option
  • Bulk insert via one really big SQL string (single insert w/ lots of concatenated value statements)

Along the way I also updated the project to include more information in failing assertions (the state is asserted after each test is run).

The Results

I was simultaneously surprised and not surprised at the results. With Mark Rendle (blog|twitter) suggesting I add Simple.Data, I fully expected it to keep up with SqlBulkCopy, but it was still surprising to see the real, raw data.

10,000 row inserts, Best times for each category

Raw SqlBulkCopy was still the best option for 10,000 records (this is the TabLock option variant), but Simple.Data was right up there with it. PetaPoco and NHibernate are our other new additions and they were fairly close, about 20-25% slower than Dapper, or about 7x the SqlBulkCopy test.

But the important item on this graph really is Simple.Data. There are many that argue that all ORMs are slow and not worth spending time on but this is clearly not so. Simple.Data was a little slower than SqlBulkCopy and much faster than the other raw ADO variants. And it does this with no column mappings, no tricks and no special configurations. That is a huge milestone for ORMs and makes it tempting to use instead of SqlBulkCopy, as this method may actually be less fragile (no column mappings have to be manually defined).

Create a connection, add as many items as you want to the list, then call Insert on the whole list. Magic.

More Detail

In the last post I included a comparison of all of the various methods used to insert data as a single graph. Unfortunately that graph was hard to read, as the basic Entity Framework methods were operating about an order of magnitude slower than everything else. I still thought the data was interesting, though, so I have created a graph with those values truncated as I did in the original post's followup. The one critical difference is that I am plotting the 10,000 record inserts instead of 100,000 like last time. That just took too long to run

10,000 row inserts, All categories and variants

With more details we can see the spread and variation a little more clearly.

Big 'Ol String method: One of the other surprises I ran into when doing this was how slow the "cram it all into one long string" method was ("SqlCommand - Insert Once" above). This is often suggested as a quick and dirty way to do batch insertion, basically by concatenating all the data into a single long INSERT statement with multiple VALUE rows or UNIONs. At 100 records this option tied with Dapper as the fastest method. Unfortunately it scales really horribly, moving up to nearly last, leading me to believe that people suggesting this method only tested it in lower ranges.

Conclusions

In my last post I concluded that I wouldn't use an ORM for batch processing, but Simple.Data has forced me to reconsider that statement. Raw speed is not the only measure I would use to select a tool for getting data A into database B, but it is clear that if my requirements include bulk data insertion, ORMs are no longer automatically taken off the table. Congratulations to Mark for making a very clean, very fast way to get a whole lot of data into a database for very little up front effort (and thanks for adding it to my todo list).

The Code, Build, Test Cycle

Imagine for a moment that you have finished writing a piece of code. Maybe it's the test, maybe it's the code you intend to test. Instead of kicking off a build and switching mental mode to run the tests, the results simply start appearing. Your test lights up red, then green as you switch to building the logic that satisfies it, never once breaking stride to wait for the test suite to run. Your uncovered code is clearly marked as uncovered before you even finish writing it to press save. It's magic.

And so very, very addictive.

Hey Kids, Try Some of This

Instead of screenshotting our way through another post, let's do this together. First download and install NCrunch. Then either download or clone the git repository sample I have set up here: https://github.com/tarwn/TDDAddress

Let's get started.

What are we doing?

The goal of this exercise is to build an Address class that is the business and formatting logic behind entry of a mailing address. The Address class will expose properties to tell an interface what address fields are available, what they should be labelled, whether the address has all the required values, and a displayable formatted address. In return, it will expect that interface to populate input properties for all the address input values.

This is both as easy and quite a bit harder than what it sounds like. Easier in that we won't be writing a game or similarly large construct, but harder because the rules for mailing addresses are not as well defined or as simple as you may think. In fact, most websites on the internet do it wrong, and not just for addresses outside the US.

Luckily there are some people that have tried to pull together all of the rules from the USPS and other sources and we can use the results of their hard work to serve as a spec for our Address logic. The rules we are using were sourced from http://www.columbia.edu/~fdc/postal/#general, but I've only included a subset of them in this project.

Project Setup

There are two projects in the solution, one to hold the Address class (Main) and one for the tests (Main.Tests).

Just a pair of small projects, nothing scary here

The Address class already has the basic properties it needs, but everything else is up to you.

Let's Go

Open the solution and enable NCrunch (it finished installing, right?) by selecting it from the top menu and selecting "Enable". For the most part you can select the defaults when it is enabling. Either select the option to enable all of your tests by default while it is going through the dialogs, or open the Tests window, make ignored tests visible (grey icon on far right) and enable tests for the two projects manually.

Ready? Ok, moving on.

Open up the AddressTests file in Main.Tests and the Specs.md file from the root of the solution. Add the first test to the AddressTests like so:

This test is the second rule in the included Specs.md file. After you add the test code, red dots will show up next to executable lines in the test that are on the path to a failed assertion.

Tests are automatically red/failing

NCrunch is building and running the tests behind the scenes as you add more code, automagically. Switching over to the Address class, we'll notice that it also has dots to indicate portions of the class that are referenced by failing tests. Right-clicking on any of these dots provides more details, options to run tests in debug mode, and so on.

Now add some code to satisfy that test. As you make addition, NCrunch continues to build and test in the background, displaying the updated dots as you work.

Tests and code turn Green automatically

When you get to all green dots, you're done. No need to stop, just move right on to the next test.

Enjoy the flow.

I decided to stick to ADO.Net methods for data and to focus on the insert, as a fast insert can be used to replace updates and deletes. SSIS and bcp would be alternative options, but would require additional setup to test alongside the .Net code.

Method

The method for these tests closely resembles the one Luke followed in his original post. The main exception is that I am using a local SQL Server 2008 R2 instance rather than a remote VM. Unfortunately attempts to run a full test set against my remote SQL Server VM ran into errors each time I tried, generally in the Entity Framework setup, teardown, and assertion code. My local system has a large enough amount of RAM and cores that any impact from running the tests locally should be limited, with only the network constraint removed from the equation.

Tests

I focused entirely on the insert tests, adding two new tests to use SqlDataAdapter and SqlBulkCopy. The test lineup then became:

• EntityFramework 4.1
  
  • Basic Configuration (No optimizations)
  • AutoDetectChanges Disabled
  • Tuned
• EntityFramework 5.0 beta1
  
  • Basic Configuration (No optimizations)
  • AutoDetectChanges Disabled
  • Proxy Entities
  • Tuned
• Dapper 1.8
  
  • Dapper Rainbow
  • My Best effort at making it go fast
  • EDIT Batching inserts/updates using transactions
• LINQ to SQL
  
  • Basic Configuration (No optimizations)
  • Tuned
• Raw ADO methods
  
  • Basic SQL Command
  • SQL Command w/ Transaction
  • SqlDataAdapter
  • SqlBulkCopy

The raw code is available on my branch at github: https://github.com/tarwn/StaticVoid.OrmPerformance and the original is located on Luke's here: https://github.com/lukemcgregor/StaticVoid.OrmPerformance.

SqlDataAdapter Method

The SqlDataAdapter method is to create a local DataSet or DataTable then provide this to a SqlDataAdapter with a configured SqlCommand object and parameters. The SqlDataAdapter takes care of the details, getting all the individual rows of data into the database via that insert command. Because we are operating on the full set of data, the test stores all of the values in memory until it is told to commit them.

SqlBulkCopy Method

The SqlBulkCopy object is designed to "let you efficiently bulk load a SQL Server table" (MSDN). It provides similar functionality as bcp, but from inside our .Net code and without the format files. This test works similarly to the SqlDataAdapter test, in that it holds the entire DataTable of test data in memory until it is told to commit it in one go (some of the tests are iterative, some are bulk, the test method caters to both).

Results

I'll admit the results were not that surprising. SqlBulkCopy was the fastest method for inserting larger amounts of data, but had some initial overhead that made it slower for the 1, 10, and 100 record tests. Compared to the best times from the other methods (SqlBulkCopy is the SqlCommand representative in the chart), the performance difference is clear:

Best Times for 1, 10, 100, 1000, 10000 scenarios

Extending this to a larger set of 100000 records and the difference is relatively the same. Relative to the prior set of results, SqlBulkCopy is not as much faster on the 100,000 run as it was on the 10,000. It would be interesting to switch to increments of 10,000 and see if there is a pattern to it.

Best Times for 1, 10, 100, 1000, 10000, 100000 scenarios

I also thought it was interesting to see how well the tuning improved some of the ORM methods. In the case of Entity Framework, it's clear that if you intend to use it for batch data then tuning is a requirement, not an option. The out-of-the-box experience for Entity Framework 4.1 and 5 were roughly an order of magnitude slower than all other tests.

Scaled out to show EF 4.1 and 5 Basic Performance

The other key indicator is memory. Our two new methods store all the data and send it in a single command, so they will have a higher memory footprint to accommodate that data. The methods that incrementally send the data, like the Dapper scenarios and basic SqlCommand option, will use very little data since they are flushing each addition directly to SQL.

Memory Usage per Test Type

This graph shows the memory/record of the 1000, 10000, and 100000 test runs. As we would expect, the memory/record for the full batch methods is reduced as the overhead is spread across more records. Entity Framework show consistently high memory usage, but the Proxy Entities method does bring it down to just about twice as much as Linq2SQL, which is in turn about 50% higher than the SqlCommand/SqlBulkCopy methods.

Conclusions

For pure, batch insertions, I still wouldn't use an ORM. These tests show that the ORMs tested are still significantly slower at batch insertion than tools built specifically for bulk operations, like SqlBulkCopy. We've also seen that when we do use an ORM, understanding it's performance characteristics and how to tune the ORM can make an enormous difference in how well or poorly it works.

Follow-up

Based on Tudor's comment below, I've generated a graph of the times for each method in the 100,000 record tests. Unlike the full chart above, I've scaled it to ignore the two basic Entity Framework entries that cause the line chart above to be so unreadable.

Readable Execution Times for 1000,000 records

Using ADO.Net does not automatically mean better performance than an ORM. SqlBulkCopy does clearly perform better, but using a SqlCommand.ExecuteNonQuery or a SqlAdapter.InsertCommand does not achieve the same level of performance. Many of the ORM tests kept up or outperformed the non-transactional SqlCommand and SqlAdapter tests, and Dapper kept up with the Transactional SqlCommand test. ADO.Net itself is not giving the boost in speed we see from SqlBulkCopy, it's the use of a tool that is built specifically for batch processing (all of the rest operate at the row level, ADO.Net or ORM).

Keep in mind, I have extremely high hopes for these types of services, due to my experience in instrumentation and logging in manufacturing environments (see the first post). None of these systems are built with this task specifically in mind, so services that are absolutely wonderful at their core competencies may not prove to be a good fit for this specific use case.

In any case, let's see what we're going to be looking at:

A few of these were non-starters, but I'll record what I know about them. The rest I'll present in similar formats for comparison.

Loggly

Loggly was one of the first logging services on the market as well as one of the first I instrumented with the application.

Highlights:

Loggly supports raw text, syslog, and JSON data posts and is a live service (not beta).

Input Support: HTTP with raw text or JSON plus an array of syslog options
Ease of Setup: No default inputs, have to create an initial HTTP JSON input which is fairly easy. Good samples provided for communicating with input.
Searching: The search uses a console-like command line input for searches with limited direction and assistance (more later), I didn't invest the time that would have been necessary to learn enough of the search interface to become even a beginning user
Visualization: Nonexistent. Has examples of how to build your own in python, jQuery, and google charts

General Opinion:

I would not use this service for application instrumentation. The search is the only feature it offers and that is in beta (Loggly has been live for several years). The command-line search idea is cute, but to me is an example of form over function that suffers from sluggish response times, low usability, and an unnecessary initial learning curve. My use of the site was characterized by extremely long loading times (30-60 seconds) and the lack of initial defaults for new users seems like a missed opportunity. If they were to focus on fixing the performance issues, improving the usability, and implementing visualization, I'd be ready to give them a second look.

Running the Sample Site w/ Loggly

Clone a copy of the sample application from tarwn/InstrumentationSampleCode on github. Go to the Loggly.com website, sign up for an account (you can get a free account by dragging the bars on the pricing page to the lowest values), create an HTTP input with JSON.

Once you have the input created, create or edit the sensitive.config file at the root of the solution with the following values (substitute your GUID in where appropriate):

sensitive.config

Open the site, try a few things, then switch over to the Loggly screen and see if a page will load long enough to show it received some data.

DataDog (Could Not Review)

DataDog looked like it would be a good option, but after setting up my initial account I found I could not continue until I installed an agent on a server with a supported operating system. Unfortunately Windows is not supported (which was not obvious until you got signed up), so I was unable to continue.

They did email me a few days later to ask if I had any difficulties getting signed up since I hadn't finished the activation step, and the email looked personal and friendly, so I may return and see if they can help me get past that step to try the service for instrumentation purposes.

Splunk Storm

Splunk Storm is a beta service from Splunk, which is a name that should be highly recognizable in the logging world. Storm is their beta service to offer the capabilities of Splunk without a local installation.

Highlights:

Input Support: HTTP with raw text, syslog, netcat, and "any other application that transmits via TCP or UDP"
Ease of Setup: Easy enough. API tokens are already available for use but error reporting on individual HTTP posts can sometimes be useless (501s for instance)
Searching: The search for splunk is the bar to measure the others by. They use a text-based language but everything on the screen is clickable, common fields are captured and listed on the side for easy searching, and the search language itself is something you can pick up a bit at a time
Visualization: Pretty decent but there are some definite learning curve moments and when you try to graph too much data it throws away parts of the dataset entirely

General Opinion:

I have been using Splunk Storm for longer than any of the other services. The service itself is very promising. It offers a really good search capability with a great drilldown capability and setup was easy. Often it will give mini-help boxes when typing terms into the search and suggest similar searches I have done recently, details on commands, and suggestions for commands I may want to use.

Unfortunately they are using the bad definition of "beta", instead of the "it's relatively stable but not feature complete" definition. There have been at least two occurrences where I was locked out of the system while they performed maintenance, on one occasion an update actually locked me out of the main account for 4-5 days (with a constant friendly reminder that service would be back momentarily). Documentation links are present throughout the application but most of them lead to 404 pages. The fact that charts throw away portions of the dataset when you ask them to chart too much can be incredibly frustrating (when you figure out what it's doing).

After the initial exposure I started to find that I was spending more and more time in the splunk documentation (once you figure out how to get there) simply trying to learn their command-line language because the interface only gets you so far. The power of the tool is impressive, but the level of effort I would have to spend learning how to use their tool is a common annoyance that reminds me of Loggly's command-line tool. I've also seen more of their 404 narwhal page then I ever expected to see, as apparently any page that is left open for too long refreshes and drops you there (session time out perhaps?).

Running the Sample Site w/ Splunk Storm:

Clone a copy of the sample application from tarwn/InstrumentationSampleCode on github. Go to the splunkstorm.com website and sign up for an account (all accounts are free while it is in beta).

In the inputs section of the project there is a tab called "API" that has the access token and project id. Add or edit the sensitive.config file at the root of the .Net solution, substituting your values where appropriate:

sensitive.config

Load up the sample app, click some buttons, then switch over to Splunk Storm and try out the search. Clicking different items in the log entries will fire off searches. Unfortunately charting is almost a blog series on it's own, sorry.

Sumo Logic (Could Not Review)

Sumo Logic claims to provide "the first cloud-based log management and analytics solution". The demo video shows a product that has similar capabilities to Splunk in the search area with additions of automatic pattern detection and monitoring. Initially I did not demo the product because they don't offer unattended demos, you have to sign up and wait for someone to contact you to hold your hand while you demo their service. Later, as I was reading their FAQ, I found that they do not offer an API, accepting data only via collectors that are installed on your local system. The collector idea isn't bad, manufacturing historians have been doing this for a couple decades after all, but without demoing I couldn't tell how easy or hard it would be to install them and automate that installation for those of us with large numbers of servers or elastic infrastructure.

logentries

logentries is a cloud logging service that has been on the market for over a year and offers free and metered accounts.

Highlights:

Input Support: HTTP with raw text, agents, or an array of syslog options
Ease of Setup: No default inputs, have to create an initial log. Doesn't respond to success or error HTTP calls, making troubleshooting difficult. Initial data didn't show in site until I specifically hit the refresh button in the top right of the app, leading to several hours of frustrated and unnecessary troubleshooting initially.
Searching: The search seems fairly basic, but they pattern matching and tagging ability lends a second dimension to search capabilities. Creating patterns was not straightforward, however.
Visualization: Graphs are purely around tags and data records, no ability to extract values from entries and graph them (so somewhere between loggly and splunk in this regard)

General Opinion:

Logentries doesn't seem like a good solution for application instrumentation, but this is more due to their focus being different from what I was looking for. I did have difficulties with the initial setup due to the lack of response from their HTTP service, the fact that all of their language examples use raw TCP sockets instead of HTTP libraries, and the delays in data being sent and actually showing up in the interface.

I also found the search and pattern sections frustrating. That being said, some of this was due to me trying to misuse their service for instrumentation and because their documentation is not linked from inside the interface. The search supports regular expressions and provides a good number of examples, which makes it almost as powerful as the other services without the need to learn a whole new syntax or language.

With one exception, if I was looking for a log monitoring and alerting system I would consider starting here because I could get farther for a reduced learning curve and startup time. Unfortunately the exception is that I can't tell if my data is actually reaching them or not. Switching to the TCP method they outline may or may not resolve this, but the lack of error feedback even if I got it working with that method.

Running the Sample Site w/ logentries:

Clone a copy of the sample application from tarwn/InstrumentationSampleCode on github. Go to the logentries.com website and sign up for an account (there is a free account with limited storage).

Add a new Host entry, then inside that host add a new Log with a type of "API Library/HTML". Add or edit the sensitive.config file at the root of the .Net solution, substituting your values where appropriate:

sensitive.config

Note: I fired up the sample app pointed at logentries when I started writing this up, my data still hasn't shown up. I'm not sure if it will or not.

Papertrail (Could Not Review)

Papertrail looks like a pretty solid service, from their front page. Unfortunately while they do support a large number of systems as log inputs, a REST API is not one of them. They do support syslog as an input source, however, so it should be possible to communicate from an instrumented app over TCP using the syslog format.After digging into more of their documentation, however, it looks like this system could offer some instrumentation support from an alerting perspective, but doesn't really offer the types of capabilities we would want for instrumentation (aggregating and analyzing values in like log entries, for instance API executing times across multiple calls).

Summary

Most instrumentation data options require local installers, many based on RRD storage or other, similar methods. I did find an open source server called Nimbits which is designed as an operational process historian and would likely be very good at storing discrete counter and numeric values (similar to graphite or an RRD tool). I also found Metrics, which appears to be a much better fit for instrumentation then these logging services and is worth considering for a future instrumentation post. Unfortunately these options are a different enough model that I couldn't compare them side-by-side with the logging services in this post.

It is certainly possible to instrument your applications with limited impact and modification to the source application, however most of the logging services I could find don't offer the type of support you would want for that type of exercise. Splunk Storm seemed to offer the closest capabilities, but the service has the ability to be unavailable when you need it the most. That being said, many of the services would probably shine when used for the purpose they were created for and the fact that I couldn't misuse them for this other purpose shouldn't dissuade you for looking into them for log management and analytics purposes.

The sample code is available on github and will continue to be updated as I add services I am trying: tarwn/InstrumentationSampleCode

The purpose of this post is to outline that common portion of the application before we get into the reviews, so we have a common starting place and something to refer back to once we start customizing to support the services.

The Sample Code

The sample code for this series is relatively simple. The solution includes 4 projects: Logging, LoggingTests, SampleSiteWithLogging, and SensitiveSettings.

Logging

This is the core project for the post series. The goal of the Logging library is to make it extremely easy to log from inside the application (think statsd + graphite ala Etsy simple) while making it easy to swap out which logging service we are using.

There are two major components in the library, the Logger class which provides singleton access to the selected logging service and the required one line log calls and the HttpJsonPost, which handles HTTP requests (currently focused on key/value data for unstructured JSON or raw text posts).

The singleton can be setup with any implementation of an ILogProvider. It provides methods to log a single message or produce a message that automatically logs itself on disposal (capturing elapsed time and including it in the message).

Logging.Logger (source)

Each log call passes in a message and a callback that will be called with the result of the HTTP post, though so far the sample website code is using fire-and-forget, not bothering to provide a callback method.

To support the ILogProvider implementation, I created an HttpJsonPost class class and associated helpers to handle the HTTP communications. This class can do synchronous and asynchronous HTTP requests to the relevant services:

Logging.Communications.HttpJsonPost (source)

This little bit of code and their supporting classes are all it takes to talk to the external logging services, and to do so with limited impact by using asynchronous requests and callbacks.

The Sample Website

The sample website contains very little code that I added. The majority of the code is the "Empty MVC 3 Web Site" template from visual studio, I've added an extremely basic HomeController and some setup code in the global.asax to setup the log provider and log a few events.

SampleSiteWithLogging.Global (source)

The global.asax file allows us to wire logic into the global application workflow. On startup we get a provider, based on our "Sensitive Settings" configuration file, set that as our default logger, then go ahead and log our first message with entries to indicate this is application startup and the current UTC timestamp. Each time we receive a request from a web browser, we use our on line logging call to log the browsers UserAgent string and a timestamp. When an error goes unhandled, we can log that too.

Elsewhere in our application we can use those same one line calls to pass information to the logging service. The HomeController logs information, but instead uses the CaptureElapsedTime method to log information and the time that elapses between it's instantiation and disposal.

SampleSiteWithLogging.Controllers.HomeController (source)

These examples are actually more wordy than I would like. If I were building this as part of a production application, I would refactor them down to take explicit arguments or infer some of the values, reducing the size of each call even further.

"Sensitive Settings"

The Sensitive Settings library is just a quick settings library I threw together so I could prevent my API keys for these services from getting committed to github. The library is referenced by the website and unit test projects, each of which have a prebuild step to copy the "sensitive.config" file from the solution folder to their build target folders.

LoggingTests

The LoggingTests folder is really just a way for me to easily test small chunks of the libraries without firing up the interface. These aren't real unit tests and that should serve as a second reason not to download and attempt to use the Logging library in a production application.

Onward to the Reviews

Now that we have some code we can easily connect to all of the services, the next post will cover the services I tried and how they measured up against my expectations for this type of usage.