Entity Framework Core

Scalable and Performant ASP.NET Core Web APIs: ORM Choice

This is another post in a series of posts on creating performant and scalable web APIs using ASP.NET Core. In this post we’ll start to focus on data access within our API which is the often the cause of performance bottlenecks. We’ll start off with chosing our object relationship mapping framework / library (ORM)

Be careful with EF Core

Entity Framework Core nicely encapsulates the database details from developers. However this approach does carry some performance overheads and gotchas.

Let’s look at an example. Here’s our database model:

Database Model

We have a controller action method /contacts/{contactId} that returns a contact record.

Here’s the SQL Profiler trace:

EF Core SQL Profile - Example 1

Where’s the WHERE clause!? EF Core has fetched all the data in the Contact table too early because of the .ToList(). If we remove the .ToList(). EF Core behaves a little more as we expect:

EF Core SQL Profile - Example 2

Let’s add some more requirements for our action method … We now want to include the primary address, primary email address and primary phone number in /contacts/{contactId}.

The implementation is below. We’ve been good EF Core developers and used .AsNoTracking() so that no unnecessary change tracking occurs. We’ve also been specific about what fields we want to retreive so that EF Core doesn’t fetch more data than we need.

Here’s the SQL Profiler trace:

EF Core SQL Profile - Example 3

We have 4 calls to the database when a single SQL statement could have done the job.

So, with EF core, we need to know what we are doing and be really careful if we are implementing an API on top of a decent sized database. There are also cases when EF Core is going to generate inefficient SQL or round trip to the database multiple times – that’s just how it works!

Here’s a great post on other performance gothas in Entity Framework. It’s not specifically about EF Core but many of the points do apply.

Dapper helps build performant data access code

Dapper is a micro ORM that doesn’t abstract the SQL from us. In Dapper, we use regular SQL to access the database. Dapper simply maps the data to our c# objects.

Here’s the data access code using Dapper for the example above.

Here’s the SQL Profiler trace confirming only 1 hit on the database:
Dapper SQL Trace

So, our ORM choice for the rest of this series on creating performant and scalable web APIs using ASP.NET core 2.0 is Dapper. We’ll continue looking at data access in our next post – this time focusing on isolation levels and the impact on performance.

Don’t forget to subscribe to the rest of this series in the footer of this page!

Scalable and Performant ASP.NET Core Web APIs: Profiling and Monitoring

Monitoring

This is the 2nd post in a series of articles on creating performant and scalable web APIs using ASP.NET Core 2.0. In this post we’ll focus on tools that can help us profile and monitor our API so that we can spot any performance and scalability issues before our customers do.

Often, like most bugs, the earlier in the development cycle we find a performance or scalability problem, the quicker and easier it is to fix. So, it is important to make use of these tools from the start of the development cycle as well as when the API is in production.

During our dev cycles, as well as checking we get the right status code, response body, … we should check the duration of the call and the size of the response. We’ll then hopefully spot if the API is slowing down during the development phase.

Below is the popular Postman tool, giving us the duration and size of the response.

Postman

Development Profiling Tools

Apart from keeping an eye on the duration and size of the API calls, what else can we do? What other tools are there in the development phase to give us confidence that the API is going to perform and scale well?

Stackify Prefix

Stackify Prefix is a great free profiling tool that can be used during the development of an ASP.NET Core Web API. It tracks web requests and database queries and we can even wire it up to Serilog. It’s really useful to have this on a 2nd screen as we build out our API.

To get started with Prefix and profile our API, first download Prefix and then bring in the following nuget package:

We then need to add the Stackify middleware before the MVC middleware. It also needs to come before any exception logging middleware as well so that the exceptions appear in Prefix:

If we want to include the Serilog logs in Prefix, we need to bring in the following nuget package:

… and add the following bits in appSettings.json:

To run prefix, we need to click on the icon in the task bar, enable it and then open it in a browser:

Run Prefix

If we then run our ASP.NET Core Web API in Visual Studio, Prefix will start to profile our API. We will see the requests, database queries and other information we’ve written to Serilog:

Prefix

Nice!

Application Insights in Visual Studio

Application Insights is Mircosoft’s fully fledged Application Performance Monitoring (APM) tool (we’ll come on to APMs later in this post). We can run this locally in Visual Studio 2017 to profile the API during development as an alternative to Stackify Prefix. It’s convenient because we are already likely using Visual Studio to develop the API.

To add this to a Visual Studio project, we right click on project in Solution Explorer and click “Add > Application Insights Telementry …”. We then click the “Start Free” button and then click “Or just add the SDK to try local only mode” at the bottom of the screen. The Application Insights SDK will then be added to the solution.

Application Insights, will automatically track our web requests – we don’t need to add any middleware. Unlike, Prefix, it doesn’t track database queries – we’d need to track these in our logger and wire Application Insights up to our logger (it is automatically wired up to the standard ILogger).

After we’ve added Application Insights to our solution in Visual Studio, we can view the trace information by going to “View > Other Windows > Application Insights Search”. If we enter a date and time in the “From” and “To” inputs and click the search icon, we will hopefully see trace information for the API calls in the bottom half of the screen. The actual individual trace items are in the middle column. If we click on a trace item, we get additional details of the item to the right of it. The element that I find really useful in the “Track Operation” section on the bottom right of the screen. This gives us an overview of the API call and we can quickly see what bits are slow and need further investigation.

Application Insights

“Application Insights Trends” is great for giving us an overview of the trace information. We can access this in Visual Studio via View > Other Windows > Application Insights Trends.

Personally, I prefer the UX of Prefix, but Application Insights is worth a look.

SQL Server Profiler

As the name suggests, SQL Server Profiler traces the SQL statements executed on a SQL Server database. This is a tool that comes with SQL Server and obviously is only useful if our API uses SQL Server for its storage! If we are using a different database then there is likely to be an equivalent profiler.

We can use this tool if our higher level profiling tool (like Prefix or an APM) has pointed to a problem in the data access code. This gives us a clear understanding of what SQL is being executed along with the associated costs.

This tool can also give us all the activity from the SQL Server – it may not be our API that is problematic – it may be some other process that is hogging the resources.

As well as the duration of each SQL statement, we can get other useful performance related information like the amount of CPU in milliseconds used by the statement, the number of page read I/Os caused by the statement and the number of page write I/Os caused by the statement.

SQL Profiler

Visual Studio Memory Profiler

Visual Studio has a set of low level profiling tools. The one that I find most useful is the memory profiler which lets us take snapshots of the managed and native memory heap and drill in to the differences between the snapshots. This can help us find memory leaks or just inefficient use of memory in our code.

We can switch the memory profiler on by clicking “Debug / Windows / Show Diagnostic Tools”.

Visual Studio Memory Profiler

We won’t be using this every day – just when our higher level profiling tool points to a problem in a specific area of code that we want to profile a little deeper.

Application Performance Monitoring (APM) Tools

APMs are primarily used to profile our code in production with regards to performance. However, these tools are also useful in the QA environment – particularly if we are running a load test and want to measure how different parts of the API perform.

Stackify Retrace

Stackify Retrace is a service that allows us to track the same as Stackify Prefix tracks, but it tracks it in production. It also tracks other metrics on the server such as CPU usage. Retrace can also notify us when certain events happen – e.g. when CPU usage > 90%.

In addition to adding the same middleware to our API code as we did for Prefix, we need to register with Stackify and download and install an agent. The agent will send the profile information to Stackify for us to view in their portal.

As with most APMs, this is a paid service which starts from $10 per month at the moment.

Application Insights

As mentioned before, Application Insights is Microsoft’s fully fledged APM tool. As well as wiring up locally, we can wire this up to the Azure Application Insights service. This allows us to view the information in the Azure Portal.

Azure Insights

The nice thing about this APM is that there is a free usage tier for up to 1GB worth of data. Worth a look – particularly if our API is hosted in Azure.

So, there we have a range of high level and low level profiling tools that work well with ASP.NET Core 2.0. In the next post we’ll look at load testing tools …

Don’t forget to subscribe to the rest of this series in the footer of this page!

Scalable and Performant ASP.NET Core Web APIs: Introduction

Performant and scalable web APIs

Over the next month or so I’ll be posting a series of posts on creating performant and scalable web APIs using ASP.NET Core 2.0.

Performance is how fast our API can deal with a single request and make a response. Scalability is the amount of concurrent requests our API can deal with before it slows down significantly.

ASP.NET core itself is very focused on performance, which makes it a great choice for building APIs that perform well. v2.0 of .NET Core gave us general performance improvements on commonly used areas such as many of the collection classes, LINQ, compression and text processing. You can read more about the improvements here. In order for us to create APIs that scale well as more users use the API, we’ll need to architect our API well with usage growth in mind.

The series will start with how to profile and load test our API from a performance point of view. This is really important if we want to know we have a performance problem well before our customers tell us!

We’ll then move on to data access. ORMs are very popular these days but they can be the cause of performance issues …

We’ll look at paging, filtering and searching which improve the consumers experience of our API as well as hopefully having a positive performance impact.

We’ll have a good look at caching … allowing the client to cache responses as well as having a gateway cache on our server.

We’ll move on to allowing our API to work asynchronously to see how that effects performance and scalability.

We’ll look at a Microservices architecture and how that can help scalability.

We’ll end up on the topic of large volume imports – a common requirement in line of business applications that store lots of data.

Ensure you don’t miss any of these posts by subscribing to this blog in the footer of this page!

Adding Useful Information to ASP.NET Core Web API Serilog Logs

In my last post, we setup structured logging leveraging Serilog and SQL Server. In this post, we’ll look closely at the log entries themselves for a web API – what comes out of the box, what’s missing and how we can fill the gaps …

A good log saves debugging time – particularly in production, by quickly helping us to pin point the root of a problem. A log containing a wealth of relevant information, reduces the amount of “I can’t reproduce” issues.

What we get out of the box

Let’s look at what we get out of the box then. We’ve already enabled Serilog with SQL Server as the destination. Let’s now tell Serilog to log as much as it can in appSettings.json:

We have a super simple controller for a contact resource in our web API that sits on top of an EF core data context. We only have methods for getting a record and inserting a record. This will be fine for allowing us to have close look at the log entries that are generated.

We also have an even more simplistic authentication controller that signs us in as “Carl” if we POST api/auth

After signing in and calling GET api/contacts/{contactId} we get:
Out of box log

That’s quite a bit of information, but let’s drill in more …

These are the properties we get from the request:

Notice that the request headers and body are missing. There is no information about the signed in user.

These are the properties we get from the response:

Notice that the response headers and body are missing. Again there is no information about the signed in user.

These are the properties we get from an EF core query execution:

Notice that the parameter value is missing – we just get “?”.

Let’s create an exception by adding a field in our data model class that doesn’t exist in the database:

Here’s what we get when GET api/contacts/{contactId}:

EF core exception

If we drill into the 2 highlighted entries, we have the following properties:

… and …

So, it’s great that we have the call stack and SQL but the parameter value for the SQL would have been nice.

What’s missing and why?

So, the key information that is missing is:

  • The request headers
  • The request body
  • The response headers
  • The response body
  • The EF core query parameter values
  • The user name

I don’t know for sure why the above are missing but I’m guessing it’s a combination of security and performance.

In terms of security, we need to secure the logs. Irregardless of adding more sensitive data, they already contain sensitive information about the internals of our app. We’ve taken a great first step by putting them in SQL Server because a person will need a valid SQL logon in order to be able to access the log directly. If we expose the log via a web page, we need to make sure that page is authenticated and also protected by an appropriate authorisation rule. So, if we secure the log properly I think we are good to add the missing information.

In terms of performance, let’s do a bench mark performance test now and do the same again after we’ve added the missing information to determine the impact. We’re going to use Rick Strahl’s excellent Web Surge tool for the test.

Here’s the results of the bench mark test where we repeatedly GET api/contacts/{contactId} for 10 seconds.

So, the average request time is 3.2ms when the app is running in IIS.

Before we go on and add this stuff, why do we need these bits of information? The information will help us pin problems down. The request headers and body are particularly important for web APIs – it’s much easier to reproduce a problem with a request, if we have all the information to replay it. If the problem is receiving unexpected data rather than an unexpected exception then the response headers and body give us all the information we need to work back through the request to determine what happened. In terms of the EF core queries, we can’t replay an exact query without the parameter values – e.g. a performance issue may be dependent on specific parameter values. Finally some problems are user specific, so capturing the user, allows us to quickly get all the log entries for the problematic user.

Adding EF core parameter values

This is a quick one. All we need to do is switch on “EnableSensitiveDataLogging” when the data context is configured.

This now includes the parameter value in the log entry:

Adding missing request and response information

This is a little more work. We’re going to use middleware so that we only have to write the code once (rather than add code to each controller and action method).

We’re going to call our middleware, SerilogRequestLogger. So, let’s register this when the app starts up. It is important that this is just after we add authentication in the middleware pipeline or we won’t have access to the user information.

Now on to the implementation of the middleware. We add the user name to all the log entries by using LogContext.PushProperty. You can see capturing the request and response body is a little tricky because they are streams.

Here’s an example of what we get in our request information log entry for a POST to api/contacts:

… and our EF call:

… and our response information:

Dealing with exceptions

So, far so good – we have added some extra useful information and this is included in exceptions as well (even though I’ve not shown it above). We can go a bit further though …

We can improve the experience of the consumer of the API by giving them an error reference that they can quote when raising a support ticket. We need to wrap an exception handler around line await _next(httpContext) in our middleware:

Here’s what the consumer gets when they hit a problem in our code:

Consumer exception

We can quickly get to that entry in our log by writing a SQL query to filter on the errorId property:

How much slower is our middleware?

To finish this post off, let’s see the performance impact of logging all this extra stuff. Let’s again repeatedly call GET api/contacts/{contactId} for 10 seconds.

Perf with middleware

The average request time was 3.6ms. So, roughly an addition of 0.4ms for this test.

Not that much slower!

Recommended reading for building great ASP.NET Web APIs:

Testing EF Core Repositories with xUnit and an In Memory Db

I came across the EF Core In Memory database recently. It obviously won’t have all the features of a relational database but it might be useful when unit testing simple repository methods.

Let’s take it for a spin …

Starting point

We have the following repository that we want to test. We’re just going to test the Add method in this post:

Here’s the EF data context and models behind our repository:

xUnit

So, let’s bring in xUnit by adding the following entries into project.json:

We also need to tell Visual Studio that xUnit is going to be our test runner by setting the following as a root property in project.json as well:

Now we can start adding xUnit tests. Let’s just add a couple of simple tests to double check xUnit is wired up properly. Let’s add the following class containing a test that should pass and a test that should fail:

If we open up Test Explorer you’ll see our tests and if you run them, 1 should pass and should 1 fail.

As a bonus, you can also run these tests from the command line by browsing to the app’s folder and running the following command:

Again, you should see 1 passing and 1 failing test.

In Memory Database

Before we test our repository, let’s bring in the In Memory database into our solution by adding the following dependency in project.json:

Repository Tests

So, let’s start testing our Add method in our repository by creating a class and a method to test the storyline when a person has no email address:

GetInMemoryPersonRepository is a method that all our tests will use to spin up a PersonRepository containing no data. Line 26 tells our data context to use the In Memory database. Lines 29 and 30 ensures we have a new database with no data in it.

The test is straight forward. Lines 6-12 creates a repository and a person with no email address. Line 14 calls the Add method in our repository passing in the person. Lines 16-19 carry our checks.

If you run the tests, all should be good.

Now, let’s add a couple more tests to test adding a person with single and multiple email addresses:

The tests are straightforward, following the same structure as the 1st test, using GetInMemoryPersonRepository to spin up a PersonRepository with an In Memory database behind it.

If you run the tests, all should be good.

The tests are also quick – on my machine the three tests took 7, 13 and 624 ms.

Recommended reading for building great ASP.NET core web APIs:

Connect with me:RSSGitHubTwitterLinkedIn

Getting Started With EF Core Migrations

Entity Framework (EF) migrations are a way to modify the database through different iterations of the software. Let’s have a play with these in EF Core in a web API project …

Models

Lets start with the following simple models to hold data about people:

Adding Entity Framework

Now let’s add EF to our solution in project.json (I’m still using .NET core 1.0):

DataContext

Let’s add the following data context:

Wiring EF up

To wire the app up to EF, first let’s add the following line to Startup.ConfigureServices:

We then need to add the following line in appsettings.json:

First migration

So, let’s have a go at our first migration …

Open a command prompt, browse to your solution directory and enter the following command:

After a second or so, our first migration will have been created in a Migrations folder in our solution:

Let’s have a look in the *_init.cs file. Cool, I can see an Up() method creating the 3 database tables and a Down() method droping the 3 tables. So, we have code that is going to create our schema which we can nicely source code control.

Let’s have a look at the PersonDataContextModelSnapshot.cs. As the name suggests, this looks like a copy of the schema – to faciliate the next migration generation.

But what will the generated migration SQL look like? Go back to the command prompt and enter:


The SQL will be output to the screen (you can output to a file by using the command dotnet ef migrations script -o {filename}).

The script creates a table called __EFMigrationsHistory which I didn’t create in my model. This will hold the list of migrations. You can see it adding our *_init migration at the bottom of the script.

I like that the primary keys have been correctly implemented as identities in the script. I like the foreign keys … I’m not liking the varchar(max) all over the place though!

Let’s fix the varchar(max) problem by adding the following code into PersonDataContext which specifies table names, field lengths and required fields in our schema:

So, let’s see what the script looks like now. First we need to remove our last migration by entering the following command:


You’ll notice the Migrations folder is now empty in our Visual Studio solution.

Now run the following command to generate the new migration and output the SQL script:

That’s much better!

Creating the database

So, let’s create the database by running the following command:


After a few seconds, the database will have been created. You should be able to see the database in Visual Studio in the SQL Server Object Explorer

Second migration

Now, let’s implement a model change. We’re going to add a Created property to our Person model:

Let’s create that migration:

If you open up *_Person_Created.cs you’ll see the migration to add our new column.

Before updating our database again, let’s check our SQL migration script. We need to specify the migration we want to start from which in my case in 20170125045706_init:

This looks good.

Updating the database

So, let’s update the database by running the following command:


After a few seconds, the column will have been added to the database:

Recommended reading for building great ASP.NET core web APIs:

Connect with me:RSSGitHubTwitterLinkedIn