Bug #44495 Prepared Statement: CALL p(<x>) - `thd->protocol == &thd->protocol_text' failed

• Submitted: 27 Apr 2009 16:30
• Modified: 18 Dec 2009 13:13
• Reporter: Ulf Wendel
• Status: Closed
• Category: MySQL Server
• Severity: S3 (Non-critical)
• Version: 5.1.34
• OS: Linux
• Assigned to: Davi Arnaut
• CPU Architecture: Any

[27 Apr 2009 16:30] Ulf Wendel

Description:
Using mysql_stmt_execute() to call a stored procedure using "CALL p(<something>)" can cause a crash of MySQL 5.1.34. The server should not crash regardless how I use the C-API. I may not be using it in the "right way", but still. http://bugs.php.net/bug.php?id=47782 may be related.

Using the mysql prompt one can run the following, which causes a server crash when running through the C-API:

mysql> drop procedure if exists p; delimiter //; create procedure p(val varchar(255)) begin set @sql=concat("select '", val, "'"); prepare stmt from @sql; execute stmt; drop prepare stmt;  end; // delimiter ; // call p("abc");
Query OK, 0 rows affected (0.00 sec)

Query OK, 0 rows affected (0.00 sec)

+-----+
| abc |
+-----+
| abc |
+-----+
1 row in set (0.00 sec)

Query OK, 0 rows affected (0.01 sec)

mysql> prepare stmt_outside from "CALL p('abc')";
Query OK, 0 rows affected (0.00 sec)
Statement prepared

mysql> execute stmt_outside;
+-----+
| abc |
+-----+
| abc |
+-----+
1 row in set (0.00 sec)

Query OK, 0 rows affected (0.00 sec)

mysql> drop prepare stmt_outside;
Query OK, 0 rows affected (0.00 sec)

mysql> call p('abc');
+-----+
| abc |
+-----+
| abc |
+-----+
1 row in set (0.00 sec)

Query OK, 0 rows affected (0.00 sec)

Compile the C example and run it:

Server:         5.1.34-debug
Protocol:       10
Client:         5.1.34

CALL using stmt_prepare()/stmt_execute...
ERROR: mysql_stmt_execute() failed
[2013] Lost connection to MySQL server during query
[2006] MySQL server has gone away

090427 18:27:03 mysqld_safe Number of processes running now: 0
090427 18:27:03 mysqld_safe mysqld restarted
mysqld: sql_prepare.cc:2233: void mysql_sql_stmt_prepare(THD*): Assertion `thd->protocol == &thd->protocol_text' failed.
090427 18:27:03 - mysqld got signal 6 ;
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=8384512
read_buffer_size=131072
max_used_connections=1
max_threads=151
threads_connected=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 338311 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 0x18a9da8
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0x44089110 thread_stack 0x40000
/usr/local/mysql/libexec/mysqld(my_print_stacktrace+0x32)[0xafda58]
/usr/local/mysql/libexec/mysqld(handle_segfault+0x28a)[0x6b5268]
/lib64/libpthread.so.0[0x2b01d834ffb0]
/lib64/libc.so.6(gsignal+0x35)[0x2b01d904bb45]
/lib64/libc.so.6(abort+0x110)[0x2b01d904d0e0]
/lib64/libc.so.6(__assert_fail+0xef)[0x2b01d904507f]
/usr/local/mysql/libexec/mysqld(_Z22mysql_sql_stmt_prepareP3THD+0x91)[0x771629]
/usr/local/mysql/libexec/mysqld(_Z21mysql_execute_commandP3THD+0x837)[0x6c6eab]
/usr/local/mysql/libexec/mysqld(_ZN13sp_instr_stmt9exec_coreEP3THDPj+0x1d)[0x888d5b]
/usr/local/mysql/libexec/mysqld(_ZN13sp_lex_keeper23reset_lex_and_exec_coreEP3THDPjbP8sp_instr+0x1b1)[0x888f93]
/usr/local/mysql/libexec/mysqld(_ZN13sp_instr_stmt7executeEP3THDPj+0x18a)[0x88f13c]
/usr/local/mysql/libexec/mysqld(_ZN7sp_head7executeEP3THD+0x5a0)[0x88b268]
/usr/local/mysql/libexec/mysqld(_ZN7sp_head17execute_procedureEP3THDP4ListI4ItemE+0x787)[0x88bff7]
/usr/local/mysql/libexec/mysqld(_Z21mysql_execute_commandP3THD+0x6fc0)[0x6cd634]
/usr/local/mysql/libexec/mysqld(_ZN18Prepared_statement7executeEP6Stringb+0x4ff)[0x76cf27]
/usr/local/mysql/libexec/mysqld(_ZN18Prepared_statement12execute_loopEP6StringbPhS2_+0x11c)[0x771084]
/usr/local/mysql/libexec/mysqld(_Z18mysql_stmt_executeP3THDPcj+0x205)[0x771573]
/usr/local/mysql/libexec/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0xaf2)[0x6d03d2]
/usr/local/mysql/libexec/mysqld(_Z10do_commandP3THD+0x24a)[0x6d1936]
/usr/local/mysql/libexec/mysqld(handle_one_connection+0x11c)[0x6be7c0]
/lib64/libpthread.so.0[0x2b01d8348020]
/lib64/libc.so.6(clone+0x6d)[0x2b01d90dff8d]
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x1922af8 = PREPARE stmt FROM @sql
thd->thread_id=1
thd->killed=NOT_KILLED
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
090427 18:27:03 mysqld_safe Number of processes running now: 0
090427 18:27:03 mysqld_safe mysqld restarted
090427 18:27:03 [Warning] Ignoring user change to 'ser=mysql' because the user was set to 'mysql' earlier on the command line

090427 18:27:03  InnoDB: Started; log sequence number 0 1997339047
090427 18:27:03 [Note] Event Scheduler: Loaded 0 events
090427 18:27:03 [Note] /usr/local/mysql/libexec/mysqld: ready for connections.
Version: '5.1.34-debug'  socket: '/tmp/mysql.sock'  port: 3306  Source distribution

How to repeat:
#include "stdio.h"
#include "stdlib.h"
#include "string.h"
#include <my_global.h>
#include <my_sys.h>
#include <mysql.h>

int exit_failure(const char *msg, MYSQL *mysql, MYSQL_RES *res, MYSQL_STMT *stmt);

/* Connection parameter - change */
const char *con_host = "localhost";
const char *con_user = "root";
const char *con_pass = "root";
const char *con_db = "test";
unsigned int con_port = 3306;
const char *con_socket = "/tmp/mysql.sock";
unsigned long con_flags = CLIENT_MULTI_RESULTS;

/* SQL statement */
const char* sql_drop = "DROP PROCEDURE IF EXISTS p";
const char* sql_proc = "CREATE PROCEDURE p(IN val VARCHAR(25)) BEGIN SET @sql = CONCAT('SELECT \"', val, '\"'); PREPARE stmt FROM @sql; EXECUTE stmt; DROP PREPARE stmt; END;";
const char* sql_call = "CALL p('abc')";

int main(void) {
	MYSQL *conn;
	MYSQL_STMT *stmt;

	printf("\n");

	conn = mysql_init(NULL);
	if (conn == NULL)
		exit_failure("mysql_init() failed", NULL, NULL, NULL);

	if (mysql_real_connect(conn, con_host, con_user, con_pass, con_db, con_port, con_socket, con_flags) == NULL)
		exit_failure("mysql_real_connect() failed", conn, NULL, NULL);

	printf("Server: 	%s\n", mysql_get_server_info(conn));
	printf("Protocol: 	%u\n", mysql_get_proto_info(conn));
	printf("Client: 	%s\n\n", mysql_get_client_info());

	if (mysql_real_query(conn, sql_drop, (unsigned long)strlen(sql_drop)))
		exit_failure(sql_drop, conn, NULL, NULL);

	if (mysql_real_query(conn, sql_proc, (unsigned long)strlen(sql_proc)))
		exit_failure(sql_proc, conn, NULL, NULL);

	printf("CALL using stmt_prepare()/stmt_execute...\n");
	stmt = mysql_stmt_init(conn);
	if (mysql_stmt_prepare(stmt, sql_call, (unsigned long)strlen(sql_call)))
		exit_failure("mysql_stmt_prepare() failed", conn, NULL, stmt);

	if (mysql_stmt_execute(stmt))
		exit_failure("mysql_stmt_execute() failed", conn, NULL, stmt);

	mysql_stmt_close(stmt);

	mysql_close(conn);
	printf("\n");

	return EXIT_SUCCESS;
}

int exit_failure(const char *msg, MYSQL *mysql, MYSQL_RES *res, MYSQL_STMT *stmt) {
	printf("ERROR: %s\n", msg);
	if (stmt) {
		printf("[%u] %s\n", mysql_stmt_errno(stmt), mysql_stmt_error(stmt));
		mysql_stmt_close(stmt);
	}
	if (mysql) {
		if (mysql_errno(mysql))
			printf("[%u] %s\n", mysql_errno(mysql), mysql_error(mysql));
		if (res)
			mysql_free_result(res);
		mysql_close(mysql);
	}
	printf("\n");
	exit(EXIT_FAILURE);
}

[27 Apr 2009 16:44] MySQL Verification Team

Thank you for the bug report. Could you please try the latest source server I couldn't repeat on Windows:

c:\build>bugtest.exe

Server:         5.1.35-Win X64 revno: 2853-log
Protocol:       10
Client:         5.1.35

CALL using stmt_prepare()/stmt_execute...

c:\build>

[27 Apr 2009 16:57] MySQL Verification Team

Sorry disregard my last comment I was using a release server.

c:\dbs>c:\dbs\5.1\bin\mysqld-debug --defaults-file=c:\dbs\5.1\my.ini --standalone --console
090427 13:55:25  InnoDB: Started; log sequence number 0 48003
090427 13:55:41 [Note] Event Scheduler: Loaded 0 events
090427 13:55:41 [Note] c:\dbs\5.1\bin\mysqld-debug: ready for connections.
Version: '5.1.35-Win X64 revno: 2853-debug-log'  socket: ''  port: 3510  Source distribution
Assertion failed: thd->protocol == &thd->protocol_text, file .\sql_prepare.cc, line 2233
090427 13:56:27 - mysqld got exception 0x80000003 ;
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=8384512
read_buffer_size=131072
max_used_connections=1
max_threads=151
threads_connected=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 338114 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 0x82aabf8
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
00000001401E11A5    mysqld-debug.exe!my_sigabrt_handler()[mysqld.cc:2013]
0000000140745921    mysqld-debug.exe!raise()[winsig.c:597]
000000014076D743    mysqld-debug.exe!__crtMessageWindowA()[dbgrpt.c:434]
000000014074688C    mysqld-debug.exe!_VCrtDbgReportA()[dbgrptt.c:420]
000000014076D183    mysqld-debug.exe!_CrtDbgReportV()[dbgrpt.c:301]
000000014076D11D    mysqld-debug.exe!_CrtDbgReport()[dbgrpt.c:317]
000000014075BE7B    mysqld-debug.exe!_NMSG_WRITE()[crt0msg.c:197]
0000000140738A97    mysqld-debug.exe!abort()[abort.c:68]
0000000140731434    mysqld-debug.exe!_wassert()[assert.c:212]
00000001403786E2    mysqld-debug.exe!mysql_sql_stmt_prepare()[sql_prepare.cc:2233]
000000014033D915    mysqld-debug.exe!mysql_execute_command()[sql_parse.cc:2209]
000000014027B9E7    mysqld-debug.exe!sp_instr_stmt::exec_core()[sp_head.cc:2904]
000000014027AA7C    mysqld-debug.exe!sp_lex_keeper::reset_lex_and_exec_core()[sp_head.cc:2732]
000000014027AF85    mysqld-debug.exe!sp_instr_stmt::execute()[sp_head.cc:2846]
0000000140275BF7    mysqld-debug.exe!sp_head::execute()[sp_head.cc:1252]
0000000140277E81    mysqld-debug.exe!sp_head::execute_procedure()[sp_head.cc:1981]
00000001403443A6    mysqld-debug.exe!mysql_execute_command()[sql_parse.cc:4323]
0000000140380FAB    mysqld-debug.exe!Prepared_statement::execute()[sql_prepare.cc:3568]
000000014037FF5C    mysqld-debug.exe!Prepared_statement::execute_loop()[sql_prepare.cc:3241]
0000000140379493    mysqld-debug.exe!mysql_stmt_execute()[sql_prepare.cc:2464]
000000014033B0D3    mysqld-debug.exe!dispatch_command()[sql_parse.cc:1172]
000000014033A5F7    mysqld-debug.exe!do_command()[sql_parse.cc:857]
00000001402FE8B6    mysqld-debug.exe!handle_one_connection()[sql_connect.cc:1115]
000000014053CAA5    mysqld-debug.exe!pthread_start()[my_winthread.c:85]
0000000140747935    mysqld-debug.exe!_callthreadstart()[thread.c:295]
0000000140747907    mysqld-debug.exe!_threadstart()[thread.c:277]
0000000076FEC3BD    kernel32.dll!BaseThreadInitThunk()
0000000077134581    ntdll.dll!RtlUserThreadStart()
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 000000000833E268=PREPARE stmt FROM @sql
thd->thread_id=1
thd->killed=NOT_KILLED
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.

[4 May 2009 8:58] Konstantin Osipov

This is fixed in 6.0.

[15 Jul 2009 17:03] Konstantin Osipov

Davi, please use the committed patch, but add a test case.

[15 Jul 2009 17:18] Bugs System

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/78756

3017 Konstantin Osipov	2009-07-15
      A fix for Bug#44495 "Prepared Statement: CALL p(<x>) - `thd->protocol == &thd->protocol_text' 
      failed"
      
      Do not assume that SQL prepared statements always run in text protocol.
      When invoked from a stored procedure, which is itself invoked
      by means of prepared CALL statement, the protocol may be binary.
      Juggle with the protocol only when we want to change it
      to binary in COM_STMT_EXECUTE, COM_STMT_PREPARE.
      
      This is a backport from 5.4/6.0, where the bug was fixed
      as part of WL#4264 "Backup: Stabilize Service Interface"

[15 Jul 2009 18:27] Davi Arnaut

Queued to 5.1-bugteam

[15 Jul 2009 18:28] Bugs System

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/78772

3028 Davi Arnaut	2009-07-15 [merge]
      Bug#44495: Prepared Statement: CALL p(<x>) - `thd->protocol == &thd->protocol_text' failed
      
      Merge Konstantin's patch and add a test case.
     @ tests/mysql_client_test.c
        Add test case for Bug#44495

[3 Aug 2009 17:26] Konstantin Osipov

Bug#38206 was marked a duplicate of this bug.

[4 Aug 2009 19:52] Bugs System

Pushed into 5.4.4-alpha (revid:[e-mail]-20090804194615-h40sa098mx4z49qg) (version source revid:[e-mail]-20090715183127-sdsodoe5w8jvtijt) (merge vers: 5.4.4-alpha) (pib:11)

[4 Aug 2009 20:45] Bugs System

Pushed into 5.1.38 (revid:[e-mail]-20090804204317-ggodqkik7de6nfpz) (version source revid:[e-mail]-20090804204317-ggodqkik7de6nfpz) (merge vers: 5.1.38) (pib:11)

[1 Sep 2009 18:21] Paul DuBois

Noted in 5.1.38, 5.4.4 changelogs.

Using mysql_stmt_execute() to call a stored procedure could cause a
server crash.

[1 Oct 2009 5:58] Bugs System

Pushed into 5.1.39-ndb-6.3.28 (revid:[e-mail]-20091001055605-ap2kiaarr7p40mmv) (version source revid:[e-mail]-20091001055605-ap2kiaarr7p40mmv) (merge vers: 5.1.39-ndb-6.3.28) (pib:11)

[1 Oct 2009 7:25] Bugs System

Pushed into 5.1.39-ndb-7.0.9 (revid:[e-mail]-20091001072547-kv17uu06hfjhgjay) (version source revid:[e-mail]-20091001071652-irejtnumzbpsbgk2) (merge vers: 5.1.39-ndb-7.0.9) (pib:11)

[1 Oct 2009 13:25] Bugs System

Pushed into 5.1.39-ndb-7.1.0 (revid:[e-mail]-20091001123013-g9ob2tsyctpw6zs0) (version source revid:[e-mail]-20091001123013-g9ob2tsyctpw6zs0) (merge vers: 5.1.39-ndb-7.1.0) (pib:11)

[5 Oct 2009 10:50] Bugs System

Pushed into 5.1.39-ndb-6.2.19 (revid:[e-mail]-20091005103850-dwij2dojwpvf5hi6) (version source revid:[e-mail]-20090930185117-bhud4ek1y0hsj1nv) (merge vers: 5.1.39-ndb-6.2.19) (pib:11)

[7 Oct 2009 20:24] Paul DuBois

The 5.4 fix has been pushed to 5.4.2.

[13 Oct 2009 18:30] Bugs System

Pushed into 5.1.41 (revid:[e-mail]-20091013182142-vgsjky3t1v4btufv) (version source revid:[e-mail]-20091013182142-vgsjky3t1v4btufv) (merge vers: 5.1.41) (pib:13)

[13 Oct 2009 23:29] Paul DuBois

Already fixed in 5.1.38.

[22 Oct 2009 6:36] Bugs System

Pushed into 6.0.14-alpha (revid:[e-mail]-20091022063126-l0qzirh9xyhp0bpc) (version source revid:[e-mail]-20091019135554-s1pvptt6i750lfhv) (merge vers: 6.0.14-alpha) (pib:13)

[22 Oct 2009 7:08] Bugs System

Pushed into 5.5.0-beta (revid:[e-mail]-20091022060553-znkmxm0g0gm6ckvw) (version source revid:[e-mail]-20091019131937-nchb8tjk88jpfjav) (merge vers: 5.5.0-beta) (pib:13)

[22 Oct 2009 19:15] Paul DuBois

Noted in 5.5.0, 6.0.14 changelogs.

[18 Dec 2009 10:36] Bugs System

Pushed into 5.1.41-ndb-7.1.0 (revid:[e-mail]-20091218102229-64tk47xonu3dv6r6) (version source revid:[e-mail]-20091218095730-26gwjidfsdw45dto) (merge vers: 5.1.41-ndb-7.1.0) (pib:15)

[18 Dec 2009 10:52] Bugs System

Pushed into 5.1.41-ndb-6.2.19 (revid:[e-mail]-20091218100224-vtzr0fahhsuhjsmt) (version source revid:[e-mail]-20091217101452-qwzyaig50w74xmye) (merge vers: 5.1.41-ndb-6.2.19) (pib:15)

[18 Dec 2009 11:07] Bugs System

Pushed into 5.1.41-ndb-6.3.31 (revid:[e-mail]-20091218100616-75d9tek96o6ob6k0) (version source revid:[e-mail]-20091217154335-290no45qdins5bwo) (merge vers: 5.1.41-ndb-6.3.31) (pib:15)

[18 Dec 2009 11:21] Bugs System

Pushed into 5.1.41-ndb-7.0.11 (revid:[e-mail]-20091218101303-ga32mrnr15jsa606) (version source revid:[e-mail]-20091218064304-ezreonykd9f4kelk) (merge vers: 5.1.41-ndb-7.0.11) (pib:15)

[18 Dec 2009 13:13] MC Brown

Already documented in 5.1.41