Bug #10178 failure to find a row in heap table by concurrent UPDATEs
Submitted: 26 Apr 2005 14:01 Modified: 28 Jun 2005 14:01
Reporter: Andrei Elkin Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server Severity:S2 (Serious)
Version:4.1.11 OS:Linux (Linux Deb ker 2.4.26, libc2.3.2)
Assigned to: Ingo Strüwing CPU Architecture:Any

[26 Apr 2005 14:01] Andrei Elkin
Description:
  concurrent UPDATEs fail to find a row in heap table created with index on primary key

  to reproduce:
  
  0. launch mysql 4.1.11

  1. extract Makefile, and c-program, run make all           => bug1316.run

  2. run ./bug1316.run 100 anode2 3304 comm user userpass 1 1 1

    It will:
       a. create db `comm` with the single table t0 having the single row with prim key 
          col_key, and `count` field, and indexes named as tbl_indt0. 
	  The row is initialized VALUES(1,0);

       b. run 100 (it can be less) connection doing increment 
       UPDATE t0 set count=count+1 where col_key=1
      
    After some number of operations you should see these warnings
   
    NO ROWS ARE AFFECTED, WHY? ...  query : UPDATE t0 SET ... WHERE col_key = 1
    However, there exists the rows, since UPDATE does not change col_key.
    You can verify this by SELECT which also will show number of successfully performed UPDATEs.

These two steps to demostrate that it works without indexes.

  3. remove the index:
     DROP INDEX tbl_indt0 on comm.t0

  4. ./bug1316.run 100 anode2 3304 comm root rootpass 1 1 0
     It will skip create step and use unindexed version of t0.
     
     Now you should not see the warnings

How to repeat:
#### Makefile:

MYSQL_CFLAGS=`mysql_config --cflags | sed s/\'//g`
MYSQL_LIBS=`mysql_config --libs | sed s/\'//g | sed s/lmysqlclient/lmysqlclient_r/g`

CFLAGS=${MYSQL_CFLAGS}
LIBS=${MYSQL_LIBS} -lpthread

all: bug_heap

bug_heap: updates2heap.c
	  gcc -DDEBUG -g  -Wall $< -o bug1316.run $(CFLAGS) $(LIBS)
-------------------------------------------------------------------------------------------------------------------------------

//  updates2heap.c:

#define _GNU_SOURCE
#include <pthread.h>
#include <stdio.h>
#include <error.h>
#include <errno.h>
#include <string.h>
#include <mysql.h>
#include <unistd.h>
#include <stdlib.h>
#include <sys/time.h>
#include <assert.h>
#include <signal.h>

#define TRUE 1
#define FALSE 0

#define N_DIM 3

#define CMD_LEN 4096
#define MAX_TABLES 256

const double rand_denom=1.0/((double)RAND_MAX + 1.0);
#define drand() ((double)rand()*rand_denom)

#define error_mysql(m) fprintf (stderr, "MySQL server: %s\n", mysql_error (m));

volatile int stop = 0;

volatile int sigint = 0;
void catch_int (int sig)
{
	sigint = 1;
	signal (SIGINT, catch_int);
	signal (SIGTERM, catch_int);
}

int n_tuples = 0;
struct
{
	char db_host[64];
	int  db_port;
	char db_name[64];
	char db_user[64];
	char db_pswd[64];
	int  n_users;
	int  n_tables;
	int  n_rows;
	int  modulus;
	int  query_min;
	int  query_max;
	int  create;
        int  index;
}
config =
{
	.db_host  = "localhost.localdomain",
	.db_port  = 3304,
	.db_name  = "comm",
	.db_user  = "test",
	.db_pswd  = "testpass",
	.n_users  = 16,
	.n_tables = 40,
	.n_rows   = 2,
	.modulus   = 32771,
	.query_min = 8,
	.query_max = 100,
        .create = 1,
        .index = 1
};

struct my_thread
{
	pthread_t thread;
	int id;
	int prim_key;
	int row[N_DIM];
	char cmd[CMD_LEN];
	int  cmd_len;
	MYSQL *mysql;
	MYSQL_RES *mysql_result;
	FILE * log_file;
} *my_threads = NULL;

struct my_table
{
	int prim_key;
	int row[N_DIM];
	int rows;
	char *name;
} *my_tables = NULL;

MYSQL *connect_mysql (MYSQL *mysql, char *db_name)
{
	mysql = mysql_init (mysql);
	if (!mysql) return NULL;
  
	if (!mysql_real_connect (mysql,
				 config.db_host,
				 config.db_user,
				 config.db_pswd,
				 db_name,
				 config.db_port,
				 NULL, 0))
	{
		fprintf (stderr, "MySQL server: %s\n", mysql_error (mysql));
		mysql_close (mysql);
		return NULL;
	}
	return mysql;
}

static inline int get_table (struct my_thread *thread)
{
	return (config.n_tables) * drand();
}

static int run_update (struct my_thread *thread)
{
	int key, table;
	
  	key = (n_tuples) * drand() + 1;
	table = get_table (thread);
	thread->cmd_len = 
		snprintf(thread->cmd, CMD_LEN,
			 "UPDATE %s SET "
			 "count = count + 1 "
			 "WHERE col_key = %d ",
			 my_tables[table].name, key);
	
	if (mysql_query (thread->mysql, thread->cmd))
	{
		error (0, errno, "Error in query: %s\n: %s",
		       thread->cmd, mysql_error(thread->mysql));
		return -1;
	}
	else
	{
		thread->mysql_result = mysql_store_result (thread->mysql);

		if (mysql_affected_rows(thread->mysql) == 0) {
			
			error (0, errno, "NO ROWS ARE AFFECTED, WHY? query: %s\n query: %s",
			       thread->cmd, mysql_error(thread->mysql));
			exit (0);
		};
		
		mysql_free_result(thread->mysql_result);
	}
  
	return 0;
}

void *user_thread (void *thr)
{
	int n_ops = 0;
	int err = 0;
	struct timeval connect;
	struct my_thread *thread = (struct my_thread *) thr;
  
	if (!thread) error (-1, errno, "Null thread pointer in user_thread");

	while (!stop)
	{
		n_ops = config.query_min + 
			(config.query_max - config.query_min)*drand();

		while (!(thread->mysql = connect_mysql(NULL, config.db_name)) && !stop)
		{
			error (0, errno, "Thread %d: unable to connect to database", thread->id);
			sleep (1);
		}
      
		gettimeofday (&connect, NULL);
		mysql_select_db (thread->mysql, config.db_name);

		while (n_ops-- && !stop)
		{
			err = run_update(thread);
		};
      
		mysql_close (thread->mysql);
		mysql_thread_end ();
	}
	return NULL;
}

static int create_table (MYSQL *mysql, struct my_table * my_tables, int i)
{
	char cmd[CMD_LEN];
	char *name = my_tables[i].name;
	static int t_num = 0;

	printf ("%s[%d] ", name, t_num); 
  
	snprintf (cmd, CMD_LEN,
		  "create table %s( "
		  "col_key int not null primary key, "
		  "count  double not null, index tbl_ind%s (col_key)) type=heap MIN_ROWS = 1 MAX_ROWS = %d",
		  name, name,
		  config.n_rows);
  
	if (mysql_query (mysql, cmd))
		error (-1, errno, "%s failed to create table '%s': %s", cmd, name, mysql_error(mysql));
  
	t_num++;
	return t_num;
}

static int fill_table (MYSQL *mysql, int n)
{
	char cmd[CMD_LEN];
	char *name =  my_tables[n].name;
	int i;
  
	printf (" %s", name); fflush (stdout);
	for (i = 0; i < config.n_rows; i++)
	{
		snprintf (cmd, CMD_LEN, "INSERT INTO %s VALUES (%d, 0)", name, i+1);
		if (mysql_query (mysql, cmd))
		{
			error_mysql(mysql);
			error (-1, errno, "Failed to insert row into %s:\n%s", my_tables[n].name, mysql_error(mysql));
		}
		my_tables[n].rows++;
	}
	return 0;
}

int comm_create ()
{
	MYSQL *mysql = NULL;
	char cmd[CMD_LEN];
	struct timeval begin;
	int i;
  
	puts ("Creating tables:");

	mysql = connect_mysql (mysql, NULL);
	if (!mysql)
		error (-1, errno, "Unable to connect to server");

	puts ("ok");

	my_tables = (struct my_table *)
		realloc (my_tables, config.n_tables * sizeof (struct my_table));
	if (NULL == my_tables)
		error (-1, errno, "Failed to allocate memory for table structure array");
	memset (my_tables, 0, config.n_tables * sizeof (struct my_table));

	for (i = 0; i < config.n_tables; i++)
	{
		snprintf (cmd, CMD_LEN, "t%d", i);
		my_tables[i].name = strdup (cmd);

		my_tables[i].prim_key = 1;

	}
  
	char *table_types[] = {};			
	unsigned char table_len = 0;
	char *p_type = "heap";		
	if (config.create==1) 
	{
		snprintf (cmd, CMD_LEN, "drop database %s", config.db_name);
		mysql_query (mysql, cmd);

		snprintf (cmd, CMD_LEN, "create database %s", config.db_name);
		if (mysql_query (mysql, cmd))
		{
			error (-1, errno, "Failed to create database %s:\n%s", config.db_name, mysql_error(mysql));
		}
   
		mysql_select_db (mysql, config.db_name);
      

		printf ("Creating tables:");
		gettimeofday (&begin, NULL);
		table_types[table_len] = p_type;		
		while (*p_type != '\0') {			
			if (*p_type == ',') {
				*p_type = '\0';			
				table_types[++table_len] = ++p_type;	
	
			}
			else {
				p_type++;
			}
		}
		for (i = 0; i < config.n_tables; i++)	 create_table(mysql, my_tables, i);
		for (i = 0; i < config.n_tables; i++)  fill_table (mysql, i);
	}
   
	n_tuples  = config.n_rows;
   
	mysql_select_db (mysql, config.db_name);
	mysql_close (mysql);
	return 0;
}

int main (int argc, char *argv[])
{
	int i;

	config.n_users = atoi(argv[1]);
	strcpy(config.db_host,argv[2]);
	config.db_port = atoi(argv[3]);
	strcpy(config.db_name,argv[4]);
	strcpy(config.db_user,argv[5]);
	strcpy(config.db_pswd,argv[6]);
	config.n_tables = atoi(argv[7]);
	config.n_rows = atoi(argv[8]);
	if (argc > 9) config.create = atoi(argv[9]);

	if (1 != mysql_thread_safe())
		error (1, errno, "This program was not compiled thread safe, exiting.");
      
	my_threads = (struct my_thread *) calloc (config.n_users, sizeof (struct my_thread));
  
	comm_create();

	for (i = 0; i < config.n_users; i++)
	{
		pthread_create (&(my_threads[i].thread), NULL, user_thread, my_threads + i);
	}

	fflush (stdout);

	printf ("Running bug test until C-c\n");
	sleep(99999);
  
	stop = 1;
	for (i = 0; i < config.n_users; i++)
		pthread_join (my_threads[i].thread, NULL);
  
	return 0;
}
[27 Apr 2005 10:32] Geert Vanderkelen
Hi Andrei,

Thanks for your Makefile and nice code!
I was able to reproduce it.

Some extra findings:
- These are MEMORY (or HEAP) tables using HASH indexes (the default).
- Small, only an int and double field, never comes near (any) limit
- After a while, this fails "UPDATE t30 SET count = count + 1 WHERE col_key = 2;", randomly over 40 tables; col_key = 1 or = 2 or = 3, doesn't matter, no update goes. Table is not big, it happens randomly. Sometimes after 30k runs, sometimes 12k..
- ALTER TABLE t30 ENGINE=myisam; ALTER TABLE t30 ENGINE=memory; -- UPDATE works again on the table
- If you update all rows "UPDATE t23 SET count= count +1", this works. Then normal updates like "UPDATE t23 SET count = count + 1 WHERE col_key = 1" again work

Reproducable in 4.1.10a, 4.1.11, 5.0.4beta.

Regards,

Geert
[27 Apr 2005 10:57] Geert Vanderkelen
Doesn't seem to to happen in 4.0.24.

Geert
[10 Jun 2005 10:54] Ingo Strüwing
Some progress information:
- The test works like a charm on Linux 2.6.8. For hours. Without any failure or warning.
- The msyqld server built on Linux 2.6 refuses to start on Linux 2.4. Error Message in the error log:
   [ERROR] bdb:  unable to initialize mutex: Function not implemented
- Completely rebuilt on Linux 2.4.27 (including make clean; configure; make; make install),
   the described failure message appears after a short time and the tests stops.
- Also on Linux 2.4.27 I get a lot of warning messages saying "too many threads", but this does not
   affect the test.
- The failure happens also with --debug=t:d, so that there might be an infinitesimal chance
   to locate the problem.
[10 Jun 2005 20:30] Ingo Strüwing
My test script based on the bug report.

Attachment: bug10178-1.sh (application/x-sh, text), 10.23 KiB.

[10 Jun 2005 20:34] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/internals/25893
[17 Jun 2005 7:44] Ingo Strüwing
Patch approved with small changes by Email from Sergei.
[20 Jun 2005 9:01] Ingo Strüwing
Review changes do not work. Need further investigation.
[22 Jun 2005 12:03] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/internals/26298
[22 Jun 2005 12:27] Ingo Strüwing
Back to patch approved as I made only the changes requested by the review.

The problems turned out as explainable. Since the key statistics are now updated in info() only, and the updating methods did only update the statistics for bigger changes, it could happen that a command started with old statistics (the surprising thing is that open() is not always called at the beginning of a command). This can happen now too, but if a command does multiple changes, it can happen that the margin for "bigger" changes is triggered in the middle of the command. Formerly the statistics were updated at that moment, while now they are updated at the start of the next command (when info() is called).
[24 Jun 2005 15:47] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/internals/26411
[24 Jun 2005 17:19] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/internals/26414
[24 Jun 2005 17:41] Ingo Strüwing
Fixed in 4.1.13 and 5.0.9.
[28 Jun 2005 14:01] Jon Stephens
Thank you for your bug report. This issue has been committed to our
source repository of that product and will be incorporated into the
next release.

If necessary, you can access the source repository and build the latest
available version, including the bugfix, yourself. More information 
about accessing the source trees is available at
    http://www.mysql.com/doc/en/Installing_source_tree.html

Additional info:

Documented fix in change history for 4.1.13 and 5.0.9. Closed.