简介
上次解决了GC长耗时问题后，系统果然平稳了许多，这是之前的文章《GC耗时高，原因竟是服务流量小？》
然而，过了一段时间，我检查GC日志时，又发现了一个GC问题，如下：
从这个图中可以发现，我们GC有一些尖峰，有时会突然有大量的内存分配。
$ grep 'concurrent humongous allocation' gc.log | awk 'match($0,/allocation request: (\w+ bytes/,a{print a[1]}' |sort -nr
1941835784
1889656848
可以看到，一次大对象分配，分配大小竟然有1.9G，这谁能抗得住啊！
async-profiler定位大对象分配
./profiler.sh start --all-user -e G1CollectedHeap::humongous_obj_allocate -f ./humongous.jfr jps
然后使用jmc打开humongous.jfr文件，调用栈如下：
TCompactProtocol.readDouble方法，方法代码如下：
可是，这里只创建了8字节的数组，怎么也不可能需要分配1.9G内存吧，真是奇了怪了！
问题链接：https://bugs.openjdk.org/browse/JDK-8178287
寻找其它tracer
在用户态上，基于ptrace系统调用实现的有strace、ltrace，我试了一下它们，并无法直接跟踪G1中的大对象分配函数G1CollectedHeap::humongous_obj_allocate。
编写gdb脚本
经过一番学习与探索(PS：其实花了我快2周😂，我终于编写出了实际可用的gdb脚本，如下：
handle all nostop noprint pass
handle SIGINT stop print nopass
break *(_ZN15G1CollectedHeap22humongous_obj_allocateEmh + 0x58c06f - 0x58c060
while 1
continue
# 如果是Ctrl+c，则退出
if $_siginfo
if $_siginfo.si_signo == 2
detach
quit
end
end
printf "word_size is %d\n",$rsi
if $rsi > 100*1024*1024/8
# 打印当前时间
shell date +%FT%T
# 打印当前线程
thread
# 打印当前调用栈
bt
python import subprocess
# 向jvm发送kill -3信号，即SIGQUIT信号
python proc = subprocess.Popen(['kill','-3',str(gdb.selected_inferior(.pid], stdout=subprocess.PIPE, stderr=subprocess.PIPE, bufsize=1, universal_newlines=True
python stdout, stderr = proc.communicate(
python print(stdout
python print(stderr
detach
quit
end
end
没学过gdb的同学可能看不明白，没关系，我们慢慢来。
handle all nostop noprint pass
handle SIGINT stop print nopass
这2句handle是处理Linux信号用的，由于我们并不需要调试信号问题，所以让gdb都不处理信号，保留SIGINT是为了按Ctrl+c时能退出gdb脚本。
break *(_ZN15G1CollectedHeap22humongous_obj_allocateEmh + 0x58c06f - 0x58c060
这个break是给G1中的大对象分配函数G1CollectedHeap::humongous_obj_allocate设置断点，方法源码如下：
word_size参数表示分配多少字的内存，而在64位机器上，1字等于8字节，所以如果能追踪到这个参数值，就能知道每次分配大对象的大小了。
_ZN15G1CollectedHeap22humongous_obj_allocateEmh，通过nm查询二进制文件的符号表，可以获取这个名称。
$ which java
/usr/local/jdk/jdk1.8.0_202/bin/java
# jvm相关实现，都在libjvm.so动态库中
$ find /usr/local/jdk/jdk1.8.0_202 | grep libjvm.so
/usr/local/jdk/jdk1.8.0_202/jre/lib/amd64/server/libjvm.so
$ nm /usr/local/jdk/jdk1.8.0_202/jre/lib/amd64/server/libjvm.so |grep humongous_obj_allocate
000000000058c060 t _ZN15G1CollectedHeap22humongous_obj_allocateEmh
000000000058b1a0 t _ZN15G1CollectedHeap41humongous_obj_allocate_initialize_regionsEjjmh
再看回之前设置断点的脚本代码：
break *(_ZN15G1CollectedHeap22humongous_obj_allocateEmh + 0x58c06f - 0x58c060
+ 0x58c06f - 0x58c060这个是在做地址偏移操作，了解过汇编的同学应该清楚，调用函数后，函数开头的一些汇编指令，一般是参数寄存器的相关操作，x86参数寄存器如下：rdi 表示第一个参数 rsi 表示第二个参数 rdx 表示第三个参数 rcx 表示第四个参数 r8 表示第五个参数 r9 表示第六个参数可以使用objdump反汇编libjvm.so，看看汇编代码，以确定断点该偏移到哪一行指令上，看官们坚持住，汇编相关内容就下面一点😁
$ objdump -d /usr/local/jdk/jdk1.8.0_202/jre/lib/amd64/server/libjvm.so |less -S然后在less里面搜索
_ZN15G1CollectedHeap22humongous_obj_allocateEmh函数，如下：
之所以要加偏移量，是因为在+ 0x58c06f - 0x58c060这个位置后，rsi寄存器(第二个参数才会有值，之所以获取每二个参数的值，是因为C++对象编程中，第一个参数是this。首先是循环，然后continue表示让程序运行起来，当程序命中断点后，continue才会执行完。
中间是信号处理，主要是为了能Ctrl+c退出循环。
最后通过print将rsi的值打印出来，这样就追踪到了word_size参数的值。当分配内存大于100M时，打印当前时间、当前线程与当前调用栈。
因为Java是解释执行的，java部分的调用栈bt是获取不到的。
对java比较熟悉的同学应该知道，jvm有一个隐藏的诊断功能，如果给jvm进程发SIGQUIT信号，jvm会在标准输出中打印线程栈信息，而SIGQUIT信号可以通过
kill -3发送，因此就有了下面的代码：
gdb真是强大，内嵌了python扩展，而通过python的subprocess包，就可以执行kill -3命令了。detach与
quit，用于退出gdb的，不用深究。运行gdb脚本追踪大对象
$ gdb -q --batch -x trace.gdb -p `pgrep java`其中
pgrep java用于获取java进程的进程号。运行后，追踪到的参数与线程信息如下：
其中LWP后面的166就是线程号，转成十六进制就是0xa6。
然后到java进程的标准输出日志中，去找这个线程的Java调用栈，如下：妈呀，它创建了一个超大的byte数组，难怪会出现1.9G的大对象分配呢！
TProtocolFactory factory = new TCompactProtocol.Factory(; TDeserializer deserializer = new TDeserializer(factory; deserializer.deserialize(deserializeObj, sourceBytes;这是在做thrift反序列化，将sourceBytes字节数组反序列化到deserializeObj对象中。
而当sourceBytes不是由deserializeObj对象序列化出来时，反序列化代码从sourceBytes中解析出字段长度时(length，可能是任意值，进而导致可能创建超大的字节数组。
简单查看了一会thrift代码，发现可以限制字段的最大长度，如下：
想一想，反序列的某个字段的长度，肯定不会有整个反序列化的数据长呀，因此使用sourceBytes.length来限制即可。TProtocolFactory factory = new TCompactProtocol.Factory(sourceBytes.length, sourceBytes.length; TDeserializer deserializer = new TDeserializer(factory; deserializer.deserialize(deserializeObj, sourceBytes;限制了后，若字段超长了会抛异常，所以若反序列化异常了，说明当前sourceBytes不是由deserializeObj序列化出来。
总结
好在最后成功了，并让我又Get到了一种新的问题解决路径，还是非常值得的😁