Percona Server moved to https://jira.percona.com/projects/PS

Prepared statements in stored procedures crash query response time plugin

Series 5.6
Bug #1426345

Bug #1426345 reported by Chandu on 2015-02-27

This bug affects 6 people

	Status	Importance	Assigned to	Milestone
Percona Server moved to https://jira.percona.com/projects/PS	Fix Released	High	Vlad Lesin	Percona Server moved to https://jira.percona.com/projects/PS 5.6.26-74.0
5.5	Invalid	Undecided	Unassigned
5.6	Fix Released	High	Vlad Lesin	Percona Server moved to https://jira.percona.com/projects/PS 5.6.26-74.0

Bug Description

The procedure we have has been working fine since mysql 5.0. What it does simply is gather the table names from a schema (lets say Schema A) and drop the view if they exists and re-create them again in another schema (Schema A_stats) .

when call it crashes with mysqld 11 signal.

Env : Rhel 5.11

uname -a
Linux 2.6.18-400.1.1.el5 #1 SMP Sun Dec 14 06:01:17 EST 2014 x86_64 x86_64 x86_64 GNU/Linux
:~ > cat /etc/redhat-release
Red Hat Enterprise Linux Server release 5.11 (Tikanga)
mysql : Percona-Server-5.6.22-rel72.0-738.Linux.x86_64

Crash log:

14:10:12 UTC - 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.
Please help us make Percona Server better by reporting any
bugs at http://bugs.percona.com/

key_buffer_size=209715200
read_buffer_size=4194304
max_used_connections=49
max_threads=252
thread_count=49
connection_count=49
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 2272884 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

hread pointer: 0x2b25743b6d90
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 = 2b2573932080 thread_stack 0x40000
/home/m_game_s1/mysql/bin/mysqld(my_print_stacktrace+0x2c)[0x8f0d5c]
/home/m_game_s1/mysql/bin/mysqld(handle_fatal_signal+0x461)[0x67a7d1]
/lib64/libpthread.so.0[0x382a40eca0]
/home/mysql/lib/mysql/plugin/query_response_time.so[0x2b2555f98b22]
/home/mysql/bin/mysqld[0x6aa205]
/home/mysql/bin/mysqld(_Z18mysql_audit_notifyP3THDjjz+0xa8)[0x6aa3d8]
/home/mysql/bin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x9c8)[0x7021d8]
/home/mysql/bin/mysqld(_Z24do_handle_one_connectionP3THD+0x162)[0x6d0172]
/home/mysql/bin/mysqld(handle_one_connection+0x40)[0x6d0260]
/lib64/libpthread.so.0[0x382a40683d]
/lib64/libc.so.6(clone+0x6d)[0x3829cd4fcd]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (2b425854dba0): drop view if exists hh_s1_stats.access_status_groups_last
Connection ID (thread ID): 53
Status: NOT_KILLED

You may download the Percona Server operations manual by visiting
http://www.percona.com/software/percona-server/. You may find information
in the manual which will help you identify the cause of the crash.
Writing a core file
150226 15:10:12 mysqld_safe Number of processes running now: 0
150226 15:10:12 mysqld_safe mysqld restarted
2015-02-26 15:10:12 0 [Warning] Using unique option prefix thread-cache instead of thread_cache_size is deprecated and will be removed in a future release. Please use the full name instead.
2015-02-26 15:10:12 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2015-02-26 15:10:12 2332 [Warning] One can only use the --user switch if running as root

2015-02-26 15:10:13 2332 [Warning] Using unique option prefix innodb-additional-mem-pool instead of innodb-additional-mem-pool-size is deprecated and will be removed in a future release. Please use the full name instead.
2015-02-26 15:10:13 2332 [Note] Plugin 'FEDERATED' is disabled.
2015-02-26 15:10:13 2b2b6b4f6d00 InnoDB: Warning: Using innodb_additional_mem_pool_size is DEPRECATED. This option may be removed in future releases, together with the option innodb_use_sys_malloc and with the InnoDB's internal memory allocator.
2015-02-26 15:10:13 2332 [Note] InnoDB: Using atomics to ref count buffer pool pages
2015-02-26 15:10:13 2332 [Note] InnoDB: The InnoDB memory heap is disabled
2015-02-26 15:10:13 2332 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2015-02-26 15:10:13 2332 [Note] InnoDB: Memory barrier is not used
2015-02-26 15:10:13 2332 [Note] InnoDB: Compressed tables use zlib 1.2.3
2015-02-26 15:10:13 2332 [Note] InnoDB: Using Linux native AIO
2015-02-26 15:10:13 2332 [Note] InnoDB: Not using CPU crc32 instructions
2015-02-26 15:10:13 2332 [Note] InnoDB: Initializing buffer pool, size = 200.0M
2015-02-26 15:10:13 2332 [Note] InnoDB: Completed initialization of buffer pool
2015-02-26 15:10:13 2332 [Note] InnoDB: Highest supported file format is Barracuda.
2015-02-26 15:10:13 2332 [Note] InnoDB: The log sequence numbers 10061582051 and 10061582051 in ibdata files do not match the log sequence number 10084984124 in the ib_logfiles!
2015-02-26 15:10:13 2332 [Note] InnoDB: Database was not shutdown normally!
2015-02-26 15:10:13 2332 [Note] InnoDB: Starting crash recovery.
2015-02-26 15:10:13 2332 [Note] InnoDB: Reading tablespace information from the .ibd files...
2015-02-26 15:10:13 2332 [Note] InnoDB: Restoring possible half-written data pages
2015-02-26 15:10:13 2332 [Note] InnoDB: from the doublewrite buffer...
InnoDB: Last MySQL binlog file position 0 54282, file name logbin.000027
2015-02-26 15:10:14 2332 [Note] InnoDB: 128 rollback segment(s) are active.
2015-02-26 15:10:14 2332 [Note] InnoDB: Waiting for purge to start
2015-02-26 15:10:14 2332 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.22-rel72.0 started; log sequence number 10084984124
2015-02-26 15:10:14 2332 [Note] Recovering after a crash using /home/mysql/data/logbin/logbin
2015-02-26 15:10:14 2332 [Note] Starting crash recovery...
2015-02-26 15:10:14 2332 [Note] Crash recovery finished.
2015-02-26 15:10:14 2332 [Note] RSA private key file not found: /home/mysql/data/dbs//private_key.pem. Some authentication plugins will not work.
2015-02-26 15:10:14 2332 [Note] RSA public key file not found: /home/mysql/data/dbs//public_key.pem. Some authentication plugins will not work.
2015-02-26 15:10:14 2332 [Note] Server hostname (bind-address): '*'; port: 3305
2015-02-26 15:10:14 2332 [Note] IPv6 is available.
2015-02-26 15:10:14 2332 [Note] - '::' resolves to '::';
2015-02-26 15:10:14 2332 [Note] Server socket created on IP: '::'.
2015-02-26 15:10:14 2332 [Note] Event Scheduler: Loaded 0 events
2015-02-26 15:10:14 2332 [Note] /home/mysql/bin/mysqld: ready for connections.
Version: '5.6.22-72.0-log' socket: '/home/mysql/data/run/mysqld.sock' port: 3305 Percona Server (GPL), Release 72.0, Revision 738

How to reproduce

Create 2 databases

CREATE DATABASE `sample` /*!40100 DEFAULT CHARACTER SET utf8 */
-- create some tables

CREATE DATABASE `sample_stats` /*!40100 DEFAULT CHARACTER SET utf8 */
empty database where we will create the view

use sample;

delimiter //
CREATE DEFINER=`root`@`localhost` PROCEDURE `recreate_views_for_stats`()
begin
  declare PROCEDURE_VERSION_INFO varchar(200);
  declare p_done int;
  declare p_table_name varchar(64);
  declare p_stats_schema varchar(64);
  declare p_cnt int;
  declare p_cnt_view int;
  declare p_stmt varchar(400);

declare view_cursor cursor for select table_name from information_schema.tables v1 where v1.table_schema=concat(database(),'_stats') and v1.table_type='VIEW';
declare table_cursor cursor for select table_name from information_schema.tables v1 where v1.table_schema=database();

declare continue handler for SQLSTATE '02000' begin set p_done = 1; end;

set PROCEDURE_VERSION_INFO = 'v 1.11 ';

select PROCEDURE_VERSION_INFO;

  set p_done = 0;
  set p_cnt_view = 0;
  set p_stats_schema = concat(database(),'_stats');
  open view_cursor;
  repeat
    fetch view_cursor into p_table_name;
    if not p_done then
      set @sql = concat('drop view if exists ',p_stats_schema,'.',p_table_name);
      prepare p_stmt from @sql;
      execute p_stmt;
      deallocate prepare p_stmt;
      set p_cnt_view = p_cnt_view + 1;

end if;
until p_done end repeat;

  set p_done = 0;
  set p_cnt = 0;
  open table_cursor;
  repeat
    fetch table_cursor into p_table_name;
    if not p_done then
      set @sql = concat('create view ',p_stats_schema,'.',p_table_name,' as select * from ',p_table_name);
      prepare p_stmt from @sql;
      execute p_stmt;
      deallocate prepare p_stmt;
      set p_cnt = p_cnt + 1;
    end if;
  until p_done end repeat;

select p_cnt_view as views_dropped, p_cnt as views_created, count(*) as views_total from information_schema.views where table_schema=p_stats_schema;
end
//

delimiter ;

use sample;
call recreate_views_for_stats();

The above call should create views in the sample_stats for all the tables in the schema sample.
may be not the first time as it might not have any views to drop . run it first might create views and on the second run it will crash.

Something has changed in the Percona-Server-5.6.22-rel72.0-738.Linux.x86_64
The same works properly when i downgraded to Percona-Server-5.6.22-rel71.0-726.Linux.x86_64 and Percona-Server-5.6.21-rel69.0-675.Linux.x86_64

See original description

Tags:

Chandu (chandusingh-dba) on 2015-02-27

information type:	Public → Private Security
information type:	Private Security → Public
description:	updated

Revision history for this message

Nilnandan Joshi (nilnandan-joshi) wrote on 2015-03-12:

Download full text (5.3 KiB)

Hi,

Couldn't verify your test case with Server version: 5.6.22-72.0-log Percona Server (GPL), Release 72.0, Revision 738
I also tried to verify with 5.6.23 and same, no error. Can you please try to check with latest PS 5.6.23?

nilnandan@desktop:~/sandboxes/rsandbox_Percona-Server-5_6_22/master$ mysql -uroot -p --socket=/tmp/mysql_sandbox21087.sock
Enter password:
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 1
Server version: 5.6.22-72.0-log Percona Server (GPL), Release 72.0, Revision 738

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> CREATE DATABASE `sample` /*!40100 DEFAULT CHARACTER SET utf8 */;
Query OK, 1 row affected (0.02 sec)

mysql> use sample
Database changed
mysql>
mysql> create table t1 (id int, name varchar(10));
Query OK, 0 rows affected (0.15 sec)

mysql> create table t2 (id int, name varchar(10), city varchar(10));
Query OK, 0 rows affected (0.04 sec)

mysql> create table t3 (id int, phone int, email varchar(25));
Query OK, 0 rows affected (0.02 sec)

mysql>
mysql> CREATE DATABASE `sample_stats` /*!40100 DEFAULT CHARACTER SET utf8 */;
Query OK, 1 row affected (0.00 sec)

Hi,

nilnandan@desktop:~/sandboxes/rsandbox_Percona-Server-5_6_22/master$ mysql -uroot -p --socket=/tmp/mysql_sandbox21087.sock
Enter password: 
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1
Server version: 5.6.22-72.0-log Percona Server (GPL), Release 72.0, Revision 738

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> CREATE DATABASE `sample` /*!40100 DEFAULT CHARACTER SET utf8 */;
Query OK, 1 row affected (0.02 sec)

mysql> use sample
Database changed
mysql> 
mysql> create table t1 (id int, name varchar(10));
Query OK, 0 rows affected (0.15 sec)

mysql> create table t2 (id int, name varchar(10), city varchar(10));
Query OK, 0 rows affected (0.04 sec)

mysql> create table t3 (id int, phone int, email varchar(25));
Query OK, 0 rows affected (0.02 sec)

mysql> 
mysql> CREATE DATABASE `sample_stats` /*!40100 DEFAULT CHARACTER SET utf8 */;
Query OK, 1 row affected (0.00 sec)

mysql> 
mysql> use sample
Database changed
mysql> delimiter //
mysql> 
mysql> CREATE DEFINER=`root`@`localhost` PROCEDURE `recreate_views_for_stats`()
    -> begin
    ->   declare PROCEDURE_VERSION_INFO varchar(200);
    ->   declare p_done int;
    ->   declare p_table_name varchar(64);
    ->   declare p_stats_schema varchar(64);
    ->   declare p_cnt int;
    ->   declare p_cnt_view int;
    ->   declare p_stmt varchar(400);
    -> 
    ->   declare view_cursor cursor for select table_name from information_schema.tables v1 where v1.table_schema=concat(database(),'_stats') and v1.table_type='VIEW';
    ->   declare table_cursor cursor for select table_name from information_schema.tables v1 where v1.table_schema=database();
    -> 
    ->   declare continue handler for SQLSTATE '02000' begin set p_done = 1; end;
    -> 
    ->   set PROCEDURE_VERSION_INFO = 'v 1.11 ';
    -> 
    ->   select PROCEDURE_VERSION_INFO;
    -> 
    ->   set p_done = 0;
    ->   set p_cnt_view = 0;
    ->   set p_stats_schema = concat(database(),'_stats');
    ->   open view_cursor;
    ->   repeat
    ->     fetch view_cursor into p_table_name;
    ->     if not p_done then
    ->       set @sql = concat('drop view if exists ',p_stats_schema,'.',p_table_name);
    ->       prepare p_stmt from @sql;
    ->       execute p_stmt;
    ->       deallocate prepare p_stmt;
    ->       set p_cnt_view = p_cnt_view + 1;
    -> 
    ->     end if;
    ->   until p_done end repeat;
    -> 
    ->   set p_done = 0;
    ->   set p_cnt = 0;
    ->   open table_cursor;
    ->   repeat
    ->     fetch table_cursor into p_table_name;
    ->     if not p_done then
    ->       set @sql = concat('create view ',p_stats_schema,'.',p_table_name,' as select * from ',p_table_name);
    ->       prepare p_stmt from @sql;
    ->       execute p_stmt;
    ->       deallocate prepare p_stmt;
    ->       set p_cnt = p_cnt + 1;
    ->     end if;
    ->   until p_done end repeat;
    -> 
    ->   select p_cnt_view as views_dropped, p_cnt as views_created, count(*) as views_total from information_schema.views where table_schema=p_stats_schema;
    -> end //
Query OK, 0 rows affected (0.14 sec)

mysql> delimiter ;
mysql> 
mysql> call recreate_views_for_stats();
+------------------------+
| PROCEDURE_VERSION_INFO |
+------------------------+
| v 1.11                 |
+------------------------+
1 row in set (0.01 sec)

+---------------+---------------+-------------+
| views_dropped | views_created | views_total |
+---------------+---------------+-------------+
|             0 |             3 |           3 |
+---------------+---------------+-------------+
1 row in set (0.13 sec)

Query OK, 0 rows affected (0.13 sec)

mysql> 
mysql> call recreate_views_for_stats();
+------------------------+
| PROCEDURE_VERSION_INFO |
+------------------------+
| v 1.11                 |
+------------------------+
1 row in set (0.00 sec)

+---------------+---------------+-------------+
| views_dropped | views_created | views_total |
+---------------+---------------+-------------+
|             3 |             3 |           3 |
+---------------+---------------+-------------+
1 row in set (0.03 sec)

Query OK, 0 rows affected (0.03 sec)

mysql> call recreate_views_for_stats();
+------------------------+
| PROCEDURE_VERSION_INFO |
+------------------------+
| v 1.11                 |
+------------------------+
1 row in set (0.00 sec)

Query OK, 0 rows affected (0.02 sec)

mysql>

Changed in percona-server:
status:	New → Incomplete

Revision history for this message

Chandu (chandusingh-dba) wrote on 2015-03-12:

Thats seems bit strange , we had this issues and even trying to see if there is something changed or wrong with procedure and did some debuging with the procedure, and then thought this might be issue with the DROP VIEW calling from porcedure, cause the DROP VIEW command works perfectly fine if you do it from mysql client.
so that's why we have downgraded this to Percona-Server-5.6.22-rel71.0-726.Linux.x86_64.

One more thing is this RPM installation or TAR we have the Linux Generic TAR downloaded from

http://www.percona.com/downloads/Percona-Server-5.6/Percona-Server-5.6.22-71.0/binary/tarball/Percona-Server-5.6.22-rel71.0-726.Linux.x86_64.tar.gz.

I will test this with 5.6.23 and update .

Thanks.

Br
Chandu

Revision history for this message

Chandu (chandusingh-dba) wrote on 2015-03-12:

Quickly test it with Percona-Server-5.6.23-rel72.1-Linux.x86_64 on Linux Red Hat Enterprise Linux Server release 5.11 (Tikanga) Kernel 2.6.18-400.1.1.el5 with Percona Linux Generic Tar.

We still have hit with this error and got restarted. And it has written a core or 700 Mb , if you would like to investiage more then i can upload it secure ftp place , as well as the mysql error.log.

Thanks

Chandu

Revision history for this message

Nilnandan Joshi (nilnandan-joshi) wrote on 2015-03-12:

Download full text (6.5 KiB)

Hi,

I downloaded from below link as you suggested and try to reproduce on CentOS 5.9 but again no error. It seems, it has something related to your environment/configurations. From the stacktrace, I can see this.

/home/mysql/lib/mysql/plugin/query_response_time.so[0x2b2555f98b22]

Are you using any plugin? can you provide your my.cnf ?

[root@localhost ~]# uname -a
Linux localhost.localdomain 2.6.18-348.el5 #1 SMP Tue Jan 8 17:53:53 EST 2013 x86_64 x86_64 x86_64 GNU/Linux
[root@localhost ~]#

[root@localhost ~]# lsb_release -a
LSB Version: :core-4.0-amd64:core-4.0-ia32:core-4.0-noarch:graphics-4.0-amd64:graphics-4.0-ia32:graphics-4.0-noarch:printing-4.0-amd64:printing-4.0-ia32:printing-4.0-noarch
Distributor ID: CentOS
Description: CentOS release 5.9 (Final)
Release: 5.9
Codename: Final
[root@localhost ~]#

[root@localhost ~]# ll Percona-Server-5.6.22-rel71.0-726.Linux.x86_64.tar.gz
-rw-r--r-- 1 root root 109151984 Jan 10 00:56 Percona-Server-5.6.22-rel71.0-726.Linux.x86_64.tar.gz
[root@localhost ~]#

[root@localhost ~]# mysql -uroot -p --socket=/tmp/mysql_sandbox5622.sock
Enter password:
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 3
Server version: 5.6.22-71.0 Percona Server (GPL), Release 71.0, Revision 726

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> CREATE DATABASE `sample` /*!40100 DEFAULT CHARACTER SET utf8 */;
Query OK, 1 row affected (0.00 sec)

mysql> use sample
Database changed
mysql>
mysql> create table t1 (id int, name varchar(10));
Query OK, 0 rows affected (0.00 sec)

mysql> create table t2 (id int, name varchar(10), city varchar(10));
Query OK, 0 rows affected (0.01 sec)

mysql> create table t3 (id int, phone int, email varchar(25));
Query OK, 0 rows affected (0.01 sec)

mysql> CREATE DATABASE `sample_stats` /*!40100 DEFAULT CHARACTER SET utf8 */;
Query OK, 1 row affected (0.00 sec)

Hi,

I downloaded from below link as you suggested and try to reproduce on CentOS 5.9 but again no error.  It seems, it has something related to your environment/configurations. From the stacktrace, I can see this.

/home/mysql/lib/mysql/plugin/query_response_time.so[0x2b2555f98b22]

Are you using any plugin? can you provide your my.cnf ?

[root@localhost ~]# uname -a
Linux localhost.localdomain 2.6.18-348.el5 #1 SMP Tue Jan 8 17:53:53 EST 2013 x86_64 x86_64 x86_64 GNU/Linux
[root@localhost ~]#

[root@localhost ~]# lsb_release -a
LSB Version:	:core-4.0-amd64:core-4.0-ia32:core-4.0-noarch:graphics-4.0-amd64:graphics-4.0-ia32:graphics-4.0-noarch:printing-4.0-amd64:printing-4.0-ia32:printing-4.0-noarch
Distributor ID:	CentOS
Description:	CentOS release 5.9 (Final)
Release:	5.9
Codename:	Final
[root@localhost ~]#

[root@localhost ~]# ll Percona-Server-5.6.22-rel71.0-726.Linux.x86_64.tar.gz 
-rw-r--r-- 1 root root 109151984 Jan 10 00:56 Percona-Server-5.6.22-rel71.0-726.Linux.x86_64.tar.gz
[root@localhost ~]#

[root@localhost ~]# mysql -uroot -p --socket=/tmp/mysql_sandbox5622.sock
Enter password: 
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 3
Server version: 5.6.22-71.0 Percona Server (GPL), Release 71.0, Revision 726

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> CREATE DATABASE `sample` /*!40100 DEFAULT CHARACTER SET utf8 */;
Query OK, 1 row affected (0.00 sec)

mysql> use sample
Database changed
mysql> 
mysql>  create table t1 (id int, name varchar(10));
Query OK, 0 rows affected (0.00 sec)

mysql> create table t2 (id int, name varchar(10), city varchar(10));
Query OK, 0 rows affected (0.01 sec)

mysql> create table t3 (id int, phone int, email varchar(25));
Query OK, 0 rows affected (0.01 sec)

mysql> CREATE DATABASE `sample_stats` /*!40100 DEFAULT CHARACTER SET utf8 */;
Query OK, 1 row affected (0.00 sec)

mysql> use sample
Database changed
mysql> 
mysql> delimiter //
mysql> 
mysql> CREATE DEFINER=`root`@`localhost` PROCEDURE `recreate_views_for_stats`()
    -> begin
    ->   declare PROCEDURE_VERSION_INFO varchar(200);
    ->   declare p_done int;
    ->   declare p_table_name varchar(64);
    ->   declare p_stats_schema varchar(64);
    ->   declare p_cnt int;
    ->   declare p_cnt_view int;
    ->   declare p_stmt varchar(400);
    -> 
    ->   declare view_cursor cursor for select table_name from information_schema.tables v1 where v1.table_schema=concat(database(),'_stats') and v1.table_type='VIEW';
    ->   declare table_cursor cursor for select table_name from information_schema.tables v1 where v1.table_schema=database();
    -> 
    ->   declare continue handler for SQLSTATE '02000' begin set p_done = 1; end;
    -> 
    ->   set PROCEDURE_VERSION_INFO = 'v 1.11 ';
    -> 
    ->   select PROCEDURE_VERSION_INFO;
    -> 
    ->   set p_done = 0;
    ->   set p_cnt_view = 0;
    ->   set p_stats_schema = concat(database(),'_stats');
    ->   open view_cursor;
    ->   repeat
    ->     fetch view_cursor into p_table_name;
    ->     if not p_done then
    ->       set @sql = concat('drop view if exists ',p_stats_schema,'.',p_table_name);
    ->       prepare p_stmt from @sql;
    ->       execute p_stmt;
    ->       deallocate prepare p_stmt;
    ->       set p_cnt_view = p_cnt_view + 1;
    -> 
    ->     end if;
    ->   until p_done end repeat;
    -> 
    ->   set p_done = 0;
    ->   set p_cnt = 0;
    ->   open table_cursor;
    ->   repeat
    ->     fetch table_cursor into p_table_name;
    ->     if not p_done then
    ->       set @sql = concat('create view ',p_stats_schema,'.',p_table_name,' as select * from ',p_table_name);
    ->       prepare p_stmt from @sql;
    ->       execute p_stmt;
    ->       deallocate prepare p_stmt;
    ->       set p_cnt = p_cnt + 1;
    ->     end if;
    ->   until p_done end repeat;
    -> 
    ->   select p_cnt_view as views_dropped, p_cnt as views_created, count(*) as views_total from information_schema.views where table_schema=p_stats_schema;
    -> end
    -> //
Query OK, 0 rows affected (0.00 sec)

mysql> delimiter ;
mysql> 
mysql> call recreate_views_for_stats();
+------------------------+
| PROCEDURE_VERSION_INFO |
+------------------------+
| v 1.11                 | 
+------------------------+
1 row in set (0.00 sec)

+---------------+---------------+-------------+
| views_dropped | views_created | views_total |
+---------------+---------------+-------------+
|             0 |             3 |           3 | 
+---------------+---------------+-------------+
1 row in set (0.01 sec)

Query OK, 0 rows affected (0.01 sec)

mysql> 
mysql> 
mysql> call recreate_views_for_stats();
+------------------------+
| PROCEDURE_VERSION_INFO |
+------------------------+
| v 1.11                 | 
+------------------------+
1 row in set (0.00 sec)

+---------------+---------------+-------------+
| views_dropped | views_created | views_total |
+---------------+---------------+-------------+
|             3 |             3 |           3 | 
+---------------+---------------+-------------+
1 row in set (0.00 sec)

Query OK, 0 rows affected (0.00 sec)

mysql> call recreate_views_for_stats();
+------------------------+
| PROCEDURE_VERSION_INFO |
+------------------------+
| v 1.11                 | 
+------------------------+
1 row in set (0.00 sec)

+---------------+---------------+-------------+
| views_dropped | views_created | views_total |
+---------------+---------------+-------------+
|             3 |             3 |           3 | 
+---------------+---------------+-------------+
1 row in set (0.00 sec)

Query OK, 0 rows affected (0.00 sec)

mysql> call recreate_views_for_stats();
+------------------------+
| PROCEDURE_VERSION_INFO |
+------------------------+
| v 1.11                 | 
+------------------------+
1 row in set (0.00 sec)

+---------------+---------------+-------------+
| views_dropped | views_created | views_total |
+---------------+---------------+-------------+
|             3 |             3 |           3 | 
+---------------+---------------+-------------+
1 row in set (0.00 sec)

Query OK, 0 rows affected (0.01 sec)

mysql> quit
Bye
[root@localhost ~]#

Revision history for this message

Chandu (chandusingh-dba) wrote on 2015-03-12:

my.cnf Edit (2.4 KiB, text/plain)

Yes we are using and installed 2 plugins QUERY_RESPONSE_TIME and QUERY_RESPONSE_TIME_AUDIT
for query_response_time_stats as suggested here http://www.percona.com/doc/percona-server/5.6/diagnostics/response_time_distribution.html

Its bit still didn't get why its failing on this server.

Revision history for this message

Chandu (chandusingh-dba) wrote on 2015-03-12:

We didn't manage to get this working in both of this releases
Percona-Server-5.6.23-rel72.1-Linux.x86_64
Percona-Server-5.6.22-rel72.0-738.Linux.x86_64

but the same works fine pretty good on in the same env with Percona-Server-5.6.22-rel71.0-726.Linux.x86_64

Br
Chandu

Revision history for this message

Jericho Rivera (jericho-rivera) wrote on 2015-03-13:

Download full text (6.4 KiB)

Crash is easy to reproduce when query_response_time_stats = ON

Server version: 5.6.23-72.1 Percona Server (GPL), Release 72.1, Revision 0503478

Test run with query_response_time_stats = OFF
mysql> select @@global.query_response_time_stats;
+------------------------------------+
| @@global.query_response_time_stats |
+------------------------------------+
| 0 |
+------------------------------------+
1 row in set (0.00 sec)

mysql> use sample;
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed
mysql> call recreate_views_for_stats();
+------------------------+
| PROCEDURE_VERSION_INFO |
+------------------------+
| v 1.11 |
+------------------------+
1 row in set (0.01 sec)

+---------------+---------------+-------------+
| views_dropped | views_created | views_total |
+---------------+---------------+-------------+
| 2 | 3 | 3 |
+---------------+---------------+-------------+
1 row in set (0.01 sec)

Query OK, 0 rows affected (0.01 sec)

mysql> call recreate_views_for_stats();
+------------------------+
| PROCEDURE_VERSION_INFO |
+------------------------+
| v 1.11 |
+------------------------+
1 row in set (0.00 sec)

+---------------+---------------+-------------+
| views_dropped | views_created | views_total |
+---------------+---------------+-------------+
| 3 | 3 | 3 |
+---------------+---------------+-------------+
1 row in set (0.01 sec)

Query OK, 0 rows affected (0.01 sec)

Then turned ON

mysql> set @@global.query_response_time_stats=ON;
Query OK, 0 rows affected (0.00 sec)

mysql> call recreate_views_for_stats();
+------------------------+
| PROCEDURE_VERSION_INFO |
+------------------------+
| v 1.11 |
+------------------------+
1 row in set (0.00 sec)

ERROR 2013 (HY000): Lost connection to MySQL server during query
mysql> 150312 19:25:38 mysqld_safe Number of processes running now: 0
150312 19:25:38 mysqld_safe mysqld restarted

mysql> exit
Bye

12:00:41 UTC - 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.
Please help us make Percona Server better by reporting any
bugs at http://bugs.percona.com/

key_buffer_size=8388608
read_buffe...

Crash is easy to reproduce when query_response_time_stats = ON

Server version: 5.6.23-72.1 Percona Server (GPL), Release 72.1, Revision 0503478

Test run with query_response_time_stats = OFF
mysql> select @@global.query_response_time_stats;
+------------------------------------+
| @@global.query_response_time_stats |
+------------------------------------+
|                                  0 |
+------------------------------------+
1 row in set (0.00 sec)

mysql> use sample;
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed
mysql> call recreate_views_for_stats();
+------------------------+
| PROCEDURE_VERSION_INFO |
+------------------------+
| v 1.11                 |
+------------------------+
1 row in set (0.01 sec)

+---------------+---------------+-------------+
| views_dropped | views_created | views_total |
+---------------+---------------+-------------+
|             2 |             3 |           3 |
+---------------+---------------+-------------+
1 row in set (0.01 sec)

Query OK, 0 rows affected (0.01 sec)

mysql> call recreate_views_for_stats();
+------------------------+
| PROCEDURE_VERSION_INFO |
+------------------------+
| v 1.11                 |
+------------------------+
1 row in set (0.00 sec)

Query OK, 0 rows affected (0.01 sec)

Then turned ON

mysql> set @@global.query_response_time_stats=ON;
Query OK, 0 rows affected (0.00 sec)

mysql> call recreate_views_for_stats();
+------------------------+
| PROCEDURE_VERSION_INFO |
+------------------------+
| v 1.11                 |
+------------------------+
1 row in set (0.00 sec)

ERROR 2013 (HY000): Lost connection to MySQL server during query
mysql> 150312 19:25:38 mysqld_safe Number of processes running now: 0
150312 19:25:38 mysqld_safe mysqld restarted

mysql> exit
Bye

12:00:41 UTC - 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.
Please help us make Percona Server better by reporting any
bugs at http://bugs.percona.com/

key_buffer_size=8388608
read_buffer_size=131072
max_used_connections=1
max_threads=153
thread_count=1
connection_count=1
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 69184 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x29ef2a0
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 = 7f343b01f050 thread_stack 0x40000
/usr/local/mysql/bin/mysqld(my_print_stacktrace+0x2c)[0x8f0d5c]
/usr/local/mysql/bin/mysqld(handle_fatal_signal+0x461)[0x67a7d1]
/lib64/libpthread.so.0[0x7f3466cd5ca0]
/usr/local/mysql/bin/mysqld[0xb8f618]
/usr/local/mysql/bin/mysqld(my_hash_first_from_hash_value+0xdd)[0x8d39bd]
/usr/local/mysql/bin/mysqld(my_hash_search+0x11)[0x8d3b01]
/usr/local/mysql/lib/mysql/plugin/query_response_time.so[0x7f343adddb22]
/usr/local/mysql/bin/mysqld[0x6aa205]
/usr/local/mysql/bin/mysqld(_Z18mysql_audit_notifyP3THDjjz+0xa8)[0x6aa3d8]
/usr/local/mysql/bin/mysqld[0x828524]
/usr/local/mysql/bin/mysqld(_ZN13sp_instr_stmt7executeEP3THDPj+0x30c)[0x829fdc]
/usr/local/mysql/bin/mysqld(_ZN7sp_head7executeEP3THDb+0x44a)[0x68089a]
/usr/local/mysql/bin/mysqld(_ZN7sp_head17execute_procedureEP3THDP4ListI4ItemE+0x636)[0x683ae6]
/usr/local/mysql/bin/mysqld(_Z21mysql_execute_commandP3THD+0x13fd)[0x6fb50d]
/usr/local/mysql/bin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x5c8)[0x701098]
/usr/local/mysql/bin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0xff9)[0x702809]
/usr/local/mysql/bin/mysqld(_Z24do_handle_one_connectionP3THD+0x162)[0x6d0172]
/usr/local/mysql/bin/mysqld(handle_one_connection+0x40)[0x6d0260]
/usr/local/mysql/bin/mysqld(pfs_spawn_thread+0x143)[0x927e53]
/lib64/libpthread.so.0[0x7f3466ccd83d]
/lib64/libc.so.6(clone+0x6d)[0x7f34654ccfcd]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (2b5cd10): drop view if exists sample_stats.t1
Connection ID (thread ID): 2
Status: NOT_KILLED

Resolve Stack:
0x8f15dc my_print_stacktrace + 44
0x67acb1 handle_fatal_signal + 1121
0x7f1a6b1aaca0 _end + 1776430904
0xb902f8 my_strnncoll_utf8 + 248
0x8d41ad my_hash_first_from_hash_value + 221
0x8d42f1 my_hash_search + 17
0x7f1a4d46fb22 _end + 1276018106
0x6aa5a5 _ZL21general_class_handlerP3THDjP13__va_list_tag + 517
0x6aa778 mysql_audit_notify(THD*, unsigned int, unsigned int, ...) + 168
0x828a34 _ZL19mysql_audit_generalP3THDjiPKc.constprop.140 + 708
0x82a4ec sp_instr_stmt::execute(THD*, unsigned int*) + 780
0x680d7a sp_head::execute(THD*, bool) + 1098
0x683fc6 sp_head::execute_procedure(THD*, List<Item>*) + 1590
0x6fb91d mysql_execute_command(THD*) + 5117
0x7014a8 mysql_parse(THD*, char*, unsigned int, Parser_state*) + 1480
0x702c19 dispatch_command(enum_server_command, THD*, char*, unsigned int) + 4089
0x6d0502 do_handle_one_connection(THD*) + 354
0x6d05f0 handle_one_connection + 64
0x9286d3 pfs_spawn_thread + 323
0x7f1a6b1a283d _end + 1776397013
0x7f1a699a1fcd _end + 1751229029

Revision history for this message

Jericho Rivera (jericho-rivera) wrote on 2015-03-13:

Does not seem to affect Percona Server 5.5.42

mysql> select @@global.query_response_time_stats;
+------------------------------------+
| @@global.query_response_time_stats |
+------------------------------------+
| 1 |
+------------------------------------+
1 row in set (0.00 sec)

mysql> call recreate_views_for_stats();
+------------------------+
| PROCEDURE_VERSION_INFO |
+------------------------+
| v 1.11 |
+------------------------+
1 row in set (0.00 sec)

+---------------+---------------+-------------+
| views_dropped | views_created | views_total |
+---------------+---------------+-------------+
| 3 | 3 | 3 |
+---------------+---------------+-------------+
1 row in set (0.01 sec)

Query OK, 0 rows affected (0.01 sec)

mysql>

Revision history for this message

Chandu (chandusingh-dba) wrote on 2015-03-13:

It didn't happen in 5.5 for us until now , only in the 5.6 couple of latest versions only. Thanks for confirming it and for the work around if we need to get this working in our environment or will wait for the fix

Br
Chandu

Revision history for this message

Chandu (chandusingh-dba) wrote on 2015-03-13:

#10

doesn't affect in versions of 5.5

Laurynas Biveinis (laurynas-biveinis) on 2015-03-13

tags:

added: query-response-time

Revision history for this message

Nickolay Ihalainen (ihanick) wrote on 2015-06-19:

#11

test case Edit (325 bytes, text/plain)

~/src/percona-server-5.6.24-72.2/plugin/query_response_time/plugin.cc line 152

LEX_STRING *name= &thd->lex->prepared_stmt_name;

(gdb) p thd->lex->prepared_stmt_name
$11 = {str = 0x0, length = 0}

But statement name is stored inside private variable:

(gdb) p ((sp_lex_instr *)thd->stmt_arena).m_lex.prepared_stmt_name
$17 = {str = 0x7f167c0626e0 "stmt", length = 4}

Revision history for this message

Nickolay Ihalainen (ihanick) wrote on 2015-06-19:

#12

stack trace Edit (14.4 KiB, text/plain)

query-response-time crashing mysqld if prepare statement is executed inside stored procedure can get an empty string for statement name.

thd->stmt_map.find_by_name is not able to work with empty strings.

tags:	added: 55751
tags:	added: i55751 removed: 55751

Revision history for this message

Valerii Kravchuk (valerii-kravchuk) wrote on 2015-07-01:

#13

Do we have any ideas at least where the fix will be, in the plugin's code or server's code?

Revision history for this message

Laurynas Biveinis (laurynas-biveinis) wrote on 2015-07-07:

#14

In the plugin

Revision history for this message

Chandu (chandusingh-dba) wrote on 2015-07-28:

#15

Thanks for the fix, in which package release this will be avaliable, i can test it once its released.

Revision history for this message

Dan Post (postster) wrote on 2015-08-06:

#16

I ran into this while loading common_schema-2.2 into Percona Server 5.6.25 73.0.

Revision history for this message

John Cesario (cesario) wrote on 2015-08-06:

#17

Is there a link to the commit in which this was fixed ?

Revision history for this message

Laurynas Biveinis (laurynas-biveinis) wrote on 2015-08-07:

#18

The pull request with fix in progress is at https://github.com/percona/percona-server/pull/120. Note that it has not been merged to the trunk yet.

Laurynas Biveinis (laurynas-biveinis) on 2015-08-11

summary:

- mysql 5.6. crashes when dropping and creating view from procedure.
+ Prepared statements in stored procedures crash query response time
+ plugin

Revision history for this message

Shahriyar Rzayev (rzayev-sehriyar) wrote on 2018-01-25:

#19

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-874

Report a bug

This report contains Public information

Everyone can see this information.

You are

Subscribing...

Edit bug mail

Other bug subscribers

Bug attachments

Add attachment

Remote bug watches

Bug watches keep track of this bug in other bug trackers.