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

innodb.innodb_prefix_index_restart_server test fails sometimes

    Details

    • Type: Bug
    • Status: Stalled
    • Priority: Minor
    • Resolution: Unresolved
    • Affects Version/s: 5.5.34
    • Fix Version/s: 5.5
    • Component/s: None
    • Labels:
      None

      Description

      innodb.innodb_prefix_index_restart_server fails sometimes: sometimes 200 such tests go without failure, and sometimes 8/200 fail.

      both innodb_plugin and xtradb are affected.

      the big question here is... is it a test failure? or a real race-condition in mysqld?

        Gliffy Diagrams

          Attachments

            Activity

            Hide
            elenst Elena Stepanova added a comment - - edited

            I ran a number of tests. The warning appears sporadically, especially on slower/busy machines.

            The relevant piece of code gives some time (2 sec) to threads to die peacefully, and then forces them:

            1463-
            1464-  /* Give threads time to die. */
            1465-  for (int i= 0; thread_count && i < 100; i++)
            1466-    my_sleep(20000);
            1467-
            1468-  /*
            1469-    Force remaining threads to die by closing the connection to the client
            1470-    This will ensure that threads that are waiting for a command from the
            1471-    client on a blocking read call are aborted.
            1472-  */
            1473-
            1474-  for (;;)
            1475-  {
            1476-    DBUG_PRINT("quit",("Locking LOCK_thread_count"));
            1477-    mysql_mutex_lock(&LOCK_thread_count); // For unlink from list
            1478-    if (!(tmp=threads.get()))
            1479-    {
            1480-      DBUG_PRINT("quit",("Unlocking LOCK_thread_count"));
            1481-      mysql_mutex_unlock(&LOCK_thread_count);
            1482-      break;
            1483-    }
            1484-#ifndef __bsdi__				// Bug in BSDI kernel
            1485-    if (tmp->vio_ok())
            1486-    {
            1487-      if (global_system_variables.log_warnings)
            1488:        sql_print_warning(ER_DEFAULT(ER_FORCING_CLOSE),my_progname,
            1489-                          tmp->thread_id,
            1490-                          (tmp->main_security_ctx.user ?
            1491-                           tmp->main_security_ctx.user : ""));
            1492-      close_connection(tmp,ER_SERVER_SHUTDOWN);
            1493-    }
            

            I increased the timeout to 20 sec to make sure that the threads die eventually and don't hang forever, and they did. The longest wait I got was 6 sec (once).

            I don't know when tmp->vio_ok() is supposed to fire, currently it seems to be always the case, whenever the timeout is exceeded. Maybe it's a bug and should be investigated further.

            If not, I can add a warning suppression to the test case:

            === modified file 'mysql-test/suite/innodb/r/innodb_prefix_index_restart_server.result'
            --- mysql-test/suite/innodb/r/innodb_prefix_index_restart_server.result	2011-10-05 13:14:14 +0000
            +++ mysql-test/suite/innodb/r/innodb_prefix_index_restart_server.result	2013-11-26 18:35:52 +0000
            @@ -2,6 +2,7 @@
             set global innodb_file_per_table=1;
             set global innodb_large_prefix=1;
             DROP TABLE IF EXISTS worklog5743;
            +call mtr.add_suppression("Forcing close of thread");
             CREATE TABLE worklog5743 (
             col_1_text TEXT(4000) , col_2_text TEXT(4000) ,
             PRIMARY KEY (col_1_text(3072))
            
            === modified file 'mysql-test/suite/innodb/t/innodb_prefix_index_restart_server.test'
            --- mysql-test/suite/innodb/t/innodb_prefix_index_restart_server.test	2012-02-07 15:22:36 +0000
            +++ mysql-test/suite/innodb/t/innodb_prefix_index_restart_server.test	2013-11-26 18:35:32 +0000
            @@ -29,6 +29,7 @@
             DROP TABLE IF EXISTS worklog5743;
             -- enable_warnings
             
            +call mtr.add_suppression("Forcing close of thread");
             
             #------------------------------------------------------------------------------
             # Stop the server in between when prefix index are created and see if state is
            

            Assigning to Sergei to decide whether it should be done or the reasons why the warning fires should be investigated further.

            Show
            elenst Elena Stepanova added a comment - - edited I ran a number of tests. The warning appears sporadically, especially on slower/busy machines. The relevant piece of code gives some time (2 sec) to threads to die peacefully, and then forces them: 1463- 1464- /* Give threads time to die. */ 1465- for (int i= 0; thread_count && i < 100; i++) 1466- my_sleep(20000); 1467- 1468- /* 1469- Force remaining threads to die by closing the connection to the client 1470- This will ensure that threads that are waiting for a command from the 1471- client on a blocking read call are aborted. 1472- */ 1473- 1474- for (;;) 1475- { 1476- DBUG_PRINT("quit",("Locking LOCK_thread_count")); 1477- mysql_mutex_lock(&LOCK_thread_count); // For unlink from list 1478- if (!(tmp=threads.get())) 1479- { 1480- DBUG_PRINT("quit",("Unlocking LOCK_thread_count")); 1481- mysql_mutex_unlock(&LOCK_thread_count); 1482- break; 1483- } 1484-#ifndef __bsdi__ // Bug in BSDI kernel 1485- if (tmp->vio_ok()) 1486- { 1487- if (global_system_variables.log_warnings) 1488: sql_print_warning(ER_DEFAULT(ER_FORCING_CLOSE),my_progname, 1489- tmp->thread_id, 1490- (tmp->main_security_ctx.user ? 1491- tmp->main_security_ctx.user : "")); 1492- close_connection(tmp,ER_SERVER_SHUTDOWN); 1493- } I increased the timeout to 20 sec to make sure that the threads die eventually and don't hang forever, and they did. The longest wait I got was 6 sec (once). I don't know when tmp->vio_ok() is supposed to fire, currently it seems to be always the case, whenever the timeout is exceeded. Maybe it's a bug and should be investigated further. If not, I can add a warning suppression to the test case: === modified file 'mysql-test/suite/innodb/r/innodb_prefix_index_restart_server.result' --- mysql-test/suite/innodb/r/innodb_prefix_index_restart_server.result 2011-10-05 13:14:14 +0000 +++ mysql-test/suite/innodb/r/innodb_prefix_index_restart_server.result 2013-11-26 18:35:52 +0000 @@ -2,6 +2,7 @@ set global innodb_file_per_table=1; set global innodb_large_prefix=1; DROP TABLE IF EXISTS worklog5743; +call mtr.add_suppression("Forcing close of thread"); CREATE TABLE worklog5743 ( col_1_text TEXT(4000) , col_2_text TEXT(4000) , PRIMARY KEY (col_1_text(3072)) === modified file 'mysql-test/suite/innodb/t/innodb_prefix_index_restart_server.test' --- mysql-test/suite/innodb/t/innodb_prefix_index_restart_server.test 2012-02-07 15:22:36 +0000 +++ mysql-test/suite/innodb/t/innodb_prefix_index_restart_server.test 2013-11-26 18:35:32 +0000 @@ -29,6 +29,7 @@ DROP TABLE IF EXISTS worklog5743; -- enable_warnings +call mtr.add_suppression("Forcing close of thread"); #------------------------------------------------------------------------------ # Stop the server in between when prefix index are created and see if state is Assigning to Sergei to decide whether it should be done or the reasons why the warning fires should be investigated further.

              People

              • Assignee:
                serg Sergei Golubchik
                Reporter:
                alien AL13N
              • Votes:
                0 Vote for this issue
                Watchers:
                3 Start watching this issue

                Dates

                • Created:
                  Updated: