| Bug #110345 | MySQL crash on MacOS typically when restoring a MySQL 5.7 sql | ||
|---|---|---|---|
| Submitted: | 11 Mar 2023 21:50 | Modified: | 20 Apr 2023 21:01 |
| Reporter: | Steve Drew | Email Updates: | |
| Status: | Can't repeat | Impact on me: | |
| Category: | MySQL Server | Severity: | S2 (Serious) |
| Version: | 8.0.32 | OS: | MacOS (Ventura 13.0.1) |
| Assigned to: | CPU Architecture: | ARM | |
[11 Mar 2023 21:50]
Steve Drew
[13 Mar 2023 14:28]
MySQL Verification Team
Hi Mr. Drew, Thank you for your bug report. We also use macOS 13.0.1. We have also upgraded from latest 5.7 to the 8.0 release that you have cited above. However, we have never, ever got the assertion. There are many other bug reports with assertions in the the open tables, but not a single one that had problems with hashing functions ....... That means that your table is quite corrupted. What you can try to do is to make another copy of that table. First use mysqldump to get a backup copy of the 8.0 version of the table. Then, you should try to find 5.7 version of that table, mysqldump it , drop the current 8.0 problematic table and then restore it by running the SQL script obtained by mysqldump. You will find all this explained in detail in our Reference Manual. Can't repeat.
[13 Mar 2023 15:29]
MySQL Verification Team
Hi, On another thought, we wonder whether you can upload the original 5.7 table that crashes. If not, then 8.0.32 dump of that table ?????
[13 Mar 2023 21:56]
Steve Drew
I dont think that is the problem as after recovering I can import the same file again with no issues. It has happened with many different import files. Now I always restart MySql before I do an import and so far have prevented the crash.
[14 Mar 2023 12:59]
MySQL Verification Team
Hi, Can you send us 8.0 mysqldump output from the problematic 8.0 table?? Please, use "Files" tab for the upload.
[14 Mar 2023 14:11]
MySQL Verification Team
Mr. Drew, Also, please, let us know what happens if you import the mysqldump file, without restarting MySQL server ??? Let us know which commands should we run on MySQL server, prior to the restore of that table, so that we also see a crash, as in your stacktrace !!!!!! Waiting on your full feedback.
[15 Mar 2023 17:55]
MySQL Verification Team
Hi, > It typically happens after I restore a database How are you restoring the database? Do you run SQL to create and populate database or you are restoring from binary files? If you are copying datadir where do you copy it from?
[15 Mar 2023 18:55]
Jakub Lopuszanski
Hi! I have a question. Does your error log contain a line about `lower_case_table_names=2`, like this one: 2023-03-15T01:31:50.082266Z 0 [Warning] [MY-010159] [Server] Setting lower_case_table_names=2 because file system for /System/Volumes/Data/export/home/pb2/var/mtr-12192/var-meb/6/mysqld.1/data/ is case insensitive
[16 Mar 2023 13:29]
MySQL Verification Team
Hi Mr. Drew, We truly need some answers from you ........ Can you try to send us 8.0 mysqldump output from the problematic 8.0 table?? Please, use "Files" tab for the upload. Also, please, let us know what happens if you import the mysqldump file, without restarting MySQL server ??? Let us know which commands should we run on MySQL server, prior to the restore of that table, so that we also see a crash, as in your stacktrace !!!!!! We are still waiting on your full feedback.
[16 Mar 2023 23:03]
Steve Drew
I am doing a mysqldump from 5.7 eg: mysqldump mydb >mydb.sql Then on Mysql 8.0 mysql -e "create database mydb" mysql <mydb.sql I do not know which table to dump. and cannot even get mysql started after this occurs. Except if I use innodb_force_recovery = 6. I do not see any messages regarding lower case names in the log file. It has not happened in a few days. I will keep testing and see if there is a way I can reproduce. my.cnf file is as follows. sql_mode = "NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,NO_ENGINE_SUBSTITUTION" port = 3306 socket = /tmp/mysql.sock innodb_file_per_table = 1 innodb_log_file_size = 100M innodb_buffer_pool_instances = 4 innodb_buffer_pool_size = 2GB innodb_flush_log_at_trx_commit=2 group_concat_max_len = 10240 interactive_timeout = 300 wait_timeout = 300 table_open_cache = 800 max_allowed_packet = 50M tmp_table_size = 8M max_heap_table_size = 64M max_connections = 280 innodb_lock_wait_timeout = 20 thread_stack = 10M
[17 Mar 2023 10:02]
Jakub Lopuszanski
Hi Steve Drew, thanks for the details shared so far. I need more specific info, though: 1. Does the sql dump contain any table with at least one upper-case letter in its name (or name of the database)? 2. What is the file system you use to store the data-dir of the MySQL 8.0? In paticular: is it case insensitive? 3. Can you share full error log file (or at least everything from the moment mysqld is started for the last time before crash) from a crash incident?
[17 Mar 2023 13:07]
MySQL Verification Team
Mr. Drew, If you manage to repeat the problem, please upload the dump.
[20 Apr 2023 21:00]
Steve Drew
It occurred again after restoring a mysql 5.7.34 dump file. 2023-03-21T19:07:05.786088Z 0 [System] [MY-010931] [Server] /opt/homebrew/opt/mysql/bin/mysqld: ready for connections. Version: '8.0.32' socket: '/tmp/mysql.sock' port: 3306 Homebrew. 2023-04-04T00:40:07.478283Z 28569 [ERROR] [MY-013183] [InnoDB] Assertion failure: dict0dict.cc:1223:table2 == nullptr thread 0x2c4963000 InnoDB: We intentionally generate a memory trap. InnoDB: Submit a detailed bug report to http://bugs.mysql.com. InnoDB: If you get repeated assertion failures or crashes, even InnoDB: immediately after the mysqld startup, there may be InnoDB: corruption in the InnoDB tablespace. Please refer to InnoDB: http://dev.mysql.com/doc/refman/8.0/en/forcing-innodb-recovery.html InnoDB: about forcing recovery. 2023-04-04T00:40:07Z UTC - mysqld got signal 6 ; Most likely, you have hit a bug, but this error can also be caused by malfunctioning hardware. Thread pointer: 0x13fe47c00 Attempting backtrace. You can use the following information to find out where mysqld died. If you see no messages after this, something went terribly wrong... stack_bottom = 2c4962f28 thread_stack 0xa00000 0 mysqld 0x000000010563bbe8 my_print_stacktrace(unsigned char const*, unsigned long) + 68 1 mysqld 0x0000000104df31b0 print_fatal_signal(int) + 572 2 mysqld 0x0000000104df33b4 my_server_abort() + 88 3 mysqld 0x0000000105636544 my_abort() + 20 4 mysqld 0x000000010590ca30 ut_dbg_assertion_failed(char const*, char const*, unsigned long long) + 400 5 mysqld 0x00000001056e016c ut::hash_string(char const*) + 0 6 mysqld 0x00000001056fdca4 dict_table_t* dd_open_table_one<dd::Table>(dd::cache::Dictionary_client*, TABLE const*, char const*, dd::Table const*, THD*, std::__1::deque<char const*, ut::allocator<char const*, ut::detail::allocator_base_pfs<char const*> > >&) + 5088 7 mysqld 0x00000001056eda78 dict_table_t* dd_open_table<dd::Table>(dd::cache::Dictionary_client*, TABLE const*, char const*, dd::Table const*, THD*) + 60 8 mysqld 0x00000001057974f0 ha_innobase::open(char const*, int, unsigned int, dd::Table const*) + 400 9 mysqld 0x0000000104a3bbdc handler::ha_open(TABLE*, char const*, int, int, dd::Table const*) + 100 10 mysqld 0x0000000104d9ad1c open_table_from_share(THD*, TABLE_SHARE*, char const*, unsigned int, unsigned int, unsigned int, TABLE*, bool, dd::Table const*) + 2412 11 mysqld 0x0000000104c56f74 open_table(THD*, Table_ref*, Open_table_context*) + 2364 12 mysqld 0x0000000104c5a524 open_tables(THD*, Table_ref**, unsigned int*, unsigned int, Prelocking_strategy*) + 596 13 mysqld 0x0000000104c5c394 open_tables_for_query(THD*, Table_ref*, unsigned int) + 108 14 mysqld 0x0000000104d19438 Sql_cmd_dml::prepare(THD*) + 336 15 mysqld 0x0000000104d19a3c Sql_cmd_dml::execute(THD*) + 372 16 mysqld 0x0000000104cda338 mysql_execute_command(THD*, bool) + 3852 17 mysqld 0x0000000104cd858c dispatch_sql_command(THD*, Parser_state*) + 740 18 mysqld 0x0000000104cd7520 dispatch_command(THD*, COM_DATA const*, enum_server_command) + 5468 19 mysqld 0x0000000104cd7cb8 do_command(THD*) + 364 20 mysqld 0x0000000104de1764 handle_connection(void*) + 476 21 mysqld 0x000000010596d370 pfs_spawn_thread(void*) + 288 22 libsystem_pthread.dylib 0x0000000188daa06c _pthread_start + 148 23 libsystem_pthread.dylib 0x0000000188da4e2c thread_start + 8 Trying to get some variables. Some pointers may be invalid and cause the dump to abort.
[20 Apr 2023 21:01]
Steve Drew
Sorry this is actually the latest one. 2023-04-13T03:11:22.404667Z 0 [System] [MY-010931] [Server] /opt/homebrew/opt/mysql/bin/mysqld: ready for connections. Version: '8.0.32' socket: '/tmp/mysql.sock' port: 3306 Homebrew. 2023-04-20T20:50:12.570662Z 17038 [ERROR] [MY-013183] [InnoDB] Assertion failure: dict0dict.cc:1223:table2 == nullptr thread 0x319e2b000 InnoDB: We intentionally generate a memory trap. InnoDB: Submit a detailed bug report to http://bugs.mysql.com. InnoDB: If you get repeated assertion failures or crashes, even InnoDB: immediately after the mysqld startup, there may be InnoDB: corruption in the InnoDB tablespace. Please refer to InnoDB: http://dev.mysql.com/doc/refman/8.0/en/forcing-innodb-recovery.html InnoDB: about forcing recovery. 2023-04-20T20:50:12Z UTC - mysqld got signal 6 ; Most likely, you have hit a bug, but this error can also be caused by malfunctioning hardware. Thread pointer: 0x1151af200 Attempting backtrace. You can use the following information to find out where mysqld died. If you see no messages after this, something went terribly wrong... stack_bottom = 319e2af28 thread_stack 0xa00000 0 mysqld 0x0000000104fe3be8 my_print_stacktrace(unsigned char const*, unsigned long) + 68 1 mysqld 0x000000010479b1b0 print_fatal_signal(int) + 572 2 mysqld 0x000000010479b3b4 my_server_abort() + 88 3 mysqld 0x0000000104fde544 my_abort() + 20 4 mysqld 0x00000001052b4a30 ut_dbg_assertion_failed(char const*, char const*, unsigned long long) + 400 5 mysqld 0x000000010508816c ut::hash_string(char const*) + 0 6 mysqld 0x00000001050a5ca4 dict_table_t* dd_open_table_one<dd::Table>(dd::cache::Dictionary_client*, TABLE const*, char const*, dd::Table const*, THD*, std::__1::deque<char const*, ut::allocator<char const*, ut::detail::allocator_base_pfs<char const*> > >&) + 5088 7 mysqld 0x0000000105095a78 dict_table_t* dd_open_table<dd::Table>(dd::cache::Dictionary_client*, TABLE const*, char const*, dd::Table const*, THD*) + 60 8 mysqld 0x000000010513f4f0 ha_innobase::open(char const*, int, unsigned int, dd::Table const*) + 400 9 mysqld 0x00000001043e3bdc handler::ha_open(TABLE*, char const*, int, int, dd::Table const*) + 100 10 mysqld 0x0000000104742d1c open_table_from_share(THD*, TABLE_SHARE*, char const*, unsigned int, unsigned int, unsigned int, TABLE*, bool, dd::Table const*) + 2412 11 mysqld 0x00000001045fef74 open_table(THD*, Table_ref*, Open_table_context*) + 2364 12 mysqld 0x0000000104602524 open_tables(THD*, Table_ref**, unsigned int*, unsigned int, Prelocking_strategy*) + 596 13 mysqld 0x0000000104604394 open_tables_for_query(THD*, Table_ref*, unsigned int) + 108 14 mysqld 0x00000001046c1438 Sql_cmd_dml::prepare(THD*) + 336 15 mysqld 0x00000001046c1a3c Sql_cmd_dml::execute(THD*) + 372 16 mysqld 0x0000000104682338 mysql_execute_command(THD*, bool) + 3852 17 mysqld 0x000000010468058c dispatch_sql_command(THD*, Parser_state*) + 740 18 mysqld 0x000000010467f520 dispatch_command(THD*, COM_DATA const*, enum_server_command) + 5468 19 mysqld 0x000000010467fcb8 do_command(THD*) + 364 20 mysqld 0x0000000104789764 handle_connection(void*) + 476 21 mysqld 0x0000000105315370 pfs_spawn_thread(void*) + 288 22 libsystem_pthread.dylib 0x000000019e04606c _pthread_start + 148 23 libsystem_pthread.dylib 0x000000019e040e2c thread_start + 8 Trying to get some variables. Some pointers may be invalid and cause the dump to abort. Query (12313de30): select SType.id, SType.Created, SType.CreatedBy, SType.LastModified, SType.LastModifiedBy, SType.IsDeleted, SType.Queue_id, SType.Name, SType.Description, SType.Details, SType.DisplayOrder, SType.Color, SType.ColorHex, SType.Duration, SType.MinAdvancedCancelHours, SType.MinAdvancedBookingHours, SType.MaxAdvancedBookingDays, SType.AllowBooking, SType.AllowOnlineBooking, SType.AllowOnlineJoin, SType.AllowKioskJoin, SType.KioskAskMeetMethod, SType.Enabled, SType.Category_id, SType.ServicePriority, SType.RequiredWaiver_id, SType.NextServiceType_id, SType.NextServiceTypeStage, SType.IncreasePriorityMins, SType.IncreasePriority, SType.ForceArrived, SType.EnableOnlineMeeting, SType.EnableMeetsMeeting, SType.EnableZoomMeeting, SType.EnableAttachment, SType.AttachmentRequired, SType.AttachmentLabel, SType.RedirectToServiceType_id, SType.UseBusinessHours, SType.MethodInPerson, SType.MethodByPhone, SType.MethodOnline, SType.EnableMeetingMethods, SType.DisableMessages, Queue.QueueName as QueueName, Connection ID (thread ID): 17038 Status: NOT_KILLED
[21 Apr 2023 8:44]
Jakub Lopuszanski
So, IIUC, please correct me if I am wrong: 1. There were at least several days since the server was started til the day it crashed. In the first log we see started 2023-03-21 -> crashed 2023-04-04 In the second log we see started 2023-04-13 -> crashed 2023-04-20 2. There are no log entries, even benign ones, before "ready for connections" 3. The first log does not contain any hint about the SQL query being executed 4. The second log hints that the problem might involve a table named SType (although we only see a prefix of the SQL so it's not clear to me if that is a name of table, a view, or an alias). It definitely involves a table named QueueName, though. If so, then the query which crashed the server involves at least one table which has at least one upper-case letter in its name: QueueName. Questions: Q1. were QueueName or SType among the tables imported from 5.7.34 dump? Q2. do you think it is possible that these tables were not referenced by any query before the crash? Q3. can you please check the 5.7.34 dump file to see how the QueueName table was referred to in it exactly - was it QueueName, queuename, Queuename? Q4. could you please check how the *.ibd file for QueueName on disc in the data-dir is named? Ideally a full path would be helpful.
[21 Apr 2023 12:35]
MySQL Verification Team
Hi Mr. Drew, We agree with all questions that are posed by Mr. Jakub Lopuszanski . We would just like to note that a stacktrace is similar to the one that you posted at the start of this report. We would also like to remind you NOT to use mixed-case table names on the macOS. It is simply unreliable, which is a fault of the OS and not of MySQL. We can not go further without a full test case. If we would have one, then we will have to replace one VERY long macro with a function or method , in order to diagnose it. It is quite possible that macOS returns the filename with lower case only ....... We are waiting on your feedback.
