Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
10.2.14, 10.0(EOL), 10.1(EOL), 10.3(EOL), 10.4(EOL)
-
Linux 4.4.0-112-generic #135-Ubuntu SMP Fri Jan 19 11:48:36 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux
I'm running 10.2.14, with roughly 300GB data (1000K +/- tables). 95% tables are innodb. I have 64GB RAM, with INNODB buffer pool size set to 46GB (full my.cnf attached). The OS is Ubuntu 16.04.4. This is a dedicated MariaDB server.Linux 4.4.0-112-generic #135-Ubuntu SMP Fri Jan 19 11:48:36 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux I'm running 10.2.14, with roughly 300GB data (1000K +/- tables). 95% tables are innodb. I have 64GB RAM, with INNODB buffer pool size set to 46GB (full my.cnf attached). The OS is Ubuntu 16.04.4. This is a dedicated MariaDB server.
Description
Restart times where great with 10.2.14, until I recently enabled FTS on thousands of tables. Shutdown and startup both take over an hour. This, coupled with MariaDB eating up far greater sums of allocated memory in my.cnf, I need to restart every few few days or risk hitting the OOM Killer.
Shutdown example pulled from my log (16 minutes):
2019-03-07 20:20:28 140185257170688 [Note] /usr/sbin/mysqld (initiated by: unknown): Normal shutdown
|
2019-03-07 20:20:28 140185257170688 [Note] Event Scheduler: Purging the queue. 0 events
|
2019-03-07 20:20:35 140185550460672 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table.
|
2019-03-07 20:20:44 140185550460672 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table.
|
2019-03-07 20:20:48 140185550460672 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table.
|
.... (hundreds more)
|
2019-03-07 20:30:24 140185550460672 [Note] InnoDB: FTS optimize thread exiting.
|
2019-03-07 20:31:02 140185257170688 [Note] InnoDB: Starting shutdown...
|
2019-03-07 20:31:02 140185299834624 [Note] InnoDB: Dumping buffer pool(s) to /var/lib/mysql/ib_buffer_pool
|
2019-03-07 20:31:02 140185299834624 [Note] InnoDB: Instance 0, restricted to 73728 pages due to innodb_buf_pool_dump_pct=25
|
2019-03-07 20:31:03 140185299834624 [Note] InnoDB: Instance 1, restricted to 73728 pages due to innodb_buf_pool_dump_pct=25
|
2019-03-07 20:31:04 140185299834624 [Note] InnoDB: Instance 2, restricted to 73728 pages due to innodb_buf_pool_dump_pct=25
|
2019-03-07 20:31:05 140185299834624 [Note] InnoDB: Instance 3, restricted to 73728 pages due to innodb_buf_pool_dump_pct=25
|
2019-03-07 20:31:06 140185299834624 [Note] InnoDB: Instance 4, restricted to 73728 pages due to innodb_buf_pool_dump_pct=25
|
2019-03-07 20:31:07 140185299834624 [Note] InnoDB: Instance 5, restricted to 73728 pages due to innodb_buf_pool_dump_pct=25
|
2019-03-07 20:31:09 140185299834624 [Note] InnoDB: Instance 6, restricted to 73728 pages due to innodb_buf_pool_dump_pct=25
|
2019-03-07 20:31:10 140185299834624 [Note] InnoDB: Instance 7, restricted to 73728 pages due to innodb_buf_pool_dump_pct=25
|
2019-03-07 20:31:12 140185299834624 [Note] InnoDB: Buffer pool(s) dump completed at 190307 20:31:12
|
2019-03-07 20:36:36 140185257170688 [Note] InnoDB: Shutdown completed; log sequence number 3123967291460
|
2019-03-07 20:36:36 140185257170688 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
|
2019-03-07 20:36:43 140185257170688 [Note] /usr/sbin/mysqld: Shutdown complete
|
Startup (close to 1 hour):
2019-03-07 20:38:36 140573848283328 [Note] Using unique option prefix 'myisam-recover' is error-prone and can break in the future. Please use the full name 'myisam-recover-options' instead.
|
2019-03-07 20:38:37 140573848283328 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
|
2019-03-07 20:38:37 140573848283328 [Note] InnoDB: Uses event mutexes
|
2019-03-07 20:38:37 140573848283328 [Note] InnoDB: Compressed tables use zlib 1.2.8
|
2019-03-07 20:38:37 140573848283328 [Note] InnoDB: Using Linux native AIO
|
2019-03-07 20:38:37 140573848283328 [Note] InnoDB: Number of pools: 1
|
2019-03-07 20:38:37 140573848283328 [Note] InnoDB: Using SSE2 crc32 instructions
|
2019-03-07 20:38:37 140573848283328 [Note] InnoDB: Initializing buffer pool, total size = 46G, instances = 8, chunk size = 128M
|
2019-03-07 20:38:37 140573848283328 [Note] InnoDB: Setting NUMA memory policy to MPOL_INTERLEAVE
|
2019-03-07 20:38:38 140573848283328 [Note] InnoDB: Setting NUMA memory policy to MPOL_DEFAULT
|
2019-03-07 20:38:38 140573848283328 [Note] InnoDB: Completed initialization of buffer pool
|
2019-03-07 20:38:38 140520675911424 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
|
2019-03-07 20:38:38 140573848283328 [Note] InnoDB: Highest supported file format is Barracuda.
|
2019-03-07 21:31:01 140573848283328 [Note] InnoDB: 128 out of 128 rollback segments are active.
|
2019-03-07 21:31:01 140573848283328 [Note] InnoDB: Creating shared tablespace for temporary tables
|
2019-03-07 21:31:01 140573848283328 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
|
2019-03-07 21:31:01 140573848283328 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
|
2019-03-07 21:31:02 140573848283328 [Note] InnoDB: Waiting for purge to start
|
2019-03-07 21:31:02 140573848283328 [Note] InnoDB: 5.7.21 started; log sequence number 3123967291460
|
2019-03-07 21:31:02 140521824470784 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
|
2019-03-07 21:31:02 140573848283328 [Note] Plugin 'FEEDBACK' is disabled.
|
2019-03-07 21:31:02 140573848283328 [Note] Server socket created on IP: '::'.
|
2019-03-07 21:31:02 140573848283328 [Warning] 'user' entry 'root@usaddxprdsqlpm1' ignored in --skip-name-resolve mode.
|
2019-03-07 21:31:02 140573848283328 [Warning] 'proxies_priv' entry '@% root@usaddxprdsqlpm1' ignored in --skip-name-resolve mode.
|
2019-03-07 21:31:02 140573848283328 [Note] Reading of all Master_info entries succeded
|
2019-03-07 21:31:02 140573848283328 [Note] Added new Master_info '' to hash table
|
2019-03-07 21:31:02 140573848283328 [Note] /usr/sbin/mysqld: ready for connections.
|
Version: '10.2.14-MariaDB-10.2.14+maria~xenial-log' socket: '/var/run/mysqld/mysqld.sock' port: 3306 mariadb.org binary distribution
|
Attachments
Issue Links
- relates to
-
MDEV-18936 Purge thread fails to exit on shutdown
-
- Closed
-
-
MDEV-13869 MariaDB slow start
-
- Closed
-
-
MDEV-18518 Implement atomic multi-table (or multi-partition) CREATE TABLE for InnoDB
-
- Closed
-
-
MDEV-28706 ALTER TABLE ... FORCE harvests 1879: Upgrade index name failed,
-
- Closed
-
While working on this, thiru noticed that the upgrade logic for a Windows-specific bug that was introduced in MySQL 5.6 and fixed in 2013 in MySQL 5.6.16 is costing significant time. The only GA version of MariaDB that is affected by this bug is MariaDB Server 10.0.10. The fix was included in MariaDB Server 10.0.11 already. I think that it is extremely unlikely that someone would only now, after quite some time of 10.0 being at its end-of-life, upgrade straight from 10.0.10 to the newest 10.2, 10.3, 10.4, 10.5, or later release. Hence, it should be acceptable to remove some logic around DICT_TF2_FTS_AUX_HEX_NAME in an effort to speed up the startup.
The first step of my previous comment was not obvious even to me when I was re-reading it now. Yes, there is no dict_table_t::id or dict_index_t::id available in fil_space_t. But, those ID are encoded in the fil_space_t::name of the FTS_*.ibd tablespace! So, we can collect them from there. The last step of constructing the table name from the pair of (TABLE_ID, ID) should now be obvious as well (just invoke snprintf()).