List:Maria Storage Engine« Previous MessageNext Message »
From:Guilhem Bichot Date:January 15 2009 3:15pm
Subject:bzr commit into MySQL/Maria:mysql-maria branch (guilhem:2719) Bug#41493
View as plain text  
#At bzr+ssh://bk-internal.mysql.com/bzrroot/server/mysql-maria/ based on revid:guilhem@stripped

 2719 Guilhem Bichot	2009-01-15
      Fix for BUG#41493 "Maria: two recovery failures (wrong logging of BLOB pages)" and some more debugging
      output related to this.
modified:
  mysql-test/suite/maria/r/maria-recovery3.result
  mysql-test/suite/maria/t/maria-recovery3.test
  storage/maria/ma_blockrec.c
  storage/maria/ma_blockrec.h
  storage/maria/ma_recovery.c

per-file messages:
  mysql-test/suite/maria/r/maria-recovery3.result
    result update
  mysql-test/suite/maria/t/maria-recovery3.test
    Test for bug; before the fix, the "CHECK TABLE EXTENDED" would mention a bad bitmap, because the
    REDO_INSERT_ROW_BLOBS was containing a page number which was actually the one of a tail, so execution of this
    record would mark the tail page as full in bitmap (like if it were a blob page), though it wasn't full.
    Also, the assertion added around ma_blockrec.c:6580 in the present revision fired.
  storage/maria/ma_blockrec.c
    - fix for BUG#41493: if we found out that logging was not needed at this point (blob_length==0 i.e. tail page),
    then we forgot to increment tmp_block, so in the second iteration (assuming two BLOB columns), we would log the
    page range of the first iteration (i.e. the tail page's number) for this second BLOB, which would cause
    Recovery to overwrite the tail page with the second BLOB.
    - assert when marking the table corrupted during REDO phase; this catches some problems earlier
    otherwise they get caught only when a later record wants to use the table.
    - _ma_apply_redo_insert_row_blobs() now fills some synthetic info about the blobs and pages involved
    in a REDO_INSERT_ROW_BLOBS record, for inclusion into maria_recovery.trace: number of blobs, of ranges,
    first and last page (does not tell about any gaps in the middle, but good enough for now). It also asserts
    that it's not overwriting a tail/head page (which happened in the bug).
  storage/maria/ma_blockrec.h
    new prototype for _ma_apply_redo_insert_row_blobs
  storage/maria/ma_recovery.c
    Print info got from _ma_apply_redo_insert_row_blobs() to maria_recovery.trace (so far this file had mentioned
    what head and tail pages a record touched, but not blob pages).
=== modified file 'mysql-test/suite/maria/r/maria-recovery3.result'
--- a/mysql-test/suite/maria/r/maria-recovery3.result	2008-12-05 21:11:46 +0000
+++ b/mysql-test/suite/maria/r/maria-recovery3.result	2009-01-15 15:14:47 +0000
@@ -25,5 +25,43 @@ Checksum-check
 ok
 use mysqltest;
 drop table t1;
+* TEST of logging of BLOBs
+CREATE TABLE `t1` (
+`blob` blob,
+`blob_key` blob
+) ENGINE=maria ROW_FORMAT=page
+;
+* copied t1 for feeding_recovery
+* compared t1 to old version
+set global maria_checkpoint_interval=0;
+INSERT INTO `t1` VALUES (NULL,repeat('A',5198));
+INSERT INTO `t1` VALUES (NULL,repeat('B',65535));
+INSERT INTO `t1` VALUES (repeat('K',5198),repeat('L',2325));
+INSERT INTO `t1` VALUES (repeat('C',65535),NULL);
+INSERT INTO `t1` VALUES (NULL,repeat('D',65535));
+INSERT INTO `t1` VALUES (repeat('E',65535),repeat('F',16111));
+INSERT INTO `t1` VALUES (repeat('G',65535),repeat('H',65535));
+INSERT INTO `t1` VALUES (repeat('I',5198),repeat('J',65535));
+check table t1 extended;
+Table	Op	Msg_type	Msg_text
+mysqltest.t1	check	status	OK
+flush table t1;
+* copied t1 for comparison
+* compared t1 to old version
+SET SESSION debug="+d,maria_flush_whole_log,maria_crash";
+* crashing mysqld intentionally
+set global maria_checkpoint_interval=1;
+ERROR HY000: Lost connection to MySQL server during query
+* copied t1 back for feeding_recovery
+* recovery happens
+check table t1 extended;
+Table	Op	Msg_type	Msg_text
+mysqltest.t1	check	status	OK
+* testing that checksum after recovery is as expected
+Checksum-check
+ok
+* compared t1 to old version
+use mysqltest;
+drop table t1;
 drop database mysqltest_for_comparison;
 drop database mysqltest;

=== modified file 'mysql-test/suite/maria/t/maria-recovery3.test'
--- a/mysql-test/suite/maria/t/maria-recovery3.test	2008-12-05 21:11:46 +0000
+++ b/mysql-test/suite/maria/t/maria-recovery3.test	2009-01-15 15:14:47 +0000
@@ -39,7 +39,6 @@ let $mvr_restore_old_snapshot=0;
 # UNDO phase prevents physical comparison, normally,
 # so we'll only use checksums to compare.
 let $mms_compare_physically=0;
-let $mvr_crash_statement= set global maria_checkpoint_interval=1;
 create table t1(a int primary key) engine=maria;
 insert into t1 values(1);
 -- source include/maria_make_snapshot_for_comparison.inc
@@ -65,6 +64,30 @@ drop table t1;
 # before checkpoint happens, test should still pass (though it won't
 # reproduce the conditions of the bug).
 
+# Test for BUG#41493 Maria: two recovery failures (wrong logging of BLOB pages)
+--echo * TEST of logging of BLOBs
+let $mvr_restore_old_snapshot=1;
+let $mms_compare_physically=1;
+CREATE TABLE `t1` (
+`blob` blob,
+`blob_key` blob
+) ENGINE=maria ROW_FORMAT=page
+;
+-- source include/maria_make_snapshot_for_feeding_recovery.inc
+set global maria_checkpoint_interval=0; # no checkpoints
+INSERT INTO `t1` VALUES (NULL,repeat('A',5198));
+INSERT INTO `t1` VALUES (NULL,repeat('B',65535));
+INSERT INTO `t1` VALUES (repeat('K',5198),repeat('L',2325));
+INSERT INTO `t1` VALUES (repeat('C',65535),NULL);
+INSERT INTO `t1` VALUES (NULL,repeat('D',65535));
+INSERT INTO `t1` VALUES (repeat('E',65535),repeat('F',16111));
+INSERT INTO `t1` VALUES (repeat('G',65535),repeat('H',65535));
+INSERT INTO `t1` VALUES (repeat('I',5198),repeat('J',65535));
+check table t1 extended;
+-- source include/maria_make_snapshot_for_comparison.inc
+-- source include/maria_verify_recovery.inc
+drop table t1;
+
 # clean up everything
 let $mms_purpose=comparison;
 eval drop database mysqltest_for_$mms_purpose;

=== modified file 'storage/maria/ma_blockrec.c'
--- a/storage/maria/ma_blockrec.c	2009-01-09 04:11:37 +0000
+++ b/storage/maria/ma_blockrec.c	2009-01-15 15:14:47 +0000
@@ -3146,8 +3146,8 @@ static my_bool write_block_record(MARIA_
 
           log_pos= store_page_range(log_pos, tmp_block, block_size,
                                     blob_length, &extents);
-          tmp_block+= tmp_block->sub_blocks;
         }
+        tmp_block+= tmp_block->sub_blocks;
       }
     }
 
@@ -6182,6 +6182,7 @@ err:
                              PAGECACHE_UNPIN, LSN_IMPOSSIBLE,
                              LSN_IMPOSSIBLE, 0, FALSE);
   _ma_mark_file_crashed(share);
+  DBUG_ASSERT(0); /* catch recovery errors early */
   DBUG_RETURN((my_errno= error));
 }
 
@@ -6280,6 +6281,7 @@ err:
                            PAGECACHE_UNPIN, LSN_IMPOSSIBLE,
                            LSN_IMPOSSIBLE, 0, FALSE);
   _ma_mark_file_crashed(share);
+  DBUG_ASSERT(0);
   DBUG_RETURN((my_errno= error));
 
 }
@@ -6337,6 +6339,7 @@ uint _ma_apply_redo_free_blocks(MARIA_HA
     if (res)
     {
       _ma_mark_file_crashed(share);
+      DBUG_ASSERT(0);
       DBUG_RETURN(res);
     }
   }
@@ -6420,6 +6423,7 @@ uint _ma_apply_redo_free_head_or_tail(MA
 
 err:
   _ma_mark_file_crashed(share);
+  DBUG_ASSERT(0);
   DBUG_RETURN(1);
 }
 
@@ -6431,6 +6435,10 @@ err:
    @parma  lsn             LSN to put on pages
    @param  header          Header (with FILEID)
    @param  redo_lsn        REDO record's LSN
+   @param[out] number_of_blobs Number of blobs found in log record
+   @param[out] number_of_ranges Number of ranges found
+   @param[out] first_page  First page touched
+   @param[out] last_page   Last page touched
 
    @note Write full pages (full head & blob pages)
 
@@ -6441,13 +6449,18 @@ err:
 
 uint _ma_apply_redo_insert_row_blobs(MARIA_HA *info,
                                      LSN lsn, const uchar *header,
-                                     LSN redo_lsn)
+                                     LSN redo_lsn,
+                                     uint * const number_of_blobs,
+                                     uint * const number_of_ranges,
+                                     pgcache_page_no_t * const first_page,
+                                     pgcache_page_no_t * const last_page)
 {
   MARIA_SHARE *share= info->s;
   const uchar *data;
   uint      data_size= FULL_PAGE_SIZE(share->block_size);
   uint      blob_count, ranges;
   uint16    sid;
+  pgcache_page_no_t first_page2= ULONGLONG_MAX, last_page2= 0;
   DBUG_ENTER("_ma_apply_redo_insert_row_blobs");
 
   share->state.changed|= (STATE_CHANGED | STATE_NOT_ZEROFILLED |
@@ -6455,9 +6468,9 @@ uint _ma_apply_redo_insert_row_blobs(MAR
 
   sid= fileid_korr(header);
   header+= FILEID_STORE_SIZE;
-  ranges= pagerange_korr(header);
+  *number_of_ranges= ranges= pagerange_korr(header);
   header+= PAGERANGE_STORE_SIZE;
-  blob_count= pagerange_korr(header);
+  *number_of_blobs= blob_count= pagerange_korr(header);
   header+= PAGERANGE_STORE_SIZE;
   DBUG_ASSERT(ranges >= blob_count);
 
@@ -6495,6 +6508,8 @@ uint _ma_apply_redo_insert_row_blobs(MAR
         enum pagecache_page_pin unpin_method;
         uint length;
 
+        set_if_smaller(first_page2, page);
+        set_if_bigger(last_page2, page);
         if (_ma_redo_not_needed_for_page(sid, redo_lsn, page, FALSE))
           continue;
 
@@ -6545,15 +6560,22 @@ uint _ma_apply_redo_insert_row_blobs(MAR
           }
           else
           {
+#ifndef DBUG_OFF
+            uchar found_page_type= (buff[PAGE_TYPE_OFFSET] & PAGE_TYPE_MASK);
+#endif
             if (lsn_korr(buff) >= lsn)
             {
               /* Already applied */
+              DBUG_PRINT("info", ("already applied %llu >= %llu",
+                                  lsn_korr(buff), lsn));
               pagecache_unlock_by_link(share->pagecache, page_link.link,
                                        PAGECACHE_LOCK_WRITE_UNLOCK,
                                        PAGECACHE_UNPIN, LSN_IMPOSSIBLE,
                                        LSN_IMPOSSIBLE, 0, FALSE);
               continue;
             }
+            DBUG_ASSERT((found_page_type == (uchar) BLOB_PAGE) ||
+                        (found_page_type == (uchar) UNALLOCATED_PAGE));
           }
           unlock_method= PAGECACHE_LOCK_WRITE_UNLOCK;
           unpin_method=  PAGECACHE_UNPIN;
@@ -6595,10 +6617,13 @@ uint _ma_apply_redo_insert_row_blobs(MAR
         goto err;
     }
   }
+  *first_page= first_page2;
+  *last_page=  last_page2;
   DBUG_RETURN(0);
 
 err:
   _ma_mark_file_crashed(share);
+  DBUG_ASSERT(0);
   DBUG_RETURN(1);
 }
 

=== modified file 'storage/maria/ma_blockrec.h'
--- a/storage/maria/ma_blockrec.h	2008-12-05 21:11:46 +0000
+++ b/storage/maria/ma_blockrec.h	2009-01-15 15:14:47 +0000
@@ -236,7 +236,11 @@ uint _ma_apply_redo_free_blocks(MARIA_HA
 uint _ma_apply_redo_free_head_or_tail(MARIA_HA *info, LSN lsn,
                                       const uchar *header);
 uint _ma_apply_redo_insert_row_blobs(MARIA_HA *info, LSN lsn,
-                                     const uchar *header, LSN redo_lsn);
+                                     const uchar *header, LSN redo_lsn,
+                                     uint * const number_of_blobs,
+                                     uint * const number_of_ranges,
+                                     pgcache_page_no_t * const first_page,
+                                     pgcache_page_no_t * const last_page);
 my_bool _ma_apply_redo_bitmap_new_page(MARIA_HA *info, LSN lsn,
                                        const uchar *header);
 my_bool _ma_apply_undo_row_insert(MARIA_HA *info, LSN undo_lsn,

=== modified file 'storage/maria/ma_recovery.c'
--- a/storage/maria/ma_recovery.c	2008-12-09 09:56:02 +0000
+++ b/storage/maria/ma_recovery.c	2009-01-15 15:14:47 +0000
@@ -1412,6 +1412,9 @@ prototype_redo_exec_hook(REDO_INSERT_ROW
 {
   int error= 1;
   uchar *buff;
+  uint number_of_blobs, number_of_ranges;
+  pgcache_page_no_t first_page, last_page;
+  char llbuf1[22], llbuf2[22];
   MARIA_HA *info= get_MARIA_HA_from_REDO_record(rec);
   if (info == NULL)
     return 0;
@@ -1426,11 +1429,19 @@ prototype_redo_exec_hook(REDO_INSERT_ROW
   }
   buff= log_record_buffer.str;
   if (_ma_apply_redo_insert_row_blobs(info, current_group_end_lsn,
-                                      buff, rec->lsn))
+                                      buff, rec->lsn, &number_of_blobs,
+                                      &number_of_ranges,
+                                      &first_page, &last_page))
     goto end;
+  llstr(first_page, llbuf1);
+  llstr(last_page, llbuf2);
+  tprint(tracef, " %u blobs %u ranges, first page %s last %s",
+         number_of_blobs, number_of_ranges, llbuf1, llbuf2);
+
   error= 0;
 
 end:
+  tprint(tracef, " \n");
   return error;
 }
 

Thread
bzr commit into MySQL/Maria:mysql-maria branch (guilhem:2719) Bug#41493Guilhem Bichot15 Jan