Bug #19961 Row-Based Replication (slave) open_tables + open_files bug
Submitted: 19 May 2006 23:57 Modified: 21 Dec 2006 9:32
Reporter: Jeff C Email Updates:
Status: No Feedback Impact on me:
None 
Category:MySQL Server: Row Based Replication ( RBR ) Severity:S1 (Critical)
Version:5.1.9 OS:Linux (RHEL4)
Assigned to: CPU Architecture:Any

[19 May 2006 23:57] Jeff C 
Description:
Using row-based replication (rbr), periodically the slave will error out as it runs out of file handles... For the record, the slave is set to "unlimited"

When the master processes a lot of changes, depending on how many are processed at once will determine if the slave lives or not.  

Ocassionally, the slaves open_table/open_file counts will grow but then it's done processing and goes back to normal.  However, when there are too many events to be processed before it starts going back down, the slave will error out.

The mysqld.trace file shows;
open_table: info: inserting table 0xdc83ee0 into the cache
open_table: info: inserting table 0xdc87f68 into the cache
open_table: info: inserting table 0xdc8bff0 into the cache
open_table: info: inserting table 0xdc90078 into the cache
open_table: info: inserting table 0xdc94100 into the cache
open_table: info: inserting table 0xdc98188 into the cache
open_table: info: inserting table 0xdc9c210 into the cache
open_table: info: inserting table 0xdca0298 into the cache
open_table: info: inserting table 0xdca4320 into the cache
open_table: info: inserting table 0xdca83a8 into the cache
open_table: info: inserting table 0xdcac430 into the cache
open_table: info: inserting table 0xdcb04b8 into the cache
open_table: info: inserting table 0xdcb4540 into the cache
open_table: info: inserting table 0xdcb85c8 into the cache
open_table: info: inserting table 0xdcbc650 into the cache
open_table: info: inserting table 0xdcc06d8 into the cache
open_table: info: inserting table 0xdcc4760 into the cache
open_table: info: inserting table 0xdcc87e8 into the cache
open_table: info: inserting table 0xdccc870 into the cache
open_table: info: inserting table 0xdcd08f8 into the cache
open_table: info: inserting table 0xdcd4980 into the cache
open_table: info: inserting table 0xdcd8a08 into the cache
open_table: info: inserting table 0xdcdca90 into the cache
open_table: info: inserting table 0xdce0b18 into the cache
open_table: info: inserting table 0xdce4ba0 into the cache
open_table: info: inserting table 0xdce8c28 into the cache
open_table: info: inserting table 0xdceccb0 into the cache
open_table: info: inserting table 0xdcf0d38 into the cache
open_table: info: inserting table 0xdcf4dc0 into the cache
open_table: info: inserting table 0xdcf8e48 into the cache
open_table: info: inserting table 0xdcfced0 into the cache
open_table: info: inserting table 0xdd00f58 into the cache
close_thread_tables: info: thd->open_tables: 0xdd00f58
open_table: info: inserting table 0xa230828 into the cache
close_thread_tables: info: thd->open_tables: 0xa230828
open_table: info: inserting table 0xa22eaf0 into the cache
open_table: info: inserting table 0xa237208 into the cache
open_table: info: inserting table 0xa234f20 into the cache
open_table: info: inserting table 0xa2356c0 into the cache
open_table: info: inserting table 0xa1b8ce8 into the cache
open_table: info: inserting table 0xa23c358 into the cache
open_table: info: inserting table 0xa1d67d0 into the cache
open_table: info: inserting table 0xa1b9e18 into the cache
open_table: info: inserting table 0xa1e35e0 into the cache
open_table: info: inserting table 0xa1bc768 into the cache
open_table: info: inserting table 0xa1c16d0 into the cache
open_table: info: inserting table 0xa1caff8 into the cache
open_table: info: inserting table 0xa1c99a8 into the cache
open_table: info: inserting table 0xa1ca698 into the cache
open_table: info: inserting table 0xa1bfe38 into the cache
open_table: info: inserting table 0xa3851f0 into the cache
open_table: info: inserting table 0xa381168 into the cache
open_table: info: inserting table 0xa387f78 into the cache
open_table: info: inserting table 0xa388c68 into the cache
open_table: info: inserting table 0xa37a3d8 into the cache
open_table: info: inserting table 0xa3753a8 into the cache
open_table: info: inserting table 0xa376098 into the cache
open_table: info: inserting table 0xa372820 into the cache
open_table: info: inserting table 0xa364db0 into the cache
open_table: info: inserting table 0xa36bbb0 into the cache
open_table: info: inserting table 0xa36c8a0 into the cache
open_table: info: inserting table 0xa35e020 into the cache
open_table: info: inserting table 0xa354b90 into the cache
open_table: info: inserting table 0xa355880 into the cache
open_table: info: inserting table 0xa370928 into the cache
open_table: info: inserting table 0xa34e108 into the cache
open_table: info: inserting table 0xa34a2d8 into the cache
open_table: info: inserting table 0xa34ffb8 into the cache
open_table: info: inserting table 0xa341a58 into the cache
open_table: info: inserting table 0xa2063f0 into the cache
open_table: info: inserting table 0xa3389e8 into the cache
...

grep "open_table" mysqld.trace | wc -l 
65847

060519 21:14:01 [ERROR] Slave: Error 'File './prod/dark.MYD' not found (Errcode: 24)' on opening table `prod`.`dark`, Error_code: 29
060519 21:14:01 [Warning] Slave: File './prod/dark.MYD' not found (Errcode: 24) Error_code: 29
060519 21:14:01 [Warning] Slave: Got error 24 from storage engine Error_code: 1030
060519 21:14:01 [Warning] Slave: Unknown error Error_code: 1105
060519 21:14:01 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'new-bin.000001' position 2693119

How to repeat:
Have a database setup for RBR, and do a lot of inserts, updates, and deletes and watch the slave go down.
[19 May 2006 23:59] Jeff C 
This is 2 seconds between each query for a few seconds to show what is happening.

+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| Open_files             | 10    |
| Open_streams           | 0     |
| Open_table_definitions | 41    |
| Open_tables            | 49231 |
| Opened_tables          | 0     |
+------------------------+-------+
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| Open_files             | 10    |
| Open_streams           | 0     |
| Open_table_definitions | 41    |
| Open_tables            | 49231 |
| Opened_tables          | 0     |
+------------------------+-------+
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| Open_files             | 10    |
| Open_streams           | 0     |
| Open_table_definitions | 41    |
| Open_tables            | 49231 |
| Opened_tables          | 0     |
+------------------------+-------+
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| Open_files             | 10    |
| Open_streams           | 0     |
| Open_table_definitions | 41    |
| Open_tables            | 11557 |
| Opened_tables          | 0     |
+------------------------+-------+
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| Open_files             | 10    |
| Open_streams           | 0     |
| Open_table_definitions | 41    |
| Open_tables            | 3866  |
| Opened_tables          | 0     |
+------------------------+-------+
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| Open_files             | 10    |
| Open_streams           | 0     |
| Open_table_definitions | 41    |
| Open_tables            | 7240  |
| Opened_tables          | 0     |
+------------------------+-------+
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| Open_files             | 10    |
| Open_streams           | 0     |
| Open_table_definitions | 41    |
| Open_tables            | 9649  |
| Opened_tables          | 0     |
+------------------------+-------+
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| Open_files             | 10    |
| Open_streams           | 0     |
| Open_table_definitions | 41    |
| Open_tables            | 11659 |
| Opened_tables          | 0     |
+------------------------+-------+
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| Open_files             | 10    |
| Open_streams           | 0     |
| Open_table_definitions | 41    |
| Open_tables            | 13365 |
| Opened_tables          | 0     |
+------------------------+-------+
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| Open_files             | 10    |
| Open_streams           | 0     |
| Open_table_definitions | 41    |
| Open_tables            | 14882 |
| Opened_tables          | 0     |
+------------------------+-------+
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| Open_files             | 485   |
| Open_streams           | 0     |
| Open_table_definitions | 41    |
| Open_tables            | 3322  |
| Opened_tables          | 0     |
+------------------------+-------+
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| Open_files             | 1122  |
| Open_streams           | 0     |
| Open_table_definitions | 41    |
| Open_tables            | 7776  |
| Opened_tables          | 0     |
+------------------------+-------+
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| Open_files             | 1506  |
| Open_streams           | 0     |
| Open_table_definitions | 41    |
| Open_tables            | 10469 |
| Opened_tables          | 0     |
+------------------------+-------+
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| Open_files             | 1809  |
| Open_streams           | 0     |
| Open_table_definitions | 41    |
| Open_tables            | 12587 |
| Opened_tables          | 0     |
+------------------------+-------+
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| Open_files             | 2068  |
| Open_streams           | 0     |
| Open_table_definitions | 41    |
| Open_tables            | 14403 |
| Opened_tables          | 0     |
+------------------------+-------+
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| Open_files             | 2306  |
| Open_streams           | 0     |
| Open_table_definitions | 41    |
| Open_tables            | 16065 |
| Opened_tables          | 0     |
+------------------------+-------+
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| Open_files             | 2518  |
| Open_streams           | 0     |
| Open_table_definitions | 41    |
| Open_tables            | 17554 |
| Opened_tables          | 0     |
+------------------------+-------+
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| Open_files             | 2716  |
| Open_streams           | 0     |
| Open_table_definitions | 41    |
| Open_tables            | 18939 |
| Opened_tables          | 0     |
+------------------------+-------+
[21 May 2006 14:21] Valeriy Kravchuk 
Changed category to a more appropriate one.
[21 Jun 2006 18:14] Jeff C 
When will this bug be assigned to someone?  This bug prevents using RBR... one of the major new 5.1 features...

Thanks,
Jeff
[22 Jun 2006 10:05] Valeriy Kravchuk 
Thank you for a problem report. Please, try to repeat with a newer version, 5.1.11, and inform about the results.
[4 Jul 2006 16:39] Jeff C 
I will retry as soon as Bug ID: 17620 is fixed.  The bug has just been assigned so  hopefully it won't be too long before it's fixed.

I will be testing this on production, so I will need my query cache.

Thanks,
J.
[20 Sep 2006 16:44] Valeriy Kravchuk 
Therte is a patch for bug #17620. Will you try to apply it to 5.1.12-BK sources or prefer to wait for 5.1.12 to be released officially?
[21 Sep 2006 15:09] Jeff C 
I will wait until it's released officially and work with the binaries you provide.

Thanks,
Jeff
[21 Nov 2006 9:32] Valeriy Kravchuk 
Version 5.1.12 is already released officially (see http://dev.mysql.com/downloads/mysql/5.1.html). So, please, check if you can repeat the same behaviour with it.
[22 Dec 2006 0:00] Bugs System 
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".