背景
- 前两天的某个上午,正在开会ing。。突然收到了报警Es服务不可用,同时几个其他业务部门的人也都过来反馈说ES挂了。
- 二话不说先启动ES恢复业务再说。然后就开始分析日志找问题了。
排查过程
- 先是怀疑系统资源被用满了,看了一下zabbix,系统负载不太高,8C 16G机器load维持在5-10左右波动,应该不是这个问题。
- 看了一下网络读取带宽,也没有达到什么高峰(时间是上午10点半左右),感觉系统方面应该不至于出问题。
- 又怀疑是出现OOM内存不足,可是也没发现dump文件,然后就开始找ES日志看问题了
- 看ES日志在down机之前有一个java.lang.StackOverflowError,应该就是这个原因了,之前还真没碰到过这个问题,将错误信息在google上面一查,有一些说是使用前缀或者正则查询导致的,感觉应该是这个问题,便开始抓取down机前1分钟的日志。
- 运气不坏,很快就找到了一个高度怀疑的参数,是在搜索建议词中出现的,搜索建议词使用的es原生suggest + prefix,传过来的关键词是一个json数组去除了双引号和冒号(应该是api做的过滤),但是里面还有1600+字符,同时包含了“{}[]”符号,在测试机上面进行一下测试,把这个Query放进去,ES果然直接Down掉了,问题排查就算是完成了。
修复过程
- 紧急发布了Hotfix(就是加入参数长度限制,特殊字符限制)
- 后续准备考虑使用Ngram来解决这个问题
- 吸取教训:
- 能不用就尽可能不用通配符查询,无论是前缀还是模糊
- 大不了空间换时间,暴力使用ngram解决问题
- 参数一定要加入校验机制
原因分析(转)
问题出现时,ES服务端日志有如下报错:
1
2
3
4
5java.lang.StackOverflowError: null
at org.apache.lucene.util.automaton.Operations.isFinite(Operations.java:1053) ~[lucene-core-6.2.1.jar:6.2.1 43ab70147eb494324a1410f7a9f16a896a59bc6f - shalin - 2016-09-15 05:15:20]
at org.apache.lucene.util.automaton.Operations.isFinite(Operations.java:1053) ~[lucene-core-6.2.1.jar:6.2.1 43ab70147eb494324a1410f7a9f16a896a59bc6f - shalin - 2016-09-15 05:15:20]
at org.apache.lucene.util.automaton.Operations.isFinite(Operations.java:1053) ~[lucene-core-6.2.1.jar:6.2.1 43ab70147eb494324a1410f7a9f16a896a59bc6f - shalin - 2016-09-15 05:15:20]
at org.apache.lucene.util.automaton.Operations.isFinite(Operations.java:1053) ~[lucene-core-6.2.1.jar:6.2.1 43ab70147eb494324a1410f7a9f16a896a59bc6f - shalin - 2016-09-15 05:15:20]Prefix/Regex/Fuzzy一类的Query,是直接构造的deterministic automaton,如果查询字符串过长,或者pattern本身过于复杂,构造出来的状态过多,之后一个isFinite的Lucene方法调用可能产生堆栈溢出。
PrefixQuery继承自Lucene的AutomatonQuery,在实例化的时候,maxDeterminizedStates传的是Integer.MAX_VALUE, 并且生成automaton之前,prefix的长度也没有做限制。
附参考链接: