JAVA 变量的作用域真的是代码块吗?原创
近期,笔者在生产环境中发现了一个问题,客户在上传文件的时候使用SDK上传,程序在线上稳定跑了一天半,通过一个定时任务不停的上传文件,但是某个时刻后,所有的上传请求都开始报错,报错内容则是上传的流被关闭了。笔者首先对服务端的日志,监控等数据进行排查,排除了服务端关闭流的可能性,然后开始对客户的代码和SDK进行分析,通过逐步排查,发现SDK中重写了一个类的finalize方法,在finalize方法中存在关流的操作。
直觉上判断,问题可能出现在这个finalize方法中,但是我们都知道,finalize方法只有在对象不可达,即将被回收前才会执行,而这个类在客户的代码中仍然是可达的,其所在的代码块并未执行完,就触发了finalize方法。
如果真的是finalize方法,那岂不是说明变量引用的对象在其代码块中都是危险的,有被回收的风险?
排查到这里,笔者发现,这个问题似乎并没有那么简单,将同样的代码和环境变量拿到测试环境进行验证,但始终无法复现问题。测试环境一切都正常,而产线仍然在不停的报错上传失败。
既然在测试环境无法复现,就不能轻易下结论,笔者又仔细复盘了下问题的现象,发现有一点被忽略了,客户的程序在线上稳定跑了一天半都没有出现问题,是否是因为在测试环境跑的案例量不够大,又或者是测试环境的并发量不够大导致无法复现,之后再测试环境增加了更多的测试数据进行测试,但仍然无法复现。
那会不会是跑的不够久?还真有这个可能,因为笔者之前在对JVM源码分析的时候接触到了一些关于JIT即时编译的知识,于是就大胆猜想,会不会是同样的代码,跑的次数达到了JIT即时编译的阈值,其对代码进行了编译优化,导致对象被回收,执行了finalize方法,提前关闭了流。
为了更直观的看问题,笔者准备了一段伪代码模拟客户的代码:
Test类:
public class Test { public static void main(String[] args) { test(); } //模拟客户的调用方法 public static void test() { //创建一个finalize类 FinalizeTest finalizeTest = new FinalizeTest(); try { //在同一个代码块中执行循环,但不使用finalize引用 int i = 0; do { i++; //手动执行gc,观察是否触发finalize方法 System.gc(); }while (i < 1000); }catch (Exception e) { System.out.println("exception"); }finally { System.out.println("finally"); } } }
FinalizeTest类:
public class FinalizeTest { String name; public FinalizeTest() {} public FinalizeTest(String name) { this.name = name; } //重写finalize方法 @Override protected void finalize() throws Throwable { System.out.println("finalize function run"); } }
正常情况下执行这段代码,发现永远不输出“finalize function run”,但是当笔者在JVM参数中添加以下三个参数,让JVM完全使用JIT的编译模式:
-Xcomp 直接将代码翻译成机器码,使用编译模式
-XX:TieredStopAtLevel=1 仅使用JIT C1编译
-XX:CompileThreshold=1 即时编译阈值设置为1
神奇的事情发生了,每次执行,都会在代码块执行完之前,输出“finalize function run”。有兴趣的读者可以用代码自己执行下。
现在基本可以确定同样的一段代码,JVM使用编译模式,编译出的机器码和JVM使用解释模式编译出的字节码执行的结果不一样。可以确定确实是JIT进行编译的时候会对代码进行优化,导致提前执行finalize方法了。
这个发现有点颠覆了大家以前的认知,局部变量的声明周期是代码块,这是我们一般的常识,事实上,使用字节码进行解释编译的执行结果确实也是这样的。但是为什么使用JIT即时编译产生的结果就不一样了呢?
为了探究问题的本质,笔者继续进行分析,在JVM参数中又添加了两个参数:
-XX:+UnlockDiagnosticVMOptions
-XX:+PrintAssembly
这两个参数可以打印出JVM的编译信息,我们借助hsdis插件(官方的反汇编插件,有兴趣的读者可以自行搜索)将编译好的汇编命令打印出来,然后使用JITWatch进行分析(由于汇编命令比较多,笔者仅挑出部分重要的):
//test方法编译结果
# {method} {0x00000159c8be04d8} 'test' '()V' in 'Test'
# [sp+0x50] (sp of caller)
[Entry Point]
0x00000159b4ceed40: mov %eax,-0x6000(%rsp)
//入栈
0x00000159b4ceed47: push %rbp
0x00000159b4ceed48: sub $0x40,%rsp
0x00000159b4ceed4c: nopl 0x0(%rax)
L0000: jmpq L000f ; {no_reloc}
0x00000159b4ceed55: add %al,(%rax)
0x00000159b4ceed57: add %al,(%rax)
0x00000159b4ceed59: add %ch,%cl
0x00000159b4ceed5b: nop
0x00000159b4ceed5c: add %eax,(%rax)
//执行new关键字
0x00000159b4ceed5e: add %cl,-0x75(%rax) ;*new ; - Test::test@0 (line 8)
0x00000159b4ceed61: rorb -0x77(%rax) ;*invokespecial <init>
; - Test::test@4 (line 8)
0x00000159b4ceed64: rex
//可以理解为调用Finalize的初始化方法
//注意这里的OopMap,其中有一个变量位于偏移量32处——指向一个对象
0x00000159b4ceed67: callq 0x00000159b4b261a0 ; OopMap{[32]=Oop off=44}
;*invokespecial <init>
; - Test::test@4 (line 8)
; {optimized virtual_call}
0x00000159b4ceed6c: mov $0x0,%esi ;*iinc
; - Test::test@10 (line 12)
0x00000159b4ceed71: nopl 0x0(%rax)
L0002: inc %esi
0x00000159b4ceed7a: mov %esi,0x28(%rsp)
0x00000159b4ceed7e: nop
//调用静态方法gc(),此时OopMap中的变量没有了
0x00000159b4ceed7f: callq 0x00000159b4b26620 ; OopMap{off=68}
;*invokestatic gc
; - Test::test@13 (line 13)
; {static_call}
0x00000159b4ceed84: nop ; OopMap{off=69}
;*if_icmplt
; - Test::test@20 (line 14)
0x00000159b4ceed85: test %eax,-0x1fbec8b(%rip) # 0x00000159b2d30100
; {poll} *** SAFEPOINT POLL ***
0x00000159b4ceed8b: mov 0x28(%rsp),%esi
0x00000159b4ceed8f: cmp $0x3e8,%esi
0x00000159b4ceed95: jl L0002 ;*if_icmplt
; - Test::test@20 (line 14)
0x00000159b4ceed97: nop
L0003: jmpq L0010 ; {no_reloc}
0x00000159b4ceed9d: add %al,(%rax)
0x00000159b4ceed9f: add %al,(%rax)
0x00000159b4ceeda1: add %ah,0xf(%rsi)
0x00000159b4ceeda4: (bad)
0x00000159b4ceeda5: add %r8b,(%rax)
L0005: jmpq L0011 ; implicit exception: dispatches to 0x00000159b4ceef63
0x00000159b4ceedad: nop
0x00000159b4ceedae: nop ;*getstatic out
; - Test::test@23 (line 18)
0x00000159b4ceedaf: cmp (%rdx),%rax ; implicit exception: dispatches to 0x00000159b4ceef7e
0x00000159b4ceedb2: movabs $0xd63a78f0,%r8 ;*invokevirtual println
; - Test::test@28 (line 18)
; {oop("finally")}
0x00000159b4ceedbc: nop
0x00000159b4ceedbd: movabs $0xffffffffffffffff,%rax
0x00000159b4ceedc7: callq 0x00000159b4b263e0 ; OopMap{off=140}
;*invokevirtual println
; - Test::test@28 (line 18)
; {virtual_call}
0x00000159b4ceedcc: add $0x40,%rsp
//出栈
0x00000159b4ceedd0: pop %rbp
0x00000159b4ceedd1: test %eax,-0x1fbecd7(%rip) # 0x00000159b2d30100
; {poll_return} *** SAFEPOINT POLL ***
代码比较多,我们重点看下OopMap,OopMap的含义为:
被JIT编译过的方法会在一些地方记录下OopMap,记录了执行到该方法的某条指令的时候,栈上和寄存器里哪些位置是引用。这样GC在扫描栈的时候就会查询这些OopMap就知道哪里是引用了。
我们可以看到,在new完finalize之后 OopMap中是有一个引用指向对象的,而在执行到手动GC方法时,OopMap中的引用没有了,所以我们可以得出结论,JIT使用C1进行即时编译时,会对代码进行优化,如果引用在后面没有使用,则可能不被记录在OopMap映射表中,从而被GC回收。
至此,这个问题算是告一段落了,笔者使用客户的代码在测试环境使用C1编译执行了几遍后,就复现了相同的报错,再结合实际产线上的问题,我们也可以解释原因了,一开始的一天半,JVM使用的是解释模式,使用字节码执行相关的方法,但是因为是定时任务执行相同的代码块,当执行到一定次数达到即时编译的阈值后,就会触发即时编译,现在来看应该是触发了C1的编译方式,导致代码被优化,被引用对象的生命周期改变,JVM本意是希望更精细化管理对象,但是由于有人重写了finalize方法,导致了问题的发生。
看来有时候我们对于JVM的一些特性不了解,可能就会导致代码产生一些不可估量的结果与问题,所以学习JVM的一些特性和知识还是很有必要的。