Bug #42176 System.ArgumentOutOfRangeException: Non-negative number required.
Submitted: 16 Jan 2009 23:38 Modified: 21 Feb 2009 7:48
Reporter: Tony Plack Email Updates:
Status: No Feedback Impact on me:
None 
Category:Connector / NET Severity:S2 (Serious)
Version:5.2.5 OS:Windows (XP)
Assigned to: Assigned Account CPU Architecture:Any
Tags: fill, Source Code, VS2003

[16 Jan 2009 23:38] Tony Plack
Description:
When performing a Fill of a dataset, which normally produces a result set, but occasionally produces an empty set, you will get the following Exception in VS 2003 VB.NET project.

System.ArgumentOutOfRangeException: Non-negative number required.
Parameter name: count
   at System.IO.BufferedStream.Read(Byte[] array, Int32 offset, Int32 count)
   at MySql.Data.MySqlClient.MySqlStream.Read(Byte[] buffer, Int32 offset, Int32 count)
   at MySql.Data.MySqlClient.MySqlStream.ReadString(Int64 length)
   at MySql.Data.MySqlClient.NativeDriver.GetFieldMetaData41()
   at MySql.Data.MySqlClient.NativeDriver.GetFieldMetaData()
   at MySql.Data.MySqlClient.NativeDriver.ReadColumnMetadata(Int32 count)
   at MySql.Data.MySqlClient.MySqlDataReader.NextResult()
   at MySql.Data.MySqlClient.MySqlCommand.ExecuteReader(CommandBehavior behavior)
   at MySql.Data.MySqlClient.MySqlCommand.ExecuteDbDataReader(CommandBehavior behavior)
   at System.Data.Common.DbCommand.System.Data.IDbCommand.ExecuteReader(CommandBehavior behavior)
   at System.Data.Common.DbDataAdapter.FillInternal(DataSet dataset, DataTable[] datatables, Int32 startRecord, Int32 maxRecords, String srcTable, IDbCommand command, CommandBehavior behavior)
   at System.Data.Common.DbDataAdapter.Fill(DataTable[] dataTables, Int32 startRecord, Int32 maxRecords, IDbCommand command, CommandBehavior behavior)
   at System.Data.Common.DbDataAdapter.Fill(DataTable dataTable)
   at MyCode.SQL.GetData()

The error is a symptom that pointed me to an interesting issue with 5.2.5 as well as 5.2.3.

The source code versions of these MySQL Connector/NET do not match the above stack trace.  In fact, it is not possible to trace this error with the source code.

If the Source code is compiled, this error has yet to appear.  It will randomly happen using the Installed Binary versions.

The next (or any) Fill call after this message will lock the thread regardless of Timeout values on the Select.Command.Timeout Settings.

How to repeat:
Have a multi-threaded system accessing the same DataAdapter.Fill function in the binary version of 5.2.5 or 5.2.3 MySQL Connector/NET, where the query may go from large tables to nothing in a single call.  This is very complex to setup in a small environment for consistent reproduction, however, I believe that my analysis should suffice to help relieve the problem.

As stated, just moving to a compiled version of the Connector versus the binary seems to have cleared it up, but there is a missing check in the Source code.

Suggested fix:
Compile the Source versions of the same connectors and the above error will disappear.

The stack trace has a MAJOR different indicating that there is two versions of source code being used.  The difference is that NativeDriver.GetFieldMetaData41 never calls MySqlStream.ReadString(Int64) directly bue calls MySqlStream.ReadLenString(), which calls MySqlStream.ReadString(Int64).  This may be a Microsoft Bug, but I have never seen this in a trace where it removes an entire function call.

The Binary version seems to be passing a negative number from GetFieldMetaData41() to ReadString(Int64 length) in the length parameter.  However, this cannot be confirmed because the Source code does not match the stack trace for the same version of the Connector.

Using the Source version, I would assume that the call to MySQLStream.ReadPackedInteger in MySqlStream.ReadLenString() is returning a -1.  This is never checked in later code and is invalid for a length when calling read.  The -1 is returned in line 533 of MySqlStream.cs in version 5.2.5.

My suggestion would be to change line 593 of the same file from:
if (length == 0)
                            to:
if (length < 1)

But I do not know the systemic ramifications of this move.  What is more of interest is why a Packed-Integer first byte of 251 should return a -1 instead of a real integer and why this should not be checked in subsequent programs.

I have NOT made this change and have not needed too so far.  Not sure why, because the code makes it certain this error will reappear.  I may make this change as insurance.
[18 Jan 2009 7:53] Tony Plack
It appears that the problem is deeper than just this issue.  I have made the change from == to < as stated above, but I now come to a further problem.

MySQL Server version is 5.0.45.

If I set that parameter and return an empty string, the Read function will hang waiting for > 322000 bytes of data on an empty recordset.

The timeout for the Command object also seems to be broken in the Source code as it is using the same thread as the read statement.  Line 417 of command.cs calls for a new Timer object with delagate, however, there is no call for a seperate thread to run this timer.  Therefore, the only thing the timeout value is being used for is to truncate large quantities of data in the datastream while the Read function is pumping data.  If the Stream.Read hangs, waiting for data, the timer delagate is never called.  This is a known issue with Microsoft Timers in .NET 2.0 because they use the current thread.

If the read function is directed by the Native Driver to read garbage, it will hang the current thread, making the timer in the Command Object worthless.

I am looking at expanding the stream object using the Stream.ReadTimeout property around line 355 of MySqlStream.cs but the stream does not seem to support this function at this time. (Throws an exception).

I do believe that I need to find out why the Native Driver is getting garbage, but these couple of checks in the Connector code goes a long way to making the product more usable in the event of corupt stream/server data.

I am attempting to produce a repeatable test to capture the rouge data stream, I have not had success yet as the point in which it fails to capture this data.

The program is also trying to pass a -1 to the Read function at 355 in MySqlStream.cs.  It appears that the function:

		int lenToRead = Math.Min(count, (int)(inLength - inPos));

is returning a -1 when inLength is 7 and inPos is 8.  There are no checks for this in the program.

This caused me to change line 341 from:

            inPos == inLength
to
            inPos >= inLength
in order to catch this condition when we have passed the Length of the current block.
[20 Jan 2009 11:28] Tonci Grgin
Hi Tony and thanks for your report.

Source is built, by default, in "debug" configuration, meaning that many options have to be turned off, including CommandTimeout, as it makes no sense to have it while I'm pondering over source lines (personally asked for this). Thus I think you can safely ignore such discrepancies. Can you produce test case focusing on your primary problem? I mean not paying attention to things that are not meant to work/work differently in debug mode? Also, try building with "release" config and see if it makes any difference.

For catching packets, I suggest to do two things:
  o turn logging on in c/NET connection string
  o use wireshark
[20 Jan 2009 22:45] Tony Plack
Tonci,
Thanks for the reply.  I actually figured out the entire thing and have been working to change my code.

I guess I made the assumption that the Connection object (or more properly, MySQLStream) was thread safe.

I was using one connection object for all threads in a multi-threaded application.  Because of this, while one read was taking place, a jump into the code on another thread read was causing the MySQLStream object to have incorrect local variables for the New Read.  This caused the reads to overlap and for counters to be incorrect in the object.

All I needed to do was move to seperate Connection objects for each thread.  This increases the memory and connections on the servers, but it works very cleanly.

It is difficult to give you an example without copying my enviroment over to you.  This is the reason that I was giving line numbers in the 5.2.5 version of the code.  I am attempting to help at least clean up some of the issues with packed integers.  Maybe not make any other change to the code than some Aserts or Throw some exceptions, but these areas should be safe guarded because it was causing memory corruption on the stack.

Personally, I prefer line numbers and errors over examples because of staging time.  I just do not have time to write custom testing software for broken code.

Most of this has to do with ReadInteger() in the MetaData and the return of a -1 when then reading strings.
[20 Jan 2009 22:52] Tony Plack
BTW,
I did do as you asked and did compile in Release with the same outcome.  Not on the stack trace, but on the muli-threaded aspect.  The system still squashes the existing Stream when a new thread enters.

In addition, the Read command still hangs the processes because it is actually in the single thread (first thread that created the connection object).  CommandTimeout therefore still does not work to do anything but truncate data streams that exceed the transmission time allowed in CommandTimeout.

Wireshark was an idea, but I was collecting in excess of 2,000 packets per second during the activity and sorting the streams was difficult.  It was not in the TCP stream, it was the fact that the threads were overlaping data.

Thanks again for looking at this with me.  I hope we can improve the product because MySQL has been great for us.
[21 Jan 2009 7:48] Tonci Grgin
Tony, I just love reporters that don't give up and present great analysis for all to see. BugsDB is a public place and I believe many will profit from this report.

Now, things might be shareable across threads but this does not imply they are thread-safe. In part, this safety relies on framework too so I'm not quite sure what we can do but to better document your report. Do you agree?
[22 Feb 2009 0:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".