MySQL Bugs: #38692: concurrent inserts cause valgrind errors in Query

Bug #38692	concurrent inserts cause valgrind errors in Query_cache::invalidate
Submitted:	9 Aug 2008 17:14	Modified:	21 Oct 2008 17:40
Reporter:	Shane Bester (Platinum Quality Contributor)	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Query Cache	Severity:	S1 (Critical)
Version:	5.1.26, 5.1.28, 6.0.7	OS:	Any
Assigned to:	Kristofer Pettersson	CPU Architecture:	Any

Description:
inserting with concurrent inserts enabled gave these errors:

==16055== 1 errors in context 1 of 3:
==16055== Invalid read of size 4
0x82BEC69: Query_cache::invalidate (sql_cache.cc:2531)
0x8234409: mysql_insert (sql_insert.cc:919)
0x81D724D: mysql_execute_command (sql_parse.cc:2953)
0x81DB910: mysql_parse (sql_parse.cc:5645)
0x81D424D: dispatch_command (sql_parse.cc:1137)
0x81D3DD2: do_command (sql_parse.cc:794)
0x81D2300: handle_one_connection (sql_connect.cc:1115)
0x4893DA: start_thread (in /lib/libpthread-2.5.so)
0x3D606D: clone (in /lib/libc-2.5.so)

Address 0x635D264 is 284 bytes inside a block of size 996 free'd
0x400501A: free (vg_replace_malloc.c:233)
0x840DF4D: my_no_flags_free (my_malloc.c:59)
0x840E6E4: free_root (my_alloc.c:355)
0x820C8D5: free_table_share (table.cc:431)
0x8209C26: table_def_free_entry (sql_base.cc:271)
0x84138D1: hash_delete (hash.c:530)
0x820D475: closefrm (table.cc:1981)
0x82026F6: intern_close_table (sql_base.cc:771)
0x8209C7B: free_cache_entry (sql_base.cc:793)
0x84138D1: hash_delete (hash.c:530)
0x8202EEE: close_thread_table (sql_base.cc:1357)
0x8209CF5: close_open_tables (sql_base.cc:1166)

==16055== 1 errors in context 2 of 3:
==16055== Invalid read of size 4
0x82BEC5D: Query_cache::invalidate (sql_cache.cc:2531)
0x8234409: mysql_insert (sql_insert.cc:919)
0x81D724D: mysql_execute_command( (sql_parse.cc:2953)
0x81DB910: mysql_parse (sql_parse.cc:5645)
0x81D424D: dispatch_command(sql_parse.cc:1137)
0x81D3DD2: do_command (sql_parse.cc:794)
0x81D2300: handle_one_connection (sql_connect.cc:1115)
0x4893DA: start_thread (in /lib/libpthread-2.5.so)
0x3D606D: clone (in /lib/libc-2.5.so)

Address 0x635D260 is 280 bytes inside a block of size 996 free'd
0x400501A: free (vg_replace_malloc.c:233)
0x840DF4D: my_no_flags_free (my_malloc.c:59)
0x840E6E4: free_root (my_alloc.c:355)
0x820C8D5: free_table_share(st_table_share*) (table.cc:431)
0x8209C26: table_def_free_entry(st_table_share*) (sql_base.cc:271)
0x84138D1: hash_delete (hash.c:530)
0x820D475: closefrm(st_table*, bool) (table.cc:1981)
0x82026F6: intern_close_table(st_table*) (sql_base.cc:771)
0x8209C7B: free_cache_entry(st_table*) (sql_base.cc:793)
0x84138D1: hash_delete (hash.c:530)
0x8202EEE: close_thread_table(THD*, st_table**) (sql_base.cc:1357)
0x8209CF5: close_open_tables(THD*) (sql_base.cc:1166)

How to repeat:
...

some extra info so i don't forget to write a testcase :)

Attachment: bug38692_more_info.txt (text/plain), 23.06 KiB.

testcase.

Attachment: bug38692.c (text/plain), 7.42 KiB.

the testcase is nondeterministic, so let it run for at least a few hundred thousand queries, until valgrind outputs errors.

progress report: The invalidation functions should probably not be executed if the query cache isn't used.

* Insert_delayed::handle_inserts issues an ER_DELAYED_CANT_CHANGE_LOCK which leads to an error. This should possibly never happen.

Truncate table calls 'remove_table_from_cache' which has a section specific for merge tables:
        for (TABLE *thd_table= in_use->open_tables;
	     thd_table ;
	     thd_table= thd_table->next)
        {
          /* Do not handle locks of MERGE children. */
	  if (thd_table->db_stat && !thd_table->parent)	// If table is open
	    signalled|= mysql_lock_abort_for_thread(thd, thd_table);
        }

This causes a Delayed_insert thread to abort wait_for_lock and fail with its attempt to upgrade to a write lock. This in turn triggered an error message which triggered a bug in error message handling which caused an assertion in Diagnostic_area.

Related to http://bugs.mysql.com/bug.php?id=17436 ALTER TABLE causes pending INSERT DELAYED updates to fail.

Note: It is ok for a concurrent TRUNCATE stmt to kill INSERT DELAY threads, because there is no way to determine in advance when an delayed insert has finished anyway. This brings us back to the original problem with how to handle error messages in a Delayed_insert object.

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/commits/53701

2729 Kristofer Pettersson	2008-09-10
      Bug#38692 concurrent inserts cause valgrind errors in Query_cache::invalidate
            
      If a delayed insert thread was aborted by a concurrent 'truncate table'
      statement, then the diagnostic area would fail with an assert in a debug build
      because no actual error message was pushed on the stack despite a thread
      being killed.
            
      This patch adds an error message to the stack.

Patch for assertion failure pushed to bugteam-tree. Need to continue testing for valgrind errors.

Query_cache execution path will be removed with patch for Bug#38551

Shane, can you try to repeat this problem using code base for current 5.1-bugteam?

output from the bugteam tree

Attachment: bug38692_5.0.30_tmp_mysql-5.1-bugteam_valgrind_errors.txt (text/plain), 18.99 KiB.

progress report:
Using an educated guess and sleep enabled me to reproduce the problem.

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/commits/55443

2730 Kristofer Pettersson	2008-10-06
      Bug#38692 concurrent inserts cause valgrind errors in Query_cache::invalidate
      
      Concurrent inserts produce valgrind error messages.
      The reason is that the query cache is invalidated after the target table object
      is closed.
      By executing query cache invalidation before the delayed insert thread is
      terminated avoids this issue.

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/commits/55555

2730 Kristofer Pettersson	2008-10-07
      Bug#38692 concurrent inserts cause valgrind errors in Query_cache::invalidate
      
      Concurrent inserts produce valgrind error messages.
      The reason is that the query cache is invalidated after the target table object
      is closed.
      
      Since the delayed insert thread already takes care of invalidating the query
      cache there is no need to try to synchronize an extra cache invalidation call.
      
      The fix is to remove the query_cache_invalidate3 call altogether.

Pushed into 5.1.30  (revid:kpettersson@mysql.com-20080910145803-q6n8g31d6mraw304) (version source revid:kpettersson@mysql.com-20080911112312-sirecjzudae3vj2n) (pib:4)

Pushed into 6.0.8-alpha  (revid:kpettersson@mysql.com-20080910145803-q6n8g31d6mraw304) (version source revid:kpettersson@mysql.com-20080915213119-3f5vwkbn3pxr1fsu) (pib:5)

This was pushed into 5.1.29, not 5.1.30.

Noted in 5.1.29, 6.0.8 changelogs.

A race condition between threads sometimes caused unallocated memory
to be addressed.

Pushed into 5.1.29-ndb-6.2.17  (revid:kpettersson@mysql.com-20080910145803-q6n8g31d6mraw304) (version source revid:tomas.ulin@sun.com-20081028140209-u4emkk1xphi5tkfb) (pib:5)

Pushed into 5.1.29-ndb-6.3.19  (revid:kpettersson@mysql.com-20080910145803-q6n8g31d6mraw304) (version source revid:tomas.ulin@sun.com-20081028194045-0353yg8cvd2c7dd1) (pib:5)

Pushed into 5.1.29-ndb-6.4.0  (revid:kpettersson@mysql.com-20080910145803-q6n8g31d6mraw304) (version source revid:jonas@mysql.com-20081101082305-qx5a1bj0z7i8ueys) (pib:5)

Pushed into 6.0.8-alpha  (revid:kpettersson@mysql.com-20081007094827-rkwu26j63j8bbva2) (version source revid:horst@mysql.com-20081015193113-1bgz7kieig6c31r8) (pib:5)

Pushed into 5.1.30  (revid:kpettersson@mysql.com-20081007094827-rkwu26j63j8bbva2) (version source revid:horst@mysql.com-20081015192632-yaq13kdfk73t0g69) (pib:5)

Pushed into 5.1.31-ndb-6.2.17 (revid:tomas.ulin@sun.com-20090119095303-uwwvxiibtr38djii) (version source revid:tomas.ulin@sun.com-20090108105244-8opp3i85jw0uj5ib) (merge vers: 5.1.31-ndb-6.2.17) (pib:6)

Pushed into 5.1.31-ndb-6.3.21 (revid:tomas.ulin@sun.com-20090119104956-guxz190n2kh31fxl) (version source revid:tomas.ulin@sun.com-20090119104956-guxz190n2kh31fxl) (merge vers: 5.1.31-ndb-6.3.21) (pib:6)

Pushed into 5.1.31-ndb-6.4.1 (revid:tomas.ulin@sun.com-20090119144033-4aylstx5czzz88i5) (version source revid:tomas.ulin@sun.com-20090119144033-4aylstx5czzz88i5) (merge vers: 5.1.31-ndb-6.4.1) (pib:6)