Timeout when setting up Entity Framework connectin

Question

I have an Azure database and am setting up Entity Framework. I think the connection string is correct...

<configSections>
   <section name="entityFramework"   type="System.Data.Entity.Internal.ConfigFile.EntityFrameworkSection, EntityFramework, Version=6.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089" requirePermission="false"/>
</configSections>
<connectionStrings>
     <add name="MyContext" connectionString="Server=tcp:azure_server_name.database.windows.net,1433;Database=azure_database_name;User ID=azure_user_account@azure_server_name;Password=azure_password;Trusted_Connection=False;Encrypt=True;Connection Timeout=30"
          providerName="System.Data.SqlClient" />
</connectionStrings>

...but I keep getting the following timeout error.

"Message":"An error has occurred.",
"ExceptionMessage":"The 'ObjectContent`1' type failed to serialize the response body for content type 'application/json; charset=utf-8'.",
"ExceptionType":"System.InvalidOperationException",
"StackTrace":null,
"InnerException":{
   "Message":"An error has occurred.",
   "ExceptionMessage":"Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.",
   "ExceptionType":"System.Data.SqlClient.SqlException",
   "StackTrace":"   
    at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)\r\n   
    at System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)\r\n   
    at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)\r\n   
    at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)\r\n   
    at System.Data.SqlClient.SqlCommand.RunExecuteNonQueryTds(String methodName, Boolean async, Int32 timeout, Boolean asyncWrite)\r\n   
    at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(TaskCompletionSource`1 completion, String methodName, Boolean sendToPipe, Int32 timeout, Boolean asyncWrite)\r\n   at System.Data.SqlClient.SqlCommand.ExecuteNonQuery()\r\n   
    at System.Data.Entity.Infrastructure.Interception.DbCommandDispatcher.<NonQuery>b__0(DbCommand t, DbCommandInterceptionContext`1 c)\r\n   
    at System.Data.Entity.Infrastructure.Interception.InternalDispatcher`1.Dispatch[TTarget,TInterceptionContext,TResult](TTarget target, Func`3 operation, TInterceptionContext interceptionContext, Action`3 executing, Action`3 executed)\r\n   
    at System.Data.Entity.Infrastructure.Interception.DbCommandDispatcher.NonQuery(DbCommand command, DbCommandInterceptionContext interceptionContext)\r\n   
    at System.Data.Entity.SqlServer.SqlProviderServices.<>c__DisplayClass1a.<CreateDatabaseFromScript>b__19(DbConnection conn)\r\n  
    at System.Data.Entity.SqlServer.SqlProviderServices.<>c__DisplayClass33.<UsingConnection>b__32()\r\n   
    at System.Data.Entity.SqlServer.DefaultSqlExecutionStrategy.<>c__DisplayClass1.<Execute>b__0()\r\n   
    at System.Data.Entity.SqlServer.DefaultSqlExecutionStrategy.Execute[TResult](Func`1 operation)\r\n   
    at System.Data.Entity.SqlServer.DefaultSqlExecutionStrategy.Execute(Action operation)\r\n   
    at System.Data.Entity.SqlServer.SqlProviderServices.UsingConnection(DbConnection sqlConnection, Action`1 act)\r\n   
    at System.Data.Entity.SqlServer.SqlProviderServices.UsingMasterConnection(DbConnection sqlConnection, Action`1 act)\r\n   
    at System.Data.Entity.SqlServer.SqlProviderServices.CreateDatabaseFromScript(Nullable`1 commandTimeout, DbConnection sqlConnection, String createDatabaseScript)\r\n   
    at System.Data.Entity.SqlServer.SqlProviderServices.DbCreateDatabase(DbConnection connection, Nullable`1 commandTimeout, StoreItemCollection storeItemCollection)\r\n   
    at System.Data.Entity.Core.Common.DbProviderServices.CreateDatabase(DbConnection connection, Nullable`1 commandTimeout, StoreItemCollection storeItemCollection)\r\n   
    at System.Data.Entity.Core.Objects.ObjectContext.CreateDatabase()\r\n   
    at System.Data.Entity.Migrations.Utilities.DatabaseCreator.Create(DbConnection connection)\r\n   
    at System.Data.Entity.Migrations.DbMigrator.EnsureDatabaseExists(Action mustSucceedToKeepDatabase)\r\n   
    at System.Data.Entity.Migrations.DbMigrator.Update(String targetMigration)\r\n   
    at System.Data.Entity.Internal.DatabaseCreator.CreateDatabase(InternalContext internalContext, Func`3 createMigrator, ObjectContext objectContext)\r\n   
    at System.Data.Entity.Internal.InternalContext.CreateDatabase(ObjectContext objectContext, DatabaseExistenceState existenceState)\r\n   
    at System.Data.Entity.Database.Create(DatabaseExistenceState existenceState)\r\n   
    at System.Data.Entity.DropCreateDatabaseAlways`1.InitializeDatabase(TContext context)\r\n   
    at System.Data.Entity.Internal.InternalContext.<>c__DisplayClassf`1.<CreateInitializationAction>b__e()\r\n   
    at System.Data.Entity.Internal.InternalContext.PerformInitializationAction(Action action)\r\n   
    at System.Data.Entity.Internal.InternalContext.PerformDatabaseInitialization()\r\n   
    at System.Data.Entity.Internal.LazyInternalContext.<InitializeDatabase>b__4(InternalContext c)\r\n   
    at System.Data.Entity.Internal.RetryAction`1.PerformAction(TInput input)\r\n 
    at System.Data.Entity.Internal.LazyInternalContext.InitializeDatabaseAction(Action`1 action)\r\n   
    at System.Data.Entity.Internal.LazyInternalContext.InitializeDatabase()\r\n   
    at System.Data.Entity.Internal.InternalContext.GetEntitySetAndBaseTypeForType(Type entityType)\r\n   
    at System.Data.Entity.Internal.Linq.InternalSet`1.Initialize()\r\n   
    at System.Data.Entity.Internal.Linq.InternalSet`1.GetEnumerator()\r\n   
    at System.Data.Entity.Infrastructure.DbQuery`1.System.Collections.IEnumerable.GetEnumerator()\r\n   
    at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeList(JsonWriter writer, IEnumerable values, JsonArrayContract contract, JsonProperty member, JsonContainerContract collectionContract, JsonProperty containerProperty)\r\n   
    at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeValue(JsonWriter writer, Object value, JsonContract valueContract, JsonProperty member, JsonContainerContract containerContract, JsonProperty containerProperty)\r\n   
    at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.Serialize(JsonWriter jsonWriter, Object value, Type objectType)\r\n   
    at Newtonsoft.Json.JsonSerializer.SerializeInternal(JsonWriter jsonWriter, Object value, Type objectType)\r\n   
    at System.Net.Http.Formatting.BaseJsonMediaTypeFormatter.WriteToStream(Type type, Object value, Stream writeStream, Encoding effectiveEncoding)\r\n   
    at System.Net.Http.Formatting.JsonMediaTypeFormatter.WriteToStream(Type type, Object value, Stream writeStream, Encoding effectiveEncoding)\r\n   
    at System.Net.Http.Formatting.BaseJsonMediaTypeFormatter.WriteToStream(Type type, Object value, Stream writeStream, HttpContent content)\r\n   
    at System.Net.Http.Formatting.BaseJsonMediaTypeFormatter.WriteToStreamAsync(Type type, Object value, Stream writeStream, HttpContent content, TransportContext transportContext, CancellationToken cancellationToken)\r\n--- End of stack trace from previous location where exception was thrown ---\r\n   
    at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)\r\n   
    at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)\r\n   
    at System.Web.Http.WebHost.HttpControllerHandler.<WriteBufferedResponseContentAsync>d__1b.MoveNext()",
   "InnerException":{
      "Message":"An error has occurred.",
      "ExceptionMessage":"The wait operation timed out",
      "ExceptionType":"System.ComponentModel.Win32Exception",
      "StackTrace":null
   }}}

**Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.**

I do have the Azure Firewall open for my IP address...and I'm running this through the debugger.

Here's the little bit of code it should be executing...

public class MyContextInitializer : DropCreateDatabaseAlways<MyContext>
{
    protected override void Seed(MyContext context)
    {
        context.Database.CommandTimeout = 0;

        var books = new List<Book>
        {
            new Book() {Name = "War and Pease", Author = "Tolstoy",Price=19.95m },
            new Book() {Name = "As I Lay Dying", Author = "Faulkner",Price=99.95m },
            new Book() {Name = "Harry Potter 1", Author = "J.K. Rowling",Price=19.95m },
            new Book() {Name = "Pro Win 8", Author = "Liberty",Price=49.95m },
            new Book() {Name = "Book one", Author = "Author1",Price=10.95m },
            new Book() {Name = "Book two", Author = "Author2",Price=20.95m },
            new Book() {Name = "Book three", Author = "Author3",Price=30.95m }
        };
        books.ForEach(b => context.Books.Add(b));
        context.SaveChanges();
        base.Seed(context);
    }
}

-----------------Adding book structure and MyContext upon request-------------------

public class Book
{
    public int Id { get; set; }
    public string Name { get; set; }
    public string Author { get; set; }
    public decimal Price { get; set; }

}


public class MyContext : DbContext
{
    public MyContext() : base("name=MyContext")
    {

    }

    public DbSet<Book> Books { get; set; }

}

Answer 1

Short Answer

It takes about 120 seconds for SQL Azure to create a database. That is why you are timing out. So, increase the CommandTimeout. One way is to drop a single line of code into your DbContext constructor.

public MyContext() : base("name=MyContext")
{
    // three minute command timeout
    this.Database.CommandTimeout = 180;
}

Troubleshooting Steps

I just recreated the exception using a brand new SQL Azure server in West US. When I turned on Entity Framework logging, the output showed that the Create database statement caused the timeout. Here is the log output.

Opened connection at 9/8/2015 9:24:14 AM -07:00
select cast(serverproperty('EngineEdition') as int)
-- Executing at 9/8/2015 9:24:14 AM -07:00
-- Completed in 40 ms with result: SqlDataReader

Closed connection at 9/8/2015 9:24:14 AM -07:00
Opened connection at 9/8/2015 9:24:15 AM -07:00
IF db_id(N'mvp1') IS NOT NULL SELECT 1 ELSE SELECT Count(*) FROM sys.databases WHERE [name]=N'mvp1'
-- Executing at 9/8/2015 9:24:15 AM -07:00
-- Completed in 306 ms with result: 1

Closed connection at 9/8/2015 9:24:15 AM -07:00
Opened connection at 9/8/2015 9:24:15 AM -07:00
drop database [mvp1]
-- Executing at 9/8/2015 9:24:15 AM -07:00
-- Completed in 10635 ms with result: -1

Closed connection at 9/8/2015 9:24:26 AM -07:00
Opened connection at 9/8/2015 9:24:26 AM -07:00
create database [mvp1]
-- Executing at 9/8/2015 9:24:26 AM -07:00
-- Failed in 30050 ms with error: Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.

Closed connection at 9/8/2015 9:24:56 AM -07:00

To troubleshoot further, I connected to the SQL Azure database with SQL Server Management Studio and ran the log output. The commands succeeded but took 1:53 to complete (just about two minutes). That exceeds the default DbContext command timeout.

The fix: increase the DbContext command timeout to exceed that duration. Bingo. It worked.

Working Console App on My Computer

packages.config

The only package is EntityFramework version 6.1.3.

<?xml version="1.0" encoding="utf-8"?>
<packages>
  <package id="EntityFramework" version="6.1.3" targetFramework="net452" />
</packages>

App.config

This config uses the interceptors section to log the generated T-SQL. That enabled me to run the logged T-SQL on SQL Server Management Studio to determine how long it takes to create the database.

<?xml version="1.0" encoding="utf-8"?>
<configuration>
  <configSections>
    <section name="entityFramework" type="System.Data.Entity.Internal.ConfigFile.EntityFrameworkSection, EntityFramework, Version=6.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089" requirePermission="false"/>
  </configSections>
  <startup>
    <supportedRuntime version="v4.0" sku=".NETFramework,Version=v4.5.2" />
  </startup>
  <connectionStrings>    
    <add name="MyContext" 
         connectionString="Server=tcp:d01kzjctcf.database.windows.net,1433;Database=mvp1;User ID=mvp@d01kzjctcf;Password=3pN*iV55XmtW;Trusted_Connection=False;Encrypt=True;Connection Timeout=120;"
         providerName="System.Data.SqlClient" />
  </connectionStrings>
  <entityFramework>
    <defaultConnectionFactory type="System.Data.Entity.Infrastructure.SqlConnectionFactory, EntityFramework" />
    <providers>
      <provider invariantName="System.Data.SqlClient" type="System.Data.Entity.SqlServer.SqlProviderServices, EntityFramework.SqlServer" />
    </providers>
    <interceptors>
      <interceptor type="System.Data.Entity.Infrastructure.Interception.DatabaseLogger, EntityFramework">
        <parameters>
          <parameter value="C:\Temp\LogOutput.txt"/>
        </parameters>
      </interceptor>
    </interceptors>
  </entityFramework>
</configuration>

Program.cs

The demo simply drops and creates the database, seeds it with books, selects all the books, and outputs the number of books to the console.

using System;
using System.Data.Entity;
using System.Collections.Generic;
using System.Data.Entity.SqlServer;

public class Program
{
    public static void Main()
    {
        Database.SetInitializer<MyContext>(new MyContextInitializer());
        var count = 0;
        using (var context = new MyContext())
        {
            count = context.Books.CountAsync().Result;
        }
        Console.WriteLine(string.Format("There are {0} books.", count));
        Console.ReadLine();
    }
}

public class MyContextInitializer : DropCreateDatabaseAlways<MyContext>
{
    protected override void Seed(MyContext context)
    {
        context.Database.CommandTimeout = 0;

        var books = new List<Book>
        {
            new Book() {Name = "War and Pease", Author = "Tolstoy",Price=19.95m },
            new Book() {Name = "As I Lay Dying", Author = "Faulkner",Price=99.95m },
            new Book() {Name = "Harry Potter 1", Author = "J.K. Rowling",Price=19.95m },
            new Book() {Name = "Pro Win 8", Author = "Liberty",Price=49.95m },
            new Book() {Name = "Book one", Author = "Author1",Price=10.95m },
            new Book() {Name = "Book two", Author = "Author2",Price=20.95m },
            new Book() {Name = "Book three", Author = "Author3",Price=30.95m }
        };
        books.ForEach(b => context.Books.Add(b));
        context.SaveChanges();
        base.Seed(context);
    }
}

public class MyContext : DbContext
{
    public MyContext() : base("name=MyContext")
    {
        this.Database.CommandTimeout = 180;
    }

    public DbSet<Book> Books { get; set; }
}

public class Book
{
    public int Id { get; set; }
    public string Name { get; set; }
    public string Author { get; set; }
    public decimal Price { get; set; }
}

See Also

Set database timeout in Entity Framework

How do I view the SQL generated by the Entity Framework?

Closing Thoughts

A global CommandTimeout of three minutes is probably appropriate only for development. In production, you will probably want to decrease that or to set it only for certain specific long-running commands such as database creation.