Bug #43470 | Repeated procedure calls on same thread hangs thread | ||
---|---|---|---|
Submitted: | 6 Mar 2009 23:58 | Modified: | 30 Apr 2012 12:49 |
Reporter: | Van Stokes | Email Updates: | |
Status: | Duplicate | Impact on me: | |
Category: | MySQL Server: InnoDB storage engine | Severity: | S1 (Critical) |
Version: | 6.0.9-alpha | OS: | Windows (XP64) |
Assigned to: | Assigned Account | CPU Architecture: | Any |
Tags: | CALL, hang, PROCEDURE, regression, Repeated, stall, thread |
[6 Mar 2009 23:58]
Van Stokes
[7 Mar 2009 0:37]
Van Stokes
We also noticed another issue. If we kill these "hung" threads (using MySQL Administrator 1.12.17) the process/thread is labeled "killed" but is never removed from the process table. Furthermore, "mysqld" pegs the CPU at 99%. "mysqld" runs fine (normal CPU usage) but when we try to kill one of these hung processes the CPU utilization pegs.
[9 Mar 2009 6:35]
Van Stokes
There is a definitely an issue with stored procedures running SELECT queries. We found more threads hung performing a SELECT. What seems to be a common denominator is that the SELECT statement is using a VIEW and either has WHERE IN or DISTINCT (or both) operands in the statement. These hung threads consume large amounts of CPU time.
[10 Mar 2009 19:23]
MySQL Verification Team
Thank you for the bug report. Testing today source server on Windows I got: c:\dbs>c:\dbs\6.0\bin\mysql -uroot --port=3600 --prompt="mysql 6.0 > " Welcome to the MySQL monitor. Commands end with ; or \g. Your MySQL connection id is 11 Server version: 6.0.10-alpha-Win x86-64 bzr revno:3036-log Source distribution Type 'help;' or '\h' for help. Type '\c' to clear the buffer. mysql 6.0 > show processlist; +----+------+-----------------+------+---------+------+-------+------------------+ | Id | User | Host | db | Command | Time | State | Info | +----+------+-----------------+------+---------+------+-------+------------------+ | 11 | root | localhost:53922 | NULL | Query | 0 | NULL | show processlist | +----+------+-----------------+------+---------+------+-------+------------------+ 1 row in set (0.00 sec) Now launch Query Browser and do the first call: mysql 6.0 > show processlist; +----+------+-----------------+---------+---------+------+-------+------------------+ | Id | User | Host | db | Command | Time | State | Info | +----+------+-----------------+---------+---------+------+-------+------------------+ | 11 | root | localhost:53922 | NULL | Query | 0 | NULL | show processlist | | 12 | root | localhost:53924 | origins | Sleep | 37 | NULL | NULL | | 14 | root | localhost:53926 | origins | Sleep | 13 | NULL | NULL | | 15 | root | localhost:53927 | NULL | Sleep | 3 | NULL | NULL | +----+------+-----------------+---------+---------+------+-------+------------------+ 4 rows in set (0.00 sec) QB returned 7 rows. Do 2nd call: mysql 6.0 > show processlist; +----+------+-----------------+---------+---------+------+-------+------------------+ | Id | User | Host | db | Command | Time | State | Info | +----+------+-----------------+---------+---------+------+-------+------------------+ | 11 | root | localhost:53922 | NULL | Query | 0 | NULL | show processlist | | 12 | root | localhost:53924 | origins | Sleep | 129 | NULL | NULL | | 14 | root | localhost:53926 | origins | Sleep | 8 | NULL | NULL | | 15 | root | localhost:53927 | NULL | Sleep | 0 | NULL | NULL | +----+------+-----------------+---------+---------+------+-------+------------------+ 4 rows in set (0.00 sec) QB returned 10 rows. Now quit QB: mysql 6.0 > show processlist; +----+------+-----------------+------+---------+------+-------+------------------+ | Id | User | Host | db | Command | Time | State | Info | +----+------+-----------------+------+---------+------+-------+------------------+ | 11 | root | localhost:53922 | NULL | Query | 0 | NULL | show processlist | +----+------+-----------------+------+---------+------+-------+------------------+ 1 row in set (0.00 sec) mysql 6.0 > The above behavior happens because QB does a connection for every query and mysql client doesn't. So I wasn't able to see a select hanging in the current source server.
[10 Mar 2009 21:26]
MySQL Verification Team
Sorry don't need feedback I didn't noticed the below error message from InnoDB displayed for every call to the procedure disregarding if perfomed by QB or mysql client: c:\dbs>c:\dbs\6.0\bin\mysqld --defaults-file=c:\dbs\6.0\my.ini --standalone --console 090310 18:16:45 InnoDB: Started; log sequence number 0 674811651 090310 18:16:45 [Note] Event Scheduler: Loaded 0 events 090310 18:16:45 [Note] c:\dbs\6.0\bin\mysqld: ready for connections. Version: '6.0.10-alpha-Win x86-64 bzr revno:3036-log' socket: '' port: 3600 Source distribution 090310 18:17:34 InnoDB: Error: trying to declare trx to enter InnoDB, but InnoDB: it already is declared. TRANSACTION 0 1514753, ACTIVE 0 sec, OS thread id 828 starting index read, thread declared inside InnoDB 0 mysql tables in use 8, locked 1 MySQL thread id 1, query id 25 localhost ::1 root Copying to tmp table SELECT Zone_View.* <cut>
[10 Mar 2009 21:27]
MySQL Verification Team
Error log
Attachment: innodb-error.txt (text/plain), 7.77 KiB.
[10 Mar 2009 21:29]
MySQL Verification Team
See bug: http://bugs.mysql.com/bug.php?id=20090.
[11 Mar 2009 9:57]
Van Stokes
Hung SELECT processes before and after kill.
Attachment: Bug43470-HungProcesses.txt (text/plain), 12.74 KiB.
[11 Mar 2009 10:15]
Van Stokes
Print Screen of Task Manager showing mysqld CPU usage.
Attachment: mysql-cpu-usage.PNG (image/png, text), 29.70 KiB.
[11 Mar 2009 10:20]
Van Stokes
I just added a couple of files to show what is happening from our point of view. We tried to kill off the hung processes but as you can see they get labeled as KILLED but never go away. Also included a print screen of the CPU usage of mysqld. The only known solution that we know to work is to KILL the mysqld process via the TASK MANAGER. We can not do a normal shutdown as the server will not respond to it.
[12 Mar 2009 13:40]
MySQL Verification Team
Not repeatable on 5.1 version.
[31 May 2009 22:08]
Van Stokes
Upgraded from MySQL 6.0.10-alpha to MySQL 6.0.11-alpha. No performance improvement in the query.
[30 Apr 2012 12:49]
MySQL Verification Team
Since 6.0.9 is not a valid version anymore, and the symptoms are closely resembling known bugs, I'll say this is a duplicate. Bug 11745800 - 20090: INNODB: ERROR: TRYING TO DECLARE TRX TO ENTER INNODB Bug 11746321 - 25439: TRX->ACTIVE_TRANS == 0, BUT TRX->CONC_STATE != TRX_NOT_STARTED http://bugs.mysql.com/bug.php?id=54475 (improper error handling causes cascading crashing failures in innodb/ndb)