Bug #47387 Batch UPDATE crashes server
Submitted: 16 Sep 2009 22:39 Modified: 30 Aug 2010 8:41
Reporter: Yvan Rodrigues Email Updates:
Status: Closed Impact on me:
None 
Category:Connector / NET Severity:S2 (Serious)
Version:5.1.38,6.1.2 OS:Microsoft Windows (.NET 2.0)
Assigned to: CPU Architecture:Any
Tags: batch, batch update, MySqlDataAdapter, MySqlDataAdapter.Update, out of memory, UPDATE

[16 Sep 2009 22:39] Yvan Rodrigues
Description:
Please move to mysql server if that is more appropriate.

My application:
- gets 2000-5000 rows from a table using MySqlDataAdapter.Fill(DataTable)
- changes all the rows, each row holding about 13,000 bytes of data; therefore total size of update is about 27MB + overhead.
- uses MySqlDataAdapter.Update(DataTable) to update the table.
- The table is big (350,000 rows, 2.9GB)
- Update batch size is set to 10000

The application catches a MySqlException:
MySql.Data.MySqlClient.MySqlException: Fatal error encountered attempting to read the resultset. ---> MySql.Data.MySqlClient.MySqlException: Connection unexpectedly terminated.
   at MySql.Data.MySqlClient.MySqlStream.LoadPacket() in G:\My Documents\Visual Studio 2008\Projects\MisMabel Trunk\MySql\Source\MySqlStream.cs:line 186
   at MySql.Data.MySqlClient.MySqlStream.ReadPacket() in G:\My Documents\Visual Studio 2008\Projects\MisMabel Trunk\MySql\Source\MySqlStream.cs:line 123
   at MySql.Data.MySqlClient.NativeDriver.ReadResult() in G:\My Documents\Visual Studio 2008\Projects\MisMabel Trunk\MySql\Source\NativeDriver.cs:line 544
   at MySql.Data.MySqlClient.ResultSet.NextResult() in G:\My Documents\Visual Studio 2008\Projects\MisMabel Trunk\MySql\Source\ResultSet.cs:line 245
   at MySql.Data.MySqlClient.MySqlDataReader.NextResult() in G:\My Documents\Visual Studio 2008\Projects\MisMabel Trunk\MySql\Source\datareader.cs:line 818
   --- End of inner exception stack trace ---
   at MySql.Data.MySqlClient.MySqlDataReader.NextResult() in G:\My Documents\Visual Studio 2008\Projects\MisMabel Trunk\MySql\Source\datareader.cs:line 838
   at MySql.Data.MySqlClient.MySqlCommand.ExecuteReader(CommandBehavior behavior) in G:\My Documents\Visual Studio 2008\Projects\MisMabel Trunk\MySql\Source\command.cs:line 432

When the server actually crashes it logs:
090916 17:12:25 [ERROR] /usr/local/libexec/mysqld: Out of memory (Needed 1750048 bytes)
090916 17:12:25 [ERROR] Out of memory; check if mysqld or some other process uses all available memory; if not, you may have to use 'ulimit' to allow mysqld to use more memory or you can add more swap space
090916 17:12:25 - mysqld got signal 11 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help diagnose
the problem, but since we have already crashed, something is definitely wrong
and this may fail.

key_buffer_size=67108864
read_buffer_size=131072
max_used_connections=15
max_threads=500
threads_connected=11
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 2180635 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

090916 17:12:25 mysqld_safe mysqld restarted
090916 17:12:25 [Warning] The syntax '--log_slow_queries' is deprecated and will be removed in MySQL 7.0. Please use '--slow_query_log'/'--slow_query_log_file' instead.
090916 17:12:25 [Warning] The syntax '--log_slow_queries' is deprecated and will be removed in MySQL 7.0. Please use '--slow_query_log'/'--slow_query_log_file' instead.
090916 17:12:25 [Note] Plugin 'FEDERATED' is disabled.
InnoDB: Log scan progressed past the checkpoint lsn 7 2540332766
090916 17:12:25  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
InnoDB: Doing recovery: scanned up to log sequence number 7 2541970695
090916 17:12:25  InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
InnoDB: Last MySQL binlog file position 0 2263424, file name ./mindy-bin.000231
090916 17:12:26  InnoDB: Started; log sequence number 7 2541970695
090916 17:12:26 [Note] Recovering after a crash using mindy-bin
090916 17:12:26 [Note] Starting crash recovery...
090916 17:12:26 [Note] Crash recovery finished.
090916 17:12:26 [Note] Event Scheduler: Loaded 0 events
090916 17:12:26 [Note] /usr/local/libexec/mysqld: ready for connections.
Version: '5.1.37-log'  socket: '/tmp/mysql.sock'  port: 3306  FreeBSD port: mysql-server-5.1.37

For debugging I tried this with the same results: mysql_args="--log-bin=mindy-bin --log-error=/var/log/mysqld.log --log_slow_queries=ON --slow_query_log=ON --slow_query_log_file=/var/log/mysqld-slow-queries.log --server-id=1 --innodb_flush_log_at_trx_commit=1 --sync-binlog=1 --binlog-format=ROW  --max_allowed_packet=100M --net_read_timeout=180 --net_write_timeout=180 --max_connections=500 --max_user_connections=0 --innodb_lock_wait_timeout=600 --sql-mode=\"NO_ZERO_DATE\" --max_connect_errors=100"

I have watched the server while the query is running, and the memory usage is negligible. There is 4GB of swap that is not even being used.

How to repeat:
Server = 5.1.37-log community, Core2 Duo 2.xGHz 2GB RAM running FreeBSD 7.2-RELEASE-p2

The actual update command in MySqlDataAdapter.ExecuteBatch looks like:
UPDATE `Production_Builder` SET `BatchNo` = @BatchNo, `OrderNo` = @OrderNo, `ItemNo` = @ItemNo, `Name` = @Name, `Colour` = @Colour, `Icon` = @Icon, `Quantity` = @Quantity, `Comments` = @Comments, `BuilderData` = @BuilderData, `Template` = @Template, `Built` = @Built, `Output` = @Output, `Learned` = @Learned, `ODid` = @ODid, `Priority` = @Priority, `MetaXml` = @MetaXml, `Font` = @Font WHERE `id` = @id

The connection string looks like:
allow batch=True;allow user variables=True;allow zero datetime=False;character set=latin1;connection lifetime=600;connection reset=True;connect timeout=600;convert zero datetime=False;database=xxxxx;default command timeout=600;respect binary flags=False;maximum pool size=25;minimum pool size=1;pooling=True;port=3306;server=xxxxx;treat tiny as boolean=True;use compression=True;use procedure bodies=True;user id=xxxxx

- no my.cnf is being used
- startup environment is: mysql_args="--log-bin=mindy-bin --log-error=/var/log/mysqld.log --log_slow_queries=ON --slow_query_log=ON --slow_query_log_file=/var/log/mysqld-slow-queries.log --server-id=1 --innodb_flush_log_at_trx_commit=1 --sync-binlog=1 --binlog-format=ROW --innodb_buffer_pool_size=512M --max_allowed_packet=100M --net_read_timeout=180 --net_write_timeout=180 --max_connections=500 --max_user_connections=0 --query_cache_size=100M --key_buffer_size=64M --sort_buffer_size=4M --innodb_lock_wait_timeout=600 --sql-mode=\"NO_ZERO_DATE\" --max_connect_errors=100"

When I change the application to NOT use batching it seems to work after about 5-10 minutes. However, a subsequent BATCH update on the same data resulted in an exception but the server does not crash. Maybe it is just a timeout. The stack trace is: 
MySql.Data.MySqlClient.MySqlException: Fatal error encountered attempting to read the resultset. ---> MySql.Data.MySqlClient.MySqlException: Reading from the stream has failed. ---> System.IO.IOException: Unable to read data from the transport connection: An established connection was aborted by the software in your host machine. ---> System.Net.Sockets.SocketException: An established connection was aborted by the software in your host machine
   at System.Net.Sockets.Socket.Receive(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags)
   at System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size)
   --- End of inner exception stack trace ---
   at System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size)
   at System.IO.BufferedStream.Read(Byte[] array, Int32 offset, Int32 count)
   at MySql.Data.MySqlClient.MySqlStream.ReadFully(Stream stream, Byte[] buffer, Int32 offset, Int32 count) in G:\My Documents\Visual Studio 2008\Projects\MisMabel Trunk\MySql\Source\MySqlStream.cs:line 159
   at MySql.Data.MySqlClient.CompressedStream.PrepareNextPacket() in G:\My Documents\Visual Studio 2008\Projects\MisMabel Trunk\MySql\Source\CompressedStream.cs:line 147
   at MySql.Data.MySqlClient.CompressedStream.Read(Byte[] buffer, Int32 offset, Int32 count) in G:\My Documents\Visual Studio 2008\Projects\MisMabel Trunk\MySql\Source\CompressedStream.cs:line 121
   at MySql.Data.MySqlClient.CompressedStream.ReadByte() in G:\My Documents\Visual Studio 2008\Projects\MisMabel Trunk\MySql\Source\CompressedStream.cs:line 102
   at MySql.Data.MySqlClient.MySqlStream.LoadPacket() in G:\My Documents\Visual Studio 2008\Projects\MisMabel Trunk\MySql\Source\MySqlStream.cs:line 183
   --- End of inner exception stack trace ---
   at MySql.Data.MySqlClient.MySqlStream.LoadPacket() in G:\My Documents\Visual Studio 2008\Projects\MisMabel Trunk\MySql\Source\MySqlStream.cs:line 205
   at MySql.Data.MySqlClient.MySqlStream.ReadPacket() in G:\My Documents\Visual Studio 2008\Projects\MisMabel Trunk\MySql\Source\MySqlStream.cs:line 123
   at MySql.Data.MySqlClient.NativeDriver.ReadResult() in G:\My Documents\Visual Studio 2008\Projects\MisMabel Trunk\MySql\Source\NativeDriver.cs:line 544
   at MySql.Data.MySqlClient.ResultSet.NextResult() in G:\My Documents\Visual Studio 2008\Projects\MisMabel Trunk\MySql\Source\ResultSet.cs:line 245
   at MySql.Data.MySqlClient.MySqlDataReader.NextResult() in G:\My Documents\Visual Studio 2008\Projects\MisMabel Trunk\MySql\Source\datareader.cs:line 818
   --- End of inner exception stack trace ---
   at MySql.Data.MySqlClient.MySqlDataReader.NextResult() in G:\My Documents\Visual Studio 2008\Projects\MisMabel Trunk\MySql\Source\datareader.cs:line 838
   at MySql.Data.MySqlClient.MySqlCommand.ExecuteReader(CommandBehavior behavior) in G:\My Documents\Visual Studio 2008\Projects\MisMabel Trunk\MySql
\Source\command.cs:line 432

Workaround: a smaller batch size of 100 seems to prevent the error.

Suggested fix:
Not sure yet. Sorry server is not compiled for debugging. I can set this up if I need to.

If in fact I am somehow using so much memory that mysqld is crashing, the condition should be caught and query aborted.
[17 Sep 2009 5:52] Tonci Grgin
Hi Yvan and thanks for your report.

If MySQL server crashes it should go to Server section and not c/NET. But I don't want to pass it to colleagues just yet. Can you please try turning compression OFF and retesting? Inform me of result.
[17 Sep 2009 6:04] MySQL Verification Team
could this be related to bug #27863 ?
[17 Sep 2009 6:14] Tonci Grgin
Yvan, as colleagues suggested, please check your report against Bug#27863 and Bug#42503. If your code works when not using COMPRESSION then we have a duplicate of first bug, otherwise, it's a duplicate of last bug I mentioned.
[17 Sep 2009 13:01] Yvan Rodrigues
I will try with compression disabled. It may be a couple of days before I reply, as I don't like crashing my server during business hours :)
[17 Sep 2009 13:23] Tonci Grgin
Ok, waiting.
[17 Oct 2009 23: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".
[19 Oct 2009 6:26] Tonci Grgin
Waiting on feedback from Yvan. Is this resolved?
[20 Nov 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".