Viraj's Weblog

Since implementing mod_log_sql for a client, I've come across some interesting issues that required a bit of MySQL tuning.

The way mod_log_sql works is each Apache process makes a connection to the MySQL server. This means the MySQL server must be able to theoretically support n * MaxClients connections where n is the number of webservers. In my case, that value turns out to be 2048. That's alot of connections! The default limit is 100. MySQL 4+ supports setting these sort of variables without restarting the server with a command such as:

set global max_connections=2048;

The other thing I am sure would be required is MySQL's INSERT DELAYED feature. This allows inserts to occur while the table is locked by another process. MySQL does not provide row-level locking on MyISAM tables. I envision the users using these apache log tables quite a bit, and didn't want that to slow down inserts. I had used insert delayed in the past in a spam filter I wrote for CommuniGate Pro. Insert delayed is still a work in progress in the version of mod_log_sql I'm using, so I ended up going to the C code and changing the inserts to 'insert delayed' syntax and recompiling.

When I did the above changes I thought it would be the end of the story. Then came the next problem. The tables are growing fairly large, about 3gigs a week. This is much more than text logs because text logs are usually compressed. So I had to setup some sort of archival scheme. I was testing some pruning SQL statements. The tables don't have indexes, and certain queries were taking minutes. I thought, that's ok, because I'm using insert delayed. Soon, I started noticing the webservers reporting the following whenever I was working on the tables:

[Sat Nov 12 10:04:46 2005] [error] mod_log_sql_mysql: database connection error: mysql error: Too many connections
[Sat Nov 12 10:04:46 2005] [error] mod_log_sql: child spawned but unable to open database link

Huh? How could locking the table cause >2048 connections attempting to be made? This could be a bad design of mod_log_sql, but I thought there has to be some other issue underlying the problem. I did a:

show variables like '%delayed%';

Which showed:

| delayed_insert_limit       | 100   |
| delayed_insert_timeout     | 300   |
| delayed_queue_size         | 100   |
| max_delayed_threads        | 20    |
| max_insert_delayed_threads | 20    |

Hmm, not knowing what these actually do and not finding too much documentation on them I tried increasing delayed_insert_limit, but that didn't do anything and I still got the connection errors. Then I thought, let me try reproducing the problem by locking the table and watching the output of 'show status' for any clues in the 'delayed' variables. So in one window I did:

lock tables access_table read;

And in another I did:

mysql> show status like '%delay%';
+--------------------------+----------+
| Variable_name            | Value    |
+--------------------------+----------+
| Delayed_errors           | 0        |
| Delayed_insert_threads   | 6        |
| Delayed_writes           | 15583200 |
| Not_flushed_delayed_rows | 5        |
+--------------------------+----------+
4 rows in set (0.00 sec)

I did this a few times and noticed Not_flushed_delayed_rows increasing rapidly, which makes sense since I locked the table and insert delayed queries are being queued. As soon as it got to 100, Apache was reporting the connection errors. That clearly told me 100 was a limit somewhere. It wasn't delayed_insert_limit since I tried increasing that already, so I tried increasing delayed_queued_limit. That was it. 'queued' should have pointed that out to me . I changed it to a much larger value (10000) and everything seems smooth now.

These can be set in /etc/my.cnf with lines like:

[mysqld]
datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock
set-variable=max_connections=2048
set-variable=delayed_queue_size=10000