MySQL · TokuDB · 日志子系统和崩溃恢复过程
最后更新于：2022-04-01 10:35:12
## TokuDB日志子系统
MySQL重启后自动加载InnoDB和其他的动态plugin，包括TokuDB。每一plugin在注册的时候指定init和deinit回调函数。TokuDB的init/deinit函数分别是`tokudb_init_func`和`tokudb_done_func`。
MySQL重启过程中调用`tokudb_init_func`进行必要的初始化。在`tokudb_init_func`里面，调用`db_env_create`创建一个env实例，进行参数设置和callback设置。`db_env_create`是一个简单的封装，最终会调用`toku_env_create`来进行参数设置，callback设置和初始化的。`toku_env_create`初始化工作中一个很重要的事情就是调用`toku_logger_create`初始化TokuDB的日志子系统。
在TokuDB中，日志子系统是由tokulogger数据结构管理的。下面仅列出了主要的数据成员。
~~~
struct tokulogger {
struct mylock input_lock; // 保护lsn和in_buf的mutex
toku_mutex_t output_condition_lock; // 保护written_lsn ，fsynced_lsn ，等待out_buf可用的条件变量的mutex
toku_cond_t output_condition; // 等待out_buf可用的条件变量
bool output_is_available; // 标志out_buf可用的条件
bool is_open; // 标志logger是否已打开
bool write_log_files; // 标示是否将redo log buffer写到redo log file
bool trim_log_files; // 标志是否要trim redo log file
char *directory; // redo log所在目录
int lg_max; // redo log最大长度，缺省100M
LSN lsn; // 下一个可用的lsn
struct logbuf inbuf; // 接收redo log entry的buffer
LSN written_lsn; // 最后一次写入的lsn
LSN fsynced_lsn; // 最后一次fsync的lsn
LSN last_completed_checkpoint_lsn; // 最近一次checkpoint开始时刻的logger的lsn
long long next_log_file_number; // 下一个可用的redo log file的序列号
struct logbuf outbuf; // 写入redo log file的buf
int n_in_file; // 当前redo log file存储日志的字节数
TOKULOGFILEMGR logfilemgr; // log file manager的handle
TXN_MANAGER txn_manager; // txn manager的handle
};
~~~
### Logger初始化
Logger子系统在env->create阶段由`toku_logger_create`进行初步的初始化工作。代码片段如下：
~~~
int toku_logger_create (TOKULOGGER *resultp) {
TOKULOGGER CALLOC(result);
if (result==0) return get_error_errno();
result->is_open=false;
result->write_log_files = true;
result->trim_log_files = true;
result->directory=0;
result->lg_max = 100<<20; // 100MB default
// lsn is uninitialized
result->inbuf = (struct logbuf) {0, LOGGER_MIN_BUF_SIZE, (char *) toku_xmalloc(LOGGER_MIN_BUF_SIZE), ZERO_LSN};
result->outbuf = (struct logbuf) {0, LOGGER_MIN_BUF_SIZE, (char *) toku_xmalloc(LOGGER_MIN_BUF_SIZE), ZERO_LSN};
// written_lsn is uninitialized
// fsynced_lsn is uninitialized
result->last_completed_checkpoint_lsn = ZERO_LSN;
// next_log_file_number is uninitialized
// n_in_file is uninitialized
toku_logfilemgr_create(&result->logfilemgr);
*resultp=result;
ml_init(&result->input_lock);
toku_mutex_init(&result->output_condition_lock, NULL);
toku_cond_init(&result->output_condition, NULL);
result->output_is_available = true;
return 0;
}
~~~
Logger子系统在env->open阶段，调用`toku_logger_open`函数进行进一步的初始化。函数`toku_logger_open`是`toku_logger_open_with_last_xid`的简单封装。Env->open最终调用`toku_logger_open_with_last_xid`解析redo log file获取下一个可用的lsn，下一个可用的redo log file的序列号index并打开相应redo log file。在env->open时，调用`toku_logger_open_with_last_xid`的最后一个参数last_xid为TXNID_NONE，表示由`toku_logger_open_with_last_xid`指定事务子系统初始化时最新的txnid。
解析redo log file的过程在函数`toku_logfilemgr_init`实现，依次解析redo log目录下的每一个文件名符合特定格式的redo log file，从中读取最后一个log entry的lsn保存下来。Redo log文件名遵循”log$index.tokulog$version”格式，$index是64位无符号整数表示的redo log file的序列号index，$version是32位无符号整数表示版本信息。
如果最新的redo log file最后一个log entry是LT_shutdown（表示正常关闭不需要进行recovery），那么把对应的txnid记录在last_xid_if_clean_shutdown变量，作为TokuDB事务子系统初始化时最新的txnid。在解析redo log file的时候，还会用最新的redo log file的最后一个log entry的lsn更新logger的lsn，written_lsn，fsynced_lsn。接着，`toku_logger_find_next_unused_log_file`找到下一个可用的redo log文件的序列号，并创建新的redo log file。每个redo log file最开始的12个字节是固定的，首先是8个字节的magic字符串“tokulogg“，紧接着4个字节是log的版本信息。代码片段如下：
~~~
int
toku_logger_open_with_last_xid(const char *directory /* redo log dir */, TOKULOGGER logger, TXNID last_xid) {
if (logger->is_open) return EINVAL;
TXNID last_xid_if_clean_shutdown = TXNID_NONE;
r = toku_logfilemgr_init(logger->logfilemgr, directory, &last_xid_if_clean_shutdown);
if ( r!=0 )
return r;
logger->lsn = toku_logfilemgr_get_last_lsn(logger->logfilemgr);
logger->written_lsn = logger->lsn;
logger->fsynced_lsn = logger->lsn;
logger->inbuf.max_lsn_in_buf = logger->lsn;
logger->outbuf.max_lsn_in_buf = logger->lsn;
r = open_logdir(logger, directory);
if (r!=0) return r;
long long nexti;
r = toku_logger_find_next_unused_log_file(logger->directory, &nexti);
if (r!=0) return r;
logger->next_log_file_number = nexti;
r = open_logfile(logger);
if (r!=0) return r;
if (last_xid == TXNID_NONE) {
last_xid = last_xid_if_clean_shutdown;
}
toku_txn_manager_set_last_xid_from_logger(logger->txn_manager, last_xid);
logger->is_open = true;
return 0;
}
~~~
到这里，TokuDB的logger子系统就初始化好了，在处理DDL或者DML或者TokuDB执行checkpoint的时候，都需要先写rollback（undo）log，redo log。Rollback在之前的月报[MySQL · TokuDB · 事务子系统和 MVCC 实现](http://mysql.taobao.org/monthly/2016/03/01/) 谈到过，这里不再赘述。
### 写redo log
下面我们一起看一下往redo log新加一条insert的过程。函数`toku_log_enq_insert`的第2，第5，第6，第7，第8参数表示描述一条insert的五元组(lsn, FT, xid, key, value)。代码片段如下：
~~~
void toku_log_enq_insert (TOKULOGGER logger, LSN *lsnp, int do_fsync, TOKUTXN txn, FILENUM filenum, TXNID_PAIR xid, BYTESTRING key, BYTESTRING value) {
if (logger == NULL) {
return;
}
if (txn && !txn->begin_was_logged) {
invariant(!txn_declared_read_only(txn));
// 记录txn begin
toku_maybe_log_begin_txn_for_write_operation(txn);
}
if (!logger->write_log_files) {
// logger->write_log_files为FALSE，表示不写redo，递增lsn就可以返回了。
ml_lock(&logger->input_lock);
logger->lsn.lsn++;
if (lsnp) *lsnp=logger->lsn;
ml_unlock(&logger->input_lock);
return;
}
const unsigned int buflen= (+4 // log entry的长度，参与crc计算
+1 // log命令，对应insert来说是‘I’
+8 // lsn
+toku_logsizeof_FILENUM(filenum) // filenum，表示哪个FT文件
+toku_logsizeof_TXNID_PAIR(xid) // xid，表示txnid
+toku_logsizeof_BYTESTRING(key) // key
+toku_logsizeof_BYTESTRING(value) // data
+8 // crc + len // crc和log entry长度（不参与crc计算）
);
struct wbuf wbuf;
ml_lock(&logger->input_lock);
toku_logger_make_space_in_inbuf(logger, buflen);
wbuf_nocrc_init(&wbuf, logger->inbuf.buf+logger->inbuf.n_in_buf, buflen);
wbuf_nocrc_int(&wbuf, buflen);
wbuf_nocrc_char(&wbuf, 'I');
logger->lsn.lsn++;
logger->inbuf.max_lsn_in_buf = logger->lsn;
wbuf_nocrc_LSN(&wbuf, logger->lsn);
if (lsnp) *lsnp=logger->lsn;
wbuf_nocrc_FILENUM(&wbuf, filenum);
wbuf_nocrc_TXNID_PAIR(&wbuf, xid);
wbuf_nocrc_BYTESTRING(&wbuf, key);
wbuf_nocrc_BYTESTRING(&wbuf, value);
wbuf_nocrc_int(&wbuf, toku_x1764_memory(wbuf.buf, wbuf.ndone));
wbuf_nocrc_int(&wbuf, buflen);
assert(wbuf.ndone==buflen);
logger->inbuf.n_in_buf += buflen;
toku_logger_maybe_fsync(logger, logger->lsn, do_fsync, true);
}
~~~
TokuDB的logger有两个buffer：inbuf和outbuf。Inbuf表示接收log entry的buffer，而outbuf表示写到redo log文件的buffer。这两个buffer是如何切换的呢？当inbuf满或者inbuf里的free space无法满足新来的log entry的存储需求时，需要触发redo buffer flush过程，即将inbuf日志flush到redo log文件里。这个过程比较耗时，而且很可能inbuf里面还有free space，只是由于当前这个log entry比较大而无法满足存储需求，TokuDB实现了output permission机制，使得需要free space的请求等待在output permission的条件变量上，其他client thread上下文的redo log请求可以继续使用inbuf写日志。等待上一个flush完成后（即条件变量被signaled），检查当前inbuf的free space，如果可以满足这条redo log entry就直接返回，说明别的线程帮我们flush好了。如果free space不够，需要在当前线程的上下文去做flush，实际上是把inbuf和outbuf互换，然后把outbuf写到redo log文件中。写完之后适当调整inbuf的大小使之满足当前redo log entry请求。最后唤醒等待inbuf提供足够空间的线程（阻塞在output permission上的线程）。简而言之，把redo log buffer拆分成inbuf和outbuf，最重要的作用是在redo log flush的时候不会阻塞新的log entry写入，感兴趣的朋友可以看一下函数`toku_logger_maybe_fsync`的实现，这里就不一一展开了。函数`toku_logger_make_space_in_inbuf`的代码片段如下：
~~~
void
toku_logger_make_space_in_inbuf (TOKULOGGER logger, int n_bytes_needed)
{
if (logger->inbuf.n_in_buf + n_bytes_needed <= LOGGER_MIN_BUF_SIZE) {
return;
}
ml_unlock(&logger->input_lock);
LSN fsynced_lsn;
// 等待前面的redo log flush完成
grab_output(logger, &fsynced_lsn);
ml_lock(&logger->input_lock);
if (logger->inbuf.n_in_buf + n_bytes_needed <= LOGGER_MIN_BUF_SIZE) {
// 其他线程帮助flush redo log，直接返回。
release_output(logger, fsynced_lsn);
return;
}
if (logger->inbuf.n_in_buf > 0) {
// 交换inbuf，outbuf
swap_inbuf_outbuf(logger);
// 把outbuf里的日志写回
write_outbuf_to_logfile(logger, &fsynced_lsn);
}
// 适当调整inbuf大小
if (n_bytes_needed > logger->inbuf.buf_size) {
assert(n_bytes_needed < (1<<30)); // redo log entry必须小于1G
int new_size = max_int(logger->inbuf.buf_size * 2, n_bytes_needed);
assert(new_size < (1<<30)); // inbuf必须小于1G
XREALLOC_N(new_size, logger->inbuf.buf);
logger->inbuf.buf_size = new_size;
}
// 唤醒等待flush redo log的线程
release_output(logger, fsynced_lsn);
}
~~~
## TokuDB崩溃恢复过程
### 判断是否进行recovery
前面提到MySQL重启过程中会调用`db_env_create`创建env实例，进行参数设置和callback设置，然后调用env->open来做进一步初始化。同样env->open也是一个回调函数，它是在`db_env_create`设置的，指向env_open函数。
在env_open里调用validate_env判断是否需要进行recovery。validate_env函数返回时表明这个env是否是emptyenv (env目录为空，且不存在rollback文件，不存在数据文件)，是否是newnev (env目录不存在)，是否是emptyrollback (env目录存在，rollback文件为空)。
如果满足条件 !emptyenv && !new_env && is_set(DB_RECOVERY) 就尝试进行recovery。简单地说recovery的条件就是env存在，log_dir存在，redo log存在。
判断是否真正做recovery的函数是`tokuft_needs_recovery`。代码如下：
~~~
int tokuft_needs_recovery(const char *log_dir, bool ignore_log_empty) {
int needs_recovery;
int r;
TOKULOGCURSOR logcursor = NULL;
r = toku_logcursor_create(&logcursor, log_dir);
if (r != 0) {
needs_recovery = true; goto exit;
}
struct log_entry *le;
le = NULL;
r = toku_logcursor_last(logcursor, &le);
if (r == 0) {
needs_recovery = le->cmd != LT_shutdown;
}
else {
needs_recovery = !(r == DB_NOTFOUND && ignore_log_empty);
}
exit:
if (logcursor) {
r = toku_logcursor_destroy(&logcursor);
assert(r == 0);
}
return needs_recovery;
}
~~~
`tokuft_needs_recovery`尝试读取最后一条redo log entry，如果不是LT_shutdown，就需要真正做recovery。读取最后一条redo log entry的代码片段如下：
~~~
int toku_logcursor_last(TOKULOGCURSOR lc, struct log_entry **le) {
// 打开最后一个redo log文件
if ( !lc->is_open ) {
r = lc_open_logfile(lc, lc->n_logfiles-1);
if (r!=0)
return r;
lc->cur_logfiles_index = lc->n_logfiles-1;
}
while (1) {
// 移到最后一个redo log的文件末尾
r = fseek(lc->cur_fp, 0, SEEK_END); assert(r==0);
// 从当前位置（redo log末尾）向前读一个log entry
r = toku_log_fread_backward(lc->cur_fp, &(lc->entry));
if (r==0) // 读成功
break;
if (r>0) {
// 读失败
toku_log_free_log_entry_resources(&(lc->entry));
// 从当前redo log头部开始向后scan直到找到第一非法log Entry的位置，并把redo log文件truncate到那个位置。
r = lc_fix_bad_logfile(lc);
if ( r != 0 ) {
fprintf(stderr, "%.24s TokuFT recovery repair unsuccessful\n", ctime(&tnow));
return DB_BADFORMAT;
}
// 重新读redo log entry
r = toku_log_fread_backward(lc->cur_fp, &(lc->entry));
if (r==0) // 读到好的redo log entry
break;
}
// 当前redo log没有访问的log entry，切换到上一个redo log文件
r = lc_close_cur_logfile(lc);
if (r!=0)
return r;
if ( lc->cur_logfiles_index == 0 )
return DB_NOTFOUND;
lc->cur_logfiles_index--;
r = lc_open_logfile(lc, lc->cur_logfiles_index);
if (r!=0)
return r;
}
}
~~~
在读最后一个log entry的过程中，在读log entry出错的情况下（crash的时候把redo log写坏了）会调用`lc_fix_bad_logfile`尝试修复redo log文件。修复的过程很简单：从当前redo log头部开始向后scan直到找到第一非法log entry的位置，并把redo log文件truncate到那个位置。此时，文件指针也指向文件末尾。极端的情况是，修复完redo log，发现当前redo log中的所有entry都是坏的，那样需要切换到前面一个redo log文件。
### Recovery过程
如果需要做recovery，TokuDB会调用do_recovery进行恢复，恢复的时候先做redo log apply，然后进行undo rollback。代码片段如下：
~~~
static int do_recovery(RECOVER_ENV renv, const char *env_dir, const char *log_dir) {
r = toku_logcursor_create(&logcursor, log_dir);
assert(r == 0);
scan_state_init(&renv->ss);
for (unsigned i=0; 1; i++) {
// 读取前一个log entry，第一次读的是最后一个log entry
le = NULL;
r = toku_logcursor_prev(logcursor, &le);
if (r != 0) {
if (r == DB_NOTFOUND)
break;
rr = DB_RUNRECOVERY;
goto errorexit;
}
// backward阶段处理log entry
assert(renv->ss.ss == BACKWARD_BETWEEN_CHECKPOINT_BEGIN_END ||
renv->ss.ss == BACKWARD_NEWER_CHECKPOINT_END);
logtype_dispatch_assign(le, toku_recover_backward_, r, renv);
if (r != 0) {
rr = DB_RUNRECOVERY;
goto errorexit;
}
if (renv->goforward)
break;
}
for (unsigned i=0; 1; i++) {
// forward阶段处理log entry，首先处理的是checkpoint begin的那个log entry
assert(renv->ss.ss == FORWARD_BETWEEN_CHECKPOINT_BEGIN_END ||
renv->ss.ss == FORWARD_NEWER_CHECKPOINT_END);
logtype_dispatch_assign(le, toku_recover_, r, renv);
if (r != 0) {
rr = DB_RUNRECOVERY;
goto errorexit;
}
// 读取下一个log entry
le = NULL;
r = toku_logcursor_next(logcursor, &le);
if (r != 0) {
if (r == DB_NOTFOUND)
break;
rr = DB_RUNRECOVERY;
goto errorexit;
}
}
// parse redo log结束
assert(renv->ss.ss == FORWARD_NEWER_CHECKPOINT_END);
r = toku_logcursor_destroy(&logcursor);
assert(r == 0);
// 重启logger
toku_logger_restart(renv->logger, lastlsn);
// abort所有未提交的事务
recover_abort_all_live_txns(renv);
// 在recovery退出前做一个checkpoint
r = toku_checkpoint(renv->cp, renv->logger, NULL, NULL, NULL, NULL, RECOVERY_CHECKPOINT);
assert(r == 0);
return 0;
}
~~~
Scan log entry分别两个阶段：backward阶段和forward阶段。这两个阶段是由scan_state状态机控制的。在scan开始之前在`scan_state_init`函数中把状态机ss的初始状态设置为BACKWARD_NEWER_CHECKPOINT_END。
* Backward阶段：从最后一个log entry开始向前读，直到读到checkpoint end。对在这个过程中读到的每一个log entry调用`logtype_dispatch_assign(le, toku_recover_backward_, r, renv)`。在这个阶段对于checkpoint以外的操作，toku_recover_backward_前缀的处理函数都是noop。当读到checkpoint end的log entry时，会把ss状态设置为BACKWARD_BETWEEN_CHECKPOINT_BEGIN_END，并记录这个checkpoint的begin_lsn和lsn。然后继续向前scan直到读到checkpoint begin的log entry，确保ss中记录的checkpoint_begin_lsn和log entry的lsn是相等的，然后 把ss的状态设置为FORWARD_BETWEEN_CHECKPOINT_BEGIN_END，并设置renv->goforward为TRUE。
* Forward阶段：对当前的log entry调用`logtype_dispatch_assign(le, toku_recover_, r, renv)`重放redo log。然后向后scan直到读到checkpoint end，确保ss中记录的`checkpoint_begin_lsn`和`checkpoint_end_lsn`与log entry里面记录的`lsn_begin_checkpoint`和lsn是相等的，然后把ss的状态设置为FORWARD_NEWER_CHECKPOINT_END。这样，崩溃之前的最后一个checkpoint就回放完成了。下面要做的事情就是，回放committed txn的redo log。代码片段如下：
~~~
static void scan_state_init(struct scan_state *ss) {
ss->ss = BACKWARD_NEWER_CHECKPOINT_END;
ss->checkpoint_begin_lsn = ZERO_LSN;
ss->checkpoint_end_lsn = ZERO_LSN;
ss->checkpoint_num_fassociate = 0;
ss->checkpoint_num_xstillopen = 0;
ss->last_xid = 0;
}
static int toku_recover_backward_end_checkpoint (struct logtype_end_checkpoint *l, RECOVER_ENV renv) {
switch (renv->ss.ss) {
case BACKWARD_NEWER_CHECKPOINT_END:
renv->ss.ss = BACKWARD_BETWEEN_CHECKPOINT_BEGIN_END;
renv->ss.checkpoint_begin_lsn.lsn = l->lsn_begin_checkpoint.lsn;
renv->ss.checkpoint_end_lsn.lsn = l->lsn.lsn;
renv->ss.checkpoint_end_timestamp = l->timestamp;
return 0;
case BACKWARD_BETWEEN_CHECKPOINT_BEGIN_END:
abort();
default:
break;
}
abort();
}
static int toku_recover_backward_begin_checkpoint (struct logtype_begin_checkpoint *l, RECOVER_ENV renv) {
int r;
switch (renv->ss.ss) {
case BACKWARD_NEWER_CHECKPOINT_END:
// incomplete checkpoint, nothing to do
r = 0;
break;
case BACKWARD_BETWEEN_CHECKPOINT_BEGIN_END:
assert(l->lsn.lsn == renv->ss.checkpoint_begin_lsn.lsn);
renv->ss.ss = FORWARD_BETWEEN_CHECKPOINT_BEGIN_END;
renv->ss.checkpoint_begin_timestamp = l->timestamp;
renv->goforward = true;
r = 0;
break;
default:
abort();
break;
}
return r;
}
static int toku_recover_begin_checkpoint (struct logtype_begin_checkpoint *l, RECOVER_ENV renv) {
int r;
TXN_MANAGER mgr = toku_logger_get_txn_manager(renv->logger);
switch (renv->ss.ss) {
case FORWARD_BETWEEN_CHECKPOINT_BEGIN_END:
assert(l->lsn.lsn == renv->ss.checkpoint_begin_lsn.lsn);
invariant(renv->ss.last_xid == TXNID_NONE);
renv->ss.last_xid = l->last_xid;
toku_txn_manager_set_last_xid_from_recovered_checkpoint(mgr, l->last_xid);
r = 0;
break;
case FORWARD_NEWER_CHECKPOINT_END:
assert(l->lsn.lsn > renv->ss.checkpoint_end_lsn.lsn);
// Verify last_xid is no older than the previous begin
invariant(l->last_xid >= renv->ss.last_xid);
// Verify last_xid is no older than the newest txn
invariant(l->last_xid >= toku_txn_manager_get_last_xid(mgr));
r = 0; // ignore it (log only has a begin checkpoint)
break;
default:
abort();
break;
}
return r;
}
static int toku_recover_end_checkpoint (struct logtype_end_checkpoint *l, RECOVER_ENV renv) {
int r;
switch (renv->ss.ss) {
case FORWARD_BETWEEN_CHECKPOINT_BEGIN_END:
assert(l->lsn_begin_checkpoint.lsn == renv->ss.checkpoint_begin_lsn.lsn);
assert(l->lsn.lsn == renv->ss.checkpoint_end_lsn.lsn);
assert(l->num_fassociate_entries == renv->ss.checkpoint_num_fassociate);
assert(l->num_xstillopen_entries == renv->ss.checkpoint_num_xstillopen);
renv->ss.ss = FORWARD_NEWER_CHECKPOINT_END;
r = 0;
break;
case FORWARD_NEWER_CHECKPOINT_END:
assert(0);
return 0;
default:
assert(0);
return 0;
}
return r;
}
~~~
上面我们是TokuDB recovery的过程。对读redo log一笔带过。现在一起看看读log entry的过程：
* 向后读：从当前位置读4个字节的长度len1，然后读1个字节cmd。然后按照不同cmd的定义来读log entry。
* 向前读：从当前位置读nocrc的长度len2，把文件指针向前移动len2个字节。从那个位置向后读。
* Verify：读的过程需要计算crc校验码。Len1是参与crc计算的，而len2不参与crc计算。计算得到的crc应该与log entry里面记录的crc相等。而且len1应该等于len2。