案例分享：记一次MongoDB性能问题

pubers · 发表于 2012-2-29 16:50

最近忙着把一个项目从MySQL迁移到MongoDB，在导入旧数据的过程中，遇到了些许波折，犯了不少错误，但同时也学到了不少知识，遂记录下来。
公司为这个项目专门配备了几台高性能务器，清一色的双路四核超线程CPU，外加32G内存，运维人员安装好MongoDB后，就交我手里了，我习惯于在使用新服务器前先看看相关日志，了解一下基本情况，当我浏览MongoDB日志时，发现一些警告信息：

WARNING: You are running on a NUMA machine. We suggest launching mongod like this to avoid performance problems: numactl –interleave=all mongod [other options]

当时我并不太清楚NUMA是什么东西，所以没有处理，只是把问题反馈给了运维人员，后来知道运维人员也没有理会这茬儿，所以问题的序幕就这样拉开了。
迁移工作需要导入旧数据。MongoDB本身有一个mongoimport工具可供使用，不过它只接受json、csv等格式的源文件，不适合我的需求，所以我没用，而是用PHP写了一个脚本，平稳运行了一段时间后，我发现数据导入的速度下降了，同时PHP抛出异常：

cursor timed out (timeout: 30000, time left: 0:0, status: 0)

我一时判断不出问题所在，想想先在PHP脚本里加大Timeout的值应付一下：

<?php

MongoCursor::$timeout = -1;

?>

可惜这样并没有解决问题，错误反倒变着花样的出现了：

max number of retries exhausted, couldn’t send query, couldn’t send query: Broken pipe

接着使用strace跟踪了一下PHP脚本，发现进程卡在了recvfrom操作上：

shell> strace -f -r -p <PID>
recvfrom(<FD>,

通过如下命令查询recvfrom操作的含义：

shell> apropos recvfrom
receive a message from a socket

或者按照下面的方式确认一下：

shell> lsof -p <PID>
shell> ls -l /proc/<PID>/fd/<FD>

此时如果查询MongoDB的当前操作，会发现几乎每个操作会消耗大量的时间：

mongo> db.currentOp()

与此同时，运行mongostat的话，结果会显示很高的locked值。
我在网络上找到一篇：MongoDB Pre-Splitting for Faster Data Loading and Importing，看上去和我的问题很类似，不过他的问题实质是由于自动分片导致数据迁移所致，解决方法是使用手动分片，而我并没有使用自动分片，自然不是这个原因。
询问了几个朋友，有人反映曾遇到过类似的问题，在他的场景里，问题的主要原因是系统IO操作繁忙时，数据文件预分配堵塞了其它操作，从而导致雪崩效应。
为了验证这种可能，我搜索了一下MongoDB日志：

shell> grep FileAllocator /path/to/log
[FileAllocator] allocating new datafile ... filling with zeroes...
[FileAllocator] done allocating datafile ... took ... secs

我使用的文件系统是ext4（xfs也不错），创建数据文件非常快，所以不是这个原因，但如果有人使用ext3，可能会遇到这类问题，所以还是大概介绍一下如何解决：
MongoDB按需自动生成数据文件：先是<DB>.0，大小是64M，然后是<DB>.1，大小翻番到128M，到了<DB>.5，大小翻番到2G，其后的数据文件就保持在2G大小。为了避免可能出现的问题，可以采用事先手动创建数据文件的策略：

#!/bin/sh

DB_NAME=$1

cd /path/to/$DB_NAME

for INDEX_NUMBER in {5..50}; do
FILE_NAME=$DB_NAME.$INDEX_NUMBER

if [ ! -e $FILE_NAME ]; then
head -c 2146435072 /dev/zero > $FILE_NAME
fi
done

注：数值2146435072并不是标准的2G，这是INT整数范围决定的。
最后一个求助方式就是官方论坛了，那里的国际友人建议我检查一下是不是索引不佳所致，死马当活马医，我激活了Profiler记录慢操作：

mongo> use <DB>
mongo> db.setProfilingLevel(1);

不过结果显示基本都是insert操作（因为我是导入数据为主），本身就不需要索引：

mongo> use <DB>
mongo> db.system.profile.find().sort({$natural:-1})

问题始终没有得到解决，求人不如求己，我又重复了几次迁移旧数据的过程，结果自然还是老样子，但我发现每当出问题的时候，总有一个名叫irqbalance的进程CPU占用率居高不下，搜索了一下，发现很多介绍irqbalance的文章中都提及了NUMA，让我一下子想起之前在日志中看到的警告信息，我勒个去，竟然绕了这么大一个圈圈！安下心来仔细翻阅文档，发现官方其实已经有了相关介绍，按如下设置搞定：

shell> echo 0 > /proc/sys/vm/zone_reclaim_mode
shell> numactl --interleave=all mongod [options]

关于zone_reclaim_mode内核参数的说明，可以参考官方文档。
至于NUMA的含义，简单点说，在有多个物理CPU的架构下，NUMA把内存分为本地和远程，每个物理CPU都有属于自己的本地内存，访问本地内存速度快于访问远程内存，缺省情况下，每个物理CPU只能访问属于自己的本地内存。对于MongoDB这种需要大内存的服务来说就可能造成内存不足，幸好可以选择关闭它。
原文出处：http://huoding.com/2011/08/09/104