MySQL Binary Logs of Death

MySQL Binary Logs of Death (er, I mean, "on Debian")

This guy (a man very much after my own heart, he started logging this problem of a full root partition before he had a solution) had the same problem, but didn't seem to think it was a problem:
MySQL binary log space (Debian) 10/15/07
http://fplanque.com/dev/linux/mysql-binary-log-space-debian

So he figured he'd only keep them five days instead of ten:

The magic conf is located in /etc/mysql/my.cnf and the magic line is:

Code:
expire_logs_days = 5

A passing visitor advised that the binary logs aren't needed at all, and could be disabled completely, pointing to the MySQL docs for their use:

http://dev.mysql.com/doc/refman/5.0/en/binary-log.html

The binary log is not used for statements such as SELECT or SHOW that do not modify data. If you want to log all statements (for example, to identify a problem query), use the general query log. See Section 5.11.2, “The General Query Log”.

The primary purpose of the binary log is to be able to update databases during a restore operation as fully as possible, because the binary log contains all updates done after a backup was made. The binary log is also used on master replication servers as a record of the statements to be sent to slave servers. See Chapter 15, Replication.

Running the server with the binary log enabled makes performance about 1% slower. However, the benefits of the binary log for restore operations and in allowing you to set up replication generally outweigh this minor performance decrement.

Agaric would rather like to know why they're filling up so damn fast in the first place.

Even though they're binary, we can read a fair amount of what's going on in there. Here's a tiny taste:

UPDATE wsf2008_net_cache SET data = 'a:5651
:{s:9:\"OPML file\";b:1;s:33:\"Successfully loaded argument %arg\";b:1;s:23:\"Action execution: %name\";b:1;s:35:\"Condition %name evaluated to %bool.\";b:1;s:49:\"Executing the configuration %name on event %event\";b:1;s:40:\"The URL the user\'s account editing page.\";b
:1;s:35:\"The URL of the user\'s profile page.\";b:1;s:39:\"The current date in the user\'s timezone\";b:1;s:32:\"Days since the user\'s last login\";b:1;s:22:\"User\'s last login date\";b:1;s:30:\"Days since the user registered\";b:1;s:24:\"User\'s registration date\";b:
1;s:20:\"User\'s email address\";b:1;s:9:\"User\'s ID\";b:1;s:11:\"User\'s name\";b:1;s:44:\"The Xst argument of the current active path.\";b:1;s:37:\"The current active url, e.g. \"admin\".\";b:1;s:15:\"ID of top group\";b:1;s:56:\"Unfiltered title of top group. WARNING
- raw user input.\";b:1;s:18:\"Title of top group\";b:1;s:30:\"Replacement patterns for @name\";b:1;s:72:\"You can make use of the replacement patterns of all available arguments.\";b:1;s:48:\"The path, to which the user is to be redirected.\";b:1;s:33:\"The action %label
has been saved.\";b:1;s:55:\"Adjust the weight to customize the ordering of actions.\";b:1;s:21:\"Editing action %label\";b:1;s:44:\"Choose an appropriate label for this action.\";b:1;s:23:\"Select an action to add\";b:1;s:16:\"Remove user role\";b:1;s:33:\"User whos rol
es should be changed\";b:1;s:13:\"Add user role\";b:1;s:15:\"Log to watchdog\";b:1;s:13:\"Page redirect\";b:1;s:39:\"Show a configurable message on the site\";b:1;s:45:\"Promote/demote content to/from the front page\";b:1;s:25:\"Publish/unpublish content\";b:1;s:28:\"User
, which is set as author\";b:1;s:22:\"Set the content author\";b:1;s:40:\"Send a mail to an arbitrary mail address\";b:1;s:9:\"Recipient\";b:1;s:21:\"Send a mail to a user\";b:1;s:28:\"Generate state change events\";b:1;s:52:\"Indent this condition by adding a logical ope
ration.\";b:1;s:36:\"The condition %label has been saved.\";b:1;s:58:\"Adjust the weight to customize the ordering of conditions.\";b:1;s:23:\"Arguments configuration\";b:1;s:65:\"If checked, the condition returns TRUE, if it evaluates to FALSE.\";b:1;s:6:\"Negate\";b:1;s
:24:\"Editing condition %label\";b:1;s:47:\"Choose an appropriate label for this condition.\";b:1;s:27:\"Select the condition to add\";b:1;s:18:\"Numeric comparison\";b:1;s:18:\"Textual comparison\";b:1;s:16:\"Content has type\";b:1;s:42:\"Whether the user has the selecte
d role(s).\";b:1;s:12:\"User to test\";b:1;s:16:\"User has role(s)\";b:1;s:68:\"Evaluates to TRUE, if both compared users are the same user account.\";b:1;s:22:\"Second user to compare\";b:1;s:21:\"First user to compare\";b:1;s:17:\"Compare two users\";b:1;s:6:\"States\";
b:1;s:20:\"The updated argument\";b:1;s:22:\"The unchanged argument\";b:1;s:25:\"Machine state has changed\";b:1;s:20:\"User has nodeprofile\";b:1;s:13:\"Add an action\";b:1;s:15:\"Add a condition\";b:1;s:10:\"Conditions\";b:1;s:16:\"Invoked on event\";b:1;s:20:\"Revert c
onfiguration\";b:1;s:25:\"Edit configuration @label\";b:1;s:40:\"The configuration %label has been added.\";b:1;s:51:\"Choose an appropriate label for this configuration.\";b:1;s:66:\"Select on which event you want to evaluate conditions and actions.\";b:1;s:48:\"The conf
iguration has been provided by a module.\";b:1;s:8:\"Inactive\";b:1;s:5:\"None.\";b:1;s:6:\"Module\";b:1;s:13:\"Configuration\";b:1;s:16:\"Filter by module\";b:1;s:14:\"Og: Group name\";b:1;s:16:\"Og: Group nid(s)\";b:1;s:72:\"Calendar view of any date field, add a date f
ield to the view to use it.\";b:1;s:44:\"This allows you to filter by a machine name.\";b:1;s:7:\"Machine\";b:1;s:21:\"States: State machine\";b:1;s:37:\"Sort after the state machine\'s state.\";b:1;s:36:\"Sort after the state machine\'s name.\";b:1;s:46:\"This field disp
lays the state machine\'s state.\";b:1;s:27:\"States: State machine state\";b:1;s:45:\"This field displays the state machine\'s name.\";b:1;s:19:\"human readable name\";b:1;s:21:\"machine readable name\";b:1;s:26:\"States: State machine name\";b:1;s:38:\"Og: Post in speci
fied groups (by name)\";b:1;s:39:\"Og: Post in specified group (by number)\";b:1;s:38:\"Restrict groups to specific languages.\";b:1;s:11:\"Invite Only\";b:1;s:9:\"Moderated\";b:1;s:4:\"Open\";b:1;s:49:\"Displays the language selected for a given group.\";b:1;s:27:\"Og: G
roup: Post Count *New*\";b:1;s:3:\"All\";b:1;s:21:\"Og: Group: Post Count\";b:1;s:30:\"Show the title of this content\";b:1;s:8:\"Is story\";b:1;s:7:\"Is page\";b:1;s:44:\"Print the content title of pages and stories\";b:1;s:38:\"Generate state change events for users\";b
:1;s:42:\"Generate state change events for new users\";b:1;s:42:\"Generate state change events for new nodes\";b:1;s:38:\"Generate state change events for nodes\";b:1;s:30:\"Event %label has been invoked.\";b:1;s:3:\"AND\";b:1;s:2:\"OR\";b:1;s:28:\"User is going to view a
page\";b:1;s:22:\"deleted comment author\";b:1;s:15:\"deleted comment\";b:1;s:24:\"Comment has been deleted\";b:1;s:22:\"updated comment author\";b:1;s:15:\"updated comment\";b:1;s:24:\"Comment has been updated\";b:1;s:24:\"commented content author\";b:1;s:17:\"commented
content\";b:1;s:22:\"created comment author\";b:1;s:15:\"created comment\";b:1;s:24:\"Comment has been created\";b:1;s:15:\"logged out user\";b:1;s:19:\"User has logged out\";b:1;s:14:\"logged in user\";b:1;s:18:\"User has logged in\";b:1;s:12:\"deleted user\";b:1;s:21:\

Every MySQL query is being logged, including the whole cache!

So it seems to be every string on the site getting thrown into the binary log, including our gigantic modules page (I see all the ERP stuff going by - Enterprise Resource Planning, that is certainly not in use)

Are there other, better ways

Would we really be churning out a gigabyte of MySQL queries every couple days with every transaction logged?

Well at least there's an error toward the top of this output chunk:

s:6:\"Olivia\";b:1;s:12:\"Pink Plastic\";b:1;s:12:\"Shiny Tomato\";b:1;s:8:\"Teal Top\";b:1;s:19:\"PostgreSQL database\";b:1;s:20:\"Buil
t-in GD2 toolkit\";b:1;s:59:\"The built-in GD2 toolkit is installed and working properly.\";b:1;s:12:\"JPEG quality\";b:1;s:1:\"%\";b:1;
s:30:\"Currently using !item !version\";b:1;s:18:\"Edit primary links\";b:1;s:27:\"Operating in off-line mode.\";b:1;s:8:\"« first\";b:1
;s:12:\"� previous\";b:1;s:8:\"next �\";b:1;s:7:\"last »\";b:1;s:16:\"Go to first page\";b:1;s:15:\"Go to last page\";b:1;s:18:\"Go to p
age @number\";b:1;s:10:\"sort by @s\";b:1;s:28:\"Parse error. Not well formed\";b:1;s:37:\"Parse error. Request not well formed.\";b:1;s
:60:\"Server error. Invalid XML-RPC. Request must be a methodCall.\";b:1;s:57:\"Server error. Requested method %methodname not specified
.\";b:1;s:48:\"Server error. Wrong number of method parameters.\";b:1;s:40:\"Server error. Invalid method parameters.\";b:1;s:56:\"Serve
r error. Requested function %method does not exist.\";b:1;s:36:\"Invalid syntax for system.multicall.\";b:1;s:50:\"Recursive calls to sy
stem.multicall are forbidden.\";b:1;s:67:\"Server error. Requested method %methodname signature not specified.\";b:1;s:12:\"Color scheme
\";b:1;s:6:\"Custom\";b:1;s:9:\"Color set\";b:1;s:10:\"Base color\";b:1;s:10:\"Link color\";b:1;s:10:\"Header top\";b:1;s:13:\"Header bo
ttom\";b:1;s:10:\"Text color\";b:1;s:13:\"Not installed\";b:1;s:10:\"GD library\";b:1;s:40:\"No help is available for module %module.\";
b:1;s:28:\"@module administration pages\";b:1;s:4:\"help\";b:1;s:13:\"Legacy filter\";b:1;s:67:\"Replaces URLs from Drupal 4.1 (and lowe
r) with updated equivalents.\";b:1;s:39:\"Failed to notify pingomatic.com (site).\";b:1;s:14:\"directory ping\";b:1;s:4:\"ping\";b:1;s:1
9:\"By !author at @date\";b:1;s:9:\"chameleon\";b:1;s:6:\"header\";b:1;s:6:\"footer\";b:1;s:22:\"Submitted by !a on @b.\";b:1;s:15:\"Ski
p navigation\";b:1;s:15:\"News aggregator\";b:1;s:8:\"Add feed\";b:1;s:12:\"Remove items\";b:1;s:12:\"Update items\";b:1;s:7:\"Sources\"
;b:1;s:9:\"OPML feed\";b:1;s:10:\"Categorize\";b:1;s:9:\"Edit feed\";b:1;s:13:\"Edit category\";b:1;s:43:\"Items shown in sources and ca
tegories pages\";b:1;s:29:\"Discard news items older than\";b:1;s:67:\"Older news items will be automatically discarded. Requires cronta
b.\";b:1;s:23:\"Category selection type\";b:1;s:10:\"checkboxes\";b:1;s:17:\"multiple selector\";b:1;s:28:\"!title category latest items
\";b:1;s:24:\"!title feed latest items\";b:1;s:29:\"Number of news items in block\";b:1;s:29:\"View this feed\'s recent news.\";b:1;s:33
:\"View this category\'s recent news.\";b:1;s:71:\"A category named %category already exists. Please enter a unique title.\";b:1;s:40:\"
The category %category has been updated.\";b:1;s:27:\"Category %category deleted.\";b:1;s:40:\"The category %category has been deleted.\
";b:1;s:25:\"Category %category added.\";b:1;s:38:\"The category %category has been added.\";b:1;s:36:\"The fully-qualified URL of the f
eed.\";b:1;s:15:\"Update interval\";b:1;s:21:\"Categorize news items\";b:1;s:63:\"A feed named %feed already exists. Please enter a uniq
ue title.\";b:1;s:68:\"A feed with this URL %url already exists. Please enter a unique URL.\";b:1;s:

Despite the "error" it's pretty clear this is simply logging every string on the site, including strings on the language page, and I think it is really the multilingual capabilities of the site that is throwing all this into the database, and therefore the update cache statement.

Is it enough to explain a gigabyte every couple days?

Could the devel module be flushing the cache without us asking it to? Does visiting and submitting the modules page do that? How about translating strings?

Because I'm still getting reams of text.

Haven't yet seen the queries for nodes and such that I assume are more common, although we'd only see saving, updating, and deleting queries in the binary log.

Aha! Now I'm seeing German scroll by. And German translations of countries and languages.

Yeah, there's probably a gigabyte of just the twenty or so enabled languages translating each other into their own language ;-)

While going through the log, the site stopped working! Did a quick:

0 stedile:/var/log/mysql# rm -f mysql-bin.00012*
0 stedile:/var/log/mysql# rm -f mysql-bin.00013*

To ditch the 120 and 130 series of logs, and both pages that were stuck loaded. That was sort of fun.

Agaric has now gone through the MySQL binary query log to see what filled it up and stopped the site, and it appears to just be the large number of UI strings and their translations being saved and updated into the temporary cache.

Next question, for production sites, is there a way to turn off MySQL's binary logging for a given table? There's no need to recreate cache tables, so we don't need to save updates to them.

For now we'll just move what's saved from 10 days to 4:

0 stedile:/# vi /etc/mysql/my.cnf
/expire_log
expire_logs_days        = 4

If we want to turn it off entirely, Agaric understands that to involve commenting out both expire _log_days and this line:

log_bin                 = /var/log/mysql/mysql-bin.log

We further assume that by "bin_log" they meant "log_bin"-- hey, I'm dyslexic too.

# WARNING: Using expire_logs_days without bin_log crashes the server! See README.Debian!

Resolution