MySQL Bugs: #49398: Incorrect 1691 Can't open the backup logs as tables error on BACKUP/RESTORE

Bug #49398	Incorrect 1691 Can't open the backup logs as tables error on BACKUP/RESTORE
Submitted:	3 Dec 2009 13:25	Modified:	2 Mar 2010 1:33
Reporter:	Philip Stoev	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Backup	Severity:	S2 (Serious)
Version:	6.0-backup	OS:	Any
Assigned to:	Ritheesh Vedire	CPU Architecture:	Any

Description:
When executing concurrent BACKUP/RESTORE in two threads, some of the operations will fail with

1691 Can't open the backup logs as tables. Check 'mysql.backup_history' and 'mysql.backup_progress' or run mysql_upgrade to repair.

This error message is not correct since those tables are OK and replaying the same operation again will succeed.

Code examination reveals that the backup code attempts to open 'mysql.backup_history' and 'mysql.backup_progress' tables and interprets an unsuccessfull open as a sign that the table does not exist, which is not a correct assumption.

It seems that there are other seasons for the table open to fail, and the code does not account for them. If it is possible for some sort of sharing violation to occur, this means that the code that prevents concurrent backups and restores from working does not operate correctly.

How to repeat:
A grammar file will be uploaded for this shortly. Apologies for the unsimplified nature of the grammar, we are having some issues with the automatic simplification tool.

Please let me know if a simplifed grammar would be required to debug this issue, and I will provide it.

Suggested fix:
* If the table open fails , identify the correct reason and print it along with the error message so that the issue can be further researched.

* Do not use open_table to figure out if the tables exist. There is probably a targeted mysql function for that.

bug49398.yy

Attachment: bug49398.yy (application/octet-stream, text), 69.76 KiB.

To reproduce with the RQG:

$ perl runall.pl \
  --grammar=conf/bug49398.yy \
  --basedir=/build/bzr/mysql-6.0-backup \
  --queries=100K \
  --mysqld=--mysql-backup \
  --gendata=conf/WL5004_data.zz \
  --threads=2

Please ignore all output from the script -- it will terminate automatically as soon as the problematic error message is encountered, usually within 20 seconds.

May be related to BUG#49399.

Rafal, this bug does not ask for concurrent backups or restores and does not ask for any change in the behavior. The bug is about the spurous error message that is being produced. I have also seen this error when the backups and restores are strictly non-concurrent.

I think what Omer meant is that it is to be expected that backup/restore operations will be *issued* by the clients concurrently, but I do not think that he expects them to be *executed* concurrently.

For Info, the output from the RQG.

Attachment: 49398_RQG.txt (text/plain), 10.99 KiB.

For Info,
 The Error 1691: "Can't open the backup logs as tables. Check 'mysql.backup_history' and 'mysql.backup_progress' or run mysql_upgrade to repair"

 actually arises due to ERROR 1100, (ER_TABLE_NOT_LOCKED) in open_n_lock_tables().

This is the same  error reported by FLUSH TABLES. ( See 49398_RQG.txt above)

If you can, please make it so that the 1100 error code (or the other actual error that caused the "can't open backup logs" situation is reported in the error message or in the logs. This is going to make debugging future bugs easier.

Hi Philip,

You suggested that it would be good to see internal errors ("internal" from the point of view of backup module) such as ER_TABLE_NOT_LOCKED in the backup logs.

I understand that it would help in investigating failures, but doing this would require substantial changes to the error reporting framework we have now - something I think we should not do just before the release. 

Currently, these "internal" errors are not logged in the backup logs, but they are pushed on the error stack and visible to client with commands such as SHOW ERRORS. Would it be possible to access them this way from your RQG framework? That is, in case of error, SHOW WARNINGS could be issued in the connection so that all errors are seen.

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/96081

2927 Ritheesh Vedire	2010-01-06
      BUG#49398: Incorrect 1691 Can't open the backup logs as 
                 tables error on BACKUP/RESTORE.
      
       This Error occurs due to the error ER_TABLE_NOT_LOCKED 
       in open_table() (sql_base.cc). 
      
      
       Replaced simple_open_n_lock_tables() with open_and_lock_tables_derived()
       and set the flags.
     @ sql/log.cc
        Set the flags to MYSQL_GET_NEW_TABLE to avoid the error.

Planned changes to the patch:

1) Instead of doing open_and_lock_tables_derived(.., .., .., 0x0080),
   I will use symbolic constant for 0x0080.
    i.e 
    open_and_lock_tables_derived(.., .., .., MYSQL_OPEN_GET_NEW_TABLE).

Just to mention the obvious. We open the log table before we check for concurrently running BACKUP or RESTORE. We want to log the error, which results from an attempt to run such in parallel.

Hence our first attempt is to get the log open right. Only if this would not be possible, we might consider to do the concurrency check earlier.

The proposed patch changes one open function by another. It does not add a test case. So it is not clear, if this fixes the problem. Also it does not mention, why an ER_TABLE_NOT_LOCKED error is produced. I have to do this investigation myself. The review might take more time as usual for a small patch like this.

This Error occurs in LOCKED TABLES mode.
One such scenario is 
1) A thread issued LOCK TABLES for a few tables.
2) It hasn't done UNLOCK TABLES.
3) In the meantime, It has issued BACKUP command
4) It couldn't open backup log tables 
     - as tables are not  locked (ER_TABLE_NOT_LOCKED).

This may not be the only scenario, there must be several.
But whatever is the scenario, when in LOCKED TABLES mode, backup tables should log and a ER_BACKUP_PROGRESS_TABLES() i.e Error 1691 is not acceptable.

PROPOSED SOLUTIONS:

1) Skip the 'If' logic in open_table() as mentioned in the first patch. 
   Kostja warned that this may lead to dead locks. This solution is ruled out.
2) Use open_performace_schema_table() for backup_log tables. general_log tables  
   use the same function. This solution will be in my next patch.

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/96698

2932 Ritheesh Vedire	2010-01-13
      BUG#49398: Incorrect 1691 Can't open the backup logs as tables
                 error on BACKUP/RESTORE.
      
       simple_open_n_lock_tables(..) was  used to check if backup tables
       are alright in MYSQL_BACKUP_LOG::check_backup_logs().
       During LTM_LOCK_TABLES mode, backup log tables cannot be opened. 
       This patch makes the backup log tables to be opened even in LOCK_TABLES mode.
                   
     @ sql/log.cc
         Replaced simple_open_n_lock_tables(...) with 
         open_performance_schema_table(...). The latter function backs up the 
         open tables state, making backup log tables to be opened even in LOCK_TABLES 
         mode.

Missing test case. Patch incomplete.

Based on discussions with Ingo, (Review mails) the next action is:
1) Wait for next merge to happen.
   (To bring mysql-6.0-codebase changes to mysql-6.0-backup)
2) Have a team + QA discussion over the general behaviour/Error generation of 
   backup log tables.

According to today's team decision the patch is fine for push. The team did not ask for a test case.

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/98325

2932 Ritheesh Vedire	2010-01-27
      BUG#49398: Incorrect 1691 Can't open the backup logs as tables
                 error on BACKUP/RESTORE.
      
      
       BACKUP operation failed during LOCK_TABLES mode when trying to
       open backup log tables in MYSQL_BACKUP_LOG::check_backup_logs(). 
       This patch makes backup log tables to be opened even in LOCK_TABLES
       mode.
     @ sql/log.cc
         Replaced simple_open_n_lock_tables() with
         open_performance_schema_table(). The latter function backs up
         the open tables state, making backup log tables to be opened
         even in LOCK_TABLES mode.

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/98461

2939 Ritheesh Vedire	2010-01-28
      BUG#49398: Incorrect 1691 Can't open the backup logs as tables 
                 error on BACKUP/RESTORE.
      
       BACKUP operation failed during LOCK_TABLES mode when trying to
       open backup log tables in MYSQL_BACKUP_LOG::check_backup_logs().
       This patch makes backup log tables to be opened even in LOCK_TABLES
       mode.
     @ sql/log.cc
         Replaced simple_open_n_lock_tables() with
         open_performance_schema_table(). The latter function backs up 
         the open tables state, making backup log tables to be opened 
         even in LOCK_TABLES mode.

Pushed.
revision-id: ritheesh.vedire@sun.com-20100128122444-vvmm6vsnbe82vgja

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/98480

3074 Chuck Bell	2010-01-28
      BUG#49398: Incorrect 1691 Can't open the backup logs as tables 
                 error on BACKUP/RESTORE.
        
      BACKUP operation failed during LOCK_TABLES mode when trying to
      open backup log tables in MYSQL_BACKUP_LOG::check_backup_logs().
      This patch makes backup log tables to be opened even in LOCK_TABLES
      mode.
      
      original changeset: 2939 (mysql-6.0-backup)

Pushed into 6.0.14-alpha (revid:ingo.struewing@sun.com-20100218152520-s4v1ld76bif06eqn) (version source revid:ingo.struewing@sun.com-20100202134837-dgbscc9m1d4dnw3y) (merge vers: 6.0.14-alpha) (pib:16)

Noted in 6.0.14 changelog.

If a LOCK TABLES statement was in effect, BACKUP DATABASE was unable
to open the backup log tables.