3

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.
  • @kenorb Right! Sorry about that. I was trying to concisely document everything in a small space I forgot to ask. I updated the question and question title. – Rick Jan 26 '15 at 20:10
  • Are you caching to the database? Do you have watchdog enabled? – mpdonadio Jan 26 '15 at 21:03
  • @MPD Watchdog if off. Instead we log to syslog and view via sudo tail -n 1000 messages | grep drupal – Rick Jan 26 '15 at 21:06
3

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.

1

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...

  • Thanks. I've turned off db_log(watchdog) in favor of syslog. Our thinking was that the OS (RHEL 6.8) does a better job of managing /var/logs/messages. – Rick Jan 26 '15 at 20:55
1

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.

  • Thank you for the added comments and direction. You're not off base and no need to apologize. Up voted. I'm posting some findings from the logs results via tail -n 10000 messages | grep drupal | grep -v "page not found" | grep -v "access denied" – Rick Jan 27 '15 at 16:43
  • Which the result of the above shows a number of errors such as: "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)." – Rick Jan 27 '15 at 16:50
  • Glad I could help. I found this disembodied patch that may, MAY, address your issue. Use at your own peril!!! drupal.org/files/issues/context_menu_block_0.patch – Greg Stout Jan 27 '15 at 20:38
1

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

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.