1.线程阻塞问题-log4j
2.26期内存持续上升,源码如何排查?源码
3.Spring Boot引起的“堆外内存泄漏”排查及经验总结
4.给你的Java程序拍个片子吧:jstack命令解析
5.What?一个 Dubbo 服务启动要两个小时!
6.面试官问:SpringBoot中@Async默认线程池导致OOM如何解决?
线程阻塞问题-log4j
Log4j:灵活的源码日志管理神器</Apache的开源之作Log4j,以其强大的源码配置能力,让我们能够精准地控制日志流向,源码无论是源码gom引擎源码控制台输出、文件记录、源码GUI组件,源码还是源码网络服务和系统日志,都能随心所欲。源码它的源码灵活性在于,只需一个配置文件,源码就能调整日志级别和格式,源码无需改动应用代码,源码大大提升了开发效率。源码
压力测试中的线程阻塞疑云</当进行压力测试时,遇到TPS不升反降的情况,尽管服务器和压力机的指标均正常,这可能暗示着线程阻塞的问题。这时,我们需要通过jstack来深入剖析,比如抓取三个进程快照:jstack进程 > 1.log、2.log、3.log,来揭示问题根源。
深入分析线程快照</在快照中,搜索关键字"BLOCKED",重点关注以"com"、"cn"、"org"开头的类,如CaseController.class。这是我们的测试焦点,它与接口调用紧密相关。反编译工具的使用有助于揭示潜在的加锁机制,即使这些锁隐藏在依赖包的内部代码中。
依赖包中的秘密</深入分析后,定位到具体代码文件和行号,这为我们找到问题的症结提供了关键线索。在日志框架的底层实现中,我们可能会发现由于框架内置的加锁机制,导致了线程阻塞。cf注入源码
解决线程阻塞:策略与选择</面对线程阻塞,我们有几种可能的应对策略:
代码层面调整</:尝试修改Log4j源码以移除潜在的锁,但这通常是不可行的,且风险较高。
日志优化</:提升日志级别,减少不必要的输出,以降低阻塞发生的概率,但这并不能从根本上解决问题。
切换日志框架</:推荐考虑升级到log4j2或logback,这些现代的日志框架往往提供了更高效的解决方案,有助于彻底解决线程阻塞问题。
总结起来,通过细致的分析和策略选择,我们能够有效地应对Log4j引发的线程阻塞问题,提升系统的性能和稳定性。
期内存持续上升,如何排查?
当内存持续上升时,定位问题并不容易,特别是在复杂的进程和业务线程中。这时,我们需要借助恰当的工具来帮助我们分析。以下是几种常用的排查内存问题的工具和方法:
首先,Linux命令行中的top命令,作为最常用的监控工具,可以实时显示进程的CPU和内存使用情况。通过top -Hp pid,可以查看特定线程的资源占用。
其次,vmstat能提供更深入的系统资源监控,包括内存和CPU使用,但主要用于观察进程的上下文切换。而pidstat则可深入到线程级别,通过其参数如pidstat -p pid -r 1 3,我们可以监测内存使用情况。
对于Java应用,JDK提供了强大的工具。例如,jstat用于实时监控堆内存和垃圾回收,而jmap则用于查看堆内存配置和详细使用情况,通过jmap -histo[:live] pid可以查看对象统计。艺术签名 源码
jstack则用于分析线程堆栈,有助于排查死锁问题。这些工具在简单场景中能快速定位问题,但在复杂场景下,可能需要结合源码分析,不断积累经验才能达到高效性能调优。
总的来说,排查内存问题并非易事,需要综合运用各种工具,不断学习和实践,才能找出问题根源。
Spring Boot引起的“堆外内存泄漏”排查及经验总结
为了更好地实现对项目的管理,我们将组内一个项目迁移到MDP框架(基于Spring Boot),随后我们就发现系统会频繁报出Swap区域使用量过高的异常。笔者被叫去帮忙查看原因,发现配置了4G堆内内存,但是实际使用的物理内存竟然高达7G,确实不正常。JVM参数配置是“-XX:MetaspaceSize=M -XX:MaxMetaspaceSize=M -XX:+AlwaysPreTouch -XX:ReservedCodeCacheSize=m -XX:InitialCodeCacheSize=m, -Xssk -Xmx4g -Xms4g,-XX:+UseG1GC -XX:G1HeapRegionSize=4M”,实际使用的物理内存如下图所示:
使用Java层面的工具定位内存区域(堆内内存、Code区域或者使用unsafe.allocateMemory和DirectByteBuffer申请的堆外内存)。
笔者在项目中添加-XX:NativeMemoryTracking=detailJVM参数重启项目,使用命令jcmd pid VM.native_memory detail查看到的内存分布如下:
发现命令显示的committed的内存小于物理内存,因为jcmd命令显示的内存包含堆内内存、Code区域、通过unsafe.allocateMemory和DirectByteBuffer申请的内存,但是不包含其他Native Code(C代码)申请的堆外内存。所以猜测是使用Native Code申请内存所导致的问题。
为了防止误判,笔者使用了pmap查看内存分布,发现大量的M的地址;而这些地址空间不在jcmd命令所给出的地址空间里面,基本上就断定就是这些M的内存所导致。
使用系统层面的工具定位堆外内存。
因为已经基本上确定是Native Code所引起,而Java层面的工具不便于排查此类问题,只能使用系统层面的工具去定位问题。
首先,使用了gperftools去定位问题。
从上图可以看出:使用malloc申请的的内存最高到3G之后就释放了,之后始终维持在M-M。c 爬虫源码笔者第一反应是:难道Native Code中没有使用malloc申请,直接使用mmap/brk申请的?(gperftools原理就使用动态链接的方式替换了操作系统默认的内存分配器(glibc)。)
然后,使用strace去追踪系统调用。
因为使用gperftools没有追踪到这些内存,于是直接使用命令“strace -f -e"brk,mmap,munmap" -p pid”追踪向OS申请内存请求,但是并没有发现有可疑内存申请。
接着,使用GDB去dump可疑内存。
因为使用strace没有追踪到可疑内存申请;于是想着看看内存中的情况。就是直接使用命令gdp -pid pid进入GDB之后,然后使用命令dump memory mem.bin startAddress endAddressdump内存,其中startAddress和endAddress可以从/proc/pid/smaps中查找。然后使用strings mem.bin查看dump的内容,如下:
从内容上来看,像是解压后的JAR包信息。读取JAR包信息应该是在项目启动的时候,那么在项目启动之后使用strace作用就不是很大了。所以应该在项目启动的时候使用strace,而不是启动完成之后。
再次,项目启动时使用strace去追踪系统调用。
项目启动使用strace追踪系统调用,发现确实申请了很多M的内存空间,截图如下:
使用该mmap申请的地址空间在pmap对应如下:
最后,使用jstack去查看对应的线程。
因为strace命令中已经显示申请内存的线程ID。直接使用命令jstack pid去查看线程栈,找到对应的线程栈(注意进制和进制转换)如下:
这里基本上就可以看出问题来了:MCC(美团统一配置中心)使用了Reflections进行扫包,底层使用了Spring Boot去加载JAR。因为解压JAR使用Inflater类,需要用到堆外内存,然后使用Btrace去追踪这个类,栈如下:
然后查看使用MCC的地方,发现没有配置扫包路径,默认是扫描所有的包。于是修改代码,配置扫包路径,发布上线后内存问题解决。
为什么堆外内存没有释放掉呢?
虽然问题已经解决了,应用app源码但是有几个疑问。带着疑问,直接看了一下 Spring Boot Loader那一块的源码。发现Spring Boot对Java JDK的InflaterInputStream进行了包装并且使用了Inflater,而Inflater本身用于解压JAR包的需要用到堆外内存。而包装之后的类ZipInflaterInputStream没有释放Inflater持有的堆外内存。于是以为找到了原因,立马向Spring Boot社区反馈了这个bug。但是反馈之后,就发现Inflater这个对象本身实现了finalize方法,在这个方法中有调用释放堆外内存的逻辑。也就是说Spring Boot依赖于GC释放堆外内存。
使用jmap查看堆内对象时,发现已经基本上没有Inflater这个对象了。于是就怀疑GC的时候,没有调用finalize。带着这样的怀疑,把Inflater进行包装在Spring Boot Loader里面替换成自己包装的Inflater,在finalize进行打点监控,结果finalize方法确实被调用了。于是又去看了Inflater对应的C代码,发现初始化的使用了malloc申请内存,end的时候也调用了free去释放内存。
此时,怀疑free的时候没有真正释放内存,便把Spring Boot包装的InflaterInputStream替换成Java JDK自带的,发现替换之后,内存问题也得以解决了。
再次看gperftools的内存分布情况,发现使用Spring Boot时,内存使用一直在增加,突然某个点内存使用下降了好多(使用量直接由3G降为M左右)。这个点应该就是GC引起的,内存应该释放了,但是在操作系统层面并没有看到内存变化,那是不是没有释放到操作系统,被内存分配器持有了呢?
继续探究,发现系统默认的内存分配器(glibc 2.版本)和使用gperftools内存地址分布差别很明显,2.5G地址使用smaps发现它是属于Native Stack。内存地址分布如下:
到此,基本上可以确定是内存分配器在捣鬼;搜索了一下glibc M,发现glibc从2.开始对每个线程引入内存池(位机器大小就是M内存),原文如下:
按照文中所说去修改MALLOC_ARENA_MAX环境变量,发现没什么效果。查看tcmalloc(gperftools使用的内存分配器)也使用了内存池方式。
为了验证是内存池搞的鬼,就简单写个不带内存池的内存分配器。使用命令gcc zjbmalloc.c -fPIC -shared -o zjbmalloc.so生成动态库,然后使用export LD_PRELOAD=zjbmalloc.so替换掉glibc的内存分配器。其中代码Demo如下:
通过在自定义分配器当中埋点可以发现实际申请的堆外内存始终在M-M之间,gperftools监控显示内存使用量也是在M-M左右。但是从操作系统角度来看进程占用的内存差别很大(这里只是监控堆外内存)。
使用不同分配器进行不同程度的扫包,占用的内存如下:
为什么自定义的malloc申请M,最终占用的物理内存在1.7G呢?因为自定义内存分配器采用的是mmap分配内存,mmap分配内存按需向上取整到整数个页,所以存在着巨大的空间浪费。通过监控发现最终申请的页面数目在k个左右,那实际上向系统申请的内存等于k * 4k(pagesize) = 2G。
为什么这个数据大于1.7G呢?因为操作系统采取的是延迟分配的方式,通过mmap向系统申请内存的时候,系统仅仅返回内存地址并没有分配真实的物理内存。只有在真正使用的时候,系统产生一个缺页中断,然后再分配实际的物理Page。
整个内存分配的流程如上图所示。MCC扫包的默认配置是扫描所有的JAR包。在扫描包的时候,Spring Boot不会主动去释放堆外内存,导致在扫描阶段,堆外内存占用量一直持续飙升。当发生GC的时候,Spring Boot依赖于finalize机制去释放了堆外内存;但是glibc为了性能考虑,并没有真正把内存归返到操作系统,而是留下来放入内存池了,导致应用层以为发生了“内存泄漏”。所以修改MCC的配置路径为特定的JAR包,问题解决。在发表这篇文章时,发现Spring Boot的最新版本(2.0.5.RELEASE)已经做了修改,在ZipInflaterInputStream主动释放了堆外内存不再依赖GC;所以Spring Boot升级到最新版本,这个问题也可以得到解决。
给你的Java程序拍个片子吧:jstack命令解析
当Java程序陷入长时间停滞,可能是健康状况堪忧,此时我们需要借助jstack进行诊断。jstack是Java虚拟机自带的堆栈跟踪工具,用于解析特定Java进程ID或core文件中的线程信息。 使用jstack的基本命令格式如下,最常见的用法就是通过指定进程ID获取堆栈信息:选项说明:
理解线程状态是分析的前提,Java的线程状态分为六种,但在jstack中,我们关注的通常是运行中的三种状态。jstack用于生成线程快照,有助于我们分析线程阻塞和同步问题。 在多线程环境中,Java的监视锁(Monitor)是关键。理解Synchronized和Monitor的关系有助于深入分析,如需了解更多,可以查阅《Synchronized解析——如果你愿意一层一层剥开我的心》。 实战中,我们先来看两个案例:一是死锁问题的排查。死锁是多个线程相互等待,无法继续执行。通过jstack分析,我们可以找到死锁的线索,比如源码中的线程阻塞情况。接着,通过jps获取进程ID,使用jstack -l查看堆栈信息,揭示死锁真相。 第二个案例是CPU过高问题。通过top命令找到高占用CPU的java进程,进一步用jstack查看线程堆栈,找到占用资源最多的线程。然后,分析堆栈信息,查找可能的死循环或耗时操作。 在实际操作中,我们通常会将这些信息记录到文件中,便于后续深入分析,甚至对比不同时间点的堆栈信息,以获取更准确的诊断结果。 最后,对于jstack命令的使用,务必记住关键步骤,如定位进程、查看堆栈和记录信息,这将有助于我们更好地理解和解决Java程序的各种问题。What?一个 Dubbo 服务启动要两个小时!
前言
在测试环境中,遇到了 Dubbo 服务启动异常的难题。现象显示,应用在初次启动时异常缓慢,需要耗时约两个小时才能正常运行。测试人员尝试排查数据库、Zookeeper 等连接问题,但并未找到原因。最终,通过 jstack 工具获取线程快照发现,主线程卡在了 Dubbo 服务配置中的某个方法中,具体为 ServiceConfig.java 的 行代码。
深入分析
根据源码分析,问题根源在于主线程试图获取本机 IP 并将其注册至 Zookeeper,以便用于服务调用。在执行 Inet4AddressImpl.getLocalHostName 方法时,发现这是一个 native 方法,且调用耗时异常长。经过测试,发现本地主机名与 IP 的交互过程存在卡顿现象,且与 DNS 服务器交互速度明显较慢。
解决策略
分析问题后,考虑到这是一个 native 方法,与应用主体逻辑无关,进一步探究问题是否源于服务器配置。通过 ping 服务器的主机名与 IP,发现主机名的获取过程存在延迟,导致整个系统启动缓慢。为了解决问题,尝试在 /etc/hosts 配置文件中添加了主机名与 IP 的映射,使得直接 ping 主机名能够快速响应,从而解决了 Dubbo 服务启动缓慢的问题。
总结与反思
解决本次问题后,我们总结了以下几个关键点:首先,DNS 服务器的交互速度对应用启动时间有显著影响,应关注其响应速度。其次,Dubbo 在依赖外部资源获取时,应提高其健壮性,例如在长时间未成功获取资源时,可以抛出异常或提供更明确的错误提示,协助开发者快速定位问题。通过此次经历,我们意识到优化 DNS 配置与提升外部依赖处理逻辑的效率对于提高系统稳定性至关重要。
面试官问:SpringBoot中@Async默认线程池导致OOM如何解决?
面临问题
在进行项目测试时,我们遇到了内存溢出(OOM)问题,具体日志显示为“unable to create new native thread”。该项目使用SpringBoot架构,我们通过Jstack工具分析,发现大量线程处于可运行状态,表明线程创建量过大。
问题解析
内存溢出主要有三种类型:第一,PermGen space,通常因程序中加载大量JAR或Class文件引起;第二,Java heap space,由程序创建对象过多导致;第三,无法创建新本地线程,这可能因创建线程数量过多,导致内存消耗过大。
初步分析
根据日志分析,我们怀疑是线程创建过多导致的问题。通过将应用线程信息打印到文件,发现大量线程处于可运行状态,这进一步确认了线程创建过多的假设。
代码探究
问题出在日志写库服务的`writeLog`方法上,该方法使用了`@Async`注解,实现异步写入逻辑。但服务并未自定义异步配置,而是使用了Spring默认的`SimpleAsyncTaskExecutor`线程池,该配置默认为每个任务创建一个新线程,这在高并发压测环境下,可能导致线程数量激增,从而导致内存溢出。
深入了解
`SimpleAsyncTaskExecutor`线程池具备限流机制,通过`concurrencyLimit`属性控制。默认情况下,此属性值为-1,即不开启限流,导致在高并发情况下持续创建线程。源码分析揭示了限流机制实现,即当线程数超过`concurrencyLimit`时,当前线程会进入等待状态,直至线程数减至允许范围。
实践验证
我们通过模拟测试验证了此机制。在未开启限流的情况下,启动个线程调用异步方法,使用Java VisualVM监控工具观察到线程数迅速增长,直至达到系统限制。开启限流后,线程数得到了有效控制,但这也引入了执行效率的降低,出现了主线程等待和线程竞争的情况。这种限流机制适用于任务处理速度较快的场景,对于处理时间较长的应用并不适用。
最终解决方案
为解决线程创建过多导致的内存溢出问题,我们采取了以下策略:
1. 自定义线程池,利用`LinkedBlockingQueue`阻塞队列限制线程池的最大线程数。
2. 定义拒绝策略,当任务队列满时,拒绝处理新任务并记录日志。
通过这些改进,我们成功解决了内存溢出问题,同时确保了应用的稳定性和响应效率。