mongodb 重建发现的问题

[chenchongqi]

报价前台索引集群的几个服务器陆续出现磁盘碎片，因此我们决定逐个重建一下，按照原来的经验，数据量不大的情况下，直接drop掉重新加入是比较快的彻底的方式，但是今天出现了新的情况：

drop掉111以后，一直加不回来持续了一个小时，日志没有被报异常，但始终是UNK的状态，同时83的负载非常高，同时swap也很高。

top - 16:09:01 up 139 days,  6:46,  5 users,  load average: 57.88, 37.94, 18.54
Tasks:  88 total,   1 running,  86 sleeping,   1 stopped,   0 zombie
Cpu(s): 26.6%us, 12.6%sy,  0.0%ni,  2.6%id, 53.6%wa,  1.9%hi,  2.7%si,  0.0%st
Mem:   7141016k total,  7100332k used,    40684k free,      220k buffers
Swap:  2096472k total,   133528k used,  1962944k free,  6756148k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                                         
21270 root      15   0 19.1g 6.6g 6.4g S 136.7 96.3  40:17.32 mongod                                                                                         
  423 root      10  -5     0    0    0 D 24.0  0.0 166:22.93 kswapd0                                                                                         
   86 root      10  -5     0    0    0 S  0.3  0.0   0:13.25 kblockd/0   

同时83的fault也很高

                        insert  query update delete getmore command flushes mapped  vsize    res faults locked % idx miss %     qr|qw   ar|aw  netIn netOut  conn             set repl       time 
192.168.237.111:5506        *0     *0     *0     *0       0     0|0       0  12.2g  12.4g   1.2g      0        0          0       0|0     0|0    68b   342b    13 itpricelibindex  UNK   16:12:37 
192.168.237.112:5506         0      0      0      0       0       0       0  14.2g  15.7g  3.72g      0        0          0       0|0     3|0    90b   587b   287 itpricelibindex    M   16:12:37 
192.168.237.117:5506        *0    129     *0     *0       0    38|0       0  14.2g  17.5g  2.41g      0        0          0       0|0     2|0    30k    61k   382 itpricelibindex  SEC   16:12:37 
 192.168.237.83:5506        *0    234     *0     *0       0    37|0       0  14.2g  19.2g  6.55g    235        0          0       0|0    82|0    49k   103k   341 itpricelibindex  SEC   16:12:37 
      localhost:5506         0      0      0      0       0       0       0  14.2g  15.7g  3.72g      0        0          0       0|0     3|0    90b   587b   287 itpricelibindex    M   16:12:37 

我们认为是83有问题，于是把83重启，结果此时变成112负载很高和刚才83的情况一样，而且83重启后也不正常，处于REC状态，所以之前的判断有问题，此时所有的读访问都集中在112上，而且还受111UNK的影响，112的负载很高，但是有83的情况在前，此时也不能轻易重启112.反倒有可能出问题的是111的同步拖累了其他服务器，所以暂时停掉了111.

好在mongo的机制还算不错，在只有一台SEC和M的服务器下，M也转成了SEC，变成两台服务器提供服务，而且停掉111后，没有了同步的影响，这两台剩下的服务器负载都比较低了。

这时候基本上能确定是同步的问题，之前同步速度都很快而且不会拖累其他服务器。但是现在最紧要的是恢复111和83的服务，然后再查找问题。欧彬提出把服务正常的112的data文件拷贝去111先看看能否直接用正常的数据文件恢复111，经过一番操作后111成功起来并加入了集群，这是个好消息，同样的方法把83也恢复起来加入了集群。

通过查看111的日志我们发现，在生成索引表price_front的时候都很正常，但是多了一个price_front_cache表，而且在处理这个表的时候就卡住等待83读数据：

Wed Jan  4 15:59:56 [replica set sync] replSet initial sync cloning db: price_front_cache
Wed Jan  4 15:59:56 [FileAllocator] allocating new datafile /data/PRG/mongodb/data/price_front_cache/price_front_cache.ns, filling with zeroes...
Wed Jan  4 15:59:56 [FileAllocator] done allocating datafile /data/PRG/mongodb/data/price_front_cache/price_front_cache.ns, size: 16MB,  took 0.017 secs
Wed Jan  4 15:59:56 [FileAllocator] allocating new datafile /data/PRG/mongodb/data/price_front_cache/price_front_cache.0, filling with zeroes...
Wed Jan  4 15:59:56 [FileAllocator] done allocating datafile /data/PRG/mongodb/data/price_front_cache/price_front_cache.0, size: 64MB,  took 0.065 secs
Wed Jan  4 15:59:56 [FileAllocator] allocating new datafile /data/PRG/mongodb/data/price_front_cache/price_front_cache.1, filling with zeroes...
Wed Jan  4 15:59:56 [replica set sync] replauthenticate: no user in local.system.users to use for authentication
building new index on { _id: 1 } for price_front_cache.cache_info
Wed Jan  4 15:59:56 [replica set sync] done for 7 records 0.001secs
Wed Jan  4 15:59:56 [replica set sync] replSet initial sync cloning db: admin
Wed Jan  4 15:59:56 [replica set sync] replauthenticate: no user in local.system.users to use for authentication
replSet initial sync query minValid
Wed Jan  4 15:59:56 [replica set sync] replSet initial sync initial oplog application
Wed Jan  4 15:59:57 [FileAllocator] done allocating datafile /data/PRG/mongodb/data/price_front_cache/price_front_cache.1, size: 128MB,  took 0.206 secs

但是price_front_cache是硬缓存表，照理说不应该出现在索引表专用的实例里，结果查了一下，当时83是从硬缓存实例挪过来的服务器，当时产品库动态那边的应用配置没有跟着相应改过来，但是mongo客户端的容错性比较强一直都还能正常用，然后写了一部分不正常的price_front_cache到83来：

<env-entry>
        <description>MongoDB Config</description>
        <env-entry-name>mongoConfig4RClient</env-entry-name>
        <env-entry-type>java.lang.String</env-entry-type>
        <env-entry-value>mongodb://price_front_app:mongoprice_front_app@192.168.237.81:5506,192.168.237.82:5506,192.168.237.83:5506/price_front_cache?replica
Set=itpricelib;slaveOk=true;maxPoolSize=64;w=1</env-entry-value>
      </env-entry>
这里的83应该配为92

会不会是这部分数据是不正常的，导致111在跟83拿这部分数据的时候，83翻天覆地的找不到呢，这也解释得通83内容用满，还到磁盘上找，导致swap很高负载很高。我们把产品库动态的配置都改回来，并且在mongo的master服务器上把price_front_cache彻底删除，再次drop 111 并且同步。结果用15分钟左右111就同步完成加入了集群，同样117和83都很快完成了重做，基本上都是10分钟左右，可见问题确实出在price_front_cache这部分数据上。

• 总结
  • 由于硬缓存和索引实例的用户密码都一样，导致客户端配置不正确的时候还能带病运行，交叉写了一些脏数据。
  • 这些脏数据的存在，导致在做集群同步操作的时候，数据输出方出现内存用满swap高负载高的现象，并且无法完成同步操作。
  • 直接拷贝data文件可以快速恢复mongo服务器并加入集群，这种方式可以考虑做为备份的一种手段。
  • 磁盘碎片用repair和重建索引没有改善，重做还是最彻底的方法（xxx was empty, skiping ahead ....）.