Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-26325

mysqld process hangs when stopped after executing mysql_upgrade

Details

    • Bug
    • Status: Closed (View Workflow)
    • Blocker
    • Resolution: Fixed
    • 10.5.12
    • 10.5.13, 10.6.5
    • Server
    • Windows

    Description

      Steps to reproduce

      1. Initializing the MariaDB data directory 

        C:\Users\Administrator>C:\mariadb-10.5.12-winx64\bin\mysql_install_db.exe --datadir=C:\db --service=MyDB --password=secret
        		 
        Running bootstrap
        		 
        2021-08-09 17:56:17 0 [Note] C:\mariadb-10.5.12-winx64\bin\mysqld.exe (mysqld 10.5.12-MariaDB) starting as process 1212 ...
        		 
        Removing default user
        		 
        Setting root password
        		 
        Creating my.ini file
        		 
        Registering service 'MyDB'
        		 
        Creation of the database was successful

      2. Upload the C:\db\my.ini file 

        [mysqld]
        		 
        datadir=C:/db
        		 
        skip-grant-tables
        		 
        skip-networking
        		 
        enable-named-pipe
        		 
        [client]
        		 
        plugin-dir=C:/mariadb-10.5.12-winx64/lib/plugin

      3. Start service 

        C:\Users\Administrator>sc start MyDB

      4. Start mysql_upgrade 

        C:\Users\Administrator>C:\mariadb-10.5.12-winx64\bin\mysql_upgrade.exe --force --host=. --protocol=pipe
        		 
        Phase 1/7: Checking and upgrading mysql database
        		 
        Processing databases
        		 
        mysql
        		 
        mysql.column_stats                                 OK
        		 
        mysql.columns_priv                                 OK
        		 
        mysql.db                                           OK
        		 
        mysql.event                                        OK
        		 
        mysql.func                                         OK
        		 
        mysql.global_priv                                  OK
        		 
        mysql.gtid_slave_pos                               OK
        		 
        mysql.help_category                                OK
        		 
        mysql.help_keyword                                 OK
        		 
        mysql.help_relation                                OK
        		 
        mysql.help_topic                                   OK
        		 
        mysql.index_stats                                  OK
        		 
        mysql.innodb_index_stats                           OK
        		 
        mysql.innodb_table_stats                           OK
        		 
        mysql.plugin                                       OK
        		 
        mysql.proc                                         OK
        		 
        mysql.procs_priv                                   OK
        		 
        mysql.proxies_priv                                 OK
        		 
        mysql.roles_mapping                                OK
        		 
        mysql.servers                                      OK
        		 
        mysql.table_stats                                  OK
        		 
        mysql.tables_priv                                  OK
        		 
        mysql.time_zone                                    OK
        		 
        mysql.time_zone_leap_second                        OK
        		 
        mysql.time_zone_name                               OK
        		 
        mysql.time_zone_transition                         OK
        		 
        mysql.time_zone_transition_type                    OK
        		 
        mysql.transaction_registry                         OK
        		 
        Phase 2/7: Installing used storage engines... Skipped
        		 
        Phase 3/7: Fixing views
        		 
        mysql.user                                         OK
        		 
        Phase 4/7: Running 'mysql_fix_privilege_tables'
        		 
        Phase 5/7: Fixing table and database names
        		 
        Phase 6/7: Checking and upgrading tables
        		 
        Processing databases
        		 
        information_schema
        		 
        performance_schema
        		 
        test
        		 
        Phase 7/7: Running 'FLUSH PRIVILEGES'
        		 
        OK

      5. Stop service 

        C:\Users\Administrator>sc stop MyDB

      Actual result
      mysqld process hands.
      In the log file:

      2021-08-09 17:56:17 0 [Note] InnoDB: The first innodb_system data file 'ibdata1' did not exist. A new tablespace will be created!
      		 
      2021-08-09 17:56:17 0 [Note] InnoDB: Uses event mutexes
      		 
      2021-08-09 17:56:17 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
      		 
      2021-08-09 17:56:17 0 [Note] InnoDB: Number of pools: 1
      		 
      2021-08-09 17:56:17 0 [Note] InnoDB: Using generic crc32 instructions
      		 
      2021-08-09 17:56:17 0 [Note] InnoDB: Initializing buffer pool, total size = 134217728, chunk size = 134217728
      		 
      2021-08-09 17:56:17 0 [Note] InnoDB: Completed initialization of buffer pool
      		 
      2021-08-09 17:56:17 0 [Note] InnoDB: Setting file '.\ibdata1' size to 12 MB. Physically writing the file full; Please wait ...
      		 
      2021-08-09 17:56:17 0 [Note] InnoDB: File '.\ibdata1' size is now 12 MB.
      		 
      2021-08-09 17:56:17 0 [Note] InnoDB: Setting log file .\ib_logfile101 size to 100663296 bytes
      		 
      2021-08-09 17:56:18 0 [Note] InnoDB: Renaming log file .\ib_logfile101 to .\ib_logfile0
      		 
      2021-08-09 17:56:18 0 [Note] InnoDB: New log file created, LSN=10317
      		 
      2021-08-09 17:56:18 0 [Note] InnoDB: Doublewrite buffer not found: creating new
      		 
      2021-08-09 17:56:18 0 [Note] InnoDB: Doublewrite buffer created
      		 
      2021-08-09 17:56:18 0 [Note] InnoDB: 128 rollback segments are active.
      		 
      2021-08-09 17:56:18 0 [Note] InnoDB: Creating foreign key constraint system tables.
      		 
      2021-08-09 17:56:18 0 [Note] InnoDB: Creating tablespace and datafile system tables.
      		 
      2021-08-09 17:56:18 0 [Note] InnoDB: Creating sys_virtual system tables.
      		 
      2021-08-09 17:56:18 0 [Note] InnoDB: Creating shared tablespace for temporary tables
      		 
      2021-08-09 17:56:18 0 [Note] InnoDB: Setting file '.\ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
      		 
      2021-08-09 17:56:18 0 [Note] InnoDB: File '.\ibtmp1' size is now 12 MB.
      		 
      2021-08-09 17:56:18 0 [Note] InnoDB: 10.5.12 started; log sequence number 0; transaction id 7
      		 
      2021-08-09 17:56:18 0 [Note] Plugin 'FEEDBACK' is disabled.
      		 
      2021-08-09 18:00:41 0 [Note] InnoDB: Uses event mutexes
      		 
      2021-08-09 18:00:41 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
      		 
      2021-08-09 18:00:41 0 [Note] InnoDB: Number of pools: 1
      		 
      2021-08-09 18:00:41 0 [Note] InnoDB: Using generic crc32 instructions
      		 
      2021-08-09 18:00:41 0 [Note] InnoDB: Initializing buffer pool, total size = 134217728, chunk size = 134217728
      		 
      2021-08-09 18:00:41 0 [Note] InnoDB: Completed initialization of buffer pool
      		 
      2021-08-09 18:00:41 0 [Note] InnoDB: 128 rollback segments are active.
      		 
      2021-08-09 18:00:41 0 [Note] InnoDB: Creating shared tablespace for temporary tables
      		 
      2021-08-09 18:00:41 0 [Note] InnoDB: Setting file '.\ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
      		 
      2021-08-09 18:00:41 0 [Note] InnoDB: File '.\ibtmp1' size is now 12 MB.
      		 
      2021-08-09 18:00:41 0 [Note] InnoDB: 10.5.12 started; log sequence number 45094; transaction id 20
      		 
      2021-08-09 18:00:41 0 [Note] Plugin 'FEEDBACK' is disabled.
      		 
      2021-08-09 18:00:41 0 [Note] Reading of all Master_info entries succeeded
      		 
      2021-08-09 18:00:41 0 [Note] Added new Master_info '' to hash table
      		 
      2021-08-09 18:00:41 0 [Note] C:\mariadb-10.5.12-winx64\bin\mysqld.exe: ready for connections.
      		 
      Version: '10.5.12-MariaDB'  socket: ''  port: 0  mariadb.org binary distribution
      		 
      2021-08-09 18:00:41 0 [Note] InnoDB: Loading buffer pool(s) from C:\db\ib_buffer_pool
      		 
      2021-08-09 18:00:41 0 [Note] InnoDB: Buffer pool(s) load completed at 210809 18:00:41
      		 
      2021-08-09 18:02:13 15 [Warning] Access denied for user 'root'@'localhost' (using password: NO)
      		 
      2021-08-09 18:04:09 0 [Note] C:\mariadb-10.5.12-winx64\bin\mysqld.exe (initiated by: unknown): Normal shutdown

      Attachments

        Issue Links

          is caused by

          Bug - A problem which impairs or prevents the functions of the product. MDEV-18353 Shutdown may miss to wait for connection thread

          • Major - Major loss of function.
          • Closed
          is duplicated by

          Bug - A problem which impairs or prevents the functions of the product. MDEV-26932 upgrade wizard never finishes at Phase 9/10 and hit "InnoDB: Upgrade after a crash is not supported" after restart

          • Major - Major loss of function.
          • Closed
          relates to

          Task - A task that needs to be done. MDEV-11499 mysqltest, Windows : improve diagnostics if server fails to shutdown

          • Major - Major loss of function.
          • Closed

          Activity

            Ascending order - Click to sort in descending order
            elenst Elena Stepanova added a comment -

            Would you be able to take a minidump from the hanging server?

            elenst Elena Stepanova added a comment - Would you be able to take a minidump from the hanging server?
            skvoboo Anton Serbulov added a comment - - edited

            The full memory dump of the mysqld process: ftp://ftp.mariadb.org/private/mysqld.exe_210809_182646.dmp.zip

            skvoboo Anton Serbulov added a comment - - edited The full memory dump of the mysqld process: ftp://ftp.mariadb.org/private/mysqld.exe_210809_182646.dmp.zip
            wlad Vladislav Vaintroub added a comment - - edited

            I can reproduce

            That's how it hangs

             	ntdll.dll!NtDelayExecution()	Unknown
            		 
             	KernelBase.dll!SleepEx()	Unknown
            		 
            >	server.dll!close_connections() Line 1719	C++
            		 
             	server.dll!win_main(int argc, char * * argv) Line 5682	C++
            		 
             	server.dll!mysql_service(void * p) Line 5728	C++
            		 
             	ucrtbase.dll!thread_start<void (__cdecl*)(void *),0>()	Unknown
            		 
             	kernel32.dll!BaseThreadInitThunk()	Unknown
            		 
             	ntdll.dll!RtlUserThreadStart()	Unknown

            That's where it hangs in close_connections()

              while (CONNECT::count)
            		 
                my_sleep(100);

            CONNECT::count is 0xfffffff3

            wlad Vladislav Vaintroub added a comment - - edited I can reproduce That's how it hangs ntdll.dll!NtDelayExecution() Unknown KernelBase.dll!SleepEx() Unknown > server.dll!close_connections() Line 1719 C++ server.dll!win_main(int argc, char * * argv) Line 5682 C++ server.dll!mysql_service(void * p) Line 5728 C++ ucrtbase.dll!thread_start<void (__cdecl*)(void *),0>() Unknown kernel32.dll!BaseThreadInitThunk() Unknown ntdll.dll!RtlUserThreadStart() Unknown That's where it hangs in close_connections() while (CONNECT::count) my_sleep(100); CONNECT::count is 0xfffffff3
            wlad Vladislav Vaintroub added a comment - - edited

            serg, this is MDEV-18353, which breaks shutdown as soon as named pipe connections are involved. Helpful MTR won't tell, and would silently kill the server process, even if we have named_pipe test.

            As consequence it breaks mysql_upgrade_service, which works somewhat like the reporter described.
            This also breaks upgrade from 10.x to 10.5 in GUI , which uses named pipes and mysql_upgrade_service.

            The reason for the bug is that there is a constructor for CONNECT that does not increment CONNECT::count, but destructor always decrements it.

            below would fix it, but I let you decide whether there is a more elegant workaround,

            diff --git a/sql/sql_connect.h b/sql/sql_connect.h
            		 
            index 1a84cb56e5c..68bdb4a1a31 100644
            		 
            --- a/sql/sql_connect.h
            		 
            +++ b/sql/sql_connect.h
            		 
            @@ -35,7 +35,10 @@ class CONNECT : public ilink {
            		 
             #ifdef _WIN32
            		 
               HANDLE pipe;
            		 
               CONNECT(HANDLE pipe_arg): pipe(pipe_arg), vio_type(VIO_TYPE_NAMEDPIPE),
            		 
            -    scheduler(thread_scheduler), thread_id(0), prior_thr_create_utime(0) {}
            		 
            +    scheduler(thread_scheduler), thread_id(0), prior_thr_create_utime(0)
            		 
            +    {
            		 
            +      count++;
            		 
            +    }
            		 
             #endif
            		 
               enum enum_vio_type vio_type;
            		 
               scheduler_functions *scheduler;

            wlad Vladislav Vaintroub added a comment - - edited serg , this is MDEV-18353 , which breaks shutdown as soon as named pipe connections are involved. Helpful MTR won't tell, and would silently kill the server process, even if we have named_pipe test. As consequence it breaks mysql_upgrade_service, which works somewhat like the reporter described. This also breaks upgrade from 10.x to 10.5 in GUI , which uses named pipes and mysql_upgrade_service. The reason for the bug is that there is a constructor for CONNECT that does not increment CONNECT::count, but destructor always decrements it. below would fix it, but I let you decide whether there is a more elegant workaround, diff --git a/sql/sql_connect.h b/sql/sql_connect.h index 1a84cb56e5c..68bdb4a1a31 100644 --- a/sql/sql_connect.h +++ b/sql/sql_connect.h @@ -35,7 +35,10 @@ class CONNECT : public ilink { #ifdef _WIN32 HANDLE pipe; CONNECT(HANDLE pipe_arg): pipe(pipe_arg), vio_type(VIO_TYPE_NAMEDPIPE), - scheduler(thread_scheduler), thread_id(0), prior_thr_create_utime(0) {} + scheduler(thread_scheduler), thread_id(0), prior_thr_create_utime(0) + { + count++; + } #endif enum enum_vio_type vio_type; scheduler_functions *scheduler;
            wlad Vladislav Vaintroub added a comment - - edited

            To reproduce it more easily

            start mysqld with 

            mysqld --console --enable-named-pipe

            and from another cmd window

            C:\work\10.5\xxx\sql>mysql --host=. -uroot -e "select 1"
            		 
            +---+
            		 
            | 1 |
            		 
            +---+
            		 
            | 1 |
            		 
            +---+
            		 
             
            		 
            C:\work\10.5\xxx\sql>mysql --host=. -uroot -e "shutdown"

            The server won't shutdown

            --host=.

            is an indicator that pipe should be used 

            --protocol=pipe

            would do the same

            wlad Vladislav Vaintroub added a comment - - edited To reproduce it more easily start mysqld with mysqld --console --enable-named-pipe and from another cmd window C:\work\10.5\xxx\sql>mysql --host=. -uroot -e "select 1" +---+ | 1 | +---+ | 1 | +---+   C:\work\10.5\xxx\sql>mysql --host=. -uroot -e "shutdown" The server won't shutdown --host=. is an indicator that pipe should be used --protocol=pipe would do the same
            wlad Vladislav Vaintroub added a comment -

            serg, what do you think of https://github.com/MariaDB/server/commit/236e7e964b79377717ac1237965f2d4bd51b5b36

            I restored the idea of the generic templated object counter, so that we do not have THD_count and CONNECT_count classes

            wlad Vladislav Vaintroub added a comment - serg , what do you think of https://github.com/MariaDB/server/commit/236e7e964b79377717ac1237965f2d4bd51b5b36 I restored the idea of the generic templated object counter, so that we do not have THD_count and CONNECT_count classes
            serg Sergei Golubchik added a comment -

            I'd prefer just one more count++ as you had in your comment above.

            Template is kind of nice, but rather artificial, because it doesn't use the type T for anything. I'm not even sure it's guaranteed to work, given that the template doesn't depend on the type, what prevents a sufficiently smart compiler to "optimize" it into only one instance of the class?

            serg Sergei Golubchik added a comment - I'd prefer just one more count++ as you had in your comment above. Template is kind of nice, but rather artificial, because it doesn't use the type T for anything. I'm not even sure it's guaranteed to work, given that the template doesn't depend on the type, what prevents a sufficiently smart compiler to "optimize" it into only one instance of the class?
            wlad Vladislav Vaintroub added a comment - - edited

            I'm not sure it is guaranteed to work either, but a similar example is in Wikipedia, so it is more trustable than I would come up with that myself , and compiler writers maybe would not like to break that use of "curiously recurring template pattern" https://en.wikipedia.org/wiki/Curiously_recurring_template_pattern#Object_counter

            Also, this is used in Scott Meyers' article from back 1998 about how to count objects in C++ ,and he perhaps can be trusted.

            Thinking a little more, I'd guess templates with different template parameters can't legally be merged into the same object. Anyway, Scott Meyers, Wikipedia , and stackoverflow may be enough evidence.

            wlad Vladislav Vaintroub added a comment - - edited I'm not sure it is guaranteed to work either, but a similar example is in Wikipedia, so it is more trustable than I would come up with that myself , and compiler writers maybe would not like to break that use of "curiously recurring template pattern" https://en.wikipedia.org/wiki/Curiously_recurring_template_pattern#Object_counter Also, this is used in Scott Meyers' article from back 1998 about how to count objects in C++ ,and he perhaps can be trusted. Thinking a little more, I'd guess templates with different template parameters can't legally be merged into the same object. Anyway, Scott Meyers, Wikipedia , and stackoverflow may be enough evidence.

            People

              wlad Vladislav Vaintroub
              skvoboo Anton Serbulov
              Votes:
              0 Vote for this issue
              Watchers:
              5 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

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