How can I find a module or activity that is excessively writing to the database?

Question

Problem:

We have two productions servers: primary and failover. The two machines are linked via mysql replication. The mysql relay logs are clogging and bringing servers down the failover server. I see dozens of mysqld-relay-bin.000Xxxx files in /var/lib/mysql on the failover box.

My Question:

How might I find if a module or some other activity is doing excessive database writes?

Why am I asking a sql question on DA?

Now I'm asking this in Drupal Answers because we're trying to trace this from source to destination. I have a suspicion that we have a module that is a bit over-aggressive at logging. We only have two content editors and changes are made on a few pages a day. I've also asked a similar question on https://superuser.com/questions/869776/ to see if there is a more mysql-specific remedy.

Master my.cnf

$ cat /etc/my.cnf 
[mysqld]
datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock
user=mysql
# Disabling symbolic-links is recommended to prevent assorted security risks
symbolic-links=0

# sync
log-bin=mysql-bin
server-id=1
expire_logs_days = 1
max_binlog_size  = 100M
.
.
.
# sync config
log-bin = /var/log/mysql/mysql-bin.log
binlog_do_db=drupal
server-id=1 

Replicant (Slave) my.cnf

$ cat /etc/my.cnf
[mysqld]
datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock
user=mysql
# Disabling symbolic-links is recommended to prevent assorted security risks
symbolic-links=0

server-id=2
master-host=xxx.xx.xx.xxx
master-user=slave_user
master-password=XXXXXXXXXXXXXXX
master-connect-retry=60
replicate-do-db=drupal
slave-skip-errors = 1062,1054
expire_logs_days = 2
max_binlog_size  = 100M
ssl

Various or interesting finds in the logfile via tail -n 10000 messages | grep drupal | grep -v "page not found" | grep -v "access denied"

Warning: in_array() expects parameter 2 to be array, string given in context_menu_tree_add_active_path() (line 128 of /var/www/html/sites/all/modules/context_menu_block/context_menu_block.module).

Other considerations:

• Drush runs once an hour via the OS's crontab. We pull in multiple calendar and RSS feeds to keep updated content.
• We've recently migrated this site to Drupal. Our log files still indicate a few broken, dead links that spiders are finding. Which if I had db_log/watchdog enabled would be an obvious culprit.

Answer 1

I recommend turning on mysql query log and examining types of queries flooding your server.

Or, pay for a product like New Relic or AppDynamics which provide per-url PHP performance metrics (including DB usage) of your application on web servers.

Answer 2

I'd agree with @tenken. There are two types of query log - normal and slow - and you can modify the config on the fly from e.g. mysql cli. Drupal logging entries normally include the module name doing the logging.

If it is not watchdog() type calls it might be more difficult. You could look into the capabilities of the 'devel' module, which includes some drupal-level Db logging.

I would add that perhaps some tuning of the replication is in order. Personally, I'd start with a lower binlog max size, so the systems are closer together. I know that sounds counterintuitive, but...

Answer 3

You should take a look at your error logs too.

The DB slow down may not be a performance issue with a module but may be driven by a module that is tossing errors or even just warnings.

Every time Drupal watchdog logs a PHP notice, warning or error, PHP executes slower and the writing operation locks the database. That could be why your replications isn't happening.

Definitely try New Relic. There are so many layers of processing that get used building out a page that it's very hard to track down where a performance issue may be. Even the free version of New Relic help pinpoint issues.

Lastly, and I could be off base here, It seems you have a lot of modules massaging your code before display. Depending on your caching that could be eating you machine resources. I'm a big fan a Damien, but modules like cpn can make efficient caching difficult. Maybe your best course of action is to get a machine for just your db and have two head head that connect to a DB server with a slaved replication backup. If you separate out your web heads from your DB then you might find you can tune your boxes for much better performance.

I've done a lot of speculation here so forgive me if I'm just off base.

Answer 4

You can try to find a very core hook or function (e.g. https://api.drupal.org/api/drupal/includes%21common.inc/function/drupal_write_record/7 ) that writes in the database and then use watchdog and backtrace (e.g. watchdog('mydebug',print_r(debug_backtrace(), 1)) to get a comprehensive list about who called it

see also https://www.lullabot.com/blog/article/quick-and-dirty-debugging

Of course anything else can be used for logging instead of watchdog