性能分析之解决 jbd2 引起 IO 高问题

前言

之前遇到过 jbd2 引起 IO 高的问题，直接关掉了日志的功能解决的。最近又见类似问题，这里重新整理下对 jbd2 的内容。

预备知识

jbd2 是什么？

The Journaling Block Device (JBD) provides a filesystem-independent interface for filesystem journaling. ext3, ext4 and OCFS2 are known to use JBD. OCFS2 starting from Linux 2.6.28[1] and ext4 use a fork of JBD called JBD2.[2]

文件系统的日志功能，jbd2 是 ext4 文件系统版本。

检查是否存在 jbd2 进程

[root@7dgroup2 ~]# ps -ef|grep jbd2
root       267     2  0 Aug21 ?        00:06:17 [jbd2/vda1-8]
root     24428 22755  0 09:48 pts/0    00:00:00 grep --color=auto jbd2
[root@7dgroup2 ~]#

检查文件系统的功能

[root@7dgroup2 ~]# dumpe2fs /dev/vda1 | grep has_journal
dumpe2fs 1.42.9 (28-Dec-2013)
Filesystem features:      has_journal ext_attr resize_inode dir_index filetype needs_recovery sparse_super large_file
[root@7dgroup2 ~]#

存在 has_journal。

问题现象

在使用 iotop 看的时候，会有如下信息出现。

Total DISK READ: 46.15 M/s | Total DISK WRITE: 8.24 K/s
  TID  PRIO  USER    DISK READ  DISK WRITE  SWAPIN    IO>    COMMAND
 4036 be/4 search  56.87 K/s  26.45 K/s  0.00 % 87.64 % [jbd2/dm-0-4]

问题原因

• 磁盘满
• 系统 bug
  • 所知 bug 号：Bug 39072 - jbd2 writes on disk every few seconds
• 即使没有以上问题。在 ext4 上有一个新加入的参数 barrier，是用来保证文件系统的完整性的。
  • [Barrier解释]（）。
  • 这个值默认是1，即是打开状态。在这个状态下，打开 jbd2 也是会导致性能下降的，这个玩意的设计逻辑就是为了损失掉性能保证文件完整性。
  • 这是个选择题，要么不用它，要么性能差。但是这个功能不能和设备映射器同时使用，也即是，如果你使用了逻辑卷、软RAID、多路径磁盘，则这个值不生效。

解决办法

方案一

关闭日志功能

tune2fs -o journal_data_writeback /dev/vda1
tune2fs -O "^has_journal" /dev/vda1
e2fsck -f /dev/vda1

如果使用 tune2fs 时候，提示 disk 正在 mount，如果是非系统盘下，你可以使用：

fuser -km /home #杀死所有使用/home下的进程
umount /dev/vda1 #umount

之后在使用上面的命令进行移除 has_journal。

方案二

如果是 bug 的话，可以用这种方式解决。如果是不是 bug，这种方式也解决不了，所以要先判断下引起问题的原因再选择解决方案。

升级系统内核：

yum update kernel

方案三

禁用 Barrier 的同时修改 commit 的值。这个方式可以解决 barrier 引起的性能下降，但是解决不了系统 bug 的问题。

修改 commit 值，降低文件系统提交次数或者禁用 barrier 特性；

建议文件系统参数为:

defaults,noatime,nodiratime,barrier=0,data=writeback,commit=60

然后重新挂载

mount -o remount,commit=60 /data

其中 barrier=0 是禁用 barrier 特性,commit=60 是减少提交次数。减少提交次数只能缓解。

方案四

如果不是 bug，并且不想禁用 barrier 时，用此方式缓解。

想尽办法降低 IO，缓解 IO 压力。这种方式也会导致其他系统资源用不上去。 比如说在 mysql 中把 syncbinlog 加大，同时将innodbflushlogattrxcommit 增加。 比如说在应用中减少 IO 的读写。

bug 的根源

在之前的版本中出现问题有一个原因是 ext4 文件系统出现 bug。 这个 bug 出现的比较早了，我看 kernel tracker 里最早的信息是2011 年，如果如果是用的老版本，我建议先做升级。如果没有升级条件，只能用上面的关闭日志功能的解决方案。

bug 原因是，在这段代码中：

int __jbd2_log_start_commit(journal_t *journal, tid_t target)
{
        /*
         * Are we already doing a recent enough commit?
         */
        if (!tid_geq(journal->j_commit_request, target)) {
                /*
                 * We want a new commit: OK, mark the request and wakup the
                 * commit thread.  We do _not_ do the commit ourselves.
                 */
                journal->j_commit_request = target;
                jbd_debug(1, "JBD: requesting commit %d/%d\n",
                          journal->j_commit_request,
                          journal->j_commit_sequence);
                wake_up(&journal->j_wait_commit);
                return 1;
        }
        return 0;
}

以上代码中的 tid_geq 的函数是这样实现的。

static inline int tid_geq(tid_t x, tid_t y)
{
        int difference = (x - y);
        return (difference >= 0);
}

假设 jcommitrequest 值为 2157483647，而 target 的值为0，看上去 if (!tidgeq(journal->jcommit_request, target)) 这个判断是不会走的。

但是 unsigned int 的 x 减去 0 之后，转为 difference 时，difference 的定义是 int 型，此时的结果是多少呢？是-2137483649。 为什么呢？因为 unsigned int 类型的最大值是 2147483647。

printf ("%d.\n", 0x7FFFFFFF);

而 2157483647 - 0 的这个结果显然溢出了，变成了负数。比如，你可以尝试这样打印。

printf ("%d.\n", 0x8FFFFFFFF);

结果就变成了：-1。 有兴趣的，可以自己写个简单的源码试一下。

#include <stdio.h>
int main( void )
{
        unsigned int x=2157483647;
        unsigned int y=0;
        int diff=0;
        diff = x - y;
        printf ("the diff is %ld.\n", diff);
        return 0;
}

执行之后是什么呢？

the diff is -2117515188..

可见在这种情况下，因为溢出的变量导致if (!tidgeq(journal->jcommit_request, target))走到了。

这个 unsigned int 的变量是 jbd2 给每个 transaction 的 tid，tid 是一直增加的，因为这个类型容易溢出，所以用 tidgeq 来判断下，意思是 2157483647 这个 tid 已经提交了，所以把 1000 号的t ransaction commit 掉，于是执行了 wakeup(&journal->jwaitcommit);。但是执行之后才发现，原来并没有运行中的事务，于是系统就疯了。

在 trace jbd2 的可以看到 target 有 0 的情况。实际上，大部分的 target 都不会是 0，这个 0 是因为 ialloc.c 中的i datasynctid没 有正确赋值，所以使用了默认的0。 idatasynctid 是在创建 inode 或者 ext4iget() 时更新的，如果应用在打开某些文件后就不再关闭，只是一直更新，这时 extent 树是不变的（ext4 使用 extent 取代了传统的 block 映射方式），但是 jcommit_request 随着 jbd2日志的提交而不断增加，所以最后这个差值会在业务运行到一定时间之后出现负值。

如果是这个 bug 引起的话，可以看到的现象是 jbd2 这个进程长时间占着 99 %的 IO。

影响版本

有此问题的 os 版本，只根据我使用过的版本统计：

• CentOS6.5-64bit
• CentOS6.9-64bit

内核版本：

• 2.6.32-131.0.15.el6.x86_64