| Bug #16988 | 99.9% CPU usage | ||
|---|---|---|---|
| Submitted: | 31 Jan 2006 22:31 | Modified: | 26 Feb 2009 22:04 |
| Reporter: | Tobias Marx | Email Updates: | |
| Status: | No Feedback | Impact on me: | |
| Category: | MySQL Server | Severity: | S1 (Critical) |
| Version: | 5.0.18, 5.0.67 | OS: | Linux (Suse Linux 9.3 x86_64) |
| Assigned to: | CPU Architecture: | Any | |
[31 Jan 2006 22:38]
Heikki Tuuri
Tobias, please post SHOW PROCESSLIST; and SHOW INNODB STATUS\G during the 99.9 % CPU usage. Regards, Heikki
[15 Feb 2006 1:00]
Chris
I also have the same issue with 3 different servers. Two of them are DUAL processors and one is dual core. Following is a strace from the non production server that I received less than 5 hours ago from the NOC. Nothing new added to it.
All 3 servers are running 4.0.25-Standard.
2 Duals are RHEL3 with Cpanel
1 Dual Code with Rhel 4 and Cpanel.
The problem seems to be caused anytime you connect to the mysql server or is this not a problem.. certainly seems like it though.
root@bubba [~]# strace -p 10382
Process 10382 attached - interrupt to quit
select(5, [3 4], NULL, NULL, NULL
===================== RUN COMMAND mysql =========================
The rest appears :
================================================== ===============
) = 1 (in [4])
fcntl64(4, F_SETFL, O_RDWR|O_NONBLOCK) = 0
accept(4, {sa_family=AF_FILE, path="ÿ¿I‰"}, [2]) = 11
fcntl64(4, F_SETFL, O_RDWR) = 0
getsockname(11, {sa_family=AF_FILE, path="/var/lib/mysql"}, [28]) = 0
fcntl64(11, F_GETFL) = 0x2 (flags O_RDWR)
fcntl64(11, F_SETFL, O_RDWR|O_NONBLOCK) = 0
setsockopt(11, SOL_IP, IP_TOS, [8], 4) = -1 EOPNOTSUPP (Operation not supported)
time(NULL) = 1139946685
rt_sigprocmask(SIG_SETMASK, NULL, [HUP INT QUIT PIPE TERM TSTP RTMIN], 8) = 0
write(8, "\0\343=\10\0\0\0\0 R?\10p\301\7\10\10>z\10\7P\10\200\0"..., 148) = 148
rt_sigprocmask(SIG_SETMASK, NULL, [HUP INT QUIT PIPE TERM TSTP RTMIN], 8) = 0
rt_sigsuspend([HUP INT QUIT PIPE TERM TSTP] <unfinished ...>
--- SIGRTMIN (Unknown signal 32) @ 0 (0) ---
<... rt_sigsuspend resumed> ) = -1 EINTR (Interrupted system call)
sigreturn() = ? (mask now [HUP INT QUIT PIPE TERM TSTP RTMIN])
select(5, [3 4], NULL, NULL, NULL
===== RUN COMMAND within MYSQL: connect mysql =========================
The rest appears :
============================
= 1 (in [4])
fcntl64(4, F_SETFL, O_RDWR|O_NONBLOCK) = 0
accept(4, {sa_family=AF_FILE, path="ÿ¿I‰"}, [2]) = 11
fcntl64(4, F_SETFL, O_RDWR) = 0
getsockname(11, {sa_family=AF_FILE, path="/var/lib/mysql"}, [28]) = 0
fcntl64(11, F_GETFL) = 0x2 (flags O_RDWR)
fcntl64(11, F_SETFL, O_RDWR|O_NONBLOCK) = 0
setsockopt(11, SOL_IP, IP_TOS, [8], 4) = -1 EOPNOTSUPP (Operation not supported)
time(NULL) = 1139946753
rt_sigprocmask(SIG_SETMASK, NULL, [HUP INT QUIT PIPE TERM TSTP RTMIN], 8) = 0
write(8, "\0\343=\10\0\0\0\0 R?\10p\301\7\10\10>z\10\7P\10\200\0"..., 148) = 148
rt_sigprocmask(SIG_SETMASK, NULL, [HUP INT QUIT PIPE TERM TSTP RTMIN], 8) = 0
rt_sigsuspend([HUP INT QUIT PIPE TERM TSTP] <unfinished ...>
--- SIGRTMIN (Unknown signal 32) @ 0 (0) ---
<... rt_sigsuspend resumed> ) = -1 EINTR (Interrupted system call)
sigreturn() = ? (mask now [HUP INT QUIT PIPE TERM TSTP RTMIN])
select(5, [3 4], NULL, NULL, NULL
[15 Feb 2006 1:00]
Chris
root@bubba [/var/lib/mysql]# mysql Welcome to the MySQL monitor. Commands end with ; or \g. Your MySQL connection id is 161 to server version: 4.0.25-standard Type 'help;' or '\h' for help. Type '\c' to clear the buffer. mysql> show processlist; +-----+-----------+-----------+-----------+---------+-------+-------+------------------+ | Id | User | Host | db | Command | Time | State | Info | +-----+-----------+-----------+-----------+---------+-------+-------+------------------+ | 54 | eximstats | localhost | eximstats | Sleep | 21467 | | NULL | | 161 | root | localhost | NULL | Query | 0 | NULL | show processlist | +-----+-----------+-----------+-----------+---------+-------+-------+------------------+ 2 rows in set (0.00 sec) mysql> show INNODB STATUS\G *************************** 1. row *************************** Status: ===================================== 060214 18:58:33 INNODB MONITOR OUTPUT ===================================== Per second averages calculated from the last 15 seconds ---------- SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 3, signal count 3 Mutex spin waits 0, rounds 0, OS waits 0 RW-shared spins 6, OS waits 3; RW-excl spins 0, OS waits 0 ------------ TRANSACTIONS ------------ Trx id counter 0 1280 Purge done for trx's n:o < 0 0 undo n:o < 0 0 Total number of lock structs in row lock hash table 0 LIST OF TRANSACTIONS FOR EACH SESSION: ---TRANSACTION 0 0, not started, process no 11843, OS thread id 692234 MySQL thread id 161, query id 751 localhost root show INNODB STATUS -------- FILE I/O -------- I/O thread 0 state: waiting for i/o request (insert buffer thread) I/O thread 1 state: waiting for i/o request (log thread) I/O thread 2 state: waiting for i/o request (read thread) I/O thread 3 state: waiting for i/o request (write thread) Pending normal aio reads: 0, aio writes: 0, ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0 Pending flushes (fsync) log: 0; buffer pool: 0 40 OS file reads, 4 OS file writes, 4 OS fsyncs 0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s ------------------------------------- INSERT BUFFER AND ADAPTIVE HASH INDEX ------------------------------------- Ibuf for space 0: size 1, free list len 0, seg size 2, 0 inserts, 0 merged recs, 0 merges Hash table size 34679, used cells 0, node heap has 0 buffer(s) 0.00 hash searches/s, 0.00 non-hash searches/s --- LOG --- Log sequence number 0 43892 Log flushed up to 0 43892 Last checkpoint at 0 43892 0 pending log writes, 0 pending chkp writes 9 log i/o's done, 0.00 log i/o's/second ---------------------- BUFFER POOL AND MEMORY ---------------------- Total memory allocated 17203732; in additional pool allocated 860928 Buffer pool size 512 Free buffers 493 Database pages 19 Modified db pages 0 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages read 19, created 0, written 0 0.00 reads/s, 0.00 creates/s, 0.00 writes/s No buffer pool page gets since the last printout -------------- ROW OPERATIONS -------------- 0 queries inside InnoDB, 0 queries in queue Main thread process no. 10390, id 28680, state: waiting for server activity Number of rows inserted 0, updated 0, deleted 0, read 0 0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s ---------------------------- END OF INNODB MONITOR OUTPUT ============================ 1 row in set (0.00 sec)
[15 Feb 2006 1:01]
Chris
From the two DUAL PROCESSOR production servers
mysql> show processlist;
+--------+-----------------+-----------+----------------+---------+------+----------------------+------------------------------------------------------------------------------------------------------+
| Id | User | Host | db | Command | Time | State | Info |
+--------+-----------------+-----------+----------------+---------+------+----------------------+------------------------------------------------------------------------------------------------------+
| 156 | eximstats | localhost | eximstats | Sleep | 14 | | NULL |
| 147072 | mailwatch | localhost | mailscanner | Sleep | 12 | | NULL |
| 151432 | eximstats | localhost | eximstats | Sleep | 108 | | NULL |
| 151622 | nursinga_wrdp1 | localhost | nursinga_wrdp1 | Sleep | 26 | | NULL |
| 151650 | sisterto_sister | localhost | sisterto_wp | Sleep | 12 | | NULL |
| 151669 | root | localhost | NULL | Query | 0 | NULL | show processlist |
| 151673 | andright_patti | localhost | andright_wp | Query | 0 | Copying to tmp table | SELECT DISTINCT DAYOFMONTH(post_date)
FROM wp_posts WHERE MONTH(post_date) = 02
|
| 151674 | xabob_wrdp1 | localhost | xabob_wrdp1 | Query | 0 | Opening tables | SELECT * FROM wp_users WHERE user_level > 0 |
+--------+-----------------+-----------+----------------+---------+------+----------------------+------------------------------------------------------------------------------------------------------+
8 rows in set (0.00 sec)
[15 Feb 2006 1:01]
Chris
mysql> show innodb status\g +------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | Status | +------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ |
[15 Feb 2006 1:01]
Chris
===================================== 060214 18:57:37 INNODB MONITOR OUTPUT ===================================== Per second averages calculated from the last 45 seconds ---------- SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 4, signal count 4 Mutex spin waits 2, rounds 20, OS waits 1 RW-shared spins 6, OS waits 3; RW-excl spins 1, OS waits 0 ------------ TRANSACTIONS ------------ Trx id counter 0 2304 Purge done for trx's n:o < 0 0 undo n:o < 0 0 Total number of lock structs in row lock hash table 0 LIST OF TRANSACTIONS FOR EACH SESSION: ---TRANSACTION 0 0, not started, process no 18929, OS thread id 23584784 MySQL thread id 151669, query id 5583447 localhost root show innodb status -------- FILE I/O -------- I/O thread 0 state: waiting for i/o request (insert buffer thread) I/O thread 1 state: waiting for i/o request (log thread) I/O thread 2 state: waiting for i/o request (read thread) I/O thread 3 state: waiting for i/o request (write thread) Pending normal aio reads: 0, aio writes: 0, ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0 Pending flushes (fsync) log: 0; buffer pool: 0 40 OS file reads, 4 OS file writes, 4 OS fsyncs 0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s ------------------------------------- INSERT BUFFER AND ADAPTIVE HASH INDEX ------------------------------------- Ibuf for space 0: size 1, free list len 0, seg size 2, 0 inserts, 0 merged recs, 0 merges Hash table size 34679, used cells 0, node heap has 0 buffer(s) 0.00 hash searches/s, 0.00 non-hash searches/s --- LOG --- Log sequence number 0 43912 Log flushed up to 0 43912 Last checkpoint at 0 43912 0 pending log writes, 0 pending chkp writes 9 log i/o's done, 0.00 log i/o's/second ---------------------- BUFFER POOL AND MEMORY ---------------------- Total memory allocated 17203732; in additional pool allocated 860928 Buffer pool size 512 Free buffers 493 Database pages 19 Modified db pages 0 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages read 19, created 0, written 0 0.00 reads/s, 0.00 creates/s, 0.00 writes/s No buffer pool page gets since the last printout -------------- ROW OPERATIONS -------------- 0 queries inside InnoDB, 0 queries in queue Main thread process no. 12244, id 28680, state: waiting for server activity Number of rows inserted 0, updated 0, deleted 0, read 0 0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s ---------------------------- END OF INNODB MONITOR OUTPUT ============================ | +------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ 1 row in set (0.03 sec) my.cnf contents from production server : root@talis [~]# more /mysqldata/my.cnf [mysqld] datadir=/mysqldata tmpdir=/mysqldata/tmp skip-locking safe-show-database skip-innodb #skip-name-resolve #thread-stack=192K thread_stack=192k query_cache_limit = 2M #query_cache_limit from 1 to 2 query_cache_size = 64M query_cache_type = 1 key_buffer=32M #key_buffer from 40 to 32 join_buffer=1M #changed from 384K wait_timeout=50 #wait_timeout from 4 to 15 interactive_timeout=50 #interative_timeout from 10 to 50 read_buffer=3M #changed from 4 to 3 #log-slow-queries=/var/log/slow_query.log #log-long-format #long_query_time=5 sort_buffer=3M #sort buffer from 4 to 3 myisam_sort_buffer_size=64M max_tmp_tables=80 tmp_table_size=256M table_cache=2056 #changed to 2056 from 1500 max_connections=1000 thread_concurrency=4 #changed to 4 from 2 thread_cache_size=1024 max_allowed_packet=1M connect_timeout=5 my.cnf from non production server : [mysqld] set-variable = max_connections=500 safe-show-database
[1 Mar 2006 0:00]
Bugs System
No feedback was provided for this bug for over a month, so it is being suspended automatically. If you are able to provide the information that was originally requested, please do so and change the status of the bug back to "Open".
[3 Mar 2006 12:45]
Valeriy Kravchuk
Tobias: Your SHOW PROCESSLIST results and SHOW INNODB STATUS results are almost empty. Please, send some valid ones that are obtained during this high processor load. Chris: Please, send SHOW CREATE TABLE and SHOW TABLE STATUS results for those tables mentioned in your SHOW PROCESSLIST results: wp_posts, and wp_users. EXPLAIN results for those 2 queries will be also useful. Please, specify the exact kernel and glibc versions, as well as MySQL binary packages you had used.
[3 Apr 2006 23:00]
Bugs System
No feedback was provided for this bug for over a month, so it is being suspended automatically. If you are able to provide the information that was originally requested, please do so and change the status of the bug back to "Open".
[4 Dec 2006 13:58]
Prakash Chandrasekaran
Hi, I am using debian linux, and mysql for request tracker. It works fine for last two months. But immedieatley it shows the cpu usage is 99.9% . I tried my level best. Please could any one can help me.
[23 Jun 2008 3:44]
Gus Sid
Hello,
I have a very similar problem on 4 yes 4 servers that have mysql installed.
They all have quad cpus and are dual core. Even with only 1 site on a 2.66 8 cpu site with 8 gb of memory mysql is using cpu through the roof.
Process Manager
Process 27256 attached - interrupt to quit
select(5, [3 4], NULL, NULL, NULL) = 1 (in [4])
fcntl64(4, F_SETFL, O_RDWR|O_NONBLOCK) = 0
accept(4, {sa_family=AF_FILE, path="mysql/func"}, [2]) = 17
fcntl64(4, F_SETFL, O_RDWR) = 0
getsockname(17, {sa_family=AF_FILE, path="/var/lib/mysql "}, [28]) = 0
fcntl64(17, F_SETFL, O_RDONLY) = 0
fcntl64(17, F_GETFL) = 0x2 (flags O_RDWR)
fcntl64(17, F_SETFL, O_RDWR|O_NONBLOCK) = 0
setsockopt(17, SOL_IP, IP_TOS, [8], 4) = -1 EOPNOTSUPP (Operation not supported)
futex(0x8689a04, FUTEX_WAKE, 1) = 1
futex(0x8689a00, FUTEX_WAKE, 1) = 1
futex(0x8687e00, FUTEX_WAKE, 1) = 1
select(5, [3 4], NULL, NULL, NULL) = 1 (in [4])
fcntl64(4, F_SETFL, O_RDWR|O_NONBLOCK) = 0
accept(4, {sa_family=AF_FILE, path="mysql/func"}, [2]) = 78
fcntl64(4, F_SETFL, O_RDWR) = 0
getsockname(78, {sa_family=AF_FILE, path="/var/lib/mysql "}, [28]) = 0
fcntl64(78, F_SETFL, O_RDONLY) = 0
fcntl64(78, F_GETFL) = 0x2 (flags O_RDWR)
fcntl64(78, F_SETFL, O_RDWR|O_NONBLOCK) = 0
setsockopt(78, SOL_IP, IP_TOS, [8], 4) = -1 EOPNOTSUPP (Operation not supported)
when you trace it in cpu process, it keeps repeating over and over again.
[25 Jan 2009 13:31]
Conor Power
I seem to be running into this problem recently. I don't have any definate stats but I've started noticing this since I upgraded the machine to 4Gb of ram on a 32bit OS Some basic stats: Dual Core AMD Opteron(tm) Processor 170 CentOS release 4.7 (Final) Linux atlantis 2.6.9-78.0.13.ELsmp #1 SMP Wed Jan 14 16:12:46 EST 2009 i686 athlon i386 GNU/Linux 4Gb ram MySQL 5.0.67-community-log I've attached the output of show processlist, show innodb status and the strace from the two processes taking all the cpu time Let me know if I can get you any more info
[26 Jan 2009 12:03]
Sveta Smirnova
Conor, thank you for the feedback. strase shows mysqld can not get resources, so please check your memory first. If all is OK with memory please send us your configuration file and dump of mysql database with sensitive data replaced with some dummy values or provide information about how many rows do you expect for each subquery used in the union query.
[26 Jan 2009 13:34]
Conor Power
Hi Sveta,
Here is the output of free -m
total used free shared buffers cached
Mem: 3994 3868 126 0 253 3002
-/+ buffers/cache: 611 3383
Swap: 2047 0 2047
I've attached a copy of my.cnf and show variables and I'm working on clean version of the database which is causing this issue.
[26 Jan 2009 22:04]
Sveta Smirnova
Thank you for the feedback.
Free shows out of RAM:
total used free shared buffers cached
Mem: 3994 3868 126 0 253 3002
Please make sure it was not taken by other processes than mysqld.
[16 Feb 2009 21:41]
Conor Power
Hi Sveta, Just an update on this. I exported the mysql database using phpmyadmin and then dropped all the tables in the mysql database After reimporting the data via the command line I ran flush privileges and everything seems to have returned to normal. The query which never seem to complete is now finishing within seconds. I'll keep my eye on this server over the next few days to see if it reoccurs.
[27 Feb 2009 0:00]
Bugs System
No feedback was provided for this bug for over a month, so it is being suspended automatically. If you are able to provide the information that was originally requested, please do so and change the status of the bug back to "Open".
Description: MySQL reaches 99.9% CPU usage really quickly and is unusually high. However this error also occurs on older MySQL version...I installed the latest version and still have this effect. If I use a different server system (e.g. a 32 Bit Suse Linux system and a singe CPU) I only have about 3% CPU usage under exactly the same load. The hardware is where this effect can be observed is: * AMD Opteron 175 (Dual-Core) * 4.096 MB DDR-RAM * 2 x 250 GB HDDs RAID1 The software: Suse Linux 9.3 How to repeat: AMD Opteron 175 (Dual-Core) and Suse Linux 9.3 and any MySQL database Suggested fix: Some unexpected error it does not recover from or some inefficiect behaviour for that hardware?