一、背景
某日晚,需要协助女朋友排查一个线上问题,其请求调用比较复杂,单次请求过来会多次通过不同路径调用存在问题的方法,并且还有很多重载的方法,排查过程中需要结合stack和各种条件判断,极其麻烦;期间也遇到了 Arthas中使用watch观测方法执行前后,基本类型参数的值不一致的问题。
此问题的结论和原因虽然都比较简单,但其排查过程也可供学习记录。
只想看结论的同学也可以直接看 第四点 !
1.代码
由于真实情况涉及公司业务,而且有很多无关紧要的逻辑,所以写了个超级简化版。
package com.company;
import java.util.concurrent.ConcurrentHashMap;
public class TmpTest {
public static void main(String[] args) throws InterruptedException {
for (int i = 0; i < 1000; i++) {
//睡眠10s,一是避免程序退出,二是可以持续观测
Thread.sleep(10*1000);
//这里使用了两个请求意在贴近实际场景,使用Arthas时,能够筛选出自己想要观测的请求是一个非常重要的能力
//第一个请求进入,该请求是我们想要观测的请求,该flow1是固定或者可控的
int flow1 = 1234;
new Thread(new Runnable() {
@Override
public void run() {
runRequest(flow1);
}
}).start();
//第二个请求进入,该请求是其他用户发起的请求,是干扰项
int flow2 = 6789;
new Thread(new Runnable() {
@Override
public void run() {
runRequest(flow2);
}
}).start();
}
}
/**
* 假设该方法为请求的处理方法
*/
private static void runRequest(int flow){
//设置流水
setFlow(flow);
//判断是否支持 https
boolean supportHttps = condition1() && condition2() == 2 && "https".equals(condition3());
//获取前缀,getPrefix的参数是我们的观测目标,看它是true还是false
String prefix = getPrefix(supportHttps);
//输出前缀
System.out.println(prefix);
}
private static String getPrefix(boolean supportHttps) {
supportHttps = subCondition();
return supportHttps ? "https" : "http";
}
private static boolean condition1() {
//复杂逻辑
return true;
}
public static int condition2() {
//复杂逻辑
return 2;
}
public static String condition3() {
//复杂逻辑
return "https";
}
private static boolean subCondition() {
//复杂逻辑
return false;
}
/**
* 存储线程流水映射
*/
private static final ConcurrentHashMap<Long,Integer> flowMap = new ConcurrentHashMap<>(10);
/**
* 根据当前线程id获取流水
* @return flow 流水值
*/
private static int getFlow(){
return flowMap.getOrDefault(Thread.currentThread().getId(),0);
}
/**
* 为当前线程id设置流水值
* @param flow 流水值
*/
private static void setFlow(int flow){
flowMap.put(Thread.currentThread().getId(),flow);
}
}
2.观测的目标
getPrefix(boolean supportHttps)
方法被调用时,supportHttps
的值,到底是true还是false呢?
二、观测&排查流程
1.直接watch观测 getPrefix()
方法,拿到参数值
如上图,我们拿到了 getPrefix()
方法的入参值supportHttps
,是 false 来的!
tips:通过静态方法拿到当前线程的flow并作为筛选条件
@com.company.TmpTest@getFlow()==1234
企业实践中,一般会将一些请求相关的信息放到可静态调用获取的地方,这就是筛选请求的重要利器
2.业务及逻辑分析与观测结果不符
boolean supportHttps = condition1() && condition2() == 2 && "https".equals(condition3());
当我们从实际的业务和逻辑分析(代码没有呈现)看的时候,我们认为上面的表达值的值应该是 true 才对,为何观测到是false呢???是业务和逻辑分析错了吗?
到底是哪里出了问题呢?为了找到答案,我们需要再进一步的分析!
3.直接获取supportHttps
变量的值?不可
getPrefix()
方法的入参值其实就是 supportHttps
变量,我们只要获取到该变量的值就能确定逻辑分析推断是否有问题了!
但是,supportHttps
是方法内的临时变量,因此我们无法通过Arthas直接获取到它的值。
相信对很多入门Arthas的人来说,都会这样的疑问:Arthas可以获取到方法内的临时变量吗?
答案:可以,但又不完全可以!
分析:既然不能直接观测,我们一般可以通过观测使用到该临时变量的方法来间接观测它的值,就像第1点做的那样,只是本次我们对这个值有所怀疑。另外,一般定义变量,都是为了接收方法的返回值,或者是作为方法的参数,因此,这部分的变量值还是有机会拿到滴!
4.侧面求证,利用好短路机制
boolean supportHttps = condition1() && condition2() == 2 && "https".equals(condition3());
从上边的代码看,supportHttps
变量就是通过表达式求出来的,因此我们可以观测表达式的执行情况呀!
分析:由于3个 condition方法 是通过 &&
串起来的,又由于java中是有短路机制的,因此可以判定 condition1()==true
和 condition2()==true
,因为只有这样才会执行 condition3()
;
5.condition3()
返回了啥?是它导致了 supportHttps
为false吗?
验证这个也非常简单,直接watch一下即可! 可以看到,condition3()
的返回值是 https,由此 "https".equals("https") == true
6.出现了!出现了!矛盾的 supportHttps
通过上边的排查, 我们知道表达式 condition1() && condition2() == 2 && "https".equals(condition3())
的值是true,那么 supportHttps
应该就是 true 才对啊!!为什么在 getPrefix()
方法的参数观测的时候,它是false来的呢???
难道Arthas有什么隐藏的Bug?
7.重新审视 watch 的使用
我们都知道,watch是可以指定观测的时间点的,方法执行前和方法执行后的参数是有可能不一致的,但是这种不一致的情况一般是指对象类型中的内容被修改了。而我们观测 getPrefix()
方法时,虽然观测的是方法执行之后参数值,但是,按理说,getPrefix()
方法的入参是一个 boolean 类型啊,它不是对象类型,即使方法执行过程中有对参数进行重新赋值,但方法结束后它的值也不应该会变啊?
private static String getPrefix(boolean supportHttps) {
//改变了supportHttps的值
supportHttps = subCondition();
return supportHttps ? "https" : "http";
}
8.没办法了,试一下吧,反正也没什么损失
本来在排查过程中,女朋友也提出了会不会是因为在方法执行后观测,所以看到的结果为false,但是我第一反应就是这不可能,值传递和地址传递我可熟了,值传递在方法执行完之后怎么会变呢!!所以排查重点还是放在方法定位(多次调用和有重载)和condition的确认上,顺手还给她讲了一下地址传递的例子,对象啊,JsonObj啊啥的才会变。
一直到最后(晚上12点多了),当时实在没有办法了,想着只能第二天开新实例开debug导流量了,最后抱着试一试的心态对watch加了-b参数,卧槽!!!还真是true,纳尼??卧槽?什么东西?三、引出问题
问题:使用watch来观测方法参数(boolean类型),在方法中对该参数进行重新赋值的时候,执行前观测和执行后观测的参数结果不一致!
四、求证
1.毋庸置疑的值传递
参数是 boolean 是值传递,这肯定是没错的。上图可见,执行完方法后,supportHttps的值是true。所以问题一定是出在Arthas观测的使用上。
2.Arthas中watch命令的实现
想要找到答案,那就必须了解arthas对watch命令的实现了,好在arthas提供了jad命令,并且允许逆编译增强过的类,让我们可以很方便地看到增强的情况。
被观测的方法(getPrefix()
)逆编译结果:
方法被调用时外层方法(runRequest()
)逆编译结果:
3.恍然大明白
对 方法结束之后 进行信息收集的两种做法:
a.方法内部收集代码示例
private static void runRequest(int flow){
...
/************************* 调用处不做处理 ***************************/
String prefix = getPrefix(supportHttps);
}
private static String getPrefix(boolean supportHttps) {
/************************* 方法内部收集参数信息 ***************************/
try {
//改变了supportHttps的值
supportHttps = subCondition();
return supportHttps ? "https" : "http";
}finally {
//方法内记录,其值会以方法内最后值为准,也就是方法内对该值进行变更会影响到记录的值
recordParams(supportHttps);
}
}
b.调用处收集代码示例
private static void runRequest(int flow){
...
/************************* 调用处收集参数信息 ***************************/
try{
String prefix = getPrefix(supportHttps);
}finally {
//调用处记录,此时 supportHttps 是值传递,因此方法内部值改变不会影响到此处记录的值
recordParams(supportHttps);
}
}
private static String getPrefix(boolean supportHttps) {
/************************* 方法内部不做处理 ***************************/
//改变了supportHttps的值
supportHttps = subCondition();
return supportHttps ? "https" : "http";
}
结果显而易见,在 方法结束之后 收集参数值的两种方法中,采用 方法内部收集 的时候,拿到的是方法内更改过的值,这也是Arthas采用的方式。
五、写在最后
当我们看到 方法结束之后的参数值的变化 时,很自然而然地想起考试和面试都出现较多的 值传递和地址传递 问题 ,也会很理所当然地认为,这个参数是不会变的;但是我们忽略了Arthas是怎么实现这个功能的,它的原理大致如何,进而导致一些误解的出现。
作者:wingli
链接:https://juejin.cn/post/7024408089302433822