Adventures while building a Silverlight Enterprise application part #37

In this post we are looking at Entity Framework and specifically at some performance quirks.

The story

Recently we were testing part of our new software. One thing we noticed is that, besides the fact that the first time we load data, things are slow because of services starting up and Entity Framework loading metadata, also the first time we save some data, it is also slow.

We decided that is was worth investigating why this was happening. The goal was to at least come up with an explanation and some more insight into when this was occurring.

Analysis

Some preliminary analysis I made:

• This was not the same thing as starting up the service and Entity Framework loading metadata because of that. I knew that because I had just loaded data from the same service and model that I was now saving to.
• It was caused by something in the service. I could tell because we have a busy indicator active whenever a service request is pending completion.
• It was not caused by any specific code for one of our business objects as it didn’t matter which object I would save. It was always slow the first time.

As you may know, if you are following this series for some time, we have a bunch of complex generic code that’s involved when either loading or saving data. I decided my first task was to identify exactly what line or section of code was causing the delay the first time around. To accomplish this I placed some debug code which would log the exact time to the debug output. This way I could easily calculate where a delay would occur.

By following this strategy I quickly found out that the delay for the first save occurred when calling SaveChanges on our model. However, reflecting the code for the method did not reveal any obvious cause for this. I searched on the internet to find out if anyone had already cracked this problem, to find out that only a handful of people had seen the same issue, but non of them actually resolved it.

As I still did not pinpoint the exact cause, I decided to build a test application to demonstrate the problem and hopefully get a better understanding. As we are currently still using version 2.0 of Entity Framework and running in .NET framework 3.5, I used Visual Studio 2008 to build my test application on top of the AdventureWorks database. I needed it to do basically two things:

1. Load a single object from the model to initialize the Entity Framework model
2. Save a change to a single object from the model and time the operation

To make my tests more flexible I decided on a WPF UI that allows me to control the above steps and it presents me with the results instantly. Check out the screenshot below:

The times displayed are in milliseconds. Let me explain what you see here. On top are two rows of buttons, one for the full AdventureWorks model and one for a model with only the Customers table (both models do connect to the same database). Below that is a listbox with performance results for each save action. At the bottom there is a general log to see what is happening.

Basically what you see in the performance logs is this. The first save action is done after loading a customer from the complete model. It takes a whopping 177ms. The next save action, after loading the same record again, takes only 2ms! This reproduces the issue we’ve been having.

Now the next step is doing exactly the same thing with a model that contains only the Customers table, so there is a lot less metadata to be loaded. It should be noted that both models are placed in separate assemblies to make sure metadata of one model is not interfering with the other. The time differences are a lot smaller between the first save (28ms) and the second save (4ms). Note that as performance is reaching lower limits times can fluctuate because of other processes on the system, which can account for the 2ms increase between the large model and the small model.

Because of this we can now conclude that Entity Framework loads some metadata as the first save occurs. Unfortunately we can not do much about that, but at least we now have an explanation.

Taking the next step

But the research didn’t end there. One of my colleagues suggested testing this with .NET 4.0 and Entity Framework 4.0 to see if there would be an improvement there. So I converted the project to Visual Studio 2010 and recreated both models using Entity Framework 4.0. The times are like this:

• Saving the first time on the complete model: 82ms
• Saving the second time on the complete model: 7ms
• Saving the first time on the single table model: 36ms
• Saving the second time on the single table model: 3ms

So work has been done in Entity Framework 4.0 to improve performance while loading metadata. Please note that my measurements were made on a system that is not exactly high performance and thus the measurements are not very accurate, however the differences between EF 2.0 and EF 4.0 with the first save are still significant enough.

Downloads

You can download the source of both versions of my test application:

• Entity framework 2.0 test application
• Entity framework 4.0 test application

Please be aware that the first project is a Visual Studio 2008 project and the second one is a Visual Studio 2010 project. You can however upgrade the first project, without changing the results.

Conclusion

So, although we can’t improve the performance of the first save action on an entity framework model right away, at least we can now explain what happens and what is the actual impact. As this only happens when IIS recycles the Application Pool for our web service, the impact is minimal. Also we can soften the pain as soon as we migrate our service to Entity framework 4.0.

I hope you have learned as much as I have writing this post. If you have any questions, please leave a comment below and I’ll be happy to help you out.

Developers 42 around for two years!

Today we celebrate the second anniversary of the Developers 42 Blog. In this article we look back at the past years and we look forward into the future.

Looking back

Wow, it’s been two years. Part of me feels like it’s been forever and part of me feels like I started yesterday. If I think about what I started this blog for, I guess it comes down to sharing my experiences as a developer with anyone who’s interested. However, if I now look back at what I got from this, I feel I got a lot more from building and maintaining Developers 42.

A learning experience

I guess I was a little ignorant when I first started out. I figured it would mostly come down to discipline to maintain a reasonable blog, but I found that it takes knowledge and skill to promote a blog and to keep everything running smoothly.

But also I found out that writing for a technical blog like this one, brings with it that you have to adapt your workflow to facilitate blog posts. One thing I find myself doing over and over, is generalizing scenario’s I run into in my day to day work. It can be very helpful in getting a better feel for the problems you work on, but it can also be a time consuming challenge to come up with good examples of something that is very specific to the field I work in.

Another thing I learned that surprised me, is the way referrals work. I never thought that putting a link in a signature for a forum would generate the results it did. Nor did I think republishing to CodeProject would bring me much hits but it does bring reasonable results.

Opportunity

Another thing I got from running Developers 42 is opportunity. Because of running a blog I get the occasional job offer, including offers to join interesting startups (unfortunately all kinds of reasons prevented me from jumping on to any of these so far). I also got invited to write for SilverlightShow.com, which I still enjoy doing from time to time.

I’ve also met new people and got the opportunity to help people from around the globe with issues they encountered, which is rewarding in itself.

Setbacks

Obviously is wasn’t all a big party. I’ve had to take a step back in posting at more then one occasion. Personal life and work life both interfered with my goals for Developers 42. This resulted in me only posting 18 times (not including this post) over the past year.

Defeat was also part of the deal. I decided to scrap the CodeEmbed4Web project, as it was clearly not going to a success. In fact I have lots of unfinished projects laying around, which I’m not likely to continue.

But enough of that. Let’s move on to more positive things.

The numbers

In fact the numbers might not all seem so positive. There was a reduction in both visitors and page views of around 27,5%. But if you compare that to the reduction of posts (around 35% less content), this suddenly becomes promising. If I would have posted the same amount as last year, hits could have doubled!

Looking at the number of subscribers reflects this positive image. There was actually an increase in subscribers of the past year. Check out the graph below!

I’m really happy with the progress made in this area. It it really motivating to know that people are interested enough to actually subscribe to my RSS feed.

Looking to the future

So what about the future? Well, if there is one thing I learned in the past year is that you can be to ambitious. I do have some plans for new things, but overall my main goal is to keep posting regularly. However if there is a topic you would like me to write about, even if it is only remotely connected to software development, I’d love to hear about it.

Further more, I hope to welcome more new readers in the coming year, both as subscribers, but also as loose visitors.

Thank you!

The last thing that remains is to thank you, the user of this blog, for sticking with me here. Without you this wouldn’t be much fun. I hope you have enjoyed yourself the past year as much as I have and that you have learned as much as I have.

A special thank you goes out to Dave Campbell from Wynapse, for so patiently following and linking to my blog. Another thanks goes out to Svetla from SilverlightShow.net for helping me out with getting published on their website.

I really value your feedback, especially if there is anything you would like to see different or added, or if you have any suggestions about topics to discuss. I hope to see you around this coming year and I hope we can share some insights.