关于java:坏代码导致的性能问题大赏CPU占用飙到了900

4次阅读

共计 6628 个字符,预计需要花费 17 分钟才能阅读完成。

读过《重构 – 改善既有代码的设计》一书的同学们应该都很理解“代码的坏滋味”。当然确定什么是代码“坏滋味”是主观的,它会随语言、开发人员和开发方法的不同而不同。在工作当中,很多时候都是在保护之前的我的项目和在此基础上减少一些新性能,为了能让我的项目代码易于了解和保护,要时刻留神代码中的“坏滋味”,当发现代码如果有坏滋味了,要及时去重构它使其变成优良的整洁的代码。明天咱们要聊的是“坏滋味的代码”给零碎性能带来的影响,笔者会给大家展现几个案例,心愿能对大家有所启发和帮忙。

FGC 实战:坏代码导致服务频繁 FGC 无响应问题剖析

问题

网络问题?

早晨七点多开始,我就开始不停地收到报警邮件,邮件显示探测的几个接口有超时状况。少数执行栈都在:

java.io.BufferedReader.readLine(BufferedReader.java:371)
java.io.BufferedReader.readLine(BufferReader.java:389)
java_io_BufferedReader$readLine.call(Unknown Source)
com.domain.detect.http.HttpClient.getResponse(HttpClient.groovy:122)
com.domain.detect.http.HttpClient.this$2$getResponse(HttpClient.groovy)

这个线程栈的报错我见得多了,咱们设置的 HTTP DNS 超时是 1s,connect 超时是 2s,read 超时是 3s,这种报错都是探测服务失常发送了 HTTP 申请,服务器也在收到申请失常解决后失常响应了,但数据包在网络层层转发中失落了,所以申请线程的执行栈会停留在获取接口响应的中央。这种状况的典型特色就是能在服务器上查找到对应的日志记录。而且日志会显示服务器响应齐全失常。与它绝对的还有线程栈停留在 Socket connect 处的,这是在建连时就失败了,服务端齐全无感知。

我留神到其中一个接口报错更频繁一些,这个接口须要上传一个 4M 的文件到服务器,而后通过一连串的业务逻辑解决,再返回 2M 的文本数据,而其余的接口则是简略的业务逻辑,我猜想可能是须要上传下载的数据太多,所以超时导致丢包的概率也更大吧。

依据这个猜测,群登上服务器,应用申请的 request_id 在近期服务日志中搜寻一下,果不其然,就是网络丢包问题导致的接口超时了。

当然这样 leader 是不会称心的,这个论断还得有人接锅才行。于是连忙分割运维和网络组,向他们确认一下过后的网络状态。网络组同学回复说是咱们探测服务所在机房的交换机老旧,存在未知的转发瓶颈,正在优化,这让我更释怀了,于是在部门群里简略交待一下,算是实现工作。

问题暴发

本认为这次值班就起这么一个小波浪,后果在早晨八点多,各种接口的报警邮件一拥而上,打得筹备拾掇货色过周日单休的我措手不及。

这次简直所有的接口都在超时,而咱们那个大量网络 I/O 的接口则是每次探测必超时,难道是整个机房故障了么。

我再次通过服务器和监控看到各个接口的指标都很失常,本人测试了下接口也齐全 OK,既然不影响线上服务,我筹备先通过探测服务的接口把探测工作停掉再缓缓排查。

后果给暂停探测工作的接口发申请良久也没有响应,这时候我才晓得没这么简略。

解决

内存透露
于是赶快登陆探测服务器,首先是 top free df 三连,后果还真发现了些异样。

咱们的探测过程 CPU 占用率特地高,达到了 900%。

咱们的 Java 过程,并不做大量 CPU 运算,失常状况下,CPU 应该在 100~200% 之间,呈现这种 CPU 飙升的状况,要么走到了死循环,要么就是在做大量的 GC。

应用 jstat -gc pid [interval] 命令查看了 java 过程的 GC 状态,果然,FULL GC 达到了每秒一次。

这么多的 FULL GC,应该是内存透露没跑了,于是 应用 jstack pid > jstack.log 保留了线程栈的现场,应用 jmap -dump:format=b,file=heap.log pid 保留了堆现场,而后重启了探测服务,报警邮件终于进行了。

jstat

jstat 是一个十分弱小的 JVM 监控工具,个别用法是:jstat [-options] pid interval

它反对的查看项有:

  • class 查看类加载信息
  • compile 编译统计信息
  • gc 垃圾回收信息
  • gcXXX 各区域 GC 的详细信息 如 -gcold

应用它,对定位 JVM 的内存问题很有帮忙。

排查

问题尽管解决了,但为了避免它再次发生,还是要把本源揪出来。

剖析栈
栈的剖析很简略,看一下线程数是不是过多,少数栈都在干嘛。

> grep 'java.lang.Thread.State' jstack.log  | wc -l
> 464

才四百多线程,并无异样。

> grep -A 1 'java.lang.Thread.State' jstack.log  | grep -v 'java.lang.Thread.State' | sort | uniq -c |sort -n

     10  at java.lang.Class.forName0(Native Method)
     10  at java.lang.Object.wait(Native Method)
     16  at java.lang.ClassLoader.loadClass(ClassLoader.java:404)
     44  at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
    344  at sun.misc.Unsafe.park(Native Method)

线程状态如同也无异样,接下来剖析堆文件。

下载堆 dump 文件
堆文件都是一些二进制数据,在命令行查看十分麻烦,Java 为咱们提供的工具都是可视化的,Linux 服务器上又没法查看,那么首先要把文件下载到本地。

因为咱们设置的堆内存为 4G,所以 dump 进去的堆文件也很大,下载它的确十分麻烦,不过咱们能够先对它进行一次压缩。

gzip 是个性能很弱小的压缩命令,特地是咱们能够设置 -1 ~ -9 来指定它的压缩级别,数据越大压缩比率越大,耗时也就越长,举荐应用 -6~7,-9 切实是太慢了,且收益不大,有这个压缩的工夫,多进去的文件也下载好了。

应用 MAT 剖析 jvm heap
MAT 是剖析 Java 堆内存的利器,应用它关上咱们的堆文件(将文件后缀改为 .hprof), 它会提醒咱们要剖析的品种,对于这次剖析,果决抉择 memory leak suspect。

从下面的饼图中能够看出,绝大多数堆内存都被同一个内存占用了,再查看堆内存详情,向下层追溯,很快就发现了罪魁祸首。

剖析代码
找到内存透露的对象了,在我的项目里全局搜寻对象名,它是一个 Bean 对象,而后定位到它的一个类型为 Map 的属性。

这个 Map 依据类型用 ArrayList 存储了每次探测接口响应的后果,每次探测完都塞到 ArrayList 里去剖析,因为 Bean 对象不会被回收,这个属性又没有革除逻辑,所以在服务十来天没有上线重启的状况下,这个 Map 越来越大,直至将内存占满。

内存满了之后,无奈再给 HTTP 响应后果分配内存了,所以始终卡在 readLine 那。而咱们那个大量 I/O 的接口报警次数特地多,预计跟响应太大须要更多内存无关。

给代码 owner 提了 PR,问题圆满解决。

小结

其实还是要检查一下本人的,一开始报警邮件里还有这样的线程栈:

groovy.json.internal.JsonParserCharArray.decodeValueInternal(JsonParserCharArray.java:166)
groovy.json.internal.JsonParserCharArray.decodeJsonObject(JsonParserCharArray.java:132)
groovy.json.internal.JsonParserCharArray.decodeValueInternal(JsonParserCharArray.java:186)
groovy.json.internal.JsonParserCharArray.decodeJsonObject(JsonParserCharArray.java:132)
groovy.json.internal.JsonParserCharArray.decodeValueInternal(JsonParserCharArray.java:186)

看到这种报错线程栈却没有细想,要晓得 TCP 是能保障音讯完整性的,况且音讯没有接管完也不会把值赋给变量,这种很显著的是外部谬误,如果注意后细查是能提前查出问题所在的,查问题真是差了哪一环都不行啊。

起源 | https://zhenbianshu.github.io/

记一次 jvm 疯狂 gc 导致 CPU 飙高的问题解决

背景

线上 web 服务器不断的呈现十分卡的状况,登录服务器 top 命令发现服务器 CPU 十分的高,重启 tomcat 之后 CPU 恢复正常,半天或者一天之后又会偶现同样的问题。解决问题首先要找到问题的暴发点,对于偶现的问题是十分难于定位的。

重启服务器之后只能期待问题再次出现,这时候首先狐疑是否某个定时工作引发大量计算或者某个申请引发了死循环,所以先把代码外面所有狐疑的中央剖析了一遍,加了一点日志,后果第二天下午问题再次出现,

这次的策略是首先爱护案发现场,因为线上是两个点,把一个点重启复原之后把另一个点只下线不重启保留犯罪现场。

排查

在问题的服务器上首先看业务日志,没有发现大量反复日志,初步排除死循环的可能,接下来只能剖析 jvm 了。

第一步:top 命令查看占用 CPU 的 pid

这是预先的截图,过后的 cpu 飙高到 500 多,pid 是 27683

而后ps aux | grep 27683 搜寻一下确认一下是不是咱们的 tomcat 占用的 cpu,这个根本是能够必定的,因为 tomcat 重启之后 CPU 立马就降下来了。

也能够应用 jps 显示 java 的 pid

第二步:top -H -p 27683 查找 27683 上面的线程 id,显示线程的 cpu 的占用工夫,占用比例,发现有很多个线程都会 CPU 占用很高,只能每个排查。

第三步:jstack 查看线程信息,命令:jstack 27683 >> aaaa.txt 输入到文本中再搜寻,也能够间接管道搜寻 jstack 27683 | grep "6c23" 这个线程 id 是 16 进制示意,须要转一下,能够用这个命令转 printf "%x\n" tid 也能够本人计算器转一下。

喜剧的是我在排查的时候被引入了一个误区,过后搜寻到 6c26 这个线程的时候,发现是在做 gc,疯狂 gc 导致的线程过高,然而找不到哪里造成的产生这么多对象,始终在找所有可能的死循环和可能的内存泄露。

而后通过命名 jstat -gcutil【PID】1000 100 查看每秒钟 gc 的状况。

这个是预先复盘的截图,过后的截图曾经没有了

发现 S0 不停的再新建对象,而后 gc,不停的重复如此 gc,去看堆栈信息,没有什么发现,无非都是 String 和 map 对象最多,确定不了死循环的代码,也找不到问题的暴发点,至此陷入彻底的困惑。一番查找之后确认也不是内存泄露,苦苦寻找无果,我陷入了深思。

CPU 还是始终放弃在超高,无奈之下,还是 jstack 27683 看线程栈,无目标的乱看,然而发现了一个问题,以后的点我是下线的也就是没有用户拜访的,CPU 还是始终这么高,而且线程栈也在不停的打印,那么也就是说以后还在运行的线程很可能就是首恶,马上剖析线程栈信息,有了重大发现。

大量的这个线程信息呈现,httpProxy_jsp 这个 jsp 的线程在不停的沉闷,这个是什么鬼 jsp?难道服务器被攻打了?马上去代码里找,发现的确有这个 jsp,查看 git 的提交记录,是几天之前另一个共事提交的代码,工夫点和问题第一次呈现的工夫十分吻合,感觉本人运气好应该是找到问题的点了,把共事叫过去剖析他的代码,这个 jsp 其实非常简单,就是做一个代理申请,发动了一个后端 http 申请。

HttpRequestUtil 如下,是共事本人写的工具类,没有用专用工具,其中一个 post 办法里 connection 没有设置链接超时工夫和 read 超时工夫:

这外面有个致命的问题,他 http 申请没有设置超时等待时间,connection 如果不设置超时工夫或者 0 就认为是无穷大,也就是会始终都不超时,这时候如果被申请的第三方页面如果不响应或者响应十分慢,这个申请就会始终的期待,或者是申请没回来接着又来一次,导致这个线程就卡住了,然而线程沉积在这里又不解体还始终的在做某些事件会产生大量的对象,而后触发了 jvm 不停的疯狂 GC 把服务器 CPU 飚到了极限,而后服务器响应变得十分慢,问题终于找到了,而且十分合乎问题的特点,果然把这个中央换了一种写法加了 2 秒钟超时的限度,问题没有再呈现。

这次问题的解决过程得出几点心得:

1、jvm 的问题是很简单的,通过日志看到的很可能不是问题的本源,解决问题也有运气成分,剖析日志 + 业务场景 + 瞎蒙都是解决问题的办法,剖析问题不要一条道走到黑,多联合以后的场景加上一些猜想。

2、这个问题的本源是 CPU 飙高,一开始总想着是代码里有死循环,起初又认为是内存泄露,所以走了很多弯路,最初还是用最笨的办法看线程栈的日志看出了问题,所以问题没有对立的解决方案,具体问题都要具体解决的,不能拘泥于以往的教训。

3、在写代码过程中尽量应用原我的项目中曾经被宽泛应用的公共工具类,尽量不要把本人借鉴的没有通过我的项目测验的代码引入工程,即便看起来很简略的一段代码可能给我的项目引入劫难,除非你有短缺的把握理解你代码的底层,比方这个超时的设置问题。

记一次 Synchronized 关键字应用不合理,导致的多线程下线程阻塞问题排查

在为客户进行性能诊断调优时,碰到了一个 Synchronized 关键字应用不合理导致多线程下线程阻塞的状况。用文字记录下了问题的整个发现 - 排查 - 剖析 - 优化过程,排查过程中应用了我司商业化产品——XLand 性能剖析平台,通过文章次要心愿跟大家分享下剖析和优化思路以及留神点,有趣味深刻理解的同学能够评论交换。

景象

在执行单接口负载“判断登陆是否失常接口”测试时候,发现 10 用户减少至 50 用户并发,TPS 放弃不变,响应工夫处于继续递增状态,利用 CPU 为 27%,数据库 CPU 为 3%,资源耗费维持稳固状态,由此判断应用程序可能存在瓶颈。


剖析

通过 XLand 剖析平台线程剖析,发现某线程存在锁期待状况,通过 XLand 中的 x 剖析定位,发现 AuthProvider 类中 getAccessor 办法有 Synchronized 关键字,当两个以上线程同时调用该同步办法时,每次只能有一个线程能进入该办法,其余线程必须等前一个线程执行完该同步办法后,能力有机会进入。

危险点

Synchronized 关键字解决的是多个线程之间拜访资源的同步性,Synchronized 关键字能够保障被它润饰的办法或者代码块在任意时刻只能有一个线程执行。审慎应用 Synchronized 关键字,以防导致不必要的线程阻塞,影响响应工夫。

优化措施

把 AuthProvider 类中的 Synchronized 关键字去掉,发现在 10 用户并发下判断登陆是否失常接口 TPS 由原来的 174 笔 / 秒增长至 624 笔 / 秒,增长了 3 倍。在日常编程中审慎应用 synchronized,如果没有多线程批改动态变量或单例属性这类需要就不要用,如果有须要也倡议只锁必要的代码块,而不是锁整个办法。

后记

Java 利用性能的瓶颈点十分多,比方磁盘、内存、网络 I/O 等零碎因素,Java 利用代码,JVM GC,数据库,缓存等。个别将 Java 性能优化分为 4 个层级:应用层、数据库层、框架层、JVM 层。每层优化难度逐级减少,波及的常识和解决的问题也会不同。但说实话,其实大多数问题还没有须要你懂框架源代码、JVM 参数、GC 工作机制这一步,只须要略会剖析 SQL,了解代码逻辑,会定位到有问题的 Java 代码并作批改即可。毕竟不是有这么一句话是这么说来着——80% 的性能问题都是你写的烂代码导致的,哈哈哈。尽管有点犀利,然而保持良好的编码习惯,正当应用某些可能引起问题的关键字,审慎应用内存资源,确实能躲避很大一部分问题。好了,最初祝大家都徒手千行无 bug!

正文完
 0