MySQL Bugs: #19178: ASP.NET Lockup under moderate load with 1.0.7. Resource contention?

Bug #19178	ASP.NET Lockup under moderate load with 1.0.7. Resource contention?
Submitted:	18 Apr 2006 21:34	Modified:	17 Aug 2006 12:30
Reporter:	Dan Guisinger	Email Updates:
Status:	Not a Bug	Impact on me:	None
Category:	Connector / NET	Severity:	S1 (Critical)
Version:	1.0.7	OS:	Windows (Windows 2003/IIS)
Assigned to:		CPU Architecture:	Any

Description:
Appears to be a resource contention of some sort; all clients accessing the ASP.NET web service lock up simultaniously during MySQL queries.  Happens when heavily in use during the afternoons when multiple people are logged into the system.  It appears similar to the Pooling problem in 1.0.4 except the lockup doesn't clear up after a connection times out.

How to repeat:
Happens several times a day while using our ASP.NET Web Service with our windows forms client.  Did not happen while using 1.0.4 (We had the pooling problem, which caused timeouts more often) but after upgrading to 1.0.7 these timeouts lock the ASP.NET Web Service perpetually (looking like a resource contention), requiring a restart of ASP.NET or the entire server.

Hi Dan. Thanks for your problem report.
Can we start collecting data from the beggining. Please provide MySQL server version. Do you have a log? If so it would be nice to see it. Also my.cnf / my.ini would be nice as well as HW info on server.

Thanks Tonci,

I've got an active conversation in the forums with another user seeing the same type of problem in his stand alone application.

Here is the thread, it was started by the other user:
http://forums.mysql.com/read.php?38,87628,87628#msg-87628

I am running Microsoft .NET 1.1 on Windows 2003 Server using IIS 6.
MySQL 5.0.19-max on Mac OS X 10.4.6 on a PPC G5 XServe
I am using MySQL .NET Connector 1.0.7

Dan, I've read forum thread. If you feel you're answered there then close this report. Otherwise I'll still need data I've requested and, at least, a sample of your code.

Unfortunately, those solutions don't work for me.  I am not doing manual Open/Closes on the connection, nor am I able to rewrite around an ODBC Connector, which is counter productive to switch to a different platform to solve the problem.  This web service is spread across about 10 seperate modules, and is between 100,000 and 200,000 lines of code; it would be extremely difficult to move away from MySQL Connector product.

We need a fix for whatever connection problem is occuring.  I'm possitive I'm having the same problem as the other gentleman, its the same description except his is a web forms app thats freezing under frequent access.  He posted his code I beleive in that thread.  Ours doesn't lockup at a specific point, it happens through out the entire web application.

Dan, please provide server configuration files as well as server logs at the time you loose service. Try netstat -a before and when lock-up occurs and send me the results.
Also, see our guidelines on how to report a bug.

I'm not sure what else you are looking for when it comes to the submission guidelines. Its pretty hard to give you any specific code when we have over 500 different SQL statements called from hundreds of locations in our source code; and it is totally random which the system freezes up on; other than its only when its under higher load. I let the DataAdapter manage the opening and closing of the connection. I can't be any more specific; I can't install VisualStudio's 2003 remote debug tools on Windows 2003 so I can't see where in MySQL .NET Connector it is freezing, and I don't have client code to test the other way around. I could try regressing to 1.0.5 or 1.0.6 butit takes atleast an hour to make sure all old copies are removed from all referenced DLL modules, so I want to make sure I'm not chasing something I shouldn't be looking at.

For Netstat, which do you want, the server side or client side? I would assume you are looking for client.

As far as the server configuration file:
[mysqld]
#Path to the database root
datadir=/Volumes/xserveraid/mysql/data
#The size of the buffer used for index blocks. Increase this to get better index
handling (for all reads and multiple writes) to as much as you can afford; 64M
on a 256M machine that mainly runs MySQL is quite common.
key_buffer_size=64M
#The number of simultaneous clients allowed.
max_connections=500

When I'm running MySQL Admin, there appears to be 0 entries around the times I lose connection in the log; and all connections from the client computer are listed as SLEEPING. As far as I can tell, the server doesn't know the client is running into problems.

Hi Dan,

I got the same problem with you and my solutions is add "pooling=false" to the connection string and my application run well.

Do Manh Hoang

Hi Dan. Please send me as much data as you can since I don't have neither code nor configuration to reproduce this behavior.
Missing info:
  Mac OS X 10.4.6  PPC G5 XServe: RAM total, disk free, RAM free (low load / moderate load)
  [mysqld]: complete ini file
  Windows 2003 Server: SP
  Netstat on client (low load / moderate load)

Fill this for me, please:key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 
(it is possible that mysqld could use up to that much of a RAM!). You can see that having max_connections=500 requires a lot of RAM on server.
If possible, turn the MySQL server logging on and provide me with log.
What's your connect string?

I am not asking for DDL or test case yet since this looks like configuration problem to me.

netstat dump on client, #1

Attachment: tmp1.txt (text/plain), 18.08 KiB.

netstat dump, client, #2

Attachment: tmp2.txt (text/plain), 11.54 KiB.

Hi Dan.
What are your clients doing listening on 3306? Or, what server do you have on client machines that brodcasts on 3306?

3rd netstat dump from client, without a local MySQL server running

Attachment: tmp3.txt (text/plain), 29.98 KiB.

Looks like there was a development copy of MySQL running locally; I disabled that and we are experiencing the same issue.  I attached another copy of the newest netstat dump.

Regarding the OS X server, its got 3GB of RAM, its a dual 2.3GHz G5 box runing OS X Server 10.4.6.

Windows 2003 - Version 5.2.3790

Hi Dan. It could be that connections are not closed properly since log is full of
  TCP    ATACOMM1:3001          ip67-90-97-212.z97-90-67.customer.algx.net:3306  TIME_WAIT
and IIS is not reusing old connections from the pool, once they fail, until some of it's timeouts do not expire, that's why you need to restart web server to make problem go away.
I found this on MS KB:
CAUSE
With connection pooling enabled, whenever IIS users try to connect to the same backend database server, the driver manager tests the existing connection in the pool before reusing the connection. If there is a bad connection in the pool and the backend database server for the bad connection is unavailable, the driver manager keeps testing the bad connection, and IIS essentially creates a thread for each attempted connection. The testing connection process takes time, and the IIS threads are also being generated continuously, which causes the performance to degrade.

STATUS
Microsoft has confirmed this to be a problem.

Now either try to close database connections explicitly or set Pooling to false in your connect string and test. Please, inform me of your result.

Tonci,

That sounds very close to what we are seeing; I don't know if MySQL .NET Connector handles pooling identically to the Microsoft data providers.

I added pooling=false; to my connections a few weeks back, and so far haven't seen a different result.  Actually, I progmatically set it in the page start of ASP.NET global file, which then generates my connection string values.  I will check to make sure we are properly turning pooling off since you and others have beleived it to be a fix and it hasn't done anything yet.

Dan, I did not believe it to be the solution! Just a thing to try in light of what I've found about inner mechanism of MS software. Can you post your actual connection string so I can test it? And please keep me informed of your efforts / results so I do not suggest things you allready tried.

Hi Dan, so you've verified that it's not connector/NET pooling function that causes the trouble. Let's check IIS server side. Can you please check following URL's and try to disable IIS pooling mechanism:
http://www.weberdev.com/get_example-241.html (the opposite of given example)
http://support.microsoft.com/?kbid=238131?

Disabled ODBC connection pooling

Attachment: Connection-pooling.jpg (image/jpeg, text), 49.56 KiB.

I will check those options this weekend when we've got some scheduled downtime to see if they make a difference.

Dan, I'm waiting on your findings.

Doesn't seem to solve the issue.

Dan, I will consult and see if I can do something more.

Dan, I didn't succeed in recreating your problem. Can you please post ASP and a sample code from client. If you think that there's particular portion of data which causes more breaks, send dump too.

Dan, you provided no feedback as per my request.
Now that connection pooling is disabled, you can also try to disable oledb resource pooling for MSDASQL provider (OLEDB provider for ODBC drivers). Set
HKEY_LOCAL_MACHINE\SOFTWARE\Classes\CLSID\{c8b522cb-5cf3-11ce-ade5-00aa0044773d}
\OLEDB_SERVICES equal to 0xfffffffe and inform me of your results.

I appologize.  With 80-100,000 lines of code, and the problem happening randomly and only when two people from two different client machines are accessing the system, I can't show you a specific section of code which causes the problem.  I have a class Property which creates the connection, I send it to a Fill or Update command in a data adapter, and let the data adapter handle the rest.  Very much a text-book approach to ADO.NET.

I have found a reference to a very similar problem using Oracle, but the solution the guy posted was not graceful by any means:

"Hi all, I think I have found a reason for this problem:

The problem is caused by, when the IIS server's "executionTimeout" for
httpRequest is reached, IIS will call Thread.Abort() to stop the
processing thread for the Request.

For instance, If a web page is requested, meanwhile the database is
very busy, the Database can't return all the result to the web
application within 40 sec (the default value of executionTimeout in
machine.config), this thread will be aborted!

I have just read the Release note of ODP .NET 10.2.0.1.0, in the
section "TIPS, LIMITATIONS AND KNOWN ISSUES", it says:

8. Thread.Abort() should not be used, as unmanaged resources may remain
unreleased properly, which can potentially cause memory leaks and
hangs.

It seems that we can just avoid the problem by setting the
executionTimeout value to a reasonablily large value. However, this
will greatly affect the web server performance as some Threads will be
hold and they are not able to serve other requests."

The concern being, if the thread timeout is made longer, DoS attacks are easier to perform.  

If this ends up being the problem, MySQL .NET Connector's documentation should be updated to reflect this issue.... I'm going to be testing this the next day or two.  

What is curious is it can happen with the most modest DB access, yet large SELECT statements simultaniously can go thru, or sometimes its the opposite.  I can't see how any of these take longer than 40 seconds to actually complete....

Dan, thanks for your input! I am leaving this issue in "Need feedback" since it seems important to me and may help other people with similar problems. Thanks again and please post your future finding here.

Maybe there is a bug after all.  I did some stress testing, opening 10 copies of the Windows Forms client simultaniously.  So far, anytime when all 10 clients are doing operations where the web-service does Fills from the database, everything works fine.

If code is executed on one of the clients that does an Update, it can at times cause all of the other clients to lock up, even when working on non-related tables -- which after the 90 second ASP.NET timeout, terns into a Operation Timeout.

Ideas?

Dan, attach full my.cnf file from server to this report, please. We may actually find something this time.

Sorry, I did some more digging. I apologize for the long post, I did alot of analyzing today trying to pinpoint more details. In our system, when we open up orders we had a Update call to lock an order to a particular host so no two people could open it for editing; I thought this Update call was triggering the freeze. I removed it, and the freeze is still happening.

I did some more digging, I turned the Timeout property off (set to -1) on our Webservice client. All of a sudden our timeout exceptions disappeared (it was always assumed they were being generated server side by IIS terminating the page). What is more curious, is all web service threads lock perpetually instead of timing out. IIS has a 90-second timeout (as is default) on all ASP.NET.

I pulled up MySQL Admin and watched the connection/bandwidth/querey graph, and everything looks normal until the clients lock up, and everything drops to 0% utilization (other than connections, which remains steady). The connections all remain in SLEEP mode.

Right now I can't point to either ASP.NET, IIS, our code, or MySQL Connector.
I have a posting in a Microsoft ASP.NET forum asking for some comments, because I'd like to see IIS abort after a certain period of time, maybe we can get a trace of where things are locking up.

What is interesting is some areas where massive amounts of data are being sent, for example our application load screen caches copies of our products and other information that is less-critical if an old copy is used, and can take 20-30 seconds to make it through the 10 queries it executes. I can run 10 clients side by side, and while slow, this load process does not lock up the web service or clients. But loading 2 different orders from 2 different clients does -- and not consistantly in the same web service call (it makes calls to load the invoice, load qty pricing data, stock information, applied payments, packages, serial numbers, and a fraud check which does a ton of similar item scans....each is a seperate web service call, utilizing a seperate DB connection, and done in serial, so not simultaniously)....and loading 2 orders, which is by far alot less data than during application load, is consistantly causing a lockup. The only thing I can think of is there are alot more INNER JOIN statements being used in loading an order than during the preloading (which has none), but even so....there shouldn't be a lockup....

All of the locked clients can be in totally different sections of code, for example, one in a shipping call for saving package data, one loading an invoice, and another saving a product change. All 3 will lock, I'm not sure if working with the orders is the one constant; there is almost always someone in an order so it could just be we are seeing that result the most but it still happens other times.

Does any of this raise any flags to you? I generate all of the Connection and Command objects statically; but they shouldn't be persistant. I use Static properties to return a new connection or command object.... This keeps coming back to some sort of multithread lockup or resource contention in my mind...... but if I'm not persistantly storing it between using the static property, I shouldn't be generating any locks say for example using the same connection in two places at the same time....but its almost the feeling I'm getting when I'm looking at the behavior of these lockups.

Dan, I see you're digging as hard as you can. Maybe now's the time to summarize findings and what has been done. Please, write in short, what have you done (disabling pooling, changing timeouts, observations on queries, OS...) so that I know wehere you are. Also, attach that configuration file from server I asked several times. Then I might come up with some ideas.

Tonci,
I haven't had a chance to track this one down further, MS had refered me to some process debugging tools to see were ASP.NET froze and I still need to follow up.

On another note, I moved our production website running 1.0.4 from our Windows 2000 servers to Windows 2003 Server.  All of a sudden I started receiving new exceptions a few times a day which had never occured before; maybe this will help track down the problem, I'm not sure if its related or not, but atleast with an ASP.NET page I receive the message (and its emailed to me), whereas in the web service something seems to be hanging long enough to give a timeout message instead.  Since this started with 2003, and our other issues started with 2003 with the web services; maybe there is a link.

The messages are Probable I/O Race Condition Detected and Connection unexpectedly terminated.

I have mentioned several times that what I am seeing on 1.0.7 looks very much like a thread-safe issue, with all connections locking up simultaniously.  Maybe this first one is a clue as to whats going on.  The 2nd one is also a message I see rarely, but has become very common since moving to 2003.

Message: Probable I/O race condition detected while copying memory.  The I/O package is not thread safe by default.  In multithreaded applications, a stream must be accessed in a thread-safe way, such as a thread-safe wrapper returned by TextReader's or TextWriter's Synchronized methods.  This also applies to classes like StreamWriter and StreamReader.
Trace:    at System.Buffer.InternalBlockCopy(Array src, Int32 srcOffset, Array dst, Int32 dstOffset, Int32 count)
   at System.IO.BufferedStream.Read(Byte[] array, Int32 offset, Int32 count)
   at MySql.Data.MySqlClient.PacketReader.Read(Byte[]& buffer, Int64 pos, Int64 len)
   at MySql.Data.MySqlClient.PacketReader.Skip(Int64 count)
   at MySql.Data.MySqlClient.PacketReader.OpenPacket()
   at MySql.Data.MySqlClient.NativeDriver.GetFieldMetaData41()
   at MySql.Data.MySqlClient.NativeDriver.GetFieldMetaData()
   at MySql.Data.MySqlClient.NativeDriver.ReadFieldMetadata(Int32 count, MySqlField[]& fields)
   at MySql.Data.MySqlClient.CommandResult.Load()
   at MySql.Data.MySqlClient.MySqlDataReader.NextResult()
   at MySql.Data.MySqlClient.MySqlCommand.ExecuteReader(CommandBehavior behavior)
   at MySql.Data.MySqlClient.MySqlCommand.ExecuteReader()
   at MySql.Data.MySqlClient.Driver.Configure(MySqlConnection connection)
   at MySql.Data.MySqlClient.NativeDriver.Configure(MySqlConnection connection)
   at MySql.Data.MySqlClient.MySqlConnection.Open()
   at System.Data.Common.DbDataAdapter.QuietOpen(IDbConnection connection, ConnectionState& originalState)
   at System.Data.Common.DbDataAdapter.FillFromCommand(Object data, Int32 startRecord, Int32 maxRecords, String srcTable, IDbCommand command, CommandBehavior behavior)
   at System.Data.Common.DbDataAdapter.Fill(DataSet dataSet, Int32 startRecord, Int32 maxRecords, String srcTable, IDbCommand command, CommandBehavior behavior)
   at System.Data.Common.DbDataAdapter.Fill(DataSet dataSet, String srcTable)
   at Atacomm.ResvNet.TemplateHandlers.PageState.StoreSettings.LoadStore(Boolean bRedirect, Boolean bIgnoreFail)
   at Atacomm.ResvNet.TemplateHandlers.PageState.ResvNetPageState.HandlePageState(Boolean bRedirect)
   at Atacomm.TemplateEngine.TemplatePageState.LoadPageState(Page page, Boolean bRedirect)
   at shops.ProductImageThumbnail.Render(HtmlTextWriter writer)
   at System.Web.UI.Control.RenderControl(HtmlTextWriter writer)
   at System.Web.UI.Page.ProcessRequestMain()
Date & Time: 7/28/2006 3:09:01 PM

Message: Connection unexpectedly terminated
Trace:    at MySql.Data.MySqlClient.PacketReader.Read(Byte[]& buffer, Int64 pos, Int64 len)
   at MySql.Data.MySqlClient.PacketReader.Skip(Int64 count)
   at MySql.Data.MySqlClient.PacketReader.OpenPacket()
   at MySql.Data.MySqlClient.NativeDriver.GetFieldMetaData41()
   at MySql.Data.MySqlClient.NativeDriver.GetFieldMetaData()
   at MySql.Data.MySqlClient.NativeDriver.ReadFieldMetadata(Int32 count, MySqlField[]& fields)
   at MySql.Data.MySqlClient.CommandResult.Load()
   at MySql.Data.MySqlClient.MySqlDataReader.NextResult()
   at MySql.Data.MySqlClient.MySqlCommand.ExecuteReader(CommandBehavior behavior)
   at MySql.Data.MySqlClient.MySqlCommand.ExecuteReader()
   at MySql.Data.MySqlClient.Driver.LoadCharacterSets()
   at MySql.Data.MySqlClient.Driver.Configure(MySqlConnection connection)
   at MySql.Data.MySqlClient.NativeDriver.Configure(MySqlConnection connection)
   at MySql.Data.MySqlClient.MySqlConnection.Open()
   at System.Data.Common.DbDataAdapter.QuietOpen(IDbConnection connection, ConnectionState& originalState)
   at System.Data.Common.DbDataAdapter.FillFromCommand(Object data, Int32 startRecord, Int32 maxRecords, String srcTable, IDbCommand command, CommandBehavior behavior)
   at System.Data.Common.DbDataAdapter.Fill(DataSet dataSet, Int32 startRecord, Int32 maxRecords, String srcTable, IDbCommand command, CommandBehavior behavior)
   at System.Data.Common.DbDataAdapter.Fill(DataSet dataSet, String srcTable)
   at Atacomm.ResvNet.TemplateHandlers.PageState.StoreSettings.LoadStore(Boolean bRedirect, Boolean bIgnoreFail)
   at Atacomm.ResvNet.TemplateHandlers.PageState.ResvNetPageState.HandlePageState(Boolean bRedirect)
   at Atacomm.TemplateEngine.TemplatePageState.LoadPageState(Page page, Boolean bRedirect)
   at shops.ProductImageThumbnail.Render(HtmlTextWriter writer)
   at System.Web.UI.Control.RenderControl(HtmlTextWriter writer)
   at System.Web.UI.Page.ProcessRequestMain()
Date & Time: 7/29/2006 8:41:06 PM

An additional glitch I am seeing after moving to Windows 2003 that hadn't come up before is this one, appears MySql Connector/NET is reading a negative number of bytes over the stream.   

Still not sure why these issues are only appearing on 2003; is it possible that the generic data adapter code (the part MySQL doesnt write) behaves differently between 2000 and 2003, and that additional validation code must be inserted to ensure proper operation?   This glitch is happening on a stream, as was the IO race condition in my previous comment from last night.  Maybe your stream code is flawed?

Message: Non-negative number required.
Parameter name: count
Trace:    at System.IO.BufferedStream.Read(Byte[] array, Int32 offset, Int32 count)
   at MySql.Data.MySqlClient.PacketReader.Read(Byte[]& buffer, Int64 pos, Int64 len)
   at MySql.Data.MySqlClient.PacketReader.Skip(Int64 count)
   at MySql.Data.MySqlClient.PacketReader.OpenPacket()
   at MySql.Data.MySqlClient.NativeDriver.Authenticate411()
   at MySql.Data.MySqlClient.NativeDriver.Authenticate()
   at MySql.Data.MySqlClient.NativeDriver.Reset()
   at MySql.Data.MySqlClient.MySqlPool.GetPooledConnection()
   at MySql.Data.MySqlClient.MySqlPool.GetConnection()
   at MySql.Data.MySqlClient.MySqlPoolManager.GetConnection(MySqlConnectionString settings)
   at MySql.Data.MySqlClient.MySqlConnection.Open()
   at System.Data.Common.DbDataAdapter.QuietOpen(IDbConnection connection, ConnectionState& originalState)
   at System.Data.Common.DbDataAdapter.FillFromCommand(Object data, Int32 startRecord, Int32 maxRecords, String srcTable, IDbCommand command, CommandBehavior behavior)
   at System.Data.Common.DbDataAdapter.Fill(DataSet dataSet, Int32 startRecord, Int32 maxRecords, String srcTable, IDbCommand command, CommandBehavior behavior)
   at System.Data.Common.DbDataAdapter.Fill(DataSet dataSet, String srcTable)
   at Atacomm.ResvNet.TemplateHandlers.PageState.StoreSettings.ReloadShopSettings()
   at Atacomm.ResvNet.TemplateHandlers.PageState.StoreSettings.get_ShopDataSet()
   at Atacomm.ResvNet.TemplateHandlers.PageState.StoreSettings.get_TemplateId()
   at Atacomm.ResvNet.TemplateHandlers.PageState.ResvNetPageState.HandlePageState(Boolean bRedirect)
   at Atacomm.TemplateEngine.TemplatePageState.LoadPageState(Page page, Boolean bRedirect)
   at Atacomm.TemplateEngine.TemplatePageState.LoadPageState(Page page)
   at shops.ViewItem.Page_Load(Object sender, EventArgs e)
   at System.Web.UI.Control.OnLoad(EventArgs e)
   at System.Web.UI.Control.LoadRecursive()
   at System.Web.UI.Page.ProcessRequestMain()

Tonci,
I may know what the problem is.  There was a static Connection property in a section of our user authentication code, that held on to the connection once it was created.  All other places I had replaced it a while back and created it on the fly; but this one was missed.  I have removed the static "cache" of the connection object and have recompiled both our web site application and our web service.

I've asked our sales team to stress test it tomorrow and see if it fixes all the problems we've been having.   Our web service used that connection to authenticate every SOAP transaction, which means it was called 20x more often from our web service than our website, and our web service was conncted to the database over a T1 unlike our webserver which was directly next to the database server.  The difference in speed and the number of calls would, to me anyways, explain why the web service was having problems when the website wasn't.  If it was a multi-threading issue, two threads grabbing the same connection at the same time,  it would make perfect sense, as with the slower connection, our webservice would have been stalled while waiting for data on that connection more often, and a 2nd request would cause problems.

So, we should know tomorrow whether or not it fixed the whole problem.   If it does, should .NET Connector have its own thread-safe locking to prevent access to the connection stream from multiple threads at the same time?

Dan, I'm consulting with connectors team.

Didn't seem to fix our lockup, hope the Connector team has an idea....

Turned out to be problem in reporters code.

Mark asked me to comment on the following comment from Dan.

"So, we should know tomorrow whether or not it fixed the whole problem.   If it
does, should .NET Connector have its own thread-safe locking to prevent access
to the connection stream from multiple threads at the same time?"

I've made a note to exmamine how we can improve the thread safety of the connector.