Re: Optimize Table and Flush Table contention on different databases
Hi Aftab,
After reading your last reply, I ran some tests with varying the number of open files compared with the ulimit -n.
On production:
table_cache = 1024
Open_tables = 1024
Open_files = 2048
open_files_limit = 2558.
max_connections = 500.
ulimit -n = 1024.
Based on the above information, I thought the problem might have to do with the number of open files compared with the ulimit -n value. I thought that if the open_files was below the ulimit -n value, that the processes would not contend with each other.
Back to my test box...
Once I began testing, I realized missed a step in my previous tests which the results were placed on this thread. So, I started over. Here is what I tested and what I found.
Situation:
When I run a mysqlhotcopy on database_A and an OPTIMIZE TABLE table_b on database_B, there is contention between the two. Basically, while the FLUSH TABLES A.table_a, A.table_b, ... is running during the time the OPTIMIZE TABLE B.table_b is running, these processes appear stuck.
In test, the processes eventually finish, at the exact same time. This would take anywhere from 15min - 45min. This would depend on the OPTIMIZE TABLE statement.
In production, we have not been able to let the process finish due to time issues. The longest we let these run, before killing the process, was about 3 hours.
Based on the documentation, mysqlhotcopy first locks all the tables in the databases READ. It then runs a FLUSH TABLES on all the tables in the database. In my previous email, I had missed the LOCK READ step.
For each test I did the following:
1- Deleted about 30% of data from B.table_b.
2- On database_A, I LOCK all the tables READ.
3- On database_A, I FLUSH TABLES to those exact tables I had LOCKED READ
-- Steps 2 and 3 take less than 2 seconds [if the delete is running or not]
4- When the delete finishes, I run OPTIMIZE TABLE B.table_b.
5- While 4 is running, I run [2] again. [2] completes in about 1 second.
6- I run [3] again.
-- At this point both the OPTIMIZE [2] and FLUSH [6 or 3] are running, on different databases. They both complete at the same time - about 25min.
I would expect that the FLUSH would complete in the 1 second, as it did when the OPTIMIZE was not running.
The constants for my tests are:
table_cache = 1024.
max_connections = 500. [though I am on a test server with only my connections...]
TEST 1 --> The value of open_files [2050] was more than the ulimit -n [1024].
TEST 2 --> The value of open_files [64] was less than the ulimit -n [1024].
In both of these tests my experiences were the same. The FLUSH would complete with the OPTIMIZE, in about 25 min.
You mentioned in your first reply:
"it is certainly not possible to for both FLUSH TABLE statment and OPTIMIZE TABLE statement to wait for each other. However it is possible if you run OPITMIZE TABLE on a big table and after a while you run FLUSH TABLES command, in this case FLUSH TABLES statement will wait for optimize table command to end."
I am running OPTIMIZE TABLE on a big table [relative - 5G]. I did run FLUSH TABLES A.tble_a, A.tble_b. You state [above] that the FLUSH will wait. Did you mean if I ran FLUSH TABLES and not if I was flushing individual tables? Do you believe this is what I am experiencing? If yes, then why did this not happen in V4.0.24 nor 4.1.11? Or, do you think we uncovered a bug? What do you think?
Here are the results from mysqladmin processlist as well as a SHOW GLOBAL STATUS like "Open%" for each TEST. You will notice that the processlist output are basically identical:
TEST 1:
mysql> show global status like "Open%";
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Open_files | 2050 |
| Open_streams | 0 |
| Open_tables | 1023 |
| Opened_tables | 42322 |
+---------------+-------+
4 rows in set (0.00 sec)
+----+--------+--------------+----------+---------+------+-----------------+------------------------------------------------------------------------------------------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+--------+--------------+----------+---------+------+-----------------+------------------------------------------------------------------------------------------------------+
| 1 | dbuser | blue50:59672 | | Sleep | 308 | | |
| 3 | dbuser | blue50:48361 | customer | Sleep | 2389 | | |
| 6 | dbuser | blue50:44208 | C19729 | Query | 1288 | Flushing tables | flush tables capture_objects, devlog, devlog_data, devlog_notes, devlog_summary, devlog_transfer, do |
| 7 | dbuser | blue50:44222 | C11116 | Query | 1366 | Sorting index | optimize table monitor_objects |
| 9 | dbuser | blue50:57284 | | Query | 0 | | show processlist |
+----+--------+--------------+----------+---------+------+-----------------+------------------------------------------------------------------------------------------------------+
+----+--------+--------------+----------+---------+------+-----------------+------------------------------------------------------------------------------------------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+--------+--------------+----------+---------+------+-----------------+------------------------------------------------------------------------------------------------------+
| 1 | dbuser | blue50:59672 | | Sleep | 314 | | |
| 3 | dbuser | blue50:48361 | customer | Sleep | 2395 | | |
| 6 | dbuser | blue50:44208 | C19729 | Query | 1294 | Flushing tables | flush tables capture_objects, devlog, devlog_data, devlog_notes, devlog_summary, devlog_transfer, do |
| 7 | dbuser | blue50:44222 | C11116 | Query | 1372 | Sorting index | optimize table monitor_objects |
| 9 | dbuser | blue50:57284 | | Query | 0 | | show processlist |
+----+--------+--------------+----------+---------+------+-----------------+------------------------------------------------------------------------------------------------------+
+----+--------+--------------+----------+---------+------+-------+------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+--------+--------------+----------+---------+------+-------+------------------+
| 1 | dbuser | blue50:59672 | | Sleep | 319 | | |
| 3 | dbuser | blue50:48361 | customer | Sleep | 2400 | | |
| 6 | dbuser | blue50:44208 | C19729 | Sleep | 1 | | |
| 7 | dbuser | blue50:44222 | C11116 | Sleep | 1 | | |
| 9 | dbuser | blue50:57284 | | Query | 0 | | show processlist |
+----+--------+--------------+----------+---------+------+-------+------------------+
TEST 2:
mysql> show global status like "Open%";
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Open_files | 64 |
| Open_streams | 0 |
| Open_tables | 45 |
| Opened_tables | 67 |
+---------------+-------+
4 rows in set (0.00 sec)
+----+--------+--------------+--------+---------+------+-----------------+------------------------------------------------------------------------------------------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+--------+--------------+--------+---------+------+-----------------+------------------------------------------------------------------------------------------------------+
| 1 | dbuser | blue50:54847 | C11116 | Query | 1112 | Sorting index | optimize table monitor_objects |
| 3 | dbuser | blue50:54857 | C19729 | Query | 1107 | Flushing tables | flush tables capture_objects, devlog, devlog_data, devlog_notes, devlog_summary, devlog_transfer, do |
| 4 | dbuser | blue50:56797 | | Query | 0 | | show processlist |
| 7 | dbuser | blue50:60711 | | Sleep | 564 | | |
+----+--------+--------------+--------+---------+------+-----------------+------------------------------------------------------------------------------------------------------+
+----+--------+--------------+--------+---------+------+-----------------+------------------------------------------------------------------------------------------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+--------+--------------+--------+---------+------+-----------------+------------------------------------------------------------------------------------------------------+
| 1 | dbuser | blue50:54847 | C11116 | Query | 1117 | Sorting index | optimize table monitor_objects |
| 3 | dbuser | blue50:54857 | C19729 | Query | 1112 | Flushing tables | flush tables capture_objects, devlog, devlog_data, devlog_notes, devlog_summary, devlog_transfer, do |
| 4 | dbuser | blue50:56797 | | Query | 0 | | show processlist |
| 7 | dbuser | blue50:60711 | | Sleep | 569 | | |
+----+--------+--------------+--------+---------+------+-----------------+------------------------------------------------------------------------------------------------------+
+----+--------+--------------+--------+---------+------+-----------------+------------------------------------------------------------------------------------------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+--------+--------------+--------+---------+------+-----------------+------------------------------------------------------------------------------------------------------+
| 1 | dbuser | blue50:54847 | C11116 | Sleep | 0 | | |
| 3 | dbuser | blue50:54857 | C19729 | Query | 1117 | Flushing tables | flush tables capture_objects, devlog, devlog_data, devlog_notes, devlog_summary, devlog_transfer, do |
| 4 | dbuser | blue50:56797 | | Query | 0 | | show processlist |
| 7 | dbuser | blue50:60711 | | Sleep | 574 | | |
+----+--------+--------------+--------+---------+------+-----------------+------------------------------------------------------------------------------------------------------+
+----+--------+--------------+--------+---------+------+-------+------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+--------+--------------+--------+---------+------+-------+------------------+
| 1 | dbuser | blue50:54847 | C11116 | Sleep | 5 | | |
| 3 | dbuser | blue50:54857 | C19729 | Sleep | 4 | | |
| 4 | dbuser | blue50:56797 | | Query | 0 | | show processlist |
| 7 | dbuser | blue50:60711 | | Sleep | 579 | | |
+----+--------+--------------+--------+---------+------+-------+------------------+
Regards,
Gabe