MySQL Bugs: #69419: Undocumented and untested table_open_cache table_definition

Bug #69419	Undocumented and untested table_open_cache table_definition_cache default change
Submitted:	7 Jun 2013 7:04	Modified:	26 Aug 2013 14:08
Reporter:	Laurynas Biveinis (OCA)	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Options	Severity:	S2 (Serious)
Version:	5.6.12	OS:	Any
Assigned to:		CPU Architecture:	Any
Tags:	table_definition_cache, table_open_cache

Description:
5.6.12 appears to change table_open_cache default from 2000 to 431 and table_definition_cache from 1400 to 615.  

This is not documented, makes 4 MTR tests fail consistently (don't you see it in your runs?), and probably was not intended.

Probably a side effect of the commit below, which says nothing about changing the defaults.

$ bzr log -r 4948
------------------------------------------------------------
revno: 4948
committer: Marc Alff <marc.alff@oracle.com>
branch nick: mysql-5.6-bug16430532
timestamp: Fri 2013-03-22 20:12:50 +0100
message:
  Bug#16430532 WRONG SIZING HINTS USED IN THE PERFORMANCE SCHEMA
  
  Before this fix, the server did perform the following actions during 
  startup.
  
  1) 
  Retrieve the value of
  - max_connections
  - table_definition_cache
  - table_open_cache
  - open_files_limit
  from the user configuration provided in my.cnf,
  and use this settings as a base to compute 
  performance_schema auto sized variables.
  
  2)
  Then, later in the startup process:
  - max_connections could be trimmed down
  - table_definition_cache default value could be changed
  - open_files_limit could be either computed (replacing the 0 value) or 
    adjusted.
  
  Because of the order used, the performance schema automated sizing 
  was based on incorrect data.
  
  With this fix, the server startup code has been changed to perform part 2) 
  first, and only when all the proper sizing parameters are finally computed 
  and adjusted, then perform the performance schema initialization in part 1)
  
  Also, the code performing 2) has been cleaned up to be maintainable.
  Clarity in this complicated process (due to related dependencies between 
  configuration settings) is critical here.

How to repeat:
./mysql-test-run table_definition_cache_basic table_open_cache_basic table_definition_cache_functionality table_open_cache_functionality

sys_vars.table_definition_cache_basic    [ fail ]
        Test ended at 2013-06-07 10:05:10

CURRENT_TEST: sys_vars.table_definition_cache_basic
--- /home/laurynas/percona/src/5.6/mysql-test/suite/sys_vars/r/table_definition_cache_basic.result	2013-04-15 16:52:51.433990000 +0300
+++ /home/laurynas/percona/src/5.6/obj/mysql-test/var/log/table_definition_cache_basic.reject	2013-06-07 10:05:10.437632860 +0300
@@ -1,7 +1,7 @@
 SET @start_value = @@global.table_definition_cache;
 SELECT @start_value;
 @start_value
-1400
+615
 '#--------------------FN_DYNVARS_019_01------------------------#'
 SET @@global.table_definition_cache = 100;
 Warnings:
@@ -9,12 +9,12 @@
 SET @@global.table_definition_cache = DEFAULT;
 SELECT @@global.table_definition_cache;
 @@global.table_definition_cache
-1400
+615
 '#---------------------FN_DYNVARS_019_02-------------------------#'
 SET @@global.table_definition_cache = DEFAULT;
 SELECT @@global.table_definition_cache = 1400;
 @@global.table_definition_cache = 1400
-1
+0
 '#--------------------FN_DYNVARS_019_03------------------------#'
 SET @@global.table_definition_cache = 1;
 Warnings:
@@ -108,4 +108,4 @@
 SET @@global.table_definition_cache = @start_value;
 SELECT @@global.table_definition_cache;
 @@global.table_definition_cache
-1400
+615

mysqltest: Result content mismatch

sys_vars.table_open_cache_basic          [ fail ]
        Test ended at 2013-06-07 10:06:08

CURRENT_TEST: sys_vars.table_open_cache_basic
--- /home/laurynas/percona/src/5.6/mysql-test/suite/sys_vars/r/table_open_cache_basic.result	2013-04-15 16:52:51.433990000 +0300
+++ /home/laurynas/percona/src/5.6/obj/mysql-test/var/log/table_open_cache_basic.reject	2013-06-07 10:06:08.793632303 +0300
@@ -1,7 +1,7 @@
 SET @start_value = @@global.table_open_cache ;
 SELECT @start_value;
 @start_value
-2000
+431
 '#--------------------FN_DYNVARS_001_01------------------------#'
 SET @@global.table_open_cache  = 99;
 SET @@global.table_open_cache  = DeFAULT;
@@ -104,4 +104,4 @@
 SET @@global.table_open_cache = @start_value;
 SELECT @@global.table_open_cache ;
 @@global.table_open_cache
-2000
+431

mysqltest: Result content mismatch

main.table_definition_cache_functionality [ fail ]
        Test ended at 2013-06-07 10:06:47

CURRENT_TEST: main.table_definition_cache_functionality
--- /home/laurynas/percona/src/5.6/mysql-test/r/table_definition_cache_functionality.result	2013-04-15 16:52:51.433990000 +0300
+++ /home/laurynas/percona/src/5.6/obj/mysql-test/var/log/table_definition_cache_functionality.reject	2013-06-07 10:06:47.357631935 +0300
@@ -9,7 +9,7 @@
 SET @@GLOBAL.table_definition_cache=DEFAULT;
 SELECT @@GLOBAL.table_definition_cache;
 @@GLOBAL.table_definition_cache
-1400
+615
 1400 Expected
 '#---------------------WL6372_VAR_5_02----------------------#'
 # Restart server with table_definition_cache 1
@@ -20,7 +20,7 @@
 SET @@GLOBAL.table_definition_cache=DEFAULT;
 SELECT @@GLOBAL.table_definition_cache;
 @@GLOBAL.table_definition_cache
-1400
+615
 1400 Expected
 '#---------------------WL6372_VAR_5_03----------------------#'
 SET @@local.table_definition_cache=1;
@@ -33,7 +33,7 @@
 SET @@GLOBAL.table_definition_cache=DEFAULT;
 SELECT @@GLOBAL.table_definition_cache;
 @@GLOBAL.table_definition_cache
-1400
+615
 1400 Expected
 '#---------------------WL6372_VAR_5_04----------------------#'
 SELECT @@GLOBAL.table_definition_cache = VARIABLE_VALUE

mysqltest: Result content mismatch

main.table_open_cache_functionality      [ fail ]
        Test ended at 2013-06-07 10:07:32

CURRENT_TEST: main.table_open_cache_functionality
--- /home/laurynas/percona/src/5.6/mysql-test/r/table_open_cache_functionality.result	2013-04-15 16:52:51.433990000 +0300
+++ /home/laurynas/percona/src/5.6/obj/mysql-test/var/log/table_open_cache_functionality.reject	2013-06-07 10:07:32.073631509 +0300
@@ -8,7 +8,7 @@
 1 Expected
 SELECT @@GLOBAL.table_open_cache;
 @@GLOBAL.table_open_cache
-2000
+431
 2000 Expected
 '#---------------------WL6372_VAR_5_02----------------------#'
 # Restart server with table_open_cache 1

mysqltest: Result content mismatch

So the difference between 5.6.11 and 5.6.12 is that 5.6.11 adjusts max connections and table cache size only if open_files_limit == 0, and 5.6.12 does that unconditionally.

This patch restores the 5.6.11 behavior and fixes the testcase failures. Not minimal due to functions moving around, but its gist is to move adjust_max_connections() and adjust_table_cache_size() calls from adjust_related_options() to the open_files_limit == 0 part of adjust_open_files_limit().

=== modified file 'sql/mysqld.cc'
--- sql/mysqld.cc	2013-04-09 05:05:18 +0000
+++ sql/mysqld.cc	2013-06-07 08:34:17 +0000
@@ -6713,6 +6713,47 @@
   return ho_error;
 }
 
+static void adjust_max_connections()
+{
+  ulong limit;
+
+  limit= open_files_limit - 10 - TABLE_OPEN_CACHE_MIN * 2;
+
+  if (limit < max_connections)
+  {
+    char msg[1024];
+
+    snprintf(msg, sizeof(msg),
+             "Changed limits: max_connections: %lu (requested %lu)",
+             limit, max_connections);
+    buffered_logs.buffer(WARNING_LEVEL, msg);
+
+    max_connections= limit;
+  }
+}
+
+void adjust_table_cache_size()
+{
+  ulong limit;
+
+  limit= max<ulong>((open_files_limit - 10 - max_connections) / 2,
+                    TABLE_OPEN_CACHE_MIN);
+
+  if (limit < table_cache_size)
+  {
+    char msg[1024];
+
+    snprintf(msg, sizeof(msg),
+             "Changed limits: table_cache: %lu (requested %lu)",
+             limit, table_cache_size);
+    buffered_logs.buffer(WARNING_LEVEL, msg);
+
+    table_cache_size= limit;
+  }
+
+  table_cache_size_per_instance= table_cache_size / table_cache_instances;
+}
+
 /**
   Adjust @c open_files_limit.
   Computation is  based on:
@@ -6759,6 +6800,8 @@
                "Changed limits: max_open_files: %lu (requested %lu)",
                effective_open_files, request_open_files);
       buffered_logs.buffer(WARNING_LEVEL, msg);
+      adjust_max_connections();
+      adjust_table_cache_size();
     }
     else
     {
@@ -6773,47 +6816,6 @@
   open_files_limit= effective_open_files;
 }
 
-void adjust_max_connections()
-{
-  ulong limit;
-
-  limit= open_files_limit - 10 - TABLE_OPEN_CACHE_MIN * 2;
-
-  if (limit < max_connections)
-  {
-    char msg[1024];
-
-    snprintf(msg, sizeof(msg),
-             "Changed limits: max_connections: %lu (requested %lu)",
-             limit, max_connections);
-    buffered_logs.buffer(WARNING_LEVEL, msg);
-
-    max_connections= limit;
-  }
-}
-
-void adjust_table_cache_size()
-{
-  ulong limit;
-
-  limit= max<ulong>((open_files_limit - 10 - max_connections) / 2,
-                    TABLE_OPEN_CACHE_MIN);
-
-  if (limit < table_cache_size)
-  {
-    char msg[1024];
-
-    snprintf(msg, sizeof(msg),
-             "Changed limits: table_cache: %lu (requested %lu)",
-             limit, table_cache_size);
-    buffered_logs.buffer(WARNING_LEVEL, msg);
-
-    table_cache_size= limit;
-  }
-
-  table_cache_size_per_instance= table_cache_size / table_cache_instances;
-}
-
 void adjust_table_def_size()
 {
   longlong default_value;
@@ -6836,8 +6838,6 @@
 
   /* The order is critical here, because of dependencies. */
   adjust_open_files_limit();
-  adjust_max_connections();
-  adjust_table_cache_size();
   adjust_table_def_size();
 }

Hello Laurynas,

Thank you for the report.
Verified as described.

Thanks,
Umesh

// 5.6.12 

mysql> show global variables like 'table%';
+----------------------------+-------+
| Variable_name              | Value |
+----------------------------+-------+
| table_definition_cache     | 615   |
| table_open_cache           | 431   |
| table_open_cache_instances | 1     |
+----------------------------+-------+
3 rows in set (0.00 sec)

Docs say othgerwise -  http://dev.mysql.com/doc/refman/5.6/en/server-system-variables.html#sysvar_table_open_cach...

//mtr results

[ushastry@ushastry mysql-test]$ ./mysql-test-run table_open_cache_basic
Logging: ./mysql-test-run  table_open_cache_basic
2013-06-07 15:20:28 22047 [Warning] Buffered warning: Changed limits: max_open_files: 1024 (requested 5000)

2013-06-07 15:20:28 22047 [Warning] Buffered warning: Changed limits: table_cache: 431 (requested 2000)

2013-06-07 15:20:28 22047 [Note] Plugin 'FEDERATED' is disabled.
2013-06-07 15:20:28 22047 [Note] Binlog end
2013-06-07 15:20:28 22047 [Note] Shutting down plugin 'CSV'
2013-06-07 15:20:28 22047 [Note] Shutting down plugin 'MyISAM'
MySQL Version 5.6.12
Checking supported features...
 - SSL connections supported
 - binaries are debug compiled
Collecting tests...
Checking leftover processes...
Removing old var directory...
Creating var directory '/home/ushastry/mybuilds/mysql-5.6.12-release/mysql-test/var'...
Installing system database...
Using server port 52305

==============================================================================

TEST                                      RESULT   TIME (ms) or COMMENT
--------------------------------------------------------------------------

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
sys_vars.table_open_cache_basic          [ fail ]
        Test ended at 2013-06-07 15:20:33

CURRENT_TEST: sys_vars.table_open_cache_basic
--- /home/ushastry/mybuilds/mysql-5.6.12-release/mysql-test/suite/sys_vars/r/table_open_cache_basic.result	2013-06-07 12:07:26.537254000 +0300
+++ /home/ushastry/mybuilds/mysql-5.6.12-release/mysql-test/var/log/table_open_cache_basic.reject	2013-06-07 12:50:33.109208308 +0300
@@ -1,7 +1,7 @@
 SET @start_value = @@global.table_open_cache ;
 SELECT @start_value;
 @start_value
-2000
+431
 '#--------------------FN_DYNVARS_001_01------------------------#'
 SET @@global.table_open_cache  = 99;
 SET @@global.table_open_cache  = DeFAULT;
@@ -104,4 +104,4 @@
 SET @@global.table_open_cache = @start_value;
 SELECT @@global.table_open_cache ;
 @@global.table_open_cache
-2000
+431

mysqltest: Result content mismatch

 - saving '/home/ushastry/mybuilds/mysql-5.6.12-release/mysql-test/var/log/sys_vars.table_open_cache_basic/' to '/home/ushastry/mybuilds/mysql-5.6.12-release/mysql-test/var/log/sys_vars.table_open_cache_basic/'
--------------------------------------------------------------------------
The servers were restarted 0 times
Spent 0.000 of 6 seconds executing testcases

Completed: Failed 1/1 tests, 0.00% were successful.

Failing test(s): sys_vars.table_open_cache_basic

The log files in var/log may give you some hint of what went wrong.

If you want to report this error, please read first the documentation
at http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html

mysql-test-run: *** ERROR: there were failing test cases

//mtr test results

[ushastry@ushastry mysql-test]$ ./mysql-test-run table_definition_cache_functionality
Logging: ./mysql-test-run  table_definition_cache_functionality
2013-06-07 15:21:01 22106 [Warning] Buffered warning: Changed limits: max_open_files: 1024 (requested 5000)

2013-06-07 15:21:01 22106 [Warning] Buffered warning: Changed limits: table_cache: 431 (requested 2000)

2013-06-07 15:21:01 22106 [Note] Plugin 'FEDERATED' is disabled.
2013-06-07 15:21:01 22106 [Note] Binlog end
2013-06-07 15:21:01 22106 [Note] Shutting down plugin 'CSV'
2013-06-07 15:21:01 22106 [Note] Shutting down plugin 'MyISAM'
MySQL Version 5.6.12
Checking supported features...
 - SSL connections supported
 - binaries are debug compiled
Collecting tests...
Checking leftover processes...
Removing old var directory...
Creating var directory '/home/ushastry/mybuilds/mysql-5.6.12-release/mysql-test/var'...
Installing system database...
Using server port 53874

==============================================================================

TEST                                      RESULT   TIME (ms) or COMMENT
--------------------------------------------------------------------------

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
main.table_definition_cache_functionality [ fail ]
        Test ended at 2013-06-07 15:21:10

CURRENT_TEST: main.table_definition_cache_functionality
--- /home/ushastry/mybuilds/mysql-5.6.12-release/mysql-test/r/table_definition_cache_functionality.result	2013-06-07 12:07:26.537254000 +0300
+++ /home/ushastry/mybuilds/mysql-5.6.12-release/mysql-test/var/log/table_definition_cache_functionality.reject	2013-06-07 12:51:09.958161779 +0300
@@ -9,7 +9,7 @@
 SET @@GLOBAL.table_definition_cache=DEFAULT;
 SELECT @@GLOBAL.table_definition_cache;
 @@GLOBAL.table_definition_cache
-1400
+615
 1400 Expected
 '#---------------------WL6372_VAR_5_02----------------------#'
 # Restart server with table_definition_cache 1
@@ -20,7 +20,7 @@
 SET @@GLOBAL.table_definition_cache=DEFAULT;
 SELECT @@GLOBAL.table_definition_cache;
 @@GLOBAL.table_definition_cache
-1400
+615
 1400 Expected
 '#---------------------WL6372_VAR_5_03----------------------#'
 SET @@local.table_definition_cache=1;
@@ -33,7 +33,7 @@
 SET @@GLOBAL.table_definition_cache=DEFAULT;
 SELECT @@GLOBAL.table_definition_cache;
 @@GLOBAL.table_definition_cache
-1400
+615
 1400 Expected
 '#---------------------WL6372_VAR_5_04----------------------#'
 SELECT @@GLOBAL.table_definition_cache = VARIABLE_VALUE

mysqltest: Result content mismatch

 - saving '/home/ushastry/mybuilds/mysql-5.6.12-release/mysql-test/var/log/main.table_definition_cache_functionality/' to '/home/ushastry/mybuilds/mysql-5.6.12-release/mysql-test/var/log/main.table_definition_cache_functionality/'
--------------------------------------------------------------------------
The servers were restarted 0 times
Spent 0.000 of 9 seconds executing testcases

Completed: Failed 1/1 tests, 0.00% were successful.

Failing test(s): main.table_definition_cache_functionality

The log files in var/log may give you some hint of what went wrong.

If you want to report this error, please read first the documentation
at http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html

mysql-test-run: *** ERROR: there were failing test cases
[ushastry@ushastry mysql-test]$ ./mysql-test-run table_open_cache_functionality
Logging: ./mysql-test-run  table_open_cache_functionality
2013-06-07 15:21:54 22200 [Warning] Buffered warning: Changed limits: max_open_files: 1024 (requested 5000)

2013-06-07 15:21:54 22200 [Warning] Buffered warning: Changed limits: table_cache: 431 (requested 2000)

2013-06-07 15:21:54 22200 [Note] Plugin 'FEDERATED' is disabled.
2013-06-07 15:21:54 22200 [Note] Binlog end
2013-06-07 15:21:54 22200 [Note] Shutting down plugin 'CSV'
2013-06-07 15:21:54 22200 [Note] Shutting down plugin 'MyISAM'
MySQL Version 5.6.12
Checking supported features...
 - SSL connections supported
 - binaries are debug compiled
Collecting tests...
Checking leftover processes...
Removing old var directory...
Creating var directory '/home/ushastry/mybuilds/mysql-5.6.12-release/mysql-test/var'...
Installing system database...
Using server port 51601

==============================================================================

TEST                                      RESULT   TIME (ms) or COMMENT
--------------------------------------------------------------------------

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
main.table_open_cache_functionality      [ fail ]
        Test ended at 2013-06-07 15:22:03

CURRENT_TEST: main.table_open_cache_functionality
--- /home/ushastry/mybuilds/mysql-5.6.12-release/mysql-test/r/table_open_cache_functionality.result	2013-06-07 12:07:26.537254000 +0300
+++ /home/ushastry/mybuilds/mysql-5.6.12-release/mysql-test/var/log/table_open_cache_functionality.reject	2013-06-07 12:52:02.818398209 +0300
@@ -8,7 +8,7 @@
 1 Expected
 SELECT @@GLOBAL.table_open_cache;
 @@GLOBAL.table_open_cache
-2000
+431
 2000 Expected
 '#---------------------WL6372_VAR_5_02----------------------#'
 # Restart server with table_open_cache 1

mysqltest: Result content mismatch

 - saving '/home/ushastry/mybuilds/mysql-5.6.12-release/mysql-test/var/log/main.table_open_cache_functionality/' to '/home/ushastry/mybuilds/mysql-5.6.12-release/mysql-test/var/log/main.table_open_cache_functionality/'
--------------------------------------------------------------------------
The servers were restarted 0 times
Spent 0.000 of 9 seconds executing testcases

Completed: Failed 1/1 tests, 0.00% were successful.

Failing test(s): main.table_open_cache_functionality

The log files in var/log may give you some hint of what went wrong.

If you want to report this error, please read first the documentation
at http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html

mysql-test-run: *** ERROR: there were failing test cases

My suggested fix missed that 

table_cache_size_per_instance= table_cache_size / table_cache_instances;

must happen in all the code paths, regardless whether table_cache_size was adjusted or not.

The default has not changed, but 5.6.12 added some auto-adjustment based on the system limit for open files per process. If this limit is less that 4161, the calculated adjusted max. value of table_open_cache will be lower than the default of 2000.

This causes a few tests checking the default setting to potentially fail, depending on your OS settings. If the open_files limit is larger that 4161, the tests pass, and they did in 5.6.12 release testing. One fix for this is to amend those tests so they skip (with an explanation as to why) if the open_files limit is, say, less than 5000.

This new-in-5.6.12 adjustment of variables with open file limit < 4161, if it was intended, is still undocumented - I checked both 5.6.12 change notes and e.g. https://dev.mysql.com/doc/refman/5.6/en/server-system-variables.html#sysvar_table_open_cac... lists a single unconditional default value. As this is an user-visible change, it should be documented.

Assuming that the 5.6.12 behavior and not the 5.6.11 one is intended, then maybe a better way to fix the tests for low-ulimit machines would be not to disable them but rather (idea credit to Alexey Kopytov)

-SELECT @@GLOBAL.table_definition_cache;
+SELECT IF (@@open_files_limit < 5000, 1400, @@GLOBAL.table_definition_cache);

This has the advantage that the tests are still run everywhere, only the default check is skipped where it should be.

I will upload a SCA contribution patch shortly. 

Of course the docs still need clarification.

Bug 69419 patch (*) I confirm the code being submitted is offered under the terms of the OCA, and that I am authorized to contribute it.

Contribution: bug69419.patch (text/x-diff), 9.82 KiB.

Ignore the "Percona-Server" in the diff paths, it applies cleanly with -p1 to the current public 5.6.

Thanks for the patch, that indeed looks like it is a better solution. I was just about to comment that I had filed Bug #69524 yesterday to track the test fix as such (not yet pushed), leaving this bug for discussing the variable settings.

I will look at using your patch instead.

The tests were fixed in 5.6.13 using the contributed solution. I was on vacation when 5.6.13 was prepared for release; sorry for forgetting to close the bug.

Changes to test suite. No changelog entry needed.
Thanks to Laurynas Biveinis for the patch.

Will update the docs to indicate that table_open_cache
is autosized at startup.