{"id":254,"date":"2017-11-28T01:01:18","date_gmt":"2017-11-28T01:01:18","guid":{"rendered":"http:\/\/www.dedicatedmanagers.com\/?p=254"},"modified":"2017-11-28T01:01:18","modified_gmt":"2017-11-28T01:01:18","slug":"error-establishing-database-connection-wordpress-xmlrpc-php-denial-service-attack-error","status":"publish","type":"post","link":"https:\/\/www.dedicatedmanagers.com\/error-establishing-database-connection-wordpress-xmlrpc-php-denial-service-attack-error\/","title":{"rendered":"\"Error establishing a database connection\" - WordPress XML-RPC Denial of Service Attack Error"},"content":{"rendered":"

Often times after taking over management of a client's website, we'll put the client's website on a sever managed by us, Dedicated Managers, Inc<\/a>.\u00a0 Last week a client's server started having database issues.\u00a0 When the website was accessed from a public computer, the message \"Error establishing a database connection<\/strong>\" was returned by the server.\u00a0 It turned out the server was experiencing a DoS (Denial of Service) attack.<\/p>\n

Database Server Down<\/h2>\n

Upon the the first notification of the database failing, which in turn caused the web server to return the failing\u00a0\"Error establishing a database connection<\/strong>\" response, a simple restart of the database was successful.\u00a0 \u00a0In this case the database was MariaDB on a CentOS 7 Server so the service command was used.<\/p>\n

service mysql start<\/span><\/strong><\/p><\/blockquote>\n

Discovery of the Cause<\/h2>\n

System Logs<\/strong>
\nThe system logs were checked via the journalctl<\/a> command to investigate the severity of the issue.<\/p>\n

journalctl -u mariadb<\/span><\/strong><\/p><\/blockquote>\n

The output showed the server failed and an attempt to restart also failed (bold added for understanding).<\/p>\n

Nov 25 08:41<\/span>:04 cs6.dedicatedmanagers.com systemd[1]: mariadb.service: main process exited, code=killed, status=9\/KILL<\/strong><\/span>
\n Nov 25 08:41:07 cs6.dedicatedmanagers.com systemd[1]: Unit mariadb.service entered failed state.<\/span>
\n Nov 25 08:41:08 cs6.dedicatedmanagers.com systemd[1]: mariadb.service failed.<\/span>
\n Nov 25 08:42:59 cs6.dedicatedmanagers.com systemd[1]: mariadb.service holdoff time over, scheduling restart.<\/span>
\n Nov 25 08:43:58 cs6.dedicatedmanagers.com systemd[1]: Starting MariaDB database server...<\/span>
\n Nov 25 08:45:43 cs6.dedicatedmanagers.com systemd[1]: mariadb.service start-pre operation timed out. Terminating.<\/span>
\n Nov 25 08:47:05 cs6.dedicatedmanagers.com systemd[1]: Failed to start MariaDB database server.<\/span>
\n Nov 25 08:47:07 cs6.dedicatedmanagers.com systemd[1]: Unit mariadb.service entered failed state.<\/span>
\n Nov 25 08:47:11 cs6.dedicatedmanagers.com systemd[1]: mariadb.service failed<\/strong>.<\/span><\/p><\/blockquote>\n

The log lines above show that the process was killed with a KILL -9<\/strong> command, which is not a nice way for a process to be terminated.\u00a0 The KILL -9 command completely terminated the MariaDB service without giving it a chance to clean itself up.\u00a0 For a database, that's not good, and means something major happened.<\/p>\n

The lines in the log before the lines shown above didn't offer much but seemed to possibly indicate that the InnoDB page_cleaner may have caused the issue as it happened just before the process was killed (red time below vs red time above<\/span>).<\/p>\n

Nov 21 06:53:40 cs6.dedicatedmanagers.com mysqld[613]: 2017-11-21 6:53:40 140264103036672 [Warning] IP address '85.93.20.74' could not be resolved: Name or service not known<\/span>
\n Nov 25 08:40<\/strong><\/span>:57 cs6.dedicatedmanagers.com mysqld[613]: 2017-11-25 8:40:55 140263595730688 [Note] InnoDB: page_cleaner: 1000ms intended loop took 9169ms. The settings might not be optimal<\/strong>. (flushed=0 and evicted=0, during the time.)<\/span><\/p><\/blockquote>\n

Possible Cause<\/strong>
\nPossibly, the InnoDB page_cleaner may have used up too much memory and caused the kernel to start killing processes. However, further investigation proved there was a greater issue elsewhere and this may have just been the \"straw that broke the camel's back\" by putting the server load \"over the top\" to the point where the extra load caused the kernel to pick the most likely offensive process and kill it.<\/p>\n

Candidates for Kernel to Kill<\/strong>
\nA quick check using the dstat command<\/a> showed that the most likely candidate to be killed by the kernel is the database:<\/p>\n

dstat --top-oom<\/span><\/strong><\/p><\/blockquote>\n

Database Corruption<\/strong>
\nThe logs also showed, that due to the abrupt stoppage of the database server, the tables were marked as crashed and needed repair.\u00a0 So the databases were checked and repaired with the mysqlcheck command:<\/p>\n

mysqlcheck -uroot -p --repair --all-databases<\/span><\/strong><\/p><\/blockquote>\n

Server Load<\/strong>
\nAfter the database was up and running again, public access to the website was restored and immediately the site started getting bogged down again.\u00a0 The server load averages (as checked through the \"top\" or \"uptime\" commands<\/a>) were incredibly high and rising:<\/p>\n

load average: 135.00, 95.01, 55.05<\/span><\/p><\/blockquote>\n

Typically the load averages (especially for the 2nd & 3rd numbers which represent the 5 minute & 15 minute averages) should be much less than 1, for a single processor system as was the case in this server's (virtual) hardware.<\/p>\n

The server also became increasingly slower and unresponsive.<\/p>\n

Something was happening.\u00a0 A hard reboot was needed just to regain responsiveness to an ssh shell session.<\/p>\n

Upon reboot the system was responsive and the system was monitored with the \"top\" and \"ps -ef\" commands.\u00a0 It didn't take long before the load averages started spiking back up.\u00a0 What could be seen was that the website was receiving multiple hits every second.\u00a0 The server was running suPHP which starts a new cgi process for each hit to the server which showed up in the output of the commands.<\/p>\n

wwwuser1 20292 18101 0 12:12 ? 00:00:00 \/usr\/bin\/php-cgi<\/strong><\/span><\/p><\/blockquote>\n

Above is one line of the \"ps -ef\" output showing a hit to the website.\u00a0 Typically those processes start up and die quickly.\u00a0 It can be so fast that on a low traffic server you may not even catch the process in the output.\u00a0 Even if you load a website page in a browser and immediately after hitting enter to load the page you run the \"ps -ef\" command in the terminal, you may not catch it.<\/p>\n

But these processes were sticking around and increasing in quantity.\u00a0 Every second another was added. Every \"ps -ef\" and top refresh showed more and more of the lines above.\u00a0 Some of the older ones died off, but the total number was continually increasing.<\/p>\n

Reducing the Server Load<\/strong>
\nThe web server was shut down and the lingering processes were killed:<\/p>\n

apachectl stop<\/span><\/strong><\/p>\n

kill $(ps aux | grep '[p]hp' | awk '{print $2}')<\/span><\/strong><\/p><\/blockquote>\n

The server load decreased and further investigation could be made.<\/p>\n

Checking IP Traffic<\/strong>
\nImmediately a listener was put on port 80 to view the http traffic:<\/p>\n

tcpdump -n -i eth1 port 80<\/span><\/strong><\/p><\/blockquote>\n

This showed there were hits coming every second coming from a single IP:<\/p>\n

08:51:15<\/strong><\/span>.178161 IP 185.188.204.6<\/strong><\/span>.40984 > 169.48.115.29.http: Flags [S], seq 2828388787, win 29200, options [mss 1460,sackOK,TS val 656190545 ecr 0,nop,wscale 7], length 0<\/span>
\n 08:51:16<\/strong><\/span>.485425 IP 185.188.204.6<\/strong><\/span>.46144 > 169.48.115.29.http: Flags [S], seq 1865138997, win 29200, options [mss 1460,sackOK,TS val 656190871 ecr 0,nop,wscale 7], length 0<\/span>
\n 08:51:17<\/strong><\/span>.483773 IP 185.188.204.6<\/strong><\/span>.46144 > 169.48.115.29.http: Flags [S], seq 1865138997, win 29200, options [mss 1460,sackOK,TS val 656191121 ecr 0,nop,wscale 7], length 0<\/span>
\n 08:51:18<\/strong><\/span>.590143 IP 185.188.204.6<\/strong><\/span>.33517 > 169.48.115.29.http: Flags [S], seq 3204880701, win 29200, options [mss 1460,sackOK,TS val 656192647 ecr 0,nop,wscale 7], length 0<\/span>
\n 08:51:19<\/strong><\/span>.587510 IP 185.188.204.6<\/strong><\/span>.33517 > 169.48.115.29.http: Flags [S], seq 3204880701, win 29200, options [mss 1460,sackOK,TS val 656192897 ecr 0,nop,wscale 7], length 0<\/span><\/p><\/blockquote>\n

Note: The output above is actually taken from after the firewall rule was imposed below.\u00a0 Before the rule, there would have been responses from the sever in between each incoming packet from the attacking machine.<\/p>\n

Short Term Resolution<\/h2>\n

Blocking the Offending Traffic with a Firewall Rule<\/strong>
\nA quick check of the IP on google showed the IP was from a foreign country and has been reported to be causing issues for others.\u00a0 This was not legitimate traffic. So the IP was blocked using an iptables firewall rule:<\/p>\n

iptables -A INPUT -s 185.188.204.6 -j DROP<\/span><\/strong><\/p><\/blockquote>\n

The web server was brought back up:<\/p>\n

apachectl start<\/span><\/strong><\/p><\/blockquote>\n

Monitoring the system again with the \"top\" and \"ps -ef\" commands showed the system to continue to be stable and the offending process load did not return.<\/p>\n

Note that the attacking traffic will still show up in a tcpdump<\/a> as\u00a0tcpdump<\/span><\/strong>\u00a0has access to the Network Interface Controller<\/a>\u00a0hardware before the packets are dumped by the firewall.\u00a0 Not knowing this can cause significant confusion as it would appear that the firewall is not blocking the attacking traffic.<\/p>\n

Deeper Discovery<\/h2>\n

So what was causing the issue?<\/p>\n

Web Server Logs<\/strong>
\nA look into the server's apache httpd logs showed the attack was on WordPress' xmlrpc interface.\u00a0 There were thousands of log entries like the following:<\/p>\n

185.188.204.6 - - [25\/Nov\/2017:08:40:11 -0800] \"POST \/xmlrpc.php<\/strong> HTTP\/1.0\" 200 370 \"-\" \"Mozilla\/4.0 (compatible: MSIE 7.0; Windows NT 6.0)\"<\/span>
\n 185.188.204.6 - - [25\/Nov\/2017:08:40:12-0800] \"POST \/xmlrpc.php<\/strong> HTTP\/1.0\" 200 370 \"-\" \"Mozilla\/4.0 (compatible: MSIE 7.0; Windows NT 6.0)\"<\/span>
\n 185.188.204.6 - - [25\/Nov\/2017:08:40:13 -0800] \"POST \/xmlrpc.php<\/strong> HTTP\/1.0\" 200 370 \"-\" \"Mozilla\/4.0 (compatible: MSIE 7.0; Windows NT 6.0)\"<\/span>
\n 185.188.204.6 - - [25\/Nov\/2017:08:40:14 -0800] \"POST \/xmlrpc.php<\/strong> HTTP\/1.0\" 200 370 \"-\" \"Mozilla\/4.0 (compatible: MSIE 7.0; Windows NT 6.0)\"<\/span>
\n 185.188.204.6 - - [25\/Nov\/2017:08:40:15 -0800] \"POST \/xmlrpc.php<\/strong> HTTP\/1.0\" 200 370 \"-\" \"Mozilla\/4.0 (compatible: MSIE 7.0; Windows NT 6.0)\"<\/span>
\n 185.188.204.6 - - [25\/Nov\/2017:08:40:16 -0800] \"POST \/xmlrpc.php<\/strong> HTTP\/1.0\" 200 370 \"-\" \"Mozilla\/4.0 (compatible: MSIE 7.0; Windows NT 6.0)\"<\/span>
\n 185.188.204.6 - - [25\/Nov\/2017:08:40:17 -0800] \"POST \/xmlrpc.php<\/strong> HTTP\/1.0\" 200 370 \"-\" \"Mozilla\/4.0 (compatible: MSIE 7.0; Windows NT 6.0)\"<\/span>
\n 185.188.204.6 - - [25\/Nov\/2017:08:40:18 -0800] \"POST \/xmlrpc.php<\/strong> HTTP\/1.0\" 200 370 \"-\" \"Mozilla\/4.0 (compatible: MSIE 7.0; Windows NT 6.0)\"<\/span>
\n 185.188.204.6 - - [25\/Nov\/2017:08:40:19 -0800] \"POST \/xmlrpc.php<\/strong> HTTP\/1.0\" 200 370 \"-\" \"Mozilla\/4.0 (compatible: MSIE 7.0; Windows NT 6.0)\"<\/span><\/p><\/blockquote>\n

WordPress uses XML-RPC<\/a> for communication between the WordPress blog and other applications (ie.\u00a0 WordPress iPhone App to post articles from an iPhone).<\/p>\n

Long Term Resolution(s)<\/h2>\n

Blocking XML-RPC access via .htaccess file<\/h3>\n

Since this client doesn't use any of the XML-RPC communication features, the interface was blocked via the .htaccess file with the following additional configuration:<\/p>\n

#added to .htaccess file<\/span>
\n <Files \"xmlrpc.php\"><\/span>
\n Order Allow,Deny<\/span>
\n Deny from all<\/span>
\n <\/Files><\/span><\/p><\/blockquote>\n

Blocking XML-RPC access via WordPress Plugin<\/h3>\n

There are plugins that can be installed to disable the XML-RPC protocol from Worpress, such as the Disable XML-RPC<\/a> plugin, but the plugin works at the php level, meaning the extra php cgi process is still loaded which uses more server memory and bogs down the server.\u00a0 Hence the .htaccess extra configuration is preferred as it blocks the request before the expensive php process is called which puts load on the server that can still allow it to fairly easily be taken down.<\/p>\n

Blocking XML-RPC access - other methods<\/h3>\n

Other methods to reduce exposure to this kind of attack can use iptables firewall rules to temporarily block requests that come in too big of bursts.\u00a0 \u00a0However today's web browsers, in trying to make user load time experience better, can make 10 (or more) connections to a server, so it can be difficult to make a distinction between legitimate traffic and illigimitate traffic as they can look fairly similar at the lower level of the iptables firewall.<\/p>\n

Some ISP's can add smarter firewalls (usually at a cost) that help alleviate these types of problematic attacks.<\/p>\n

One could also delete the xmlrpc.php file, but WordPress updates may overwrite\/reinstall the file.\u00a0 If you use a security mechanism like Wordfence<\/a> (we at DMI highly recommend you do so), you'll also likely get warnings that a core file was changed, which is annoying.<\/p>\n

Wordfence protects against brute force attacks, and if this had been a security attack, it would have blocked the attacker due to too many failed login attempts.\u00a0 But as it turns out, per below, this was simply a Denial of Service attack, there was no attempt to hack a login.<\/p>\n

Checking the Severity of the Attack<\/h2>\n

To see if the attack on this server was an attempt to brute force access through password vulnerabilities in XML-RPC on WordPress, a simple script was put in place of the xmlrpc.php file and the parameters were dumped to a file fore each request.\u00a0 The firewall rule was suspended to allow a few requests to come through and then the rule was put back in place.<\/p>\n

<?php<\/span>
\n $file = print_r($_REQUEST, true);<\/span>
\n file_put_contents(\"xmlrpc.data.\" . time(), $file);<\/span>
\n exit;<\/span>
\n ?><\/span><\/p><\/blockquote>\n

The output saved to each file was an empty array, showing that this was just a DoS attack and not an attempt to hack passwords.\u00a0 If it was a password attack there would have been some payload conforming to XML-RPC standards in the request variables.<\/p>\n

Conclusion<\/h2>\n

This article was about a Denial of Service (Dos) attack that happened to a website running WordPress.\u00a0 The initial indicator of the issue was the database failure and public attempts to reach the website via a web browser received the message \"Error establishing a database connection<\/strong>\".<\/p>\n

The database failing was because the server was overloaded with too many HTTP requests.\u00a0 The HTTP requests were causing memory intensive cgi processes to load without closing them out.\u00a0 Due to the amount of processes open, the computer's memory became overloaded and the kernel had to choose which process to kill in order to save the overall stability of the server.\u00a0 The database server was chosen to be killed by the kernel's algorithm.<\/p>\n

The process to discover the cause of the issue\u00a0was shown along with short term and long term resolutions to help prevent similar attacks in the future.<\/p>\n

Further Reading:<\/h2>\n