Bug #35202 Huge SQL statement make mysql-proxy abort.
Submitted: 11 Mar 2008 2:58 Modified: 15 Oct 2009 6:55
Reporter: Meiji KIMURA Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Proxy: Core Severity:S3 (Non-critical)
Version:0.6.1, 0.8.0 r OS:Any
Assigned to: Jan Kneschke CPU Architecture:Any
Triage: D1 (Critical)

[11 Mar 2008 2:58] Meiji KIMURA
Description:
When mysql-proxy use lua scipt, Huge SQL statement (200M) make mysql-proxy abort.

In Windows environment, mysql-proxy disply this message,

D:\MySQL\mysql-proxy-0.6.1-win32-x86>mysql-proxy --proxy-lua-script=insert_log.lua
\cygwin\home\mysqldev\mysql-proxy\src\mysql-proxy-0.6.1\src\network-mysqld-proxy
.c.3523: COM_(0x32) is not handled

And two windows message are displayed like these,

(1) Unspecified fatal error encountered, aborting.
(2) Runtime Error!
    Program: D:\MySQL\mysql\proxy-0.6.1-win32-x86-mysql-proxy.exe

After mysql-proxy abortion, client display this error message.
ERROR 2013 (HY000) at line 1: Lost connection to MySQL server during query

How to repeat:
(1) I made a lua script for outputing INSERT SQL statement to log like this,

ocal log_file = 'c:\\insert.log'
local fh = io.open(log_file, "a+")

function read_query( packet )
  if (string.byte(packet) == proxy.COM_QUERY) or (string.byte(packet) == proxy.COM_STMT_PREPARE) then
    local query = string.sub(packet, 2)
    local action = " "
    if string.match(string.lower(query), "^insert") then action = "I"
    end

    if action ~= " " then
      fh:write(string.format("%s|%s| -- %s \n",os.date('%Y-%m-%d %H:%M:%S'), action, query))
      fh:flush()
    end
  end
end

(2) I made a table 't1' for testing on test database like this,

create table t1(i1 int);

(3) I made a huge INSERT SQL file like this,

insert into t1 values(1),(2),(3),.........

Total size of the file is 210MB. It contains single huge insert statement.

(4) Activate mysql-proxy with lua script like this.
D:\MySQL\mysql-proxy-0.6.1-win32-x86>mysql-proxy.exe --proxy-lua-script=insert_l
og.lua

(5) Activate mysql CUI command with huge insert SQL file(insert.sql) like this.
D:\mysql\bin>mysql -u root -h 127.0.0.1 -P 4040 test < insert.sql

(6) It takes a long time in my environment (abound 1-hour) and abort.
    The message(see 'Description:' part of this report) are output.

Suggested fix:
N/A
[12 Mar 2008 7:03] Kay Roepke
What is the max_allowed_packet of the backend mysqld?

I think the issue is that we buffer up the packets you send to the proxy to call the Lua script and then after the callback runs we pass it on to the server, which in turn closes the connection because the packet is too large.

Could you also obtain a stacktrace, please?

Kay
[24 Apr 2008 11:25] Meiji KIMURA
>What is the max_allowed_packet of the backend mysqld?

I set it lager than whole SQL statement.

>Could you also obtain a stacktrace, please?

How can I get stacktrace ? I have to use debug build of MySQL-proxy ?
[3 Jun 2009 18:15] Diego Medina
Now the Proxy process does not abort, but you still get this message on the log

(critical) network-mysqld-packet.c:615: COM_(0xffffffff) is not handled
(debug) [network-mysqld.c:784]: error on a connection (fd: -1 event: 0). closing client connection.
[2 Jul 2009 15:45] Diego Medina
Simpler steps to reproduce the bug:

You do not need a lua script, so you can start the proxy like this:

$ ./sbin/mysql-proxy --proxy-backend-addresses=127.0.0.1:5132

Generate a 32M sql file

$ echo "insert into t1 values" > bug-35202.sql
$ for i in {1..30000}; do echo "($i)," >> bug-35202.sql; done;
$ for i in {1..5}; do cat bug-35202.sql >> bug-35202.2.sql; cat bug-35202.2.sql >> bug-35202.sql ; done;

Run the generated sql file

$ mysql -h127.0.0.1 -P4040 test -e "source  bug-35202.sql "

Note, if you have a smaller sql file, you get 
"ERROR 1153 (08S01): Got a packet bigger than 'max_allowed_packet' bytes"
[30 Jul 2009 11:35] Andrii Nikitin
mem agent debug log

Attachment: bug35202-agent-debug.log (application/octet-stream, text), 4.04 KiB.

[31 Jul 2009 9:38] Andrii Nikitin
It looks because of this bug proxy will not properly handle SQL-statements longer than 16Mb .
[11 Aug 2009 14:55] Enterprise Tools JIRA Robot
Jan Kneschke writes: 
Simplified the test-case a bit more:

    $ perl -e 'printf("SELECT 1 AS %s", "o" x 16777216)' | mysql --port=4040 

As long as the packet we send is larger than 16M, it triggers the same behaviour.
[27 Aug 2009 17:44] Jan Kneschke
Pushed a cleanup for the packet-id handling and test-cases to trunk, will be in 0.8.0

revno: 796
committer: jan@mysql.com
branch nick: trunk
timestamp: Thu 2009-08-27 19:37:33 +0200
message:
  after we append all packets (raw) the packet sequence checks should be
  reset as the next we expect is the client sending another command
------------------------------------------------------------
revno: 795
committer: jan@mysql.com
branch nick: trunk
timestamp: Thu 2009-08-27 19:31:23 +0200
message:
  added tests for the >16M packet handling
------------------------------------------------------------
revno: 794
committer: jan@mysql.com
branch nick: trunk
timestamp: Tue 2009-08-25 18:17:38 +0200
message:
  moved the packet-id handling down into the core
  
    * no direct get/set of ->packet_id in the plugins
    * network_mysqld_queue_append() tracks the packet_id's itself
    * replaced network_queue_append() by network_mysqld_queue_append_raw() 
      to track the packet-ids
    * added _reset() to figure out when a packet-id-sequence is finished
------------------------------------------------------------
revno: 793
committer: jan@mysql.com
branch nick: trunk
timestamp: Mon 2009-08-17 12:30:34 +0200
message:
  rewrote the >16MByte packet handling
  
    * removed the PACKET_LEN_UNSET handling from the plugins
    * removed network_mysqld_con_parse.packet_len, use network_mysqld_proto_get_packet_len() instead
    * changed network_mysqld_queue_append() to take a *int instead of int as _append()
      may increment the packet_id a few times for >16Mbyte packets 
    * removed ->is_overlong_packet, this is hidden from the upper layers for now
    * merge overlong packets into one string as the scripting layer expects it like this
------------------------------------------------------------
revno: 792
committer: jan@mysql.com
branch nick: trunk
timestamp: Mon 2009-08-17 12:28:57 +0200
message:
  added a test for the >16MByte packet handling
[31 Aug 2009 14:39] Enterprise Tools JIRA Robot
Diego Medina writes: 
Verified fixed on 0.8 r798
[15 Oct 2009 6:55] MC Brown
A note has been added to the 0.8.0 changelog: 

 MySQL Proxy would raise an error when processing query packets larger than 16MB in size.
[28 May 2010 11:38] Andrii Nikitin
bash script to generate SQL file with large statement

Attachment: test.sh (application/octet-stream, text), 373 bytes.

[28 May 2010 12:10] Andrii Nikitin
related to bug 54063