Not user what is currently going on. Restarting our slave. Last start process was around an hour. This time around I'm at close to 2 hours and still waiting. According to gbd, looks it is stuck in storage/innobase/fts/fts0fts.cc:6870 fts_check_and_drop_orphaned_tables. Not sure if I hit some infinite loop.... Oh boy! On 2019-03-08 10:44 p.m., Michael Caplan wrote:
Hi Marko,
Hope it is okay to resurrect this thread. 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.
Any ideas?
Thanks
Mike
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
On 2018-01-16 2:35 p.m., Marko Mäkelä wrote:
Hi Mike,
I will use MDEV-13869 MariaDB slow start <https://jira.mariadb.org/browse/MDEV-13869> for tracking this fix. The fix is not as trivial as I thought; I got some of my corruption-injection tests failing. Furthermore, I think that in MariaDB 10.2+, we could remove the extended checks also when crash recovery is needed, to avoid unnecessarily long downtime. That one is the already mentioned MDEV-9843 <https://jira.mariadb.org/browse/MDEV-9843>InnoDB hangs on startup… <https://jira.mariadb.org/browse/MDEV-9843>. Related to that, there is also MDEV-14481 Execute InnoDB crash recovery in the background <https://jira.mariadb.org/browse/MDEV-14481> which we could have in MariaDB 10.4 or maybe even earlier.
Best regards,
Marko