Bug #21515 socket write error with longblob > 16Mb
Submitted: 8 Aug 2006 17:30 Modified: 19 Dec 2007 14:30
Reporter: Andrey Grebnev Email Updates:
Status: Can't repeat Impact on me:
None 
Category:Connector / J Severity:S3 (Non-critical)
Version:3.1.12 OS:Windows (WIndows XPsp2)
Assigned to: Mark Matthews CPU Architecture:Any
Tags: 16Mb, longblob, socket write error

[8 Aug 2006 17:30] Andrey Grebnev
Description:
Hello 

I have the application which uses: 
- MySQL 5.0.15
- Connector/J 3.1.12 
- commons-dbcp 1.2.1 
- Hibernate 3.1.3 
under Windows XPsp2 

I have the following options in my.ini

key_buffer_size=16M 
max_allowed_packet=100M 

The connection string is ?characterEncoding=utf-8&useUnicode=true&autoReconnect=true&dumpQueriesOnException=true&logger=com.mysql.jdbc.log.Log4JLogger&enablePacketDebug=true

The max pool size = 20 

I have the following table:
create table `al_core_resource_data` (`id` bigint not null, `raw_data` longblob not null, primary key (`id`)) type=InnoDB

I can upload the data (with size till 100M) into this table with success. However when I try to download it immediately after uploading and the data is more then 16Mb I get the following error: 

Client com.mysql.jdbc.ByteArrayBuffer@a00cc8--------------------> Server

Packet payload:

91 00 00 00 16 73 65 6c     . . . . . s e l 
65 63 74 20 72 65 73 6f     e c t . r e s o 
75 72 63 65 64 61 30 5f     u r c e d a 0 _ 
2e 60 69 64 60 20 61 73     . ` i d ` . a s 
20 69 64 31 5f 32 30 5f     . i d 1 _ 2 0 _ 
30 5f 2c 20 72 65 73 6f     0 _ , . r e s o 
75 72 63 65 64 61 30 5f     u r c e d a 0 _ 
2e 60 72 61 77 5f 64 61     . ` r a w _ d a 
74 61 60 20 61 73 20 72     t a ` . a s . r 
61 77 32 5f 32 30 5f 30     a w 2 _ 2 0 _ 0 
5f 20 66 72 6f 6d 20 60     _ . f r o m . ` 
61 6c 5f 63 6f 72 65 5f     a l _ c o r e _ 
72 65 73 6f 75 72 63 65     r e s o u r c e 
5f 64 61 74 61 60 20 72     _ d a t a ` . r 
65 73 6f 75 72 63 65 64     e s o u r c e d 
61 30 5f 20 77 68 65 72     a 0 _ . w h e r 
65 20 72 65 73 6f 75 72     e . r e s o u r 
63 65 64 61 30 5f 2e 60     c e d a 0 _ . ` 
69 64 60 3d 3f 69 70 74     i d ` = ? i p t 
34 5f                       4 _ 

Server (re-used) com.mysql.jdbc.ByteArrayBuffer@1a75942 --------------------> Client

Packet payload:

0c 00 00 01 00 92 1c 00     . . . . . . . . 
00 02 00 01                 . . . . 

Server (new) com.mysql.jdbc.ByteArrayBuffer@1d4897 --------------------> Client

Packet payload:

17 00 00 02 03 64 65 66     . . . . . d e f 
00 00 00 01 3f 00 0c 3f     . . . . ? . . ? 
00 00 00 00 00 fd 80 00     . . . . . . . . 
                            

Server (new) com.mysql.jdbc.ByteArrayBuffer@88cc3b --------------------> Client

Packet payload:

05 00 00 03 fe 00           . . . . . . 

Server (new) com.mysql.jdbc.ByteArrayBuffer@1186e2e --------------------> Client

Packet payload:

4b 00 00 04 03 64 65 66     K . . . . d e f 
09 61 74 6c 65 61 70 5f     . a t l e a p _ 
64 62 0c 72 65 73 6f 75     d b . r e s o u 
72 63 65 64 61 30 5f 15     r c e d a 0 _ . 
61 6c 5f 63 6f 72 65 5f     a l _ c o r e _ 
72 65 73 6f 75 72 63 65     r e s o u r c e 
5f 64 61 74 61 09 69 64     _ d a t a . i d 
31 5f 32 30 5f 30 5f 02     1 _ 2 0 _ 0 _ . 
69 64 0c 3f 00 14 00 00     i d . ? . . . . 
00 08 03 50                 . . . P 

Server (new) com.mysql.jdbc.ByteArrayBuffer@e9baae --------------------> Client

Packet payload:

52 00 00 05 03 64 65 66     R . . . . d e f 
09 61 74 6c 65 61 70 5f     . a t l e a p _ 
64 62 0c 72 65 73 6f 75     d b . r e s o u 
72 63 65 64 61 30 5f 15     r c e d a 0 _ . 
61 6c 5f 63 6f 72 65 5f     a l _ c o r e _ 
72 65 73 6f 75 72 63 65     r e s o u r c e 
5f 64 61 74 61 0a 72 61     _ d a t a . r a 
77 32 5f 32 30 5f 30 5f     w 2 _ 2 0 _ 0 _ 
08 72 61 77 5f 64 61 74     . r a w _ d a t 
61 0c 3f 00 ff ff ff ff     a . ? . . . . . 
fc 91 10                    . . . 

Server (new) com.mysql.jdbc.ByteArrayBuffer@def807 --------------------> Client

Packet payload:

05 00 00 06 fe 00           . . . . . . 

Client com.mysql.jdbc.ByteArrayBuffer@11f0aa0--------------------> Server

Packet payload:

16 00 00 00 17 92 1c 00     . . . . . . . . 
00 00 01 00 00 00 00 01     . . . . . . . . 
08 00 04 00 00 00 00 00     . . . . . . . . 
00 00 6f 75 72 63 65        . . o u r c e 

2006-08-08 21:00:25,123 WARN http-8081-Processor25 org.hibernate.util.JDBCExceptionReporter - SQL Error: 0, SQLState: 08S01
2006-08-08 21:00:25,123 ERROR http-8081-Processor25 org.hibernate.util.JDBCExceptionReporter - Communications link failure due to underlying exception: 

** BEGIN NESTED EXCEPTION ** 

java.net.SocketException
MESSAGE: Connection reset by peer: socket write error

STACKTRACE:

java.net.SocketException: Connection reset by peer: socket write error
    at java.net.SocketOutputStream.socketWrite0(Native Method)
    at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:92)
    at java.net.SocketOutputStream.write(SocketOutputStream.java:136)
    at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:65)
    at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:123)
    at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:2692)
    at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:2621)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1552)
    at com.mysql.jdbc.ServerPreparedStatement.realClose(ServerPreparedStatement.java:892)
    at com.mysql.jdbc.ServerPreparedStatement.close(ServerPreparedStatement.java:458)
    at org.apache.commons.dbcp.DelegatingStatement.close(DelegatingStatement.java:165)
    at org.hibernate.jdbc.AbstractBatcher.closePreparedStatement(AbstractBatcher.java:471)
    at org.hibernate.jdbc.AbstractBatcher.closeStatement(AbstractBatcher.java:218)
    at org.hibernate.jdbc.AbstractBatcher.closeQueryStatement(AbstractBatcher.java:234)
    at org.hibernate.jdbc.AbstractBatcher.closeQueryStatement(AbstractBatcher.java:162)
    at org.hibernate.loader.Loader.getResultSet(Loader.java:1683)
    at org.hibernate.loader.Loader.doQuery(Loader.java:662)

** END NESTED EXCEPTION **
Last packet sent to the server was 15 ms ago.

So the error is appeared during execution the following query:

select resourceda0_.`id` as id1_20_0_, resourceda0_.`raw_data` as raw2_20_0_ from `al_core_resource_data` resourceda0_ where resourceda0_.`id`=?

I have debuged my application and can say that the exception is risen
in the method "fill" of class "com.mysql.jdbc.util.ReadAheadInputStream" line

int n = this.underlyingStream.read(this.buf, currentPosition, bytesToRead);

However if I try to download it the second time I will have success. Moreover if I restart the mysql between uploading and downloading I will have success too. But sometimes the error does not show itself at all. The error is non-determined. 

I have supposition that the problem shows itself when uploading and downloading are in the same connection of the pool. Possibly this bug is in MySQL server not in MySQL Connector/J.

I have tested my application under MySQL 4.0.20d, 4.1.10a, 4.1.12a I have the same problem. But I do not have this error with other databases (e.g. HSQLDB). 

Any ideas?

How to repeat:
Right now I have not and small example to show you.
[4 Sep 2006 11:25] Tonci Grgin
Hi Andrey, thanks for your problem report.
I was unable to repeat it with our standard BLOB test and following settings:
  - MySQL server 5.0.23-log on WinXP Pro SP2
  - JRE 1.5.07
  - Latest repo snapshot of connector/J
  - I don't have hibernate so it's not used in test

C:\mysql507\bin>mysql -uroot test
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1 to server version: 5.0.23-log
...
mysql> show variables like "%char%";
+--------------------------+-----------------------------+
| Variable_name            | Value                       |
+--------------------------+-----------------------------+
| character_set_client     | utf8                        |
| character_set_connection | utf8                        |
| character_set_database   | utf8                        |
| character_set_filesystem | binary                      |
| character_set_results    | utf8                        |
| character_set_server     | utf8                        |
| character_set_system     | utf8                        |
| character_sets_dir       | C:\mysql507\share\charsets\ |
+--------------------------+-----------------------------+
8 rows in set (0.00 sec)

mysql> show variables like "max_all%";
+--------------------+-----------+
| Variable_name      | Value     |
+--------------------+-----------+
| max_allowed_packet | 104856576 |
+--------------------+-----------+
1 row in set (0.00 sec)

mysql> select @@key_buffer_size;
+-------------------+
| @@key_buffer_size |
+-------------------+
|          16777216 |
+-------------------+
1 row in set (0.33 sec)

Connect URL: //localhost:3306/test?user=root&password=&characterEncoding=utf-8&&useUnicode=true
File used for testing is 17MB in size.

Other meanings of SQL state reported:
SQLSTATE: 08S01 (ER_NET_PACKETS_OUT_OF_ORDER)
Message: Got packets out of order
This I get using enablePacketDebug=true option and will investigate more.
I think you're trying to use utf-8 on non unicode server and/or database and/or table. Can you please post output from show variables like "%char%"; command at the time of error?
[4 Sep 2006 12:06] Andrey Grebnev
Here it is

mysql> show variables like "max_all%";
+--------------------+-----------+
| Variable_name      | Value     |
+--------------------+-----------+
| max_allowed_packet | 104856576 |
+--------------------+-----------+
1 row in set (0.00 sec)

mysql> select @@key_buffer_size;
+-------------------+
| @@key_buffer_size |
+-------------------+
|          33554432 |
+-------------------+
1 row in set (0.00 sec)

mysql> show variables like "%char%";
+--------------------------+----------------------------------------------+
| Variable_name            | Value                                        |
+--------------------------+----------------------------------------------+
| character_set_client     | utf8                                         |
| character_set_connection | utf8                                         |
| character_set_database   | utf8                                         |
| character_set_results    | utf8                                         |
| character_set_server     | utf8                                         |
| character_set_system     | utf8                                         |
| character_sets_dir       | D:\ProgramFiles\mysql-5.0.15\share\charsets/ |
+--------------------------+----------------------------------------------+
7 rows in set (0.00 sec)
[4 Sep 2006 13:59] Tonci Grgin
Andrey, great. Now can you tell me if the error persists if you remove packet debug? Also, can you reproduce the error not using hibernate?
[4 Sep 2006 17:19] Andrey Grebnev
Yes, the bug is both with and wihtout packet debug. I have just created simplest test with such big longblog. It works fine. I think the problem is under the combination of circumstances. If you have a time you can try to setup my application and debug mysql server. Maybe it can allow you to find out the reason of unexpected socket termination.
[4 Sep 2006 17:23] Tonci Grgin
Andrey, if you are able to reproduce unwanted crash without hibernate and debugpacket, please post your entire project so I can take a look at it.
[5 Sep 2006 13:55] Andrey Grebnev
Tonci, I hope you have noticed that I have already posted the comment in hide mode.
[7 Sep 2006 5:37] Tonci Grgin
Andrey, indeed I did.
Since I can't repeat exact problem but do have errors I can't explain I'll ask for consult.
[19 Dec 2007 14:30] Mark Matthews
We're not able to repeat this behavior with any recent C/J release. If you still see this problem after upgrading to C/J 5.1, feel free to re-open this report.