Bug #50615 Test backup_logs triggers assertion on Windows debug build.
Submitted: 26 Jan 2010 8:26 Modified: 2 Mar 2010 2:10
Reporter: Rafal Somla Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Backup Severity:S3 (Non-critical)
Version:mysql-6.0-backup-merge OS:Windows (debug build only)
Assigned to: Rafal Somla CPU Architecture:Any

[26 Jan 2010 8:26] Rafal Somla
Description:
Test backup_logs fails because of violated assertion:

------------------------------------------------------------------------------
backup.backup_logs                       [ fail ]
        Test ended at 2010-01-23 01:36:33

CURRENT_TEST: backup.backup_logs
mysqltest: At line 552: query 'SET @@global.backup_progress_log_file = repeat('a',255)' failed with wrong errno 2013: 'Lost connection to MySQL server during query', instead of 0...

The result from queries just before the failure was:
< snip >
503
The backup id for this command should be 504.
BACKUP DATABASE backup_logs to 'backup_logs_orig.bak';
backup_id
504
The backup id for this command should be 505.
BACKUP DATABASE backup_logs to 'backup_logs_orig.bak';
backup_id
505

Attempt to set the backup log paths to a really long string.

SET global max_allowed_packet=1024*100;

Now attempt to set the backup_progress_log_file to 127 characters.

SET @@global.backup_progress_log_file = repeat('a',127);

Now attempt to set the backup_progress_log_file to 255 characters.
------------------------------------------------------------------------------

STACK_TEXT:  
mysqld!my_sigabrt_handler [g:\pb2\build\sb_2-1227256-1264205023.46\mysql-6.0.14-alpha-win-x86\mysys\my_thr_init.c @ 590]
mysqld!raise [f:\dd\vctools\crt_bld\self_x86\crt\src\winsig.c @ 590]
mysqld!abort [f:\dd\vctools\crt_bld\self_x86\crt\src\abort.c @ 71]
mysqld!_wassert [f:\dd\vctools\crt_bld\self_x86\crt\src\assert.c @ 346]
mysqld!Diagnostics_area::set_ok_status [g:\pb2\build\sb_2-1227256-1264205023.46\mysql-6.0.14-alpha-win-x86\sql\sql_error.cc @ 358]
mysqld!my_ok [g:\pb2\build\sb_2-1227256-1264205023.46\mysql-6.0.14-alpha-win-x86\sql\sql_class.h @ 2697]
mysqld!mysql_execute_command [g:\pb2\build\sb_2-1227256-1264205023.46\mysql-6.0.14-alpha-win-x86\sql\sql_parse.cc @ 3544]
mysqld!mysql_parse [g:\pb2\build\sb_2-1227256-1264205023.46\mysql-6.0.14-alpha-win-x86\sql\sql_parse.cc @ 5979]
mysqld!dispatch_command [g:\pb2\build\sb_2-1227256-1264205023.46\mysql-6.0.14-alpha-win-x86\sql\sql_parse.cc @ 1092]
mysqld!do_command [g:\pb2\build\sb_2-1227256-1264205023.46\mysql-6.0.14-alpha-win-x86\sql\sql_parse.cc @ 776]
mysqld!do_handle_one_connection [g:\pb2\build\sb_2-1227256-1264205023.46\mysql-6.0.14-alpha-win-x86\sql\sql_connect.cc @ 1173]
mysqld!handle_one_connection [g:\pb2\build\sb_2-1227256-1264205023.46\mysql-6.0.14-alpha-win-x86\sql\sql_connect.cc @ 1113]
mysqld!pfs_spawn_thread [g:\pb2\build\sb_2-1227256-1264205023.46\mysql-6.0.14-alpha-win-x86\storage\perfschema\pfs.cc @ 1011]
mysqld!pthread_start [g:\pb2\build\sb_2-1227256-1264205023.46\mysql-6.0.14-alpha-win-x86\mysys\my_winthread.c @ 61]
mysqld!_callthreadstartex [f:\dd\vctools\crt_bld\self_x86\crt\src\threadex.c @ 348]
mysqld!_threadstartex [f:\dd\vctools\crt_bld\self_x86\crt\src\threadex.c @ 331]
kernel32!BaseThreadInitThunk
ntdll!__RtlUserThreadStart
ntdll!_RtlUserThreadStart

How to repeat:
Assertion is triggered when the following statement is executed:

  SET @@global.backup_progress_log_file = repeat('a',255);

This happens on Windows platform when tree is build in debug mode.
[26 Jan 2010 10:47] Rafal Somla
REFINED PROBLEM DESCRIPTION
---------------------------

When backup_progress_log_file gets new value, function fix_backup_progress_log_file() (sys_vars.cc:2643) is called from sys_var::update() (set_var.cc:173). Internally, this function calls fix_log() (sys_vars.cc:2572) which calls reopen_backup_progress_log() (sys_vars.cc:2638) which calls MYSQL_BACKUP_LOG::open_backup_progress_log()  at sys_vars.cc:2641.

An error can happen during the latter call, but there is no way to signal this error to the caller because reopen_backup_progress_log() does not return any value per API definition. Thus the error is ignored and the parser tries to execute my_ok() which leads to assertion.

For some reason which I don't understand, error happens only on Windows platform and only in debug build.
[26 Jan 2010 10:51] Rafal Somla
The error which happens during reopen is "File ... not found (error:2)". SQL error number is 29.
[26 Jan 2010 12:50] 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/98184

3819 Rafal Somla	2010-01-26
      BUG#50615 - Test backup_logs triggers assertion on Windows debug build.
      
      When fix_log() calls reopen_backup_{history,progress}_log callback, an error 
      can happen and be reported in the THD object. However, the callback has no 
      way of informing about the error (as it does not return any value) and thus 
      this error is not noticed by the caller. As a result, my_ok() is called on 
      THD with error reported which is prohibited and leads to an assertion.
      
      This is fixed by adding extra check for errors in THD after a call to 
      fix_log() in fix_backup_{history,progress}_log_path() functions.
     @ sql/sys_vars.cc
        In fix_backup_{history,progress}_log_path() add extra check for errors that
        might happen during fix_log() call and be reported in the THD object even
        if fix_log() returns 0.
[26 Jan 2010 14:20] Ingo Strüwing
Approved. No comments.
[26 Jan 2010 14:25] 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/98202

3822 Ingo Struewing	2010-01-26 [merge]
      Merged fix for Bug#50615.
[26 Jan 2010 15:52] Ingo Strüwing
Queued to mysql-6.0-backup-merge.
[20 Feb 2010 9:19] Bugs System
Pushed into 6.0.14-alpha (revid:ingo.struewing@sun.com-20100218152520-s4v1ld76bif06eqn) (version source revid:ingo.struewing@sun.com-20100126142427-jrs9e270s1kcs7l9) (merge vers: 6.0.14-alpha) (pib:16)
[2 Mar 2010 2:10] Paul DuBois
Noted in 6.0.14 changelog.

For debug builds on Windows, incorrect error handling for the backup
logs caused an assertion to be raised.