Bug #58179 cannot start mysqld with app verifier
Submitted: 14 Nov 2010 7:06 Modified: 3 May 2011 1:19
Reporter: Shane Bester (Platinum Quality Contributor) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Windows Severity:S3 (Non-critical)
Version:5.5.7 OS:Windows (XP64)
Assigned to: Magne Mæhre CPU Architecture:Any
Tags: application verifier, regression

[14 Nov 2010 7:06] Shane Bester
Description:
For debug build we get earlier message:

<avrf:message>Invalid TLS index used for current stack trace.</avrf:message> 
<avrf:parameter1>0 - Invalid TLS index.</avrf:parameter1> 
<avrf:parameter2>abba - Expected lower part of the index.</avrf:parameter2> 
<avrf:parameter3>0 - Not used.</avrf:parameter3> 
<avrf:parameter4>0 - Not used.</avrf:parameter4> 

ntdll.dll!DbgBreakPoint	
vrfcore.dll!VerifierStopMessageEx	
vfbasics.dll!CheckTlsIndex
vfbasics.dll!AVrfpTlsGetValue
mysqld-debug.exe!my_thread_var_dbug
mysqld-debug.exe!code_state  Line 382	
mysqld-debug.exe!_db_enter__  Line 1141
mysqld-debug.exe!my_path Line 39	
mysqld-debug.exe!mysqld_main Line 4743	
mysqld-debug.exe!main Line 25	
mysqld-debug.exe!__tmainCRTStartup Line 266	
mysqld-debug.exe!mainCRTStartup  Line 182	
kernel32.dll!BaseProcessStart  + 0x2c bytes	

The code in question is this:
  struct st_my_thread_var *tmp=
    my_pthread_getspecific(struct st_my_thread_var*,THR_KEY_mysys);

THD_KEY_mysys is still 0x00000000

For release build we get:

VERIFIER STOP 0000000000000211: pid 0x1FE0: Critical section is already initialized. 

00001408FA4E0 : Critical section address.
0000002B74FD0 : Critical section debug info address.
0000000181548 : First initialization stack trace. Use dps to dump it if non-NULL
0000000000000 : Not used.

ntdll!DbgBreakPoint
vrfcore!VerifierStopMessageEx+0x772
vfbasics!AVrfpInitializeCriticalSectionCommon+0xf8
kernel32!InitializeCriticalSection+0xa
mysqld!my_thread_global_init+0x5c [.\mysys\my_thr_init.c @ 218]
mysqld!my_init+0x29 [.\mysys\my_init.c @ 142]
mysqld!win_main+0x1ea [.\sql\mysqld.cc @ 4318]
mysqld!mysql_service+0x38 [.\sql\mysqld.cc @ 4637]
mysqld!mysqld_main+0x2e3 [.\sql\mysqld.cc @ 4823]
mysqld!__tmainCRTStartup+0x15b [.\src\crt0.c @ 266]
kernel32!BaseProcessStart+0x29

It appears that my_basic_init() already called my_thread_global_init()
who did mysql_mutex_init(key_THR_LOCK_isam, &THR_LOCK_isam, MY_MUTEX_INIT_SLOW);

Both these errors are continuable and are not fatal.

How to repeat:
enable basic checks for mysqld.exe and mysqld-debug.exe in app verifier.
start the server.

Suggested fix:
i'm not sure.  it would be nice to be able to run the server under these tools without a zillion errors, and starting it up should be error free.

there is probably some windows app certification that cannot be obtained as long as these errors exist..
[15 Nov 2010 1:49] MySQL Verification Team
Thank you for the bug report.

<?xml version="1.0" encoding="UTF-8" standalone="no" ?> 
- <avrf:logfile xmlns:avrf="Application Verifier">
- <avrf:logSession TimeStarted="2010-11-14 : 23:42:30" PID="5444" Version="2">
- <avrf:logEntry Time="2010-11-14 : 23:42:31" LayerName="Handles" StopCode="0x301" Severity="Error">
  <avrf:message>Invalid TLS index used for current stack trace.</avrf:message> 
  <avrf:parameter1>0 - Invalid TLS index.</avrf:parameter1> 
  <avrf:parameter2>abba - Expected lower part of the index.</avrf:parameter2> 
  <avrf:parameter3>0 - Not used.</avrf:parameter3> 
  <avrf:parameter4>0 - Not used.</avrf:parameter4> 
- <avrf:stackTrace>
  <avrf:trace>vfbasics!CheckTlsIndex+84 (d:\avrf\source\base\avrf\vrfcommon\tls.c @ 227)</avrf:trace> 

<cut>
[16 Nov 2010 5:16] MySQL Verification Team
Omer, Application verifier is a Microsoft application that checks for certain commonly made programming mistakes on Windows.

http://support.microsoft.com/kb/286568
http://technet.microsoft.com/en-us/library/cc778113(WS.10).aspx
http://technet.microsoft.com/en-us/library/bb457063.aspx

5.1 didn't have problems starting up under app verifier.  5.5 does.
There appears to be no direct user impact here, which I why I set I3.

Oracle should care about such bugs in the unlikely event they want any windows certification logos [i believe].
[14 Dec 2010 12:17] Magne Mæhre
App.ver also reports an issue on shutdown:

 <?xml version="1.0" encoding="UTF-8" standalone="no" ?> 
- <avrf:logfile xmlns:avrf="Application Verifier">
- <avrf:logSession TimeStarted="2010-12-14 : 13:12:45" PID="3604" Version="2">
- <avrf:logEntry Time="2010-12-14 : 13:12:51" LayerName="Handles" StopCode="0x303" Severity="Error">
  <avrf:message>NULL handle passed as parameter. A valid handle must be used.</avrf:message> 
  <avrf:parameter1>0 - Not used.</avrf:parameter1> 
  <avrf:parameter2>0 - Not used.</avrf:parameter2> 
  <avrf:parameter3>0 - Not used.</avrf:parameter3> 
  <avrf:parameter4>0 - Not used.</avrf:parameter4> 
- <avrf:stackTrace>
  <avrf:trace>vfbasics!AVrfpHandleSanityChecks+29 (d:\avrf\source\base\avrf\vrfcommon\handle.c @ 178)</avrf:trace> 
  <avrf:trace>vfbasics!AVrfpNtSetEvent+1f (d:\avrf\source\base\avrf\vrfcommon\handle.c @ 390)</avrf:trace> 
  <avrf:trace>kernel32!SetEvent+10 ( @ 0)</avrf:trace> 
  <avrf:trace>mysqld!kill_server+e8 (c:\x\tb\sql\mysqld.cc @ 1280)</avrf:trace> 
  <avrf:trace>mysqld!handle_shutdown+6d (c:\x\tb\sql\mysqld.cc @ 2875)</avrf:trace> 
  <avrf:trace>mysqld!pfs_spawn_thread+11b (c:\x\tb\storage\perfschema\pfs.cc @ 1360)</avrf:trace> 
  <avrf:trace>mysqld!pthread_start+48 (c:\x\tb\mysys\my_winthread.c @ 61)</avrf:trace> 
  <avrf:trace>mysqld!_callthreadstartex+53 (f:\dd\vctools\crt_bld\self_x86\crt\src\threadex.c @ 348)</avrf:trace> 
  <avrf:trace>mysqld!_threadstartex+a4 (f:\dd\vctools\crt_bld\self_x86\crt\src\threadex.c @ 331)</avrf:trace> 
  <avrf:trace>vfbasics!AVrfpStandardThreadFunction+2f (d:\avrf\source\base\avrf\vrfcommon\thread.c @ 656)</avrf:trace> 
  <avrf:trace>kernel32!GetModuleFileNameA+1ba ( @ 0)</avrf:trace> 
  </avrf:stackTrace>
  </avrf:logEntry>
  </avrf:logSession>
  </avrf:logfile>
[14 Dec 2010 12:38] MySQL Verification Team
Magne, the shutdown crash in appverifier is reported in bug #55730
[14 Dec 2010 13:39] 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/126773

3426 Magne Mahre	2010-12-14
      Bug #58179 cannot start mysqld with app verifier
      Bug #55730 kill_server() calls SetEvent on a null handle, 
                  smem_event_connect_request
      
      Application Verifier is a Microsoft tool used for
      detecting certain classes of programming errors.
      In particular, MS Windows OS resource usage is 
      monitored for wrong usage (handles, thread local
      storage, critical sections, ...)
      
      In MySQL 5.5.x, an error was introduced where an
      object on thread local storage was used before the
      TLS and the object was created.
      
      The fix has been to move the mysys initialization
      to an earlier stage in the boot process when built for
      Windows.  For non-win builds, the init already happens
      early.
      
      Some un-tangling of calls to my_init(), my_basic_init() 
      and my_thread_global_init() was done.  There is no
      longer a need to do init in steps, so the full my_init()
      is called instead of my_init_basic().
      
      In addition, Bug#55730 was fixed.  The event handle
      'smem_event_connect_request' is only created if 
      'opt_enable_shared_memory' is set.  When killing the
      server, an event was flagged on the handle
      unconditionally.  Added a test, so it will only be 
      flagged if created.
     @ mysys/my_init.c
        my_thread_global_init is already called from
        my_basic_init.
[14 Dec 2010 13:40] Magne Mæhre
Above patch will also fix Bug#54334 Double initialization of mysys mutexes
[5 Jan 2011 13:56] 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/127977

3461 Magne Mahre	2011-01-05
      Bug#58179 cannot start mysqld with app verifier
      Bug#55730 kill_server() calls SetEvent on a null handle, 
                 smem_event_connect_request
            
      Application Verifier is a Microsoft tool used for
      detecting certain classes of programming errors.
      In particular, MS Windows OS resource usage is 
      monitored for wrong usage (handles, thread local
      storage, critical sections, ...)
            
      In MySQL 5.5.x, an error was introduced where an
      object on thread local storage was used before the
      TLS and the object was created.
            
      The fix has been to split the mysys initialization
      into additional parts so the different subsystems
      of mysys can be initialized at different stages
      in the database startup sequence.
            
      In addition, Bug#55730 was fixed.  The event handle
      'smem_event_connect_request' is only created if 
      'opt_enable_shared_memory' is set.  When killing the
      server, an event was flagged on the handle
      unconditionally.  Added a test, so it will only be 
      flagged if created.
     @ mysys/my_init.c
        my_basic_init was renamed to my_init_part1
        The rest of mysys initialization is moved
        to my_init_part2.   my_init() now only
        calls my_init_part1() and my_init_part2()
        
        my_init_part1() now calls my_thread_init_part1()
        my_init_part2() call my_thread_init_part2() and
        my_thread init_part3()
     @ mysys/my_thr_init.c
        Thread initialization is split into three
        parts (was two).  my_thread_init_part1()
        initializes 'THR_KEY_mysys', as this must
        be done before you can use debugging
        features.
        
        my_thread_init_part2 is a new name for
        my_thread_basic_global_init
        
        my_thread_init_part3 is mostly just a rename
        for my_thread_global_init.
[10 Jan 2011 10:33] Marc ALFF
The following patch
http://lists.mysql.com/commits/127977
looks ok.

Thanks for the cleanup in this area.

Waiting for the other reviewer before setting status to approved.
[3 May 2011 1:19] Paul DuBois
Noted in 5.5.11, 5.6.3 changelogs.

On Windows, an object in thread local storage could be used before
the object was created. 

CHANGESET - http://lists.mysql.com/commits/132185