Bug #56241 Valgrind/CDB warnings for many tests in trunk-bugfixing
Submitted: 25 Aug 2010 7:21 Modified: 2 Sep 2010 16:04
Reporter: Alexander Nozdrin Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: General Severity:S1 (Critical)
Version:M4 (Dahlia) OS:Any
Assigned to: Jon Olav Hauglid CPU Architecture:Any
Tags: pb2, test falure

[25 Aug 2010 7:21] Alexander Nozdrin
Description:
Many tests started to crash on Windows with the symptoms below.

It seems to begin on Aug-20 after innocent push with updating
test result files. However, that might be misleading.

The symptoms:

EXCEPTION_RECORD:  ffffffffffffffff -- (.exr 0xffffffffffffffff)
ExceptionAddress: 000000013f86a3fd (mysqld!purge_table_share)
   ExceptionCode: c0000005 (Access violation)
  ExceptionFlags: 00000000
NumberParameters: 2
   Parameter[0]: 0000000000000000
   Parameter[1]: ffffffffffffffff
Attempt to read from address ffffffffffffffff

PROCESS_NAME:  mysqld.exe

ERROR_CODE: (NTSTATUS) 0xc0000005 - The instruction at 0x%08lx referenced memory at 0x%08lx. The memory could not be %s.

EXCEPTION_CODE: (NTSTATUS) 0xc0000005 - The instruction at 0x%08lx referenced memory at 0x%08lx. The memory could not be %s.

EXCEPTION_PARAMETER1:  0000000000000000

EXCEPTION_PARAMETER2:  ffffffffffffffff

READ_ADDRESS:  ffffffffffffffff 

FOLLOWUP_IP: 
mysqld!purge_table_share+2d [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\storage\perfschema\pfs_instr_class.cc @ 888]
 cmp     dword ptr [rax+1E4h],1

FAULTING_THREAD:  0000000000001184

BUGCHECK_STR:  APPLICATION_FAULT_INVALID_POINTER_READ_FILL_PATTERN_dddddddd

PRIMARY_PROBLEM_CLASS:  INVALID_POINTER_READ_FILL_PATTERN_dddddddd

DEFAULT_BUCKET_ID:  INVALID_POINTER_READ_FILL_PATTERN_dddddddd

LAST_CONTROL_TRANSFER:  from 000000013f86591b to 000000013f86a3fd

STACK_TEXT:  
mysqld!purge_table_share [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\storage\perfschema\pfs_instr_class.cc @ 888]
mysqld!release_table_share_v1 [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\storage\perfschema\pfs.cc @ 953]
mysqld!free_table_share [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\table.cc @ 486]
mysqld!table_def_free_entry [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sql_base.cc @ 290]
mysqld!my_hash_delete [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\mysys\hash.c @ 584]
mysqld!get_table_share [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sql_base.cc @ 548]
mysqld!get_table_share_with_discover [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sql_base.cc @ 622]
mysqld!open_table [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sql_base.cc @ 2854]
mysqld!open_and_process_table [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sql_base.cc @ 4347]
mysqld!open_tables [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sql_base.cc @ 4776]
mysqld!open_and_lock_tables [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sql_base.cc @ 5365]
mysqld!open_and_lock_tables [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sql_base.h @ 457]
mysqld!execute_sqlcom_select [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sql_parse.cc @ 4522]
mysqld!mysql_execute_command [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sql_parse.cc @ 2166]
mysqld!sp_instr_stmt::exec_core [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sp_head.cc @ 3119]
mysqld!sp_lex_keeper::reset_lex_and_exec_core [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sp_head.cc @ 2920]
mysqld!sp_instr_stmt::execute [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sp_head.cc @ 3056]
mysqld!sp_head::execute [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sp_head.cc @ 1390]
mysqld!sp_head::execute_procedure [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sp_head.cc @ 2137]
mysqld!mysql_execute_command [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sql_parse.cc @ 4019]
mysqld!sp_instr_stmt::exec_core [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sp_head.cc @ 3119]
mysqld!sp_lex_keeper::reset_lex_and_exec_core [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sp_head.cc @ 2920]
mysqld!sp_instr_stmt::execute [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sp_head.cc @ 3056]
mysqld!sp_head::execute [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sp_head.cc @ 1390]
mysqld!sp_head::execute_procedure [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sp_head.cc @ 2137]
mysqld!mysql_execute_command [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sql_parse.cc @ 4019]
mysqld!mysql_parse [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sql_parse.cc @ 5586]
mysqld!dispatch_command [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sql_parse.cc @ 1133]
mysqld!do_command [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sql_parse.cc @ 802]
mysqld!do_handle_one_connection [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sql_connect.cc @ 1191]
mysqld!handle_one_connection [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\sql\sql_connect.cc @ 1131]
mysqld!pfs_spawn_thread [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\storage\perfschema\pfs.cc @ 1063]
mysqld!pthread_start [g:\pb2\build\sb_2-2196875-1282692712.96\mysql-5.6.1-m4-win-x86_64\mysys\my_winthread.c @ 62]
mysqld!_callthreadstartex [f:\dd\vctools\crt_bld\self_64_amd64\crt\src\threadex.c @ 348]
mysqld!_threadstartex [f:\dd\vctools\crt_bld\self_64_amd64\crt\src\threadex.c @ 331]
kernel32!BaseThreadInitThunk
ntdll!RtlUserThreadStart

How to repeat:
Check out PB.
For example:
http://tinyurl.com/34hqwpr
[25 Aug 2010 7:32] Alexander Nozdrin
There are also valgrind warnings:
[25 Aug 2010 7:33] Alexander Nozdrin
==11512== Invalid read of size 8
==11512==    at 0x6649B5: free_table_share(TABLE_SHARE*) (table.cc:482)
==11512==    by 0x567E9F: table_def_free_entry(TABLE_SHARE*) (sql_base.cc:289)
==11512==    by 0xA52AE1: my_hash_delete (hash.c:583)
==11512==    by 0x572CD7: get_table_share(THD*, TABLE_LIST*, char*, unsigned, unsigned, int*, unsigned) (sql_base.cc:547)
==11512==    by 0x573699: get_table_share_with_discover(THD*, TABLE_LIST*, char*, unsigned, unsigned, int*, unsigned) (sql_base.cc:622)
==11512==    by 0x574259: open_table(THD*, TABLE_LIST*, st_mem_root*, Open_table_context*) (sql_base.cc:2851)
==11512==    by 0x5754AA: open_and_process_table(THD*, LEX*, TABLE_LIST*, unsigned*, unsigned, Prelocking_strategy*, bool, Open_table_context*, st_mem_root*) (sql_base.cc:4347)
==11512==    by 0x575D1D: open_tables(THD*, TABLE_LIST**, unsigned*, unsigned, Prelocking_strategy*) (sql_base.cc:4776)
==11512==    by 0x576308: open_and_lock_tables(THD*, TABLE_LIST*, bool, unsigned, Prelocking_strategy*) (sql_base.cc:5365)
==11512==    by 0x5657B2: open_and_lock_tables(THD*, TABLE_LIST*, bool, unsigned) (sql_base.h:457)
==11512==    by 0x5B9D2C: execute_sqlcom_select(THD*, TABLE_LIST*) (sql_parse.cc:4522)
==11512==    by 0x5BAFD6: mysql_execute_command(THD*) (sql_parse.cc:2166)
==11512==    by 0x7EA0AE: sp_instr_stmt::exec_core(THD*, unsigned*) (sp_head.cc:3119)
==11512==    by 0x7EAA9D: sp_lex_keeper::reset_lex_and_exec_core(THD*, unsigned*, bool, sp_instr*) (sp_head.cc:2920)
==11512==    by 0x7EB1D2: sp_instr_stmt::execute(THD*, unsigned*) (sp_head.cc:3056)
==11512==    by 0x7ED778: sp_head::execute(THD*) (sp_head.cc:1390)
==11512==  Address 0xBA9AEB8 is 872 bytes inside a block of size 960 free'd
==11512==    at 0x4A0541E: free (vg_replace_malloc.c:233)
==11512==    by 0xA71DA9: my_free (my_malloc.c:128)
==11512==    by 0xA67275: free_root (my_alloc.c:365)
==11512==    by 0x664606: TABLE_SHARE::destroy() (table.cc:434)
==11512==    by 0x664908: free_table_share(TABLE_SHARE*) (table.cc:458)
==11512==    by 0x567E9F: table_def_free_entry(TABLE_SHARE*) (sql_base.cc:289)
==11512==    by 0xA52AE1: my_hash_delete (hash.c:583)
==11512==    by 0x572CD7: get_table_share(THD*, TABLE_LIST*, char*, unsigned, unsigned, int*, unsigned) (sql_base.cc:547)
==11512==    by 0x573699: get_table_share_with_discover(THD*, TABLE_LIST*, char*, unsigned, unsigned, int*, unsigned) (sql_base.cc:622)
==11512==    by 0x574259: open_table(THD*, TABLE_LIST*, st_mem_root*, Open_table_context*) (sql_base.cc:2851)
==11512==    by 0x5754AA: open_and_process_table(THD*, LEX*, TABLE_LIST*, unsigned*, unsigned, Prelocking_strategy*, bool, Open_table_context*, st_mem_root*) (sql_base.cc:4347)
==11512==    by 0x575D1D: open_tables(THD*, TABLE_LIST**, unsigned*, unsigned, Prelocking_strategy*) (sql_base.cc:4776)
==11512==    by 0x576308: open_and_lock_tables(THD*, TABLE_LIST*, bool, unsigned, Prelocking_strategy*) (sql_base.cc:5365)
==11512==    by 0x5657B2: open_and_lock_tables(THD*, TABLE_LIST*, bool, unsigned) (sql_base.h:457)
==11512==    by 0x5B9D2C: execute_sqlcom_select(THD*, TABLE_LIST*) (sql_parse.cc:4522)
==11512==    by 0x5BAFD6: mysql_execute_command(THD*) (sql_parse.cc:2166)
[25 Aug 2010 7:33] Alexander Nozdrin
Valgrind log: http://tinyurl.com/36w68ye
[26 Aug 2010 14:26] Alexander Nozdrin
The problem seems to be introduced by a merge from 5.5-runtime
(the push "jon.hauglid@orac... 2010-08-20 11:23:52" in trunk-bugfixing).
[26 Aug 2010 15: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/commits/116909

3242 Jon Olav Hauglid	2010-08-26
      Bug #56241 Valgrind/CDB warnings for many tests in trunk-bugfixing
      
      The reason for the warnings was that the performance schema
      instrumentation function release_table_share() could be called
      on a TABLE_SHARE that had already been free'd.
      
      The bug was introduced during merging of the patch for Bug#52044
      from mysql-5.5-bugfixing (which does not include the call to
      PSI release_table_share()) to mysql-trunk-bugfixing.
      
      This patch fixes the problem by moving the release_table_share()
      call to TABLE_SHARE::destroy() before the TABLE_SHARE is free'd.
      
      No test case added as this problem is detected by existing 
      valgrind tests.
[26 Aug 2010 15:41] Jon Olav Hauglid
Pushed to mysql-trunk-bugfixing and merged to mysql-next-mr-bugfixing.
[30 Aug 2010 8:32] Bugs System
Pushed into mysql-trunk 5.6.1-m4 (revid:alik@sun.com-20100830082732-n2eyijnv86exc5ci) (version source revid:alik@sun.com-20100830082732-n2eyijnv86exc5ci) (merge vers: 5.6.1-m4) (pib:21)
[30 Aug 2010 8:36] Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100830082745-n6sh01wlwh3itasv) (version source revid:alik@sun.com-20100830082745-n6sh01wlwh3itasv) (pib:21)
[2 Sep 2010 16:04] Paul DuBois
Bug did not appear in any released version. No changelog entry needed.