[MDEV-18867] Long Time to Stop and Start - Jira

XML

Word

Printable

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Major
Resolution: Fixed
Affects Version/s: 10.0, 10.1, 10.2.14, 10.3, 10.4
Fix Version/s: 10.2.35, 10.3.26, 10.4.16, 10.5.7
Component/s: Full-text Search, Storage Engine - InnoDB, Storage Engine - XtraDB
Labels:
Environment:

Hide
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.

Show
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

- Sort By Name
- Sort By Date
- Ascending
- Descending
- Thumbnails
- List
- Download All

gbd.txt
2019-03-10 12:15
22 kB
Michael Caplan
gdb-startup.txt
2019-03-10 15:57
22 kB
Michael Caplan
globalstatus.txt
2019-03-09 03:05
57 kB
Michael Caplan
globalvars.txt
2019-03-09 03:05
75 kB
Michael Caplan
innodbstatus.txt
2019-03-09 03:05
12 kB
Michael Caplan
my.cnf
2019-03-09 03:05
2 kB
Michael Caplan
startup1.txt
2019-03-14 06:09
43 kB
Michael Caplan
startup2.txt
2019-03-14 06:09
43 kB
Michael Caplan
startup3.txt
2019-03-14 06:09
43 kB
Michael Caplan

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

Activity

People

Assignee:: Thirunarayanan Balathandayuthapani

Reporter:: Michael Caplan

Votes:: 2 Vote for this issue

Watchers:: 8 Start watching this issue

Dates

Created:: 2019-03-09 03:05

Updated:: 2023-11-02 13:27

Resolved:: 2020-09-10 08:55

Git Integration

Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.