MySql inserts high CPU load

cpu-usage, insert, mysql, nginx, php

Solution

By "later" processing, do you possibly mean 1 hour or 1 day later? If that is the case then I would write the information to a CSV file which you rotate out once an hour or so and then when you need to do your "later"processing you can load the files into MySQL using `LOAD DATA INFILE`

http://dev.mysql.com/doc/refman/5.1/en/load-data.html

I have had LOAD DATA INFILE load 100s of MB of information in less than a minute, this method would be a great way to speed up your web response.

Problem

I have nginx receiving POST requests and a tiny PHP script that puts request body to MySql. The problem is very high MySql CPU usage when I have 300 POSTs per second. I expected MySql to be a fast thing that can handle much more that 300 inserts per second. I use Amazon EC2 small instance, Amazon Linux. ``` top - 18:27:06 up 3 days, 1:43, 2 users, load average: 4.40, 5.39, 5.76 Tasks: 178 total, 4 running, 174 sleeping, 0 stopped, 0 zombie Cpu(s): 24.6%us, 13.4%sy, 0.0%ni, 0.0%id, 1.1%wa, 0.0%hi, 4.9%si, 56.0%st Mem: 1717480k total, 1640912k used, 76568k free, 193364k buffers Swap: 917500k total, 5928k used, 911572k free, 824136k cached PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 7677 mysql 20 0 313m 153m 6124 S 39.0 9.2 393:49.11 mysqld 16529 nginx 20 0 157m 151m 820 R 15.2 9.0 28:36.50 nginx 29793 php 20 0 36780 3240 1896 S 2.5 0.2 0:00.34 php-fpm 29441 php 20 0 36780 3204 1892 S 2.2 0.2 0:00.78 php-fpm 29540 php 20 0 36780 3204 1900 S 2.2 0.2 0:00.82 php-fpm 29603 php 20 0 36780 3220 1892 S 2.2 0.2 0:00.61 php-fpm 29578 php 20 0 36780 3200 1900 S 1.9 0.2 0:00.42 php-fpm 29950 php 20 0 36780 3192 1900 S 1.9 0.2 0:00.48 php-fpm 30030 php 20 0 36780 3180 1888 S 1.9 0.2 0:00.08 php-fpm 30025 php 20 0 36780 3200 1888 S 1.6 0.2 0:00.11 php-fpm 29623 php 20 0 36780 3184 1892 S 1.3 0.2 0:00.49 php-fpm 29625 php 20 0 36780 3236 1900 S 1.3 0.2 0:00.46 php-fpm 29686 php 20 0 36780 3364 1900 R 1.3 0.2 0:00.51 php-fpm 29863 php 20 0 36780 3184 1892 S 1.3 0.2 0:00.23 php-fpm 30018 php 20 0 36780 3192 1892 S 1.3 0.2 0:00.19 php-fpm 29607 php 20 0 36780 3224 1900 S 1.0 0.2 0:00.42 php-fpm 29729 php 20 0 36780 3180 1888 R 1.0 0.2 0:00.41 php-fpm ``` Here is my PHP code: ``` <?php $mysqli=new mysqli("localhost", "root", "", "errorreportsraw"); $project_id=$_REQUEST["project_id"]; $data=$_REQUEST["data"]; $date=date("Y-m-d H-i-s"); $mysqli->query("insert into rawreports(date, data, project_id) values ('$date', '$data', '$project_id')") ?> ``` I tried mysql_connect, mysql_pconnect, mysqli("localhost",...), mysqli("p:localhost", ...) - still the same. No queries are running against the database except these inserts. Here's my table: ``` CREATE TABLE `rawreports` ( `id` bigint(20) NOT NULL AUTO_INCREMENT, `date` datetime NOT NULL, `data` mediumtext NOT NULL, `project_id` varchar(100) NOT NULL, PRIMARY KEY (`id`) ); ``` It's pretty simple, no indexes, just to store the POST data for later processing. 'data' field is something about 3 kilobytes in most cases. Tried innodb and myisam - still the same. Here's my SHOW PROCESSLIST, nothing except multiple inserts: ``` mysql> show processlist; +---------+----------------------+-----------+-----------------+---------+------+------------------+------------------------------------------------------------------------------------------------------+ | Id | User | Host | db | Command | Time | State | Info | +---------+----------------------+-----------+-----------------+---------+------+------------------+------------------------------------------------------------------------------------------------------+ | 3872248 | root | localhost | NULL | Query | 0 | NULL | show processlist | | 3901991 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902003 | root | localhost | errorreportsraw | Sleep | 0 | | NULL | | 3902052 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902053 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902054 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902055 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902056 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902057 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902058 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902059 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902060 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"protocol_version":" | | 3902061 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902062 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902063 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902064 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902065 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902066 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902067 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902068 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902069 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902070 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902071 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902072 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902073 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902074 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902075 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902076 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902077 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902078 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902079 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902080 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902081 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902082 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902083 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902084 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902085 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902086 | root | localhost | errorreportsraw | Query | 0 | update | insert into rawreports(date, data, project_id) values ('2012-05-05 17-01-37', '{"exceptions":[{"stac | | 3902087 | unauthenticated user | localhost | NULL | Connect | NULL | Reading from net | NULL | +---------+----------------------+-----------+-----------------+---------+------+------------------+------------------------------------------------------------------------------------------------------+ 39 rows in set (0.00 sec) ``` Here's the PROFILE when I do the same insert manually while server is still under pressure: ``` set profiling=1; insert into rawreports(date, data, project_id) values('2012-05-04 00:58:08','[3000-chars-data-here]','5'); show profile ALL for query 1; Status Duration CPU_user CPU_system Context_voluntary Context_involuntary Block_ops_in Block_ops_out Messages_sent Messages_received Page_faults_major Page_faults_minor Swaps Sourc starting 0.000231 0.000000 0.000000 0 0 0 0 0 0 0 0 0 NULL NULL NULL checking permissions 0.000030 0.000000 0.000000 0 0 0 0 0 0 0 0 0 check_access sql_parse.cc 4745 Opening tables 0.000057 0.001000 0.000000 0 0 0 0 0 0 0 0 0 open_tables sql_base.cc 4836 System lock 0.000030 0.000000 0.000000 0 0 0 0 0 0 0 0 0 mysql_lock_tables lock.cc 299 init 0.000037 0.000000 0.000000 0 0 0 0 0 0 0 0 0 mysql_insert sql_insert.cc 721 update 0.075716 0.001999 0.011998 166 2 0 0 0 0 0 0 0 mysql_insert sql_insert.cc 806 Waiting for query cache lock 0.000087 0.000000 0.000000 0 0 0 0 0 0 0 0 0 lock sql_cache.cc 552 update 0.000037 0.000000 0.000000 0 0 0 0 0 0 0 0 0 NULL NULL NULL end 0.000024 0.000000 0.000000 0 0 0 0 0 0 0 0 0 mysql_insert sql_insert.cc 1049 query end 0.000042 0.000000 0.000000 0 0 0 0 0 0 0 0 0 mysql_execute_command sql_parse.cc 4434 closing tables 0.000031 0.000000 0.001000 0 0 0 0 0 0 0 0 0 mysql_execute_command sql_parse.cc 4486 freeing items 0.000126 0.000000 0.000000 0 1 0 0 0 0 0 0 0 mysql_parse sql_parse.cc 5634 logging slow query 0.000030 0.000000 0.000000 0 0 0 0 0 0 0 0 0 log_slow_statement sql_parse.cc 1460 cleaning up 0.000024 0.000000 0.000000 0 0 0 0 0 0 0 0 0 dispatch_command sql_parse.cc 1416 ``` I use MySql 5.5.20. Tried both InnoDB and MyISAM - both the same. Here's my iostat output: ``` # iostat -x Linux 3.2.12-3.2.4.amzn1.i686 05/15/2012 _i686_ (1 CPU) avg-cpu: %user %nice %system %iowait %steal %idle 23.67 0.03 18.39 4.09 52.87 0.95 Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await svctm %util xvdap1 0.00 1.74 0.03 0.78 1.50 25.12 32.85 0.01 14.03 5.92 0.48 xvdap3 0.00 0.00 0.01 0.01 0.05 0.08 10.47 0.00 5.72 1.09 0.00 xvdf 0.40 18.59 23.14 117.55 753.12 3465.25 29.98 0.53 3.74 2.38 33.46 ``` The most obvious thing is to batch insert and commit them all together not one by one. But I can't do that because every insert is a separate POST request, separate PHP script execution. They're all executed simultaneously and don't interfer with each other. Seems to be a pretty simple task, what my CPU is actually doing so hard? Don't have much experience with mysql, php, linux. Probably I just miss something. Thanks for any ideas!

Original source

Related problems