Java thread dump 里面的 re-lock 行
网上有些web工具, 可以分析 Java thread dump, 通常是根据栈的情况作出火焰图, 指出死锁, 根据线程优先级, 线程组的名字做分类. 我在公司内部也做了一个这么一个工具. 基本思路是通过正则表达式匹配各种行, 然后重新组装成栈的模型. 然后做分析报告.
最近 2 天有人抱怨说, 我写的这个工具在分析他们的 thread dump 的时候, 总是报 5xx 内部错误. 于是, 根据提供的 thread dump 去分析原因. 原来这个工具在分析下面一个线程栈的时候, 出错了:
"Finalizer" #3 daemon prio=8 os_prio=0 cpu=4.41ms elapsed=1059.54s tid=0x00007f072ce76000 nid=0x151d in Object.wait() [0x00007f0704976000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(java.base@11.0.11/Native Method)
- waiting on <0x00000006c0001478> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.11/ReferenceQueue.java:155)
- waiting to re-lock in wait() <0x00000006c0001478> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@11.0.11/ReferenceQueue.java:176)
at java.lang.ref.Finalizer$FinalizerThread.run(java.base@11.0.11/Finalizer.java:170)
Locked ownable synchronizers:
- None具体的出错在识别下面这行的处理中:
- waiting to re-lock in wait() <0x00000006c0001478> (a java.lang.ref.ReferenceQueue$Lock)为什么处理这行会出错呢?
根据这个栈的信息, 我们可以看到, 栈顶说正在等待这个锁: 0x00000006c0001478, 而下面一行又说 在 wait 里面要 relock 这个锁. 并且是在 remove 方法里面. 这里到底发生了什么事情呢?
重新认识一下最基础的 java.lang.Object 的 wait(), wait(timeout), notify(), notifyAll() 方法
wait 方法表示当前线程主动让出 cpu, 等待其它线程通过 notify()/notifyAll() 方法唤醒, 或者被 inerrupt 唤醒, 或者设置 timeout等着超时唤醒
notify/notifyAll 方法告诉之前让出 CPU 进入 wait 的线程, 你可以醒了.
那么 wait 和 notify 机制的载体是什么呢? 就是 wait 方法和 notify 方法所在的实体对象(object/instance). 更具体一点就是这个实体对象的锁(Monitor).
所以要调用一个实体对象的 wait 方法, 你必须先获得这个实现对象的锁, 否则虽然编译通过, 运行时也会报错. 比如:
try {
lockObj.wait();
} catch (InterruptedException e) {
e.printStackTrace();
}运行时出错:
Exception in thread "main" java.lang.IllegalMonitorStateException
at java.base/java.lang.Object.wait(Native Method)
at java.base/java.lang.Object.wait(Object.java:328)正确的做法是这样:
synchronized (lock) {//获得锁, 如果不能获得, 进入等待队列
try {
lock.wait();//释放锁, 进入 sleep 队列, 被 notify 之后, 重新尝试去获得锁
} catch (InterruptedException e) {
e.printStackTrace();
}
}必须在另外一个线程 notify 上面的等待线程, 否则上面的线程将死等在这. 除非设置timeout 或者被 interrupt. 唤醒代码(这里的 lock 对象就是上面的同一个 lock 对象):
lock.notify(); // 或者 lock.notifyAll()关于这里的 2 个队列
这里涉及 2 个队列: 1) 该锁对象的等待队列(wait queue); 2) 该锁对象的睡眠队列 (sleep queue);
当一个线程尝试获得某个锁, 而不能获得的时候, 就会进入一个这个锁的等待队列(逻辑上,实际代码实现不一定是队列). 每当等待队列里面的线程获得 CPU 时间片的时候, 它就尝试再去获得一次, 直到获得锁.
当一个线程执行 wait 方法的时候, 它肯定已经获得了这个锁. 虽然获得了这个锁, 可能业务上某个其它条件不满足, 必须等在这里, 而又不能阻碍其它线程获得之前这个锁, 所以, 它进入 wait 方法之后的第一件事就是释放之前已经获得这个锁, 同时当前线程进入一个逻辑上的这个锁的睡眠队列(sleep)队列, 之后这个线程不会被分配 CPU 时间, 直到有 1)有其他线程调用这个锁的 notify/notifyAll 方法, 唤醒它 2) 被 interrupt, 3) 设置了 timeout, 到了超时时间. 当这个线程被唤醒之后, 它首先尝试去获得之前释放的锁, 如果立马获得, 则退出 wait 方法, 继续执行. 否则进入这个锁的等待队列, 在里面排队, 直到再次获得这个锁, 然后从 wait 方法退出, 继续执行.
关于重新获得锁 re-lock
根据上面的描述, 当一个线程被唤醒(notify/notifyAll, 被 interrupt, 或 timeout 到), 它要再次获得这个锁. 所以在这个JDK 的 task (https://bugs.openjdk.java.net/browse/JDK-8130448) 当中, 有人就想把第一次想获得这个锁和进入 wait 方法之后再次获得锁的这 2 种情况区分开来, 于是在 thread dump 中, 就有了 re-lock 这行.
为什么我们遇到的栈里面的 re-lock 不对?
我们可以找出我们看到的情况的源代码(java.lang.ref.ReferenceQueue.remove(long)方法):
public Reference<? extends T> remove(long timeout)
throws IllegalArgumentException, InterruptedException
{
if (timeout < 0) {
throw new IllegalArgumentException("Negative timeout value");
}
synchronized (lock) {
Reference<? extends T> r = reallyPoll();
if (r != null) return r;
long start = (timeout == 0) ? 0 : System.nanoTime();
for (;;) {
lock.wait(timeout);
r = reallyPoll();
if (r != null) return r;
if (timeout != 0) {
long end = System.nanoTime();
timeout -= (end - start) / 1000_000;
if (timeout <= 0) return null;
start = end;
}
}
}
}从上面的代码可以看出, 该线程已经在 synchronized (lock) { 这行获得了锁, 可是我们从 thread dump 里面读出的是: "waiting to re-lock in wait", 这明显是与事实不符的. 这行应该是获得了锁, 虽然之后释放了.
同时从 lock.wait(timeout) 这行, 我们可以知道, 等到 timeout 或者被唤醒, 这个线程应该要重新获得锁, 所以这里标记为 re-lock 比较合适.
根据这个逻辑, 我们确实找到了有人早就上报了这个问题, 并且已经修复: https://bugs.openjdk.java.net/browse/JDK-8150689. 不过从这个 bug 给出的信息看, 这个 bug 由于是低优先级, 要到 JDK 12 里面才有 fix. 所以我们公司大部分 JVM 都无法有这个修复.