Mysqld.bin CPU usage issue in Bitnami WordPress with NGINX and SSL Stack on Microsoft Azure

v-namac 2019-11-13 11:24:22 UTC #1

Keywords: WordPress + NGINX + SSL - Microsoft Azure - Technical issue - Other
Description:
Suddenly the 'mysqld.bin' file is taking huge CPU utilization since Oct 29th on wards and we didn't installed and activate any plugins. Site was running well and good until that day.

$ ps -e -o pcpu,nice,state,cputime,args --sort -pcpu | head -10

Output:
%CPU NI S TIME COMMAND
1261 0 S 17-02:29:18 /opt/bitnami/mysql/bin/mysqld.bin --defaults-file=/opt/bitnami/mysql/my.cnf --basedir=/opt/bitnami/mysql --datadir=/opt/bitnami/mysql/data --plugin-dir=/opt/bitnami/mysql/lib/plugin --user=mysql --lower-case-table-names=1 --log-error=/opt/bitnami/mysql/data/mysqld.log --pid-file=/opt/bitnami/mysql/data/mysqld.pid --socket=/opt/bitnami/mysql/tmp/mysql.sock --port=3306
2.4 0 S 00:47:16 nginx: worker process
1.8 0 S 00:36:28 nginx: worker process
1.4 0 S 01:30:23 python3 -u bin/WALinuxAgent-2.2.44-py2.7.egg -run-exthandlers
1.1 0 S 00:22:45 nginx: worker process
0.7 0 S 00:15:36 nginx: worker process
0.7 0 S 00:12:25 /opt/omi/bin/omiagent 9 10 --destdir / --providerdir /opt/omi/lib --loglevel WARNING
0.5 0 S 00:10:07 nginx: worker process
0.4 0 S 00:02:55 php-fpm: pool www

Ran the 'Bitnami Support Tool' but didn't get the code at end.
Error changing permissions to 00644 in /datadrive/bitnami/bnsupport-regex.ini
Abort, Retry, Ignore ? [A/r/i]i -- tried with r as well

Error: There has been an error.
Error reading INI file /datadrive/bitnami/bnsupport-regex.ini

v-namac 2019-11-14 11:10:15 UTC #2

Hi All,

Looking for urgent help, as this is impacting in Production.

Thanks,
NKM

jota 2019-11-14 12:38:58 UTC #3

Hi @v-namac,

I think this error might be related with the memory available in the machine. Can you stop the MySQL's server and run the Bitnami support tool again?

sudo /opt/bitnami/ctlscript.sh stop mysql

If the Bitnami Support tool fails, can you share the latest 100 lines of the MySQL's log here?

sudo cat /opt/bitnami/mysql/data/mysqld.log | tail -n 100

Apart from that, can you check if bots or attackers are trying to take down your site?

https://docs.bitnami.com/azure/apps/wordpress/troubleshooting/deny-connections-bots/

The guide is for Apache but you can use this command instead to get the connections

tail -n 10000 /opt/bitnami/nginx/logs/access.log | awk '{print $1}'| sort| uniq -c| sort -nr| head -n 10

v-namac 2019-11-15 08:51:27 UTC #4

Thanks for your reply jota.

here is the output for the above command.

2019-11-14T12:36:02.629439Z 1940458 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:03.185900Z 1940465 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:03.748035Z 1940471 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:04.303866Z 1940476 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:04.864278Z 1940481 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:05.420356Z 1940486 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:05.985734Z 1940493 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:06.547743Z 1940502 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:07.106040Z 1940508 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:07.657831Z 1940514 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:08.210663Z 1940521 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:08.779783Z 1940526 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:09.335490Z 1940530 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:09.896734Z 1940539 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:10.451955Z 1940544 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:11.009260Z 1940549 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:11.574936Z 1940552 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:12.136723Z 1940558 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:12.689926Z 1940562 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:13.249306Z 1940566 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:13.808029Z 1940569 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:14.357047Z 1940573 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:14.915768Z 1940578 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:15.476747Z 1940581 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:16.033587Z 1940584 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:16.596346Z 1940592 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:17.147751Z 1940596 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:17.706494Z 1940601 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:18.267416Z 1940604 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:18.823754Z 1940610 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:19.381248Z 1940614 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:19.944450Z 1940619 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:20.505614Z 1940625 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:21.061229Z 1940628 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:21.619840Z 1940631 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:22.180668Z 1940637 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:22.732689Z 1940642 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:23.283527Z 1940644 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:23.838038Z 1940652 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:24.389374Z 1940658 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:24.943747Z 1940663 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:25.507747Z 1940668 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:26.071755Z 1940672 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:26.634629Z 1940676 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:27.203935Z 1940682 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:27.765203Z 1940686 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:28.320320Z 1940691 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:28.876608Z 1940697 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:29.431749Z 1940703 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:29.991306Z 1940705 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:30.547350Z 1940709 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:31.105165Z 1940711 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:31.670688Z 1940716 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:32.222491Z 1940722 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:32.770885Z 1940727 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:33.323924Z 1940735 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:33.878424Z 1940741 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:34.428449Z 1940747 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:34.985258Z 1940754 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T12:36:35.546480Z 1940758 [Note] Access denied for user 'root'@'219.89.196.131' (using password: YES)
2019-11-14T13:38:28.354313Z 642416 [Note] Aborted connection 642416 to db: 'wp_mydbanme' user: 'myusername' host: '52.176.44.16' (Table 'wp_mydbanme.wptempuser_table' doesn't exist)
2019-11-14T14:57:08.379424Z 2003319 [Note] Aborted connection 2003319 to db: 'wp_mydbanme' user: 'myusername' host: '192.8.244.228' (Got an error writing communication packets)
2019-11-14T15:33:26.033343Z 2084619 [Note] Access denied for user 'root'@'118.193.28.58' (using password: NO)
2019-11-14T15:33:26.522280Z 2084630 [Note] Access denied for user 'root'@'118.193.28.58' (using password: YES)
2019-11-14T15:33:27.087359Z 2084642 [Note] Access denied for user 'root'@'118.193.28.58' (using password: YES)
2019-11-14T15:33:27.789391Z 2084651 [Note] Access denied for user 'root'@'118.193.28.58' (using password: YES)
2019-11-14T15:33:28.391426Z 2084661 [Note] Access denied for user 'root'@'118.193.28.58' (using password: YES)
2019-11-14T15:33:28.980792Z 2084668 [Note] Access denied for user 'root'@'118.193.28.58' (using password: YES)
2019-11-14T15:33:29.612742Z 2084681 [Note] Access denied for user 'root'@'118.193.28.58' (using password: YES)
2019-11-14T15:33:30.255782Z 2084692 [Note] Access denied for user 'mysql'@'118.193.28.58' (using password: YES)
2019-11-14T15:33:31.027521Z 2084709 [Note] Access denied for user 'root'@'118.193.28.58' (using password: YES)
2019-11-14T15:33:32.461435Z 2084740 [Note] Access denied for user 'mysqld'@'118.193.28.58' (using password: YES)
2019-11-14T15:33:33.486936Z 2084761 [Note] Access denied for user 'root'@'118.193.28.58' (using password: YES)
2019-11-14T15:33:34.767506Z 2084782 [Note] Access denied for user 'root'@'118.193.28.58' (using password: YES)
2019-11-14T15:33:35.979549Z 2084802 [Note] Access denied for user 'root'@'118.193.28.58' (using password: YES)
2019-11-14T15:33:37.263209Z 2084830 [Note] Access denied for user 'mysqld'@'118.193.28.58' (using password: YES)
2019-11-14T15:33:38.458362Z 2084852 [Note] Access denied for user 'root'@'118.193.28.58' (using password: YES)
2019-11-14T15:33:39.483303Z 2084890 [Note] Access denied for user 'root'@'118.193.28.58' (using password: YES)
2019-11-14T15:33:40.947879Z 2084924 [Note] Access denied for user 'root'@'118.193.28.58' (using password: YES)
2019-11-14T15:33:41.886374Z 2084935 [Note] Access denied for user 'root'@'118.193.28.58' (using password: YES)
2019-11-14T15:33:42.981003Z 2084958 [Note] Access denied for user 'root'@'118.193.28.58' (using password: YES)
2019-11-14T15:53:14.165928Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 6206ms. The settings might not be optimal. (flushed=144 and evicted=0, during the time.)
2019-11-14T16:14:14.940905Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 4630ms. The settings might not be optimal. (flushed=10 and evicted=0, during the time.)
2019-11-14T16:16:37.721580Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 4094ms. The settings might not be optimal. (flushed=0 and evicted=0, during the time.)
2019-11-14T17:47:16.045222Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 6572ms. The settings might not be optimal. (flushed=112 and evicted=0, during the time.)
2019-11-14T17:55:38.117520Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 13158ms. The settings might not be optimal. (flushed=18 and evicted=0, during the time.)
2019-11-14T18:03:01.782980Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 5683ms. The settings might not be optimal. (flushed=19 and evicted=0, during the time.)
2019-11-14T18:23:06.408766Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 5191ms. The settings might not be optimal. (flushed=104 and evicted=0, during the time.)
2019-11-14T18:45:45.414675Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 5027ms. The settings might not be optimal. (flushed=16 and evicted=0, during the time.)
2019-11-14T18:51:20.133914Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 4368ms. The settings might not be optimal. (flushed=90 and evicted=0, during the time.)
2019-11-14T18:53:59.756900Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 7267ms. The settings might not be optimal. (flushed=18 and evicted=0, during the time.)
2019-11-14T19:07:39.521251Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 4967ms. The settings might not be optimal. (flushed=16 and evicted=0, during the time.)
2019-11-14T21:55:41.862325Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 4415ms. The settings might not be optimal. (flushed=11 and evicted=0, during the time.)
2019-11-15T02:12:02.187156Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 9802ms. The settings might not be optimal. (flushed=7 and evicted=0, during the time.)
2019-11-15T02:31:27.024175Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 4945ms. The settings might not be optimal. (flushed=0 and evicted=0, during the time.)
2019-11-15T02:38:36.538160Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 4926ms. The settings might not be optimal. (flushed=0 and evicted=0, during the time.)
2019-11-15T06:25:11.201800Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 6812ms. The settings might not be optimal. (flushed=153 and evicted=0, during the time.)
2019-11-15T06:26:33.439113Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 4176ms. The settings might not be optimal. (flushed=0 and evicted=0, during the time.)
2019-11-15T07:31:55.603939Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 4678ms. The settings might not be optimal. (flushed=0 and evicted=0, during the time.)
2019-11-15T07:35:59.799464Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 10880ms. The settings might not be optimal. (flushed=0 and evicted=0, during the time.)

And here is the output for the above command.

231 49.199.120.49
197 84.234.179.91
165 46.135.8.165
162 159.86.182.133
156 124.189.3.160
136 62.50.172.50
135 111.220.171.245
124 1.156.178.234
107 1.54.162.164
 98 139.98.2.55

here is the output of htop command.

Please do the needful asap, as its impacting the production website and I imported the same database in other environment and tested but there I didn't see this high CPU utilization for mysqld.bin file.

If possible we will sync up to discuss on this. I will be available from 10am to 6pm IST. Please let me know your feasible time and where to discuss.

Thanks
Nanda K M

jota 2019-11-15 09:53:16 UTC #5

Hi @v-namac,

We recently received several support cases of user whose WordPress' deployments went down without any apparent reason. For this reason, we published a security notice in our blog post

https://docs.bitnami.com/azure/security/security-2019-11-08/

Could you please check it and ensure your site is secure? It seems your database is receiving multiple connection requests and there might be a configuration problem in WordPress.

Regards

v-namac 2019-11-15 17:34:30 UTC #6

Hi @jota,

As mentioned earlier, we haven't uploaded or installed any new plugins or themes in the recent days.

Also searched for 'wp_vcd' on through out the production files, but couldn't able to find anything like that.

Google safety browsing also showing 'no unsafe content found'.

Please let me know which is the good time to discuss with you people directly so that I will share and will discuss more on the server, mysql, php-fpm etc settings.

Thanks
Nanda K M

jariza 2019-11-18 12:57:01 UTC #7

Hi @v-namac

Please note that you could be affected by this issue, even if you didn't installed any plugin/theme recently. The WP-VCD attack started in August 2019.

Could you please re-check your plugins and follow this guide provided by Wordfence to ensure you don't have any malware on your WP site?

I am afraid we don't offer this kind of support (phone or any other kind of call support). We will, however, be happy to help through this platform.

Best regards,

Juan Ariza

v-namac 2019-11-19 17:43:20 UTC #8

Hi Jariza,

I already gone through this article and couldn't find any malware on our WP site.

Earlier we had direct discussion with the support team regarding setting up the config values as site is giving poor performance at that time, hope you guys will do the same now as well.

Please let me know what are the other things which are taking or utilizing high CPU utilization, mainly mysqld.bin file.Here is the latest screenshot for high cpu utilization.

Thanks
Nanda K M

jariza 2019-11-21 08:47:52 UTC #9

Hi @v-namac

Please let me know what are the other things which are taking or utilizing high CPU utilization, mainly mysqld.bin file

Yes, it seems its basically the database the one consuming all the CPU. You can try to enable the slow queries log (as it's explained on this thread) so you can inspect/identify why MySQL is so slow. In the link below you can find some guidance to debug issues by inspecting slow queries:

What team did you discuss with? Was it the Bitnami team or AWS team? Bitnami only provides support through this platform and GitHub.

Best Regards,

Juan Ariza

v-namac 2019-12-04 11:03:24 UTC #10

Hi Jariza,

I checked the slow query log setup and found 2 queries are taking time, but those were there since 2 years and couldn't find any high CPU usage because of those queries.

Even I verified the site with Wordfence and couldn't find any suspicious things happened. So any other reasons and things that I need to check for why mysqld.bin is taking more than 1000+ CPU usage?

Thanks
Nanda K M

jsalmeron 2019-12-06 14:30:30 UTC #11

Hi,

What's the size of the blog (not exactly in terms of GB but in terms of posts and pages)? And which are those queries? Maybe the database became too big and that would partially explain the problem.

Best regards,

Javier J. Salmerón

Was my answer helpful? Click on

v-namac 2019-12-11 11:17:05 UTC #12

Hi Javier,

Yes, the size of the database is now around 4GB. Below image explains table sizes which is having more than 50MB.

According to the above image we have huge userbase which is increased on day to day base and not suddenly. Whereas in our case from Oct 26th onwards all off sudden the mysqld.bin CPU usage got increase to 1000% to 1400%. Now we are continuously seeing the high CPU utilization more than 70%.

Please help me on this to figure out the issue, as this is impacting the production server.

Thanks
Nanda K M

Bitnami provides free all-in-one installers, virtual machines and cloud images for popular open source applications. Get them now!