The other day I had a case where the customer reported that their web application intermittently got stuck.And as usual there was no clear cut pattern for when this happened.
Luckily I have worked in the SQL Developer team even if I now work for the Internet Developer team and thishelped in figuring out what was going on when we finally got a dump taken when the application pool was hanging.
What was happening was that the code created an instance of a class and in this class there was an Open of a SqlConnectiontaking place in the constructor. The creation of this instance occurred in the Application_AuthenticateRequest method in the Global.asax.The problem here was that the connection was opened and not closed. Or rather, the close was in the Dispose method so this will not be called until the instance is removed.This meant that for every request there would be a connection opened and as such it would not be made available to the connection pool.
And the end result as that after a X number of hits on this page we would have maxed out the number of available connections in the pool and we would get the following exception:
Exception type: System.InvalidOperationExceptionMessage: Timeout expired. The timeout period elapsed prior to obtaining a connection from the pool. This may have occurred because all pooled connections were in use and max pool size was reached.
The solution here was to simply rewrite the code to follow the Open/Excute/Close pattern.This allowed the connection to be opened and used and closed. Which would put the connection back into the pool and the next query or next creation of an instance wouldbe able to use that connection from the pool rather than waiting to timeout.
So, let me illustrate this scenario. And how a small change in code makes a lot of difference.
Start with creating a new WebSite in Visual Studio. I’ve called it ConPoolRepro.Put something like this into the .aspx page to see that it has been refreshed.
<div> Time of refresh : <%Response.Write( DateTime.Now.ToLongTimeString() );%> </div>
Then add a new class called BadClass to the solutions App_Code directory. The content of the class should look like this:
public class BadClass : IDisposable{ private SqlConnection con; private String cs = @"Data Source=tcp:<your sql server>;Initial Catalog=<your database>;" + "User=<your user>;Password=<your password>; Max Pool Size=20; Connection Timeout=10";
public BadClass() { Debug.WriteLine("In BadClass.Constructor"); this.OpenConnection(); }
private void OpenConnection() { Debug.WriteLine("In BadClass.OpenConnection"); try { this.con = new SqlConnection(cs); this.con.Open(); } catch (Exception ex) { Debug.WriteLine(ex); } }
public void ExecuteSql() { Debug.WriteLine("In BadClass.ExecuteSql()"); try { SqlCommand cmd = con.CreateCommand(); cmd.CommandText = "select CURRENT_TIMESTAMP"; DateTime dt = (DateTime)cmd.ExecuteScalar(); Debug.WriteLine(String.Format("Time from Server: {0}", dt.ToLongTimeString())); } catch (Exception ex) { Debug.WriteLine(ex); } }
private void CloseConnection() { Debug.WriteLine("In BadClass.CloseConnection()"); this.con.Close(); }
public void Dispose() { Debug.WriteLine("In BadClass.Dispose()"); this.CloseConnection(); }}
You need to fix the connection string to point to your server.Then add Global.asax to the solution and add the following method to it:
public void Application_AuthenticateRequest(Object src, EventArgs e) { BadClass bc = new BadClass(); bc.ExecuteSql(); }
Now you are ready to exhaust the connection pool.Navigate to the page you just created.Start WinDbg and attach (F6) to the w3wp.exe process. This will pause the process once attached so simply hit F5 to go.Refresh the webpage and you should see the following in the debugger:
0:027> gIn BadClass.ConstructorIn BadClass.OpenConnectionIn BadClass.ExecuteSql()Time from Server: 14:58:01
Refresh the page again and you should see the same output. And you have add a connection to the connection pool that can’t be used since Close() is never called on the connection.Let’s have a closer look. Break (CTRL+Break) into the process and load sos.
0:025> .loadby sos.dll mscorwks
Then we will set a breakpoint on the SqlConnection Open method.
0:025> !name2ee System.Data.dll System.Data.SqlClient.SqlConnection.OpenModule: 000007fee6e21000 (System.Data.dll)Token: 0x0000000006002477MethodDesc: 000007fee6e3ded0
this will give you the MethodDesc. Use that and run:
0:025> !bpmd -md 000007fee6e3ded0
Now we need to figure out the MT for the ConnectionPool, simply run:
0:025> !dumpheap -stat -type System.Data.ProviderBase.DbConnectionPool
this will give something like the following:
MT Count TotalSize Class Name…
000007fee6fd3c58 1 104 System.Data.ProviderBase.DbConnectionPool+TransactedConnectionPool000007fee6fcff20 1 176 System.Data.ProviderBase.DbConnectionPool…
So, we will use the MT for the System.Data.ProviderBase.DbConnectionPool.First list the breakpoints, should be only one, use that address and the MT.
0:025> bl 0 e 000007fe`e7626950 0001 (0001) 0:**** System_Data_ni!IID_IRowsetBookmark+0x1440e0
Finally do this to print out useful information when the Open is called:
0:025> bp 000007fe`e7626950 ".foreach (abc {!dumpheap -mt 000007fee767ff20 -short}) {!do ${abc}};g"
Make sure that the first argument is the BP and that the MT is the one for the DbConnectionPool.Finally hit go again (F5). Now for every time you refresh the webpage you should see output like this in the debugger:
Name: System.Data.ProviderBase.DbConnectionPoolMethodTable: 000007fee767ff20EEClass: 000007fee74e7080Size: 176(0xb0) bytes (C:\Windows\assembly\GAC_64\System.Data\2.0.0.0__b77a5c561934e089\System.Data.dll)Fields: MT Field Offset Type VT Attr Value Name…000007feea0ced78 4001551 98 System.Int32 1 instance 7 _totalObjects…
I have removed all the unnecessary fields. For each refresh of the page, the _totalObjects will increase by one.Keep refreshing the page until it reaches 20, which is what we have set the Max Pool Size to in the connection string. We have also set a shorter timeout.Once you reach 20 you will get the following in the debugger:
System.InvalidOperationException: Timeout expired. The timeout period elapsed prior to obtaining a connection from the pool. This may have occurred because all pooled connections were in use and max pool size was reached. at System.Data.ProviderBase.DbConnectionFactory.GetConnection(DbConnection owningConnection) at System.Data.ProviderBase.DbConnectionClosed.OpenConnection(DbConnection outerConnection, DbConnectionFactory connectionFactory) at System.Data.SqlClient.SqlConnection.Open() at BadClass.OpenConnection() in c:\inetpub\wwwroot\ConPoolRepro\App_Code\BadClass.cs:line 27
And this is because we have filled the pool and all connections are in use and max pool size is reached. Pretty much what the error is telling us JJust to confirm this you can break into the process again and then run:
0:027> !dumpheap -mt 000007fee767ff20
This will give you the address for the DbConnectionPool. Dump that address:
0:027> !do 00000001bf355320Name: System.Data.ProviderBase.DbConnectionPoolMethodTable: 000007fee767ff20EEClass: 000007fee74e7080Size: 176(0xb0) bytes (C:\Windows\assembly\GAC_64\System.Data\2.0.0.0__b77a5c561934e089\System.Data.dll)Fields: MT Field Offset Type VT Attr Value Name…000007fee767fcd0 400153f 18 ...nnectionPoolGroup 0 instance 00000001bf352af0 _connectionPoolGroup000007fee7680a58 4001540 20 ...nPoolGroupOptions 0 instance 00000001bf352ac8 _connectionPoolGroupOptions…000007feea0ced78 4001551 98 System.Int32 1 instance 20 _totalObjects
So here we see again the 20 connections. Dump the _connectionPoolGroupOptions
0:027> !do 00000001bf352ac8Name: System.Data.ProviderBase.DbConnectionPoolGroupOptionsMethodTable: 000007fee7680a58EEClass: 000007fee750b058Size: 40(0x28) bytes (C:\Windows\assembly\GAC_64\System.Data\2.0.0.0__b77a5c561934e089\System.Data.dll)Fields: MT Field Offset Type VT Attr Value Name000007feea0c6cd8 4001599 14 System.Boolean 1 instance 0 _poolByIdentity000007feea0ced78 400159a 8 System.Int32 1 instance 0 _minPoolSize000007feea0ced78 400159b c System.Int32 1 instance 20 _maxPoolSize
We can see that the _maxPoolSize is indeed 20. Which means that we get the error when trying open the 21st connection.All this happens because we have in the constructor of the BadClass opened a connection that is never closed.And since we create an instance of the BadClass in the Application_AuthenticateRequest method we will get a new connection for each page load.So seeing the error and exception can be very intermittent. It may happen quickly if you have many concurrent users or slowly if you do not.Or some instances of BadClass may get disposed and then the connection will be closed and put into the pool for reuse.
Hope this all makes sense.
The natural fix is to, as mentioned, Open/Execute/Close. You can either fix the BadClass or create a new one called GoodClass:
public class GoodClass : IDisposable{ private SqlConnection con; private String cs = @"Data Source=tcp:<your sql server>;Initial Catalog=<your database>;" + "User=<your user>;Password=<your password>; Max Pool Size=20; Connection Timeout=10";
public GoodClass() { Debug.WriteLine("In GoodClass.Constructor"); }
private void OpenConnection() { Debug.WriteLine("In GoodClass.OpenConnection"); try { this.con = new SqlConnection(cs); this.con.Open(); } catch (Exception ex) { Debug.WriteLine(ex); } }
public void ExecuteSql() { Debug.WriteLine("In GoodClass.ExecuteSql()"); try { this.OpenConnection(); SqlCommand cmd = con.CreateCommand(); cmd.CommandText = "select CURRENT_TIMESTAMP"; DateTime dt = (DateTime)cmd.ExecuteScalar(); Debug.WriteLine(String.Format("Time from Server: {0}", dt.ToLongTimeString())); this.CloseConnection(); } catch (Exception ex) { Debug.WriteLine(ex); } }
private void CloseConnection() { Debug.WriteLine("In GoodClass.CloseConnection()"); this.con.Close(); }
public void Dispose() { Debug.WriteLine("In GoodClass.Dispose()"); this.CloseConnection(); }}
You need to change the call in global.asax of course:
public void Application_AuthenticateRequest(Object src, EventArgs e) { GoodClass gc = new GoodClass(); gc.ExecuteSql(); }
All we are doing is to move the OpenConnection call to the ExecuteSql method and calling it at the end of the same method.Redo the steps in the debugger and you should see that the _totalObjects is not increasing. Thus not giving the error.This not the only scenario where you may get this error. I’ve written about it some time ago:
Timeout expired. The timeout period elapsed prior to obtaining a connection from the pool. http://blogs.msdn.com/b/spike/archive/2008/08/25/timeout-expired-the-timeout-period-elapsed-prior-to-obtaining-a-connection-from-the-pool.aspx
Hmm, I'd say that BadClass does as well as GoodClass - the problem is that the types implement IDisposable, but the Dispose method is never called! So the real problem is in Application_AuthenticateRequest -- it should read as follows:
public void Application_AuthenticateRequest(Object src, EventArgs e)
{
using (BadClass bc = new BadClass())
bc.ExecuteSql();
}
See [1] for more information on the Dispose pattern. There are many rules for implementing Finalizers/IDisposable listed on the page, it’s not just about unmanaged resources as the title implies.
Highly recommend associated reading: "Framework Design Guidelines: Conventions, Idioms, and Patterns for Reusable .NET Libraries" by Krzysztof Cwalina and Brad Abrams. It’s really a great resource.
[1] Implementing Finalize and Dispose to Clean Up Unmanaged Resources
msdn.microsoft.com/.../b1yfkh5e.aspx
That is absolutelty true. And this is what I recommend in the link at the end.
The intention here was to illustrate a situation where Using is not used and a intermittent issue with maxing out the pool occurs
because the connection is not closed.