Solr复制bug一例：Unable to move index file from tempfile to indexfile

Posted in solr on 十一月 24th, 2010 by kafka0102

22日下午3时多，收到搜索系统的报警邮件，错误日志如下：

[2010-11-22 15:16:14][ERROR][pool-6-thread-1][SnapPuller.java(650)]Unable to move index file from: /indexpath/index.20101122031500/_21.frq to: /indexpath/index.20101122031000/_21.frq

SnapPuller是Solr复制用到的一个类，我对它做了一些修改，所以把它挪到我的代码里了。报错的代码片断如下：

private boolean copyAFile(final File tmpIdxDir, final File indexDir, final String fname, final List<String> copiedfiles) {
    final File indexFileInTmpDir = new File(tmpIdxDir, fname);
    final File indexFileInIndex = new File(indexDir, fname);
    final boolean success = indexFileInTmpDir.renameTo(indexFileInIndex);
    if (!success) {
      LOG.error("Unable to move index file from: " + indexFileInTmpDir
          + " to: " + indexFileInIndex);
      for (final String f : copiedfiles) {
        final File indexFile = new File(indexDir, f);
        if (indexFile.exists()) {
          indexFile.delete();
        }
      }
      delTree(tmpIdxDir);
      return false;
    }
    return true;
  }

错误现象表明，indexFileInTmpDir.renameTo(indexFileInIndex)失败了。在这个复制过程中，这种失败最大的可能性就是indexFileInIndex所在的indexDir不存在。查看索引数据目录，确实没有找到index.20101122031000文件夹。不过，从库的index.properties文件却记录“index=index.20101122031000”，也就是说，当前提供查询服务的索引目录就是index.20101122031000。查看进程打开的句柄，进程确实保持着index.20101122031000目录下的索引文件句柄，但它们也确实被删除了。

这里补充一下背景，搜索系统使用的是最新solr1.4.1版本，从库每5分钟同步一次主库。所以，当上面的错误出现以后，后续每5分钟就又会出现类似的错误，使得复制总是失败。Solr复制的部分原理是：从库默认的索引目录是index，在正常复制时，从库只是对该目录里的索引文件做修改（添加新的，删除旧的），但当从库索引提交点（IndexCommit）的generation大于主库时，会发生索引文件的全copy，也就是抛弃当前使用的索引目录，而是使用新生成的临时索引目录作为新的索引目录，并修改index.properties，临时目录的命名格式就是取当前的一时间戳（也就是bug所在，但到这里我还没发现这个bug）。Solr wiki也有提到，从库的IndexCommit.generation大于的bad case就是外界对从库做了不适当的提交。而在我的系统里，这种现象是由于重建索引造成的，系统重建索引没有使用DIH，而是在不影响更新时单独线程重建，建完后覆盖旧的索引，这造成重建后的索引的generation会比从库小，所以每次重建从库都会使用新的索引目录。

回到这个问题上来，临时的解决办法就是重启从库，因为重启后从库读index.properties发现index.20101122031000并不存在，默认就会使用index目录的索引，而index目录的generation会和主库不一致，就产生全复制，短时间内恢复成最新的索引，但这样可能后续还会触发到bug。但问题并没有解决，我继续查看主从库的日志，再没有发现其他错误信息。而这个问题之前是没有出现的，所以可能是最近的什么操作引起的。而最近的操作就是老高22号凌晨重建了索引，我对照了重建完成时间，是凌晨3点多，而从库的index.20101122031000应该就是之后复制生成的。

google之错误信息，找到https://issues.apache.org/jira/browse/SOLR-1822，报bug的人出现和我一样的错误！！不过他也不清楚索引目录怎么没了，他是建议发现目录没了就新建一个，这也是可以曲线解决问题的（我想了一下，这种方法应该不会产生句柄泄漏）。可问题是，好端端的一个索引目录怎么就没了。我继续查看从库复制相关的log，发现在下午3点10分之前都是有正常的复制log的。初想一下，复制过程中发生删除的地方也就是和过期的IndexCommit相关联的索引文件被删除，但也不会删除目录阿！！！莫不是被系统外界下的黑手？

回家的地铁上就在琢磨，复制过程有删除目录的操作吗？有！！！复制的最后会删除临时目录！！！那会不会是临时目录和目标索引目录重名了，结果复制后把索引目录给删除了？回家再回看错误日志，这临时索引目录名称是：index.20101122031500，而出错当时是下午的15:15,而不是凌晨的03:15，查找创建临时索引目录的代码：

 private File createTempindexDir(final SolrCore core) {
    final String tmpIdxDirName = "index." + new SimpleDateFormat(SnapShooter.DATE_FMT).format(new Date());
    final File tmpIdxDir = new File(core.getDataDir(), tmpIdxDirName);
    tmpIdxDir.mkdirs();
    return tmpIdxDir;
  }

SnapShooter.DATE_FMT的定义是：

  public static final String DATE_FMT = "yyyyMMddhhmmss";

注意时间串格式中的小时是“hh”（范围是01-12）而不是“HH”（范围是00-23），这就造成从库如果在当天上午某个时间点全复制，而不幸的，在下午的相应时刻复制又来了，就使得临时索引目录和当前索引目录名称相同，而在复制的最后误删掉当前索引目录。从Bug效果来说，这绝对有破坏性，并且其真的是够低级的。
我后来check了solr的trunk，发现这个bug已经被修复了，log显示是：

r964312 | koji | 2010-07-15 14:32:22 +0800 (四, 2010-07-15) | 1 行
SOLR-1995: Use proper format for SimpleDateFormat

找到https://issues.apache.org/jira/browse/SOLR-1995，发现修复的初衷和我所出现的问题还不一样，它的破坏性也要小的多。话说又说回来，这个bug其实是很隐蔽的，触发的条件是：1）从库要在当天的上午某点进行全复制,如果使用DIH复制，这种情况是不会出现的，而我的系统的全复制通常是在下午，所以之前没出现该问题。2）下午的相应时刻也要发生复制，这要求复制间隔能被12小时整除（我的5分钟间隔中招了），并且当时主库的索引有更新变化（我的系统10多个库当时就有部分库就因为那个时间段没有更新而没有中招）。

=============================== 华丽的终止符 ================================

本文作者：kafka0102，转载文章请注明来源，谢谢！！
本文链接：http://www.kafka0102.com/2010/11/414.html

4 Responses

30 Says:
十一月 25th, 2010 at 10:38 上午
呵呵这么细微的bug 都被你们遇到了恭喜中大奖了
话说回来博主你们的搜索应用，大概是多少的索引量。

[回复]
kafka0102 回复:
十一月 25th, 2010 at 3:14 下午
@30,
也就一普通站内的，大库有几千万记录，6G的索引，小库也就M级别的。

[回复]
大头娃娃 Says:
十二月 4th, 2010 at 2:32 下午
厉害啊，想请教楼主，像您这样几千万记录进行solr查询，采用了什么样的架构来保证较小的响应时间，这块我一直比较迷糊，请楼主谈谈呢。

[回复]
kafka0102 回复:
十二月 4th, 2010 at 9:11 下午
@大头娃娃,
响应时间的多数可能会有多种因素造成，数据规模是其一种。以我网站论坛为例，索引的记录有3000多万，索引大小有7个G（除了主键其他字段都不存储），论坛搜索平均响应时间在30ms，满足应用需求。这6G的索引也就一个server，内存开大些保证lucene和solr需要的缓存够用。所以，从满足需求的角度来说，中小规模的搜索系统架构不会很复杂。往往一些性能问题可能源于一些细节没做好。
而就搜索架构来说，其实都差不多，除了我使用的一主一从模式，还有两种通用策略：
1、如果单实例响应时间满足需求（比如平均搜索耗时在几十毫秒），但搜索量大，那就多开几个实例，客户端查询时加个负载均衡策略。如果不要求实时性，可以一主负责更新索引多从负责查询。
2、如果索引量很大，单实例响应时间长，比如典型的通用搜索，那就做shard，每个实例索引一部分数据，这样查询端实际有两层（bs和as），as对各实例结果（bs）做合并处理后返回给客户端。
当然，实际情况可能是两者的接合，这还要看搜索的规模。
对搜索的响应方面，重要的就是要使得基本查询快，这方面的一个调优点是cache，可以对索引、查询模式等特点做分析，使得cache效果最大化。因为搜索对磁盘主要是随机读，所以使用ssd也会有更好的效果。如果使用lucene或solr，可以从其wiki查找一些关于性能方面的资料看看。

[回复]

kafka0102的边城客栈

Solr复制bug一例：Unable to move index file from tempfile to indexfile

相关日志

4 Responses

留下评论

站内搜索

自画像

最新博文

热点视野

分类浏览

年代编纂

友情演出