[MDEV-11688] fil_crypt_threads_end() tries to create threads after aborted InnoDB startup Created: 2016-12-30  Updated: 2017-08-11  Resolved: 2017-01-03

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.1.21, 10.2.4
Fix Version/s: 10.1.21, 10.2.4

Type: Bug Priority: Minor
Reporter: Elena Stepanova Assignee: Marko Mäkelä
Resolution: Fixed Votes: 0
Labels: None

Issue Links:
Relates
relates to MDEV-12905 InnoDB occasionally skips the doublew... Closed

 Description   
  • start server with innodb_flush_method value which is not on the list of valid values, e.g. 

    --innodb-flush-method=foo

    or

    --innodb-flush-method=


2016-12-30 12:30:57 140008187467648 [ERROR] InnoDB: Unrecognized value  for innodb_flush_method
 
2016-12-30 12:30:57 140008187467648 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[1602] with error Generic error
 
2016-12-30 12:30:57 0x7f5632479780  InnoDB: Assertion failure in thread 140008187467648 in file sync0types.h line 885
 
InnoDB: Failing assertion: static_cast<size_t>(id) < latch_meta.size()
 
 
 
#5  0x00007f562e7e3448 in __GI_abort () at abort.c:89
 
#6  0x00007f5631992995 in ut_dbg_assertion_failed (expr=0x7f5631e79308 "static_cast<size_t>(id) < latch_meta.size()", file=0x7f5631e792a0 "/data/src/10.2/storage/innobase/include/sync0types.h", line=885) at /data/src/10.2/storage/innobase/ut/ut0dbg.cc:67
 
#7  0x00007f56317d7e5f in sync_latch_get_meta (id=LATCH_ID_FIL_CRYPT_THREADS_MUTEX) at /data/src/10.2/storage/innobase/include/sync0types.h:885
 
#8  0x00007f56317d7f05 in sync_latch_get_pfs_key (id=LATCH_ID_FIL_CRYPT_THREADS_MUTEX) at /data/src/10.2/storage/innobase/include/sync0types.h:935
 
#9  0x00007f56317d8e81 in PolicyMutex<TTASEventMutex<GenericPolicy> >::init (this=0x7f56328118c0 <fil_crypt_threads_mutex>, id=LATCH_ID_FIL_CRYPT_THREADS_MUTEX, filename=0x7f5631f0c830 "/data/src/10.2/storage/innobase/fil/fil0crypt.cc", line=2453) at /data/src/10.2/storage/innobase/include/ib0mutex.h:698
 
#10 0x00007f56317d869b in mutex_init<PolicyMutex<TTASEventMutex<GenericPolicy> > > (mutex=0x7f56328118c0 <fil_crypt_threads_mutex>, id=LATCH_ID_FIL_CRYPT_THREADS_MUTEX, file_name=0x7f5631f0c830 "/data/src/10.2/storage/innobase/fil/fil0crypt.cc", line=2453) at /data/src/10.2/storage/innobase/include/ut0mutex.h:185
 
#11 0x00007f5631aa3ccf in fil_crypt_threads_init () at /data/src/10.2/storage/innobase/fil/fil0crypt.cc:2453
 
#12 0x00007f5631aa3a25 in fil_crypt_set_thread_cnt (new_cnt=0) at /data/src/10.2/storage/innobase/fil/fil0crypt.cc:2381
 
#13 0x00007f5631aa3d03 in fil_crypt_threads_end () at /data/src/10.2/storage/innobase/fil/fil0crypt.cc:2470
 
#14 0x00007f5631931c24 in srv_shutdown_all_bg_threads () at /data/src/10.2/storage/innobase/srv/srv0start.cc:1229
 
#15 0x00007f563193208f in srv_init_abort_low (create_new_db=false, file=0x7f5631ec2ee8 "/data/src/10.2/storage/innobase/srv/srv0start.cc", line=1602, err=DB_ERROR) at /data/src/10.2/storage/innobase/srv/srv0start.cc:1353
 
#16 0x00007f56319329b4 in innobase_start_or_create_for_mysql () at /data/src/10.2/storage/innobase/srv/srv0start.cc:1602
 
#17 0x00007f56317618d1 in innobase_init (p=0x7f562dc130f0) at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:4727
 
#18 0x00007f5631522e85 in ha_initialize_handlerton (plugin=0x7f562defc7f8) at /data/src/10.2/sql/handler.cc:512
 
#19 0x00007f56312d2df2 in plugin_initialize (tmp_root=0x7ffeec1239f0, plugin=0x7f562defc7f8, argc=0x7f563278bff0 <remaining_argc>, argv=0x7f562dc0e1a0, options_only=false) at /data/src/10.2/sql/sql_plugin.cc:1415
 
#20 0x00007f56312d399d in plugin_init (argc=0x7f563278bff0 <remaining_argc>, argv=0x7f562dc0e1a0, flags=2) at /data/src/10.2/sql/sql_plugin.cc:1690
 
#21 0x00007f56311e2213 in init_server_components () at /data/src/10.2/sql/mysqld.cc:5297
 
#22 0x00007f56311e3286 in mysqld_main (argc=12, argv=0x7f562dc0e1a0) at /data/src/10.2/sql/mysqld.cc:5886
 
#23 0x00007f56311d82f0 in main (argc=12, argv=0x7ffeec124738) at /data/src/10.2/sql/main.cc:25

Happens on 10.2 only. All other versions that I checked (MySQL 5.6.33, 5.7.13, MariaDB 5.5, 10.0, 10.1) just shut down with the regular

2016-12-30 12:30:44 140329872000896 [ERROR] InnoDB: Unrecognized value  for innodb_flush_method
 
2016-12-30 12:30:44 140329872000896 [ERROR] Plugin 'InnoDB' init function returned error.
 
2016-12-30 12:30:44 140329872000896 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
 
2016-12-30 12:30:44 140329872000896 [Note] Plugin 'FEEDBACK' is disabled.
 
2016-12-30 12:30:44 140329872000896 [ERROR] Unknown/unsupported storage engine: InnoDB
 
2016-12-30 12:30:44 140329872000896 [ERROR] Aborting

Which is of course nicer than the assertion failure.

(Although, it's also sad, because it means you cannot, for example, use the command line to unset the value that has been set in a config file; but I guess that's just how it works).

 Comments   
Comment by Marko Mäkelä [ 2016-12-30 ]

I wonder if --innodb-flush-method=default would cause any value that was specified in the config file to be forgotten.

That said, this bug is something much worse. I will try to fix it soon.

Comment by Elena Stepanova [ 2016-12-30 ]

I wonder if --innodb-flush-method=default would cause any value that was specified in the config file to be forgotten.

Not really, default fails in the same fashion:

2016-12-30 17:46:15 140513839458176 [ERROR] InnoDB: Unrecognized value default for innodb_flush_method
 
2016-12-30 17:46:15 140513839458176 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[1602] with error Generic error
 
2016-12-30 17:46:15 0x7fcbed7ca780  InnoDB: Assertion failure in thread 140513839458176 in file sync0types.h line 885
 
InnoDB: Failing assertion: static_cast<size_t>(id) < latch_meta.size()
 
I

Comment by Marko Mäkelä [ 2017-01-03 ]

This patch fixes this particular InnoDB problem:

diff --git a/storage/innobase/fil/fil0crypt.cc b/storage/innobase/fil/fil0crypt.cc
 
index fd1cc24c92a..708dbd0fd01 100644
 
--- a/storage/innobase/fil/fil0crypt.cc
 
+++ b/storage/innobase/fil/fil0crypt.cc
 
@@ -2458,8 +2458,9 @@ void
 
 fil_crypt_threads_end()
 
 /*===================*/
 
 {
 
-	/* stop threads */
 
-	fil_crypt_set_thread_cnt(0);
 
+	if (fil_crypt_threads_inited) {
 
+		fil_crypt_set_thread_cnt(0);
 
+	}
 
 }
 
 
 /*********************************************************************

I think that the same patch is necessary also for 10.1.

However, another problem (introduced by MDEV-5800) remains: thd_destructor_proxy() keeps waiting, causing

Error in my_thread_global_end(): 1 threads didn't exit
 
mysqld: /home/marko/mariadb/server/sql/mysqld.cc:2154: void mysqld_exit(int): Assertion `global_status_var.global_memory_used == 0' failed.

Comment by Marko Mäkelä [ 2017-01-03 ]

I filed MDEV-11710 for the remaining issue in 10.2.

Comment by Jan Lindström (Inactive) [ 2017-01-03 ]

ok to push.

Generated at Thu Feb 08 07:51:54 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.