Innodb redo log archiving

Myth丶恋晨 2022-08-10 14:38 2阅读 0赞

本文转载自：http://www.mysqlperformanceblog.com/2014/03/28/innodb-redo-log-archiving/

# Innodb redo log archiving #

March 28, 2014 by  [Vlad Lesin][]  [5 Comments][]

[Tweet][]

[![Innodb redo log archiving][]][Innodb redo log archiving 1]Percona Server 5.6.11-60.3 introduces a new “log archiving” feature.[Percona XtraBackup 2.1.5][] supports “apply archived logs.” What does it mean and how it can be used?

Percona products propose three kinds of incremental backups. The first is full scan of data files and comparison the data with backup data to find some delta. This approach provides a history of changes and saves disk space by storing only data deltas. But the disadvantage is a full-data file scan that adds load to the disk subsystem. The second kind of incremental backup avoids extra disk load during data file scans.

The idea is in reading only changed data pages. The information about what specific pages were changed is provided by the server itself which writes files with the information during work. It’s a good alternative but changed-pages tracking adds some small load. And Percona XtraBackup’s delta reading leads to non-sequential disk io. This is good alternative but there is one more option.

The Innodb engine has a data log. It writes all operations which modify database pages to log files. This log is used in the case of unexpected server terminating to recover data. The Innodb log consists of the several log files which are filled sequentially in circular. The idea is to save those files somewhere and apply all modifications from archived logs to backup data files. The disadvantage of this approach is in using extra disk space. The advantage is there is no need to do an “explicit” backup on the host server. A simple script could sit and wait for logs to appear then scp/netcat them over to another machine.

But why not use good-old replication? Maybe replication does not have such performance as logs recovering but it is more controlled and well-known. Archived logs allows you to do any number of things with them from just storing them to doing periodic log applying. You can not recover from a ‘DROP TABLE’, etc with replication. But with this framework one could maintain the idea of “point in time” backups.

So the “archived logs” feature is one more option to organize incremental backups. It is not widely used as it was issued not so far and there is not A good understanding of how it works and how it can be used. We are open to any suggestions about its suggest improvements and use cases. The subject of this post is to describe how it works in depth. As log archiving is closely tied with innodb redo logs the internals of redo logs will be covered too. This post would be useful not only for DBA but also for Software Engineers because not only common principles are considered but the specific code too, and knowledge from this post can be used for further MySQL code exploring and patching.

## What is the innodb log and how it is written? ##

Let’s remember what are innodb logs, why they are written, what they are used for.

The Innodb engine has buffer pool. This is a cache of database pages. Any changes are done on page in buffer pool, then page is considered as “dirty,” which means it must be flushed, and pushed to the flush list which is processed periodically by special thread. If pages are not flushed to disk and server is terminated unexpectedly the changes will be lost. To avoid this innodb writes changes to redo log and recover data from redo log during start. This technique allows to delay buffer pool pages flushing. It can increase performance because several changes of one page can be accumulated in memory and then flushed by one io. Except that flushed pages can be grouped to decrease the number of non-sequential io’s. But the down-side of this approach is time for data recovering. Let’s consider how this log is stored, generated and used for data recovering.

### Log files ###

Redo log consists of a several log files which are treated as a circular buffer. The number and the size of log files can be configured. Each log file has a header. The description of this header can be found in “storage/innobase/include/log0log.h” by “LOG\_GROUP\_ID” keyword.

Each log file contains log records. Redo log records are written sequentially by log blocks of OS\_FILE\_LOG\_BLOCK\_SIZE size which is equal to 512 bytes by default and can be changed with innodb option. Each record has its LSN. LSN is a “Log Sequence Number” – the number of bytes written to log from the log creation to the certain log record. Each block consists of header, trailer and log records.

### Log blocks ###

Let’s consider log block header. The first 4 bytes of the header is log block number. The block number is very similar as LSN but LSN is measured in bytes and block number is measured by OS\_FILE\_LOG\_BLOCK\_SIZE. Here is the simple formula how LSN is converted to block number:

`return(((ulint) (lsn / OS_FILE_LOG_BLOCK_SIZE) & 0x3FFFFFFFUL) + 1);`

This formula can be found in log\_block\_convert\_lsn\_to\_no() function. The next two bytes is the number of bytes used in the block. The next two bytes is the offset of the first MTR log record in this block. What is MTR will be described below. Currently it can be considered as a synonym of bunch of log records which are gathered together as a description of some logical operation. For example it can be a group of log records for inserting new row to some table. This field is used when there are records of several MTR’s in one block. The next four bytes is a checkpoint number. The trailer is four bytes of log block checksum. The above description can be found in “storage/innobase/include/log0log.h” by “LOG\_BLOCK\_HDR\_NO” keyword.

Before writing to disk log blocks must be somehow formed and stored. And the question is:

### How log blocks are stored in memory and on disk? ###

Where log blocks are stored before flushing to disk and how they are written and flushed?

#### Global log object and log buffer ####

The answer to the first part of the question is log buffer. Server holds very important global object log\_sys in memory. It contains a lot of useful information about logging state. Log buffer is pointed by log\_sys->buf pointer which is initialized in log\_init(). I would highlight the following log\_sys fields that are used for work with log buffer and flushing:

log\_sys->buf\_size – the size of log buffer, can be set with innodb-log-buffer-size variable, the default value is 8M;  
log\_sys->buf\_free – the offset from which the next log record will be written;  
log\_sys->max\_buf\_free – if log\_sys->buf\_free is greater then this value log buffer must be flushed, see log\_free\_check();  
log\_sys->buf\_next\_to\_write – the offset of the next log record to write to disk;  
log\_sys->write\_lsn – the LSN up to which log is written;  
log\_sys->flushed\_to\_disk\_lsn – the LSN up to which log is written and flushed;  
log\_sys->lsn – the last LSN in log buffer;

So log\_sys->buf\_next\_to\_write is between 0 and log\_sys->buf\_free, log\_sys->write\_lsn is equal or less log\_sys->lsn, log\_sys->flushed\_to\_disk\_lsn is less or equal to log\_sys->write\_lsn.

The relationships for those fields can be easily traced with debugged by setting up watchpoints.

Ok, we have log buffer, but how do log records come to this buffer?

#### Where log records come from? ####

Innodb has special objects that allow you to gather redo log records for some operations in one bunch before writing them to log buffer. These objects are called “mini-transactions” and corresponding functions and data types have “mtr” prefix in the code. The objects itself are described in mtr\_t “c” structure. The most interesting fields of this structure are the following:

mtr\_t::log – contains log records for the mini-transaction,  
mtr\_t::memo – contains pointers to pages which are changed or locked by the mini-transaction, it is used to push pages to flush list and release locks after logs records are copied to log buffer in mtr\_commit() (see mtr\_memo\_pop\_all() called in mtr\_commit()).

mtr\_start() function initializes an object of mtr\_t type and mtr\_commit() writes log records from mtr\_t::log to log\_sys->buf + log\_sys->buf\_free. So the typical sequence of any operation which changes data is the following:

`mtr_start(); // initialize mtr object some_ops... // operations on data which are logged in mtr_t::log mtr_commit(); // write logged operations from mtr_t::log to log buffer log_sys->buf`

page\_cur\_insert\_rec\_write\_log() is a good example of how mtr records can be written and mtr::memo can be filled. The low-level function which writes data to log buffer is log\_write\_low(). This function is invoked inside of mtr\_commit() and not only copy the log records from mtr\_t object to log buffer log\_sys->buf but also creates a new log blocks inside of log\_sys->buf, fills their header, trailer, calculates checksum.

So log buffer contains log blocks which are sequentially filled with log records which are grouped in “mini-transactions” which logically can be treated as some logical operation over data which consists of a sequence of mini-operations(log records).

As log records are written sequentially in log buffer one mini-transaction and even one log record can be written in two neighbour blocks. That is why the header field which would contain the offset of the first MTR in the block is necessary to calculate the point from which log records parsing can be started. This field was described in 2.2.

So we have a buffer of log blocks in a memory. How is data from this buffer written to disk? The mysql documentation says that this depends on innodb\_flush\_log\_at\_trx\_commit option. There can be three cases depending on the value of this option. Let’s consider each of them.

#### Writing log buffer to disk: innodb\_flush\_log\_at\_trx\_commit is 1 or 2. ####

The first two cases is when innodb\_flush\_log\_at\_trx\_commit is 1 or 2. In these cases flush log records are written for 2 and flushed for 1 on each transaction commit. If innodb\_flush\_log\_at\_trx\_commit is 2 log records are flushed periodically by special thread which will be considered later. The low-level function which writes log records from buffer to file is log\_group\_write\_buf(). But in the most cases it is not called directly but it is called from more high level log\_write\_up\_to(). For the current case the calling stack is the following:

`(trx_commit_in_memory() or trx_commit_complete_for_mysql() or trx_prepare() e.t.c)-> trx_flush_log_if_needed()-> trx_flush_log_if_needed_low()-> log_write_up_to()-> log_group_write_buf().`

It is quite easy to find the higher levels of calling stack, just set up breakpoint on log\_group\_write\_buf() and execute any sql query that modifies innodb data. For example for the simple “insert” sql query the higher levels of calling stack are the following:

`mysql_execute_command()-> trans_commit_stmt()-> ha_commit_trans()-> TC_LOG_DUMMY::commit()-> ha_commit_low()-> innobase_commit()-> trx_commit_complete_for_mysql()-> trx_flush_log_if_needed()-> ... .`

log\_io\_complete() callback is invoked when i/o is finished for log files (see fil\_aio\_wait()). log\_io\_complete() flushes log files if this is not forbidden by innodb\_flush\_method or innodb\_flush\_log\_at\_trx\_commit options.

#### Writing log buffer to disk: innodb\_flush\_log\_at\_trx\_commit is equal to 0 ####

The third case is when innodb\_flush\_log\_at\_trx\_commit is equal to 0. For this case log buffer is NOT written to disk on transaction commit, it is written and flushed periodically by separate thread “srv\_master\_thread”. If innodb\_flush\_log\_at\_trx\_commit = 0 log files are flushed in the same thread by the same calls. The calling stack is the following:

`srv_master_thread()-> (srv_master_do_active_tasks() or srv_master_do_idle_tasks() or srv_master_do_shutdown_tasks())-> srv_sync_log_buffer_in_background()-> log_buffer_sync_in_background()->log_write_up_to()->... .`

#### Special cases for logs flushing ####

While log\_io\_complete() do flushing depending on innodb\_flush\_log\_at\_trx\_commit value among others log\_write\_up\_to() has it’s own flushing criteria. This is flush\_to\_disk function argument. So it is possible to force log files flushing even if innodb\_flush\_log\_at\_trx\_commit = 0. Here are examples of such cases:

1) buf\_flush\_write\_block\_low()  
Each page contains information about the last applied LSN(buf\_flush\_write\_block\_low::newest\_modification), each log record is a description of change on certain page. Imagine we flushed some changed pages but log records for these pages were not flushed and server goes down. After starting the server some pages will have the newest modifications, but some of them were not flushed and the correspondent log records are lost too. We will have inconsistent database in this case. That is why log records must be flushed before the pages they refer.

2) srv\_sync\_log\_buffer\_in\_background()  
As it was described above this function is called periodically by special thread and forces flushing.

3) log\_checkpoint()  
When checkpoint is made log files must be reliably flushed.

4) The special handlerton innobase\_flush\_logs() which can be called through ha\_flush\_logs() from mysql server.  
For example ha\_flush\_logs() is called from MYSQL\_BIN\_LOG::reset\_logs() when “RESET MASTER” or “RESET SLAVE” are executed.

5) srv\_master\_do\_shutdown\_tasks() – on shutdown, ha\_innobase::create() – on table creating, ha\_innobase::delete\_table() – on table removing, innobase\_drop\_database() – on all database tables removing, innobase\_rename\_table() – on table rename e.t.c

#### If log files are treated as circular buffer what happens when the buffer is overflown? ####

Briefly. Innodb has a mechanism which allows you to avoid overflowing. It is called “checkpoints.” The checkpoint is a state when log files are synchronized with data files. In this case there is no need to keep the history of changes before checkpoint because all pages with the last modifications LSN less or equal to checkpoint LSN are flushed and the log files space from the last written LSN to the last checkpoint LSN can be reused. We will not describe a checkpoint process here because it is a separate interesting subject. The only thing we need to know is when checkpoint happens all pages with modification LSN less or equal to checkpoint LSN are reliably flushed.

## How archived logs are written by server. ##

So the log contains information about page changes. But as we said, log files are the circular buffer. This means that they occupy fixed disk size and the oldest records can be rewritten by the newest ones as there are points when data files are synchronized with log files called checkpoints and there is no need to store the previous history of log records to guarantee database consistency. The idea is to save somewhere all log records to have the possibility of applying them to backuped data to have some kind if incremental backup. For example if we want to have an archive of log records. As log consists of log files it is reasonable to store log records in such files too, and these files are called “archived logs.”

Archived log files are written to the directory which can be set with special innodb option. Each file has the same size as innodb log size and the suffix of each archived file is the LSN from which it is started.

As well as log writing system log archiving system stores its data in global log\_sys object. Here are the most valuable fields in log\_sys from my point of view:

log\_sys->archive\_buf, log\_sys->archive\_buf\_size – logs archive buffer and its size, log records are copied from log buffer log\_sys->buf to this buffer before writing to disk;  
log\_sys->archiving\_phase – the current phase of log archiving: LOG\_ARCHIVE\_READ when log records are being copied from log\_sys->buf to log\_sys->archive\_buf, LOG\_ARCHIVE\_WRITE when log\_sys->archive\_buf is being written to disk;  
log\_sys->archived\_lsn – the LSN to which log files are written;  
log\_sys->next\_archived\_lsn – the LSN to which write operations was invoked but not yet finished;  
log\_sys->max\_archived\_lsn\_age – the maximum difference between log\_sys->lsn and log\_sys->archived\_lsn, if this difference exceeds the log are being archived synchronously, i.e. the difference is decreased;  
log\_sys->archive\_lock – this is rw-lock which is used for synchronizing LOG\_ARCHIVE\_WRITE and LOG\_ARCHIVE\_READ phases, it is x-locked on LOG\_ARCHIVE\_WRITE phase.

So how is data copied from log\_sys->buf to log\_sys->archived\_buf? log\_archive\_do() is used for this. It is not only set the proper state for archived log fields in log\_sys but also invokes log\_group\_read\_log\_seg() with corresponding arguments which not only copy data from log buffer to archived log buffer but also invokes asynchronous write operation for archived log buffer. log\_archive\_do() can wait until io operations are finished using log\_sys->archive\_lock if corresponding function parameter is set.

The main question is on what circumstances log\_archive\_do() is invoked, i.e. when log records are being written to archived log files. The first call stack is the following:

`log_free_check()-> log_check_margins()-> log_archive_margin()-> log_archive_do().`

Here is text of log\_free\_check() with comments:

`/*********************************************************************// Checks if there is need for a log buffer flush or a new checkpoint, and does this if yes. Any database operation should call this when it has modified more than about 4 pages. NOTE that this function may only be called when the OS thread owns no synchronization objects except the dictionary mutex. */ UNIV_INLINE void log_free_check(void) /*================*/ {`

\#ifdef UNIV\_SYNC\_DEBUG  
ut\_ad(sync\_thread\_levels\_empty\_except\_dict());  
\#endif /\* UNIV\_SYNC\_DEBUG \*/

if (log\_sys->check\_flush\_or\_checkpoint) \{

`log_check_margins(); } }`

log\_sys->check\_flush\_or\_checkpoint is set when there is no enough free space in log buffer or it is time to do checkpoint or any other bound case. log\_archive\_margin() is invoked only if the limit if the difference between log\_sys->lsn and log\_sys->archived\_lsn is exceeded. Let’s refer to this difference as archived lsn age.

One more call log\_archive\_do() is from log\_open() when archived lsn age exceeds some limit. log\_open() is called on each mtr\_commit(). And for this case archived logs are written synchronously.

The next synchronous call is from log\_archive\_all() during shutdown.

Summarizing all above archived logs begins to be written when the log buffer is full enough to be written or when checkpoint happens or when the server is in the process of shut down. And there is no any delay between writing to archive log buffer and writing to disk. I mean there is no way to say that archived logs must be written once a second as it is possible for redo logs with innodb\_flush\_log\_at\_trx\_commit = 0. As soon as data is copied to the buffer the write operation is invoked immediately for this buffer. Archived log buffer is not filled on each mtr\_commit() so it does not slow down the usual logging process. The exception is when there are a lot of io operations what can be the reason of archive log age is too big. The result of big archive log age is the synchronous archived logs writing during mtr\_commit(). Memory to memory copying is quite fast operation that is why the data is copied to archived log buffer and is written to disk asynchronously minimizing delays which can be caused by logs archiving.

PS: Here is another call stack for writing archived log buffer to archived log files:

log\_io\_complete()->log\_io\_complete\_archive()->log\_archive\_check\_completion\_low()->log\_archive\_groups().

I propose to explore this stack yourself.

## Logs recovery process, how it is started and works inside. Archived logs applying. ##

So we discovered how innodb redo logging works, and how redo logs are archived. And the last uncovered thing is how recovery works and how archived logs are applied. These two processes are very similar – that is why they are discussed in one section of this post.

The story begins with innobase\_start\_or\_create\_for\_mysql() which is invoked from innobase\_init(). The following trident in innobase\_start\_or\_create\_for\_mysql() can be used to search the relevant code:

`if (create_new_db) { ... } else if (srv_archive_recovery) { ... } else { ... }`

The second condition and the last one is the place from which archived logs applying and innodb logs recovery processes correspondingly start. These two blocks wrap two pairs of functions:

`recv_recovery_from_archive_start() recv_recovery_from_archive_finish()`  
and  
`recv_recovery_from_checkpoint_start() recv_recovery_from_checkpoint_finish()`

And all the magic happens in these pairs. As well as global log\_sys object for redo logging there is global recv\_sys object for innodb recovery and archived logs applying. It is created and initialized in recv\_sys\_create() and recv\_sys\_init() functions correspondingly. The following fields if recv\_sys object are the most important from my point:

recv\_sys->limit\_lsn – the LSN up to which recovery should be made, this value is initialized with the maximum value of uint64\_t(see \#define LSN\_MAX) for the recovery process and with certain value which is passed as an argument of recv\_recovery\_from\_archive\_start() function and can be set via xtrabackup option for log applying;  
recv\_sys->parse\_start\_lsn – the LSN from which logs parsing is started, for the the logs recovery this value equals to the last checkpoint LSN, for logs applying this is last applied LSN;  
recv\_sys->scanned\_lsn – the LSN up to which log files are scanned;  
recv\_sys->recovered\_lsn – the LSN up to which log records are applied, this value <= recv\_sys->scanned\_lsn;

The first thing that must be done for starting recovery process is to find out the point in log files where the recovery must be started from. This is the last checkpoint LSN. recv\_find\_max\_checkpoint() proceed this. As we can see in log\_group\_checkpoint() the following code writes checkpoint info into two places in the first log file depending on the checkpoint number:

`/* We alternate the physical place of the checkpoint info in the first log file */`

`if ((log_sys->next_checkpoint_no & 1) == 0) { write_offset = LOG_CHECKPOINT_1; } else { write_offset = LOG_CHECKPOINT_2; }`

So recv\_find\_max\_checkpoint() reads checkpoint info from both places and selects the latest checkpoint.

The same idea is applied for logs, too, but the last applied LSN instead of last checkpoint LSN must be found. Here is the call stack for reading last applied LSN:

`innobase_start_or_create_for_mysql()-> open_or_create_data_files()-> fil_read_first_page().`

The last applied LSN is stored in the first page of data files in (min|max)\_flushed\_lsn fields(see FIL\_PAGE\_FILE\_FLUSH\_LSN offset). These values are written in fil\_write\_flushed\_lsn\_to\_data\_files() function on server shutdown.

So the main difference between logs applying and recovery process at this stage is the manner of calculating LSN from which log records will be read. For logs applying the last flushed LSN is used but for recovery process it is the last checkpoint LSN. Why does this difference take place? Logs can be applied periodically. Assume we gather archived logs and apply them once an hour to have fresh backup. After applying the previous bunch of log files there can be unfinished transactions. For the recovery process any unfinished transactions are rolled back to have consistent db state at server starting. But for the logs applying process there is no need to roll back them because any unfinished transactions can be finished during the next logs applying.

After calculating the start LSN the sequence of actions is the same for both recovering and applying. The next step is reading and parsing log records. See recv\_group\_scan\_log\_recs() which is invoked from recv\_recovery\_from\_checkpoint\_start\_func() for logs recovering and recv\_recovery\_from\_archive\_start()->log\_group\_recover\_from\_archive\_file() for logs applying.

The first we read log records to some buffer and then invoke recv\_scan\_log\_recs() to parse them. recv\_scan\_log\_recs() checks each log block on consistency(checksum + comparing the log block number written in log block with log block number calculated from log block LSN) and other edge cases and copy it to parsing buffer recv\_sys->buf with recv\_sys\_add\_to\_parsing\_buf() function. The parsing buffer is then parsed by recv\_parse\_log\_recs(). Log records are stored in hash table recv\_sys->addr\_hash. The key for this hash table is calculated basing on space id and page number pair. This pair refers to the page to which log records must be applied. The value of the hash table is object of recv\_addr\_t type. recv\_addr\_t type contains rec\_list field which is the list of log records for applying to the (space id, page num) page (see recv\_add\_to\_hash\_table().

After parsing and storing log record in hash table recv\_sys->addr\_hash log records are applied. The function which is responsible for log records applying is recv\_apply\_hashed\_log\_recs(). It is invoked from recv\_scan\_log\_recs() if there is no enough memory to store log records and at the end of recovering/applying process. For each element of recv\_sys->addr\_hash, i.e. for each DB page which must be changed with log records recv\_recover\_page() is invoked. It can be invoked as from recv\_apply\_hashed\_log\_recs() in the case if page is already in buffer pool of from buf\_page\_io\_complete() on io completion, i.e. just after page was read from storage. Applying log records on page read completion is necessary and very convenient. Assume log records have not yet applied as we had enough memory to store the whole recovery log records. But we want for example to boot DB dictionary. I this case any records that concern to the pages of the dictionary will be applied to those pages just after reading them from storage to buffer pool.

The function which applies log records to the certain page is recv\_recover\_page\_func(). It gets the list of log records for the certain page from recv\_sys->addr\_hash hash table, for each element of this list it compares the lsn of last page changes with the LSN of the record, and if the former is greater the later it applies log record to the page.

After applying all log records from archived logs xtrabackup writes last applied LSN to (min|max)\_flushed LSN fields of each data file and finishes execution. The logs recovery process rollbacks all unfinished transactions unless this is forbidden with innodb-force-recovery parameter.

## Conclusion ##

We covered the processes of redo logs writing and recovery in depth. These are very important processes as they provide data consistency on crashes. These two processes became a base for logs archiving and applying features. As log records can describe any data changes the idea is to store these records somewhere and then apply them to backups for organizing some kind of incremental backup.

The features were implemented a short time ago and currently they are not widely used. So if you have something to say about them you are welcome to comment for discussion.

注：近期参加MySQL运维学习，老师推荐该文章作为学习和技术提高的扩展阅读，先记录到自己的博客中，随后慢慢消化、学习、提高。本文章与“日志系统”主题相关。

[Vlad Lesin]: http://www.mysqlperformanceblog.com/author/vlad-lesin/
[5 Comments]: http://www.mysqlperformanceblog.com/2014/03/28/innodb-redo-log-archiving/#comments
[Tweet]: http://twitter.com/share
[Innodb redo log archiving]: /images/20220810/21f0dcccc31e49f1b652c4e959db5122.png
[Innodb redo log archiving 1]: http://www.mysqlperformanceblog.com/wp-content/uploads/2014/03/Innodb-redo-log-archiving.jpg
[Percona XtraBackup 2.1.5]: http://www.percona.com/software/percona-xtrabackup