记录工作以来遇到的最离谱的一个 Bug

发布于:2024-05-06 ⋅ 阅读:(43) ⋅ 点赞:(0)

零、故事的开始从一次 Kafka 的消费者说起

public void handleMessage() {        Properties properties = new Properties();        // 添加若干配置....        KafkaConsumer<String, String> consumer = new KafkaConsumer<>(properties, new StringDeserializer(), new StringDeserializer());        String topic = "foo_bar";        consumer.subscribe(Collections.singleton(topic));        while (!stopMark) {            ConsumerRecords<String, String> records = consumer.poll(Duration.of(300, MILLIS));            for (ConsumerRecord<String, String> record : records) {                // 处理消息            }        }}

乍一看,没有任何问题,之前的代码也都是这么写的,也都没有任何问题,但是这个 topic 就始终没法消费到数据??!!!

查看日志时,我发现了一丝端倪

[Consumer clientId=foo, groupId=bar] Setting offset for partition foo_bar-8 to the committed offset FetchPosition{offset=1590039403, offsetEpoch=Optional.empty, currentLeader=LeaderAndEpoch{leader=Optional[1.2.3.4:9000 (id: 4 rack: rack-0)], epoch=0}}

突然,我发现了一个特别的现象,“offset=1590039403”,offset 初始化不是 0 么?怎么变成....好像是一个秒级时间戳了??

一、一次离谱的 log 记录

为了探究为啥默认的 offset=0,变成了奇怪的数据,我写了如下的 Test,替换消费者的消费代码,代码如下:

Thread t = new Thread(() -> {            Integer a = 0;            while (true) {                System.out.println(a);                try {                    TimeUnit.SECONDS.sleep(1);                } catch (Throwable ignore) {                }            }        });t.start();

简单来说,线程内有一个 Integer 类型的变量 a,然后每隔 1s,打印一下这个变量 a 的值。那么不出意外的话,这段代码的结果应该每秒打印一个 0,但是不出意外的话,意外出现了。

000001590039403159003940315900394031590039403

在中间某一个时刻,突然打印出来变量的值变成了 1590039403,当时看到结果,我人都裂开了😢。裂开的原因如下:

•线程内部完全没有修改这个变量的操作

•这个变量是在方法内部创建的,并没有暴露给外部类

二、一次更离谱的定位问题过程

先从一个 IDEA 的智能提示开始,对于下面这个方法定义:

public static void hahaha(Integer s){}

如果我们在调用的时候这么写:

此时,IDEA 会机智的提示你:

如果你按照 IDEA 的指示,移除"不必要的装箱",那么就会变成下面这种调用方式:

hahaha(0);

这么一看,好像也没什么问题对吧?我理解也是,IDEA 真智能👍,我就这么改了。

接下来回到问题的开始,我发现,我的程序就是调用了一个下面这样的方法后,打印出来的 a 变量的值就发生了变化

public native int GetConfFile(String var1, int var2, StringBuffer var4);

注意:

1.这是一个 native 方法,内部是通过 JNI 调用的 C++的 so 文件

2.通常来说,c++都是通过指针操作,然后返回值也可能放在参数列表中,所以这个 var2 虽然是传递进去的参数,但同样也是这个方法的返回值

接下来,我就按照 IDEA 的指示,这么调用了此方法:

StringBuffer sb = new StringBuffer();int code = ConfigAccess.GetConfFile("myConfigFile", 0, sb); 

这么一看好像,也没有什么问题,但就是调用了此方法以后,所有值等于 0 的 Integer 类,都变成了 1590039403!!!!😨

1590039403???!!!

这不是这个 myConfigFile 的 version 值嘛??!!

三、原来是这样!

《吃瓜吃到八股文头上是一种怎样的体验?》

四、我们简单用 Java 模拟复现一下

public static void main(String[] args) throws NoSuchFieldException, IllegalAccessException, InterruptedException {        Thread t = new Thread(() -> {            Integer a = 0;            while (true) {                System.out.println(a);                try {                    TimeUnit.SECONDS.sleep(1);                } catch (Throwable ignore) {                }            }        });        t.start();        TimeUnit.SECONDS.sleep(5);        Integer b = 0;        // 获取Unsafe的实例        Field f = Unsafe.class.getDeclaredField("theUnsafe");        f.setAccessible(true);        Unsafe unsafe = (Unsafe) f.get(null);        // 获取对象的字段        Field field = Integer.class.getDeclaredField("value");        // 计算字段在对象中的偏移量        long offset = unsafe.objectFieldOffset(field);        // 修改字段的值        unsafe.putInt(b, offset, 1);        System.out.println("+++++" + unsafe.getInt(b, offset));    }

见证奇迹的时刻到了

00000+++++1 //此时修改了内存中的值11111

五、小结

1.八股文有些时候还是有用的

2.Java 和 C++打交道真的要谨慎、谨慎再谨慎,各种离奇的 bug 都能出现

3.当我循环打印一个没有任何改变的变量却发现内容变化时,我整个人真的裂开了😑

六、Q & A

Q: 很好奇这个缓存的对象是怎么被改了的?

A: 操作主要分成以下四步:

1、调用的”GetConfFile“是一个 native 方法,也就是底层是 c++方法

2、c++方法通常参数传递的都是“指针”,也就是对象的内存地址

3、c++方法中修改了这个指针对应的内存地址的值

4、好巧不巧,步骤 3 的内存地址是一个 jvm 的缓存,因此所有用到这个缓存的对象行为全部发生了异常

Q:这个是什么 JDK 版本呀,升级 JDK 还能复现吗?

A: 目前看和 JDK 的版本无关,因为:

1、 问题的根源是 c++直接操作了内存地址的数据,而这个数据恰好被 jvm 缓存

2、第四节的例子我是使用 jdk17 执行的,同样会有影响。这个缓存机制是有利于性能的,所以我理解应该不会去掉