From d6faf6c464f948480952873b15701d696a422245 Mon Sep 17 00:00:00 2001 From: marko <> Date: Wed, 16 Sep 2009 07:07:21 +0000 Subject: [PATCH] branches/zip: Introduce UNIV_LOG_LSN_DEBUG and MLOG_LSN for redo log diagnostics. This was written in order to better track down Issue #313 in InnoDB Hot Backup. MLOG_LSN: A new redo log entry type, for recording the current log sequence number (LSN). This will be checked in an assertion in recv_parse_log_rec(). rb://161, discussed with Sunny and Vasil. --- include/log0log.ic | 35 ++++++++++++++++++++++++++++++----- include/mtr0mtr.h | 3 +++ include/univ.i | 3 +++ log/log0recv.c | 32 +++++++++++++++++++++++++++++--- srv/srv0start.c | 4 ++++ 5 files changed, 69 insertions(+), 8 deletions(-) diff --git a/include/log0log.ic b/include/log0log.ic index 4d2f64af695..36d151a3064 100644 --- a/include/log0log.ic +++ b/include/log0log.ic @@ -312,11 +312,20 @@ log_reserve_and_write_fast( ib_uint64_t* start_lsn)/*!< out: start lsn of the log record */ { ulint data_len; - ib_uint64_t lsn; +#ifdef UNIV_LOG_LSN_DEBUG + /* length of the LSN pseudo-record */ + ulint lsn_len = 1 + + mach_get_compressed_size(log_sys->lsn >> 32) + + mach_get_compressed_size(log_sys->lsn & 0xFFFFFFFFUL); +#endif /* UNIV_LOG_LSN_DEBUG */ mutex_enter(&log_sys->mutex); - data_len = len + log_sys->buf_free % OS_FILE_LOG_BLOCK_SIZE; + data_len = len +#ifdef UNIV_LOG_LSN_DEBUG + + lsn_len +#endif /* UNIV_LOG_LSN_DEBUG */ + + log_sys->buf_free % OS_FILE_LOG_BLOCK_SIZE; if (data_len >= OS_FILE_LOG_BLOCK_SIZE - LOG_BLOCK_TRL_SIZE) { @@ -330,7 +339,23 @@ log_reserve_and_write_fast( *start_lsn = log_sys->lsn; - ut_memcpy(log_sys->buf + log_sys->buf_free, str, len); +#ifdef UNIV_LOG_LSN_DEBUG + { + /* Write the LSN pseudo-record. */ + byte* b = &log_sys->buf[log_sys->buf_free]; + *b++ = MLOG_LSN | (MLOG_SINGLE_REC_FLAG & *(const byte*) str); + /* Write the LSN in two parts, + as a pseudo page number and space id. */ + b += mach_write_compressed(b, log_sys->lsn >> 32); + b += mach_write_compressed(b, log_sys->lsn & 0xFFFFFFFFUL); + ut_a(b - lsn_len == &log_sys->buf[log_sys->buf_free]); + + memcpy(b, str, len); + len += lsn_len; + } +#else /* UNIV_LOG_LSN_DEBUG */ + memcpy(log_sys->buf + log_sys->buf_free, str, len); +#endif /* UNIV_LOG_LSN_DEBUG */ log_block_set_data_len((byte*) ut_align_down(log_sys->buf + log_sys->buf_free, @@ -344,14 +369,14 @@ log_reserve_and_write_fast( ut_ad(log_sys->buf_free <= log_sys->buf_size); - lsn = log_sys->lsn += len; + log_sys->lsn += len; #ifdef UNIV_LOG_DEBUG log_check_log_recs(log_sys->buf + log_sys->old_buf_free, log_sys->buf_free - log_sys->old_buf_free, log_sys->old_lsn); #endif - return(lsn); + return(log_sys->lsn); } /***********************************************************************//** diff --git a/include/mtr0mtr.h b/include/mtr0mtr.h index 44bba43b1ab..bc3f1951be9 100644 --- a/include/mtr0mtr.h +++ b/include/mtr0mtr.h @@ -106,6 +106,9 @@ For 1 - 8 bytes, the flag value must give the length also! @{ */ #define MLOG_IBUF_BITMAP_INIT ((byte)27) /*!< initialize an ibuf bitmap page */ /*#define MLOG_FULL_PAGE ((byte)28) full contents of a page */ +#ifdef UNIV_LOG_LSN_DEBUG +# define MLOG_LSN ((byte)28) /* current LSN */ +#endif #define MLOG_INIT_FILE_PAGE ((byte)29) /*!< this means that a file page is taken into use and the prior diff --git a/include/univ.i b/include/univ.i index 0f5949cf2e6..b23a2b20254 100644 --- a/include/univ.i +++ b/include/univ.i @@ -185,6 +185,9 @@ command. Not tested on Windows. */ #define UNIV_LRU_DEBUG /* debug the buffer pool LRU */ #define UNIV_HASH_DEBUG /* debug HASH_ macros */ #define UNIV_LIST_DEBUG /* debug UT_LIST_ macros */ +#define UNIV_LOG_LSN_DEBUG /* write LSN to the redo log; +this will break redo log file compatibility, but it may be useful when +debugging redo log application problems. */ #define UNIV_MEM_DEBUG /* detect memory leaks etc */ #define UNIV_IBUF_DEBUG /* debug the insert buffer */ #define UNIV_IBUF_COUNT_DEBUG /* debug the insert buffer; diff --git a/log/log0recv.c b/log/log0recv.c index e2d85b2f1bb..ca1a4d3636c 100644 --- a/log/log0recv.c +++ b/log/log0recv.c @@ -853,6 +853,11 @@ recv_parse_or_apply_log_rec_body( } switch (type) { +#ifdef UNIV_LOG_LSN_DEBUG + case MLOG_LSN: + /* The LSN is checked in recv_parse_log_rec(). */ + break; +#endif /* UNIV_LOG_LSN_DEBUG */ case MLOG_1BYTE: case MLOG_2BYTES: case MLOG_4BYTES: case MLOG_8BYTES: #ifdef UNIV_DEBUG if (page && page_type == FIL_PAGE_TYPE_ALLOCATED @@ -1924,6 +1929,17 @@ recv_parse_log_rec( return(0); } +#ifdef UNIV_LOG_LSN_DEBUG + if (*type == MLOG_LSN) { + ib_uint64_t lsn = (ib_uint64_t) *space << 32 | *page_no; +# ifdef UNIV_LOG_DEBUG + ut_a(lsn == log_sys->old_lsn); +# else /* UNIV_LOG_DEBUG */ + ut_a(lsn == recv_sys->recovered_lsn); +# endif /* UNIV_LOG_DEBUG */ + } +#endif /* UNIV_LOG_LSN_DEBUG */ + /* Check that page_no is sensible */ if (UNIV_UNLIKELY(*page_no > 0x8FFFFFFFUL)) { @@ -2181,6 +2197,12 @@ loop: #endif /* In normal mysqld crash recovery we do not try to replay file operations */ +#ifdef UNIV_LOG_LSN_DEBUG + } else if (type == MLOG_LSN) { + /* Do not add these records to the hash table. + The page number and space id fields are misused + for something else. */ +#endif /* UNIV_LOG_LSN_DEBUG */ } else { recv_add_to_hash_table(type, space, page_no, body, ptr + len, old_lsn, @@ -2212,11 +2234,11 @@ loop: = recv_sys->recovered_offset + total_len; recv_previous_parsed_rec_is_multi = 1; - if ((!store_to_hash) && (type != MLOG_MULTI_REC_END)) { #ifdef UNIV_LOG_DEBUG + if ((!store_to_hash) && (type != MLOG_MULTI_REC_END)) { recv_check_incomplete_log_recs(ptr, len); -#endif /* UNIV_LOG_DEBUG */ } +#endif /* UNIV_LOG_DEBUG */ #ifdef UNIV_DEBUG if (log_debug_writes) { @@ -2280,7 +2302,11 @@ loop: break; } - if (store_to_hash) { + if (store_to_hash +#ifdef UNIV_LOG_LSN_DEBUG + && type != MLOG_LSN +#endif /* UNIV_LOG_LSN_DEBUG */ + ) { recv_add_to_hash_table(type, space, page_no, body, ptr + len, old_lsn, diff --git a/srv/srv0start.c b/srv/srv0start.c index 1d7f5e1227e..37263317126 100644 --- a/srv/srv0start.c +++ b/srv/srv0start.c @@ -1097,6 +1097,10 @@ innobase_start_or_create_for_mysql(void) "InnoDB: !!!!!!!! UNIV_SEARCH_DEBUG switched on !!!!!!!!!\n"); #endif +#ifdef UNIV_LOG_LSN_DEBUG + fprintf(stderr, + "InnoDB: !!!!!!!! UNIV_LOG_LSN_DEBUG switched on !!!!!!!!!\n"); +#endif /* UNIV_LOG_LSN_DEBUG */ #ifdef UNIV_MEM_DEBUG fprintf(stderr, "InnoDB: !!!!!!!! UNIV_MEM_DEBUG switched on !!!!!!!!!\n");