2023年4月

Java 9 之后 解决多个模块包含相同包名的问题

最近接手一个新的Java项目, 架构师明确要Java 11 版本, 于是在 eclipse 里面设置使用JDK 17, JDK 编译器兼容 level 设置成 11. 设置完成后, 然后重新编译, 竟然报错了, 还是几百个错误!

错误内容全部是: The package java.util is accessible from more than one module: <unnamed>, java.base.

如下图, 这些从java.util引用的类, 全部都报这个错:
java.util.package.png

这个错误代表什么意思

Java 9 开始有了模块化系统的概念(JPMS), 每个Java 文件都属于某个模块. 例如上面例子中出现的 java.util.HashMap, java.util.concurrent.TimeUnit 都属于JDK里面的 java.base 模块.

那么<unnamed> 模块是什么呢?

对于JDK本身, 它默认已经分了模块, 但是我们还有很多jar包, 并没有按照模块的方式去打包, 或者在JDK 9 之前就有了这些jar包, 我们照样可以依赖它们.

对各种模块的依赖, 会加到modulepath, 对于非模块的依赖, 继续使用classpath. classpath上的类会被统一的分配到一个叫<unnamed>的模块.

如下面的 eclipse 截图所示, 所有maven的依赖全部放到了classpath.

moduepath.png

错误含义

所以, 这个错误的真正含义是: 在我们依赖中, java.util包即出现在了 JDK 的 java.base 这个模块, 也出现在了我们依赖的classpath上. 而Java模块化系统不允许同一个包出现在2个模块里面.

如何修复

有2种可能的方案:

  1. 退回到Java 8, 不使用模块化的概念, 错误消失.
  2. 找到提供java.util包的jar包, 质问开发者为啥给自己的jar包加入jdk的包名, 是想夹带私货吗?

我们这里只能选择第二个选项, 所以如何找到这个包含java.util的jar包成了重点.

如何找到第二个包含java.util的jar包

看到最初错误截图里面那些类, 我们很直观的可能认为: 只要使用eclipse的 open type 菜单是不是就很容易找到了, 我们试一下:

hashmap.png

从上面截图可以看到, eclipse 只找到一个HashMap, 并且源自于JDK11, 同样, 对于java.uti.Map, java.util.concurrent.TimeUnit 我们也只能找到仅有的一个属于JDK的.

明明报了java.util包来自2个模块, 为啥我们只找到一个呢?

其实, 我们上面的方式去找HashMap这个类出现在哪个包, 但是这个错误的真正的重点是包的名字, 也就是说, 有另外一个jar包里包含了java.util.Xxxx, 它不管类名是什么, 只管包名和JDK里面的java.util包重复了.

我们可以同样的方式在 eclipse 的 open type 里面输入java.util.*, 只不过会出现非常长的列表, 然后人工一个个对比.

如何手工找到这个jar包

这里提供2个方法:

  1. 方法一: 使用 eclipse open type, 然后输入 java.util.*,如下图, 按顺序找一定能找到:
    conc.png
  2. 方法二: 在 maven 的pom.xml 里面去掉一部分依赖, 看是不是这个错误消失了(同时其它依赖缺失错误会出现), 如果这个消失了, 说明去掉的这个依赖里面(直接或间接)包含这个包名. 使用一次去掉多个依赖(二分查找)可以加快速度.

如何自动化找到这个jar

eclipse 能报出这个错误, 说明它在我们的依赖中, 除了JDK之外还有一个jar包含这个包. 那么, 我们可以用同样的方法, 找到这个jar.

步骤:

  1. 通过 mvn 命令找到所有的依赖jar.
  2. 查找 jar 里面的类全名是不是包含 java.util.

mvn 命令找到所有的依赖jar

首先, 我们进入的项目pom.xml 所在的目录, 然后执行mvn 的goal: dependency:build-classpath, 把输出结果全部放到/tmp/dep.txt文件.

$ cd <project_dir>
$ ~/work/tools/apache-maven-3.9.1/bin/mvn dependency:build-classpath -Dmdep.outputFile=/tmp/dep.txt

打开/tmp/dep.txt文件, 可以看到里面是以:(MAC上)分割开的jar文件名.

遍历查找每个jar的类

第二步, 读取上面的输出, 以:分隔成多个jar, 然后遍历每个jar, 找出包含java.util的类,

    jars=(${(s/:/)$(cat /tmp/dep.txt)})
    for i in "${jars[@]}" 
    do 
        jar -tf $i | grep '^java.util' && echo "\t\tfind in ${i}"
    done

执行上面的脚本(mac 上的zsh), 得到如下结果:

java/util/
java/util/concurrent/
java/util/Hashtable.class
java/util/concurrent/ConcurrentHashMap.class
        find in /Users/eric/.m2/repository/com/boundary/high-scale-lib/1.0.6/high-scale-lib-1.0.6.jar

最终, 通过几行shell命令, 我们也找到了包含这个包名的jar包.

总结

Java 9 之后, 开始分模块, 一个项目可能既有对模块的依赖, 还有对普通jar包的依赖, 这些以前的jar包会被放到一个<unnamed>的模块. 如果一个包名出现在多个模块中(包含<unnamed>的模块), 就会出现这个错.

本文中另外一个出现在<unnamed>的模块, 可以通过遍历查找依赖jar的方式去查找到这个jar包.

JDK 里面有哪些模块?

java --list-modules

关于Java syncrhonized 关键字用到的 monitor 的概念

学习Java syncrhonized 关键字, 以及wait(), notify(), notifyAll 的时候, 经常会遇到一个单词: monitor 或者另外一个关键词 intrinsic lock(内置锁), 它们都是同一个东西. 也会有人说: wait(), notify(), notifyAll都是 monitor 的方法. 那么 monitor 到底是什么呢? 翻译成中文应该是什么呢?


在计算机科学中,"monitor"是一种用于管理并发访问共享资源的高级抽象。它由Per Brinch Hansen和C.A.R. Hoare于1970年代提出,并成为了处理并发的重要概念。

Monitor的基本思想是将共享资源(例如内存、文件、设备等)封装成一个单一的实体,称为"monitor"。这个monitor可以被多个并发执行的进程或线程所访问,但是一次只允许一个进程或线程执行其中的代码,从而避免了对共享资源的竞争条件和数据不一致性。

Monitor通常包含了以下几个要素:

  1. 互斥(Mutual Exclusion):当一个进程或线程进入monitor并执行其中的代码时,其他进程或线程将被阻塞,无法同时进入monitor。这样可以保证在同一时刻只有一个进程或线程可以访问共享资源,从而避免了竞争条件。
  2. 条件变量(Condition Variables):用于实现进程或线程之间的等待和通知机制。一个进程或线程可以在monitor中等待某个条件变为真,而其他进程或线程可以通过设置条件变量的值来通知等待的进程或线程条件已经满足,从而避免了忙等待。
  3. 入口队列(Entry Queue):用于管理等待访问monitor的进程或线程。当一个进程或线程请求进入monitor时,如果monitor已经被占用,则该进程或线程将被放入入口队列中,按照先来先服务的原则等待访问monitor。

使用monitor可以简化并发编程的复杂性,提供了一种结构化的方式来管理共享资源的访问,并且避免了许多并发编程中可能出现的问题,如竞争条件、死锁和饥饿等。它在操作系统、并发编程框架和并发控制算法中得到了广泛的应用,成为了并发编程中的重要工具。


看完上面的介绍, 是不是感觉跟 Java 的 syncrhonized 很像, 是的. Java 最初的设计就是想实现任何一个Java 对象都是一个包含 monitor 的想法.

但是 Java 对象跟最初 monitor 的实现有点差别:

  1. Monitor 的设计中, 任何对象的字段都是隐藏的, 任何方法都是需要获得锁才能进入的, 但是Java的对象并不是这样的.
  2. Monitor 可以有多个条件变量, 这类似后面Java 引入的Lock关联的Condition的概念, 一个Lock有多个Condtion, 但是 syncrhonized 却只有一个条件变量.
  3. 若有多个线程等待同一个条件变量, 只能notifyAll, 然后再由线程自己去判断自己等待的条件满足了吗.

monitor 在操作系统层面的实现

monitor 只是一个概念, 具体到操作系统层面, 要具体到特定的技术去实现. 比如用Semaphore(信号量)去实现, 或者使用 test-and-set 指令去实现

关于 monitor 的概念, 这篇wiki 讲的比较详细: https://en.wikipedia.org/wiki/Monitor_(synchronization)#Semaphore.

关于Java syncrhonized 的实现, 可以参考: https://blogs.oracle.com/javamagazine/post/java-thread-synchronization-synchronized-blocks-adhoc-locks

JVM 统一的日志框架

引言

对于基于 Java 开发的应用程序而言, GC 日志是我们了解 JVM 内存使用的情况的一个重要信息源, 所以我们在生产环境都打开 GC 的日志. 在 JDK 8 之前, 我们都使用诸如: -XX:+PrintGCDetails, -XX:+PrintGCDateStamps, -XX:+UseGCLogFileRotation, -XX:NumberOfGCLogFiles=5, 等这些 JVM 启动选项, 然而, 自从 JDK 9 开始, 我们却开始使用另外一套 JVM 启动选项, 如: -Xlog:gc*=debug:file=/tmp/gc.log:uptime,tid:filecount=5,filesize=2m 来设置 GC 的日志相关的配置.

为什么同样是设置 GC 的日志配置, 却有了不同的 JVM 启动选项呢? 这是因为: 自从 JDK 9 开始, JVM 有了一套统一的日志框架(JVM Unified Logging Framework). GC 日志作为 JVM 输出的一种日志, 也可以通过这个统一的日志框架来配置. 虽然 JVM 还接受原来的启动选项, 但是长久来看, 所有的这些跟日志相关的选项, 最终都将只保留通过这个统一的日志框架来配置.

什么是 JVM 统一的日志框架

JVM 统一的日志框架(JVM Unified Logging Framework)是 JDK 9 引入的一个中心化的日志框架, 通过这个日志框架, 我们可以观测 JVM 的 类加载(class loading), 线程(thread), 垃圾收集(GC), 模块系统(Module System) 等相关信息. 我们可以通过设置设置 JVM 启动参数 -Xlog 来与这个统一的日志框架交互, 从而让这个统一的日志框架输出不同组建的, 不同层级(level)的日志到我们指定的日志文件.

除了通过 -Xlog 这个启动参数外, 我们也可以在运行时实时修改统一日志框架的输出. 一种方法是通过 jcmd 命令的 VM.log 子命令来修改, 另外一种方法是通过修改对应的 MBean. -Xlog 是在应用启动应用时候修改, 后面2种都是运行时动态修改.

后面的例子中, 为了举例方便, 我们都使用 jcmd VM.log 动态修改, 然后观察修改的结果.

简单的例子

假设我们有一个正在运行的 Java 应用, 它的进程号(pid)是 3499:

$ jps
16527 Jps
3499 Pycharm

我们把所有的日志都打印到 /tmp/my.log 文件去, 可以这么操作:

$ jcmd 3499 VM.log output="file=/tmp/my.log" what="all=trace"
3499:
Command executed successfully

$ tail -f /tmp/my.log
[238674.318s][debug][gc,task               ] G1 Service Thread (Remembered Set Sampling Task) (run) 0.330ms (cpu: 0.327ms)
[238674.318s][trace][gc,task               ] G1 Service Thread (wait) 0.300s
[238674.333s][trace][monitorinflation,owner] try_set_owner_from(): mid=0x000060000089e220, prev=0x0000000000000000, new=0x00007fc6860d8c00
[238674.333s][trace][monitorinflation,owner] release_clear_owner(): mid=0x000060000089e220, old_value=0x00007fc6860d8c00
[238675.209s][trace][monitorinflation,owner] try_set_owner_from(): mid=0x0000600014b634d0, prev=0x0000000000000000, new=0x00007fc607a54a00
[238675.209s][trace][monitorinflation,owner] release_clear_owner(): mid=0x0000600014b634d0, old_value=0x00007fc607a54a00

上面的代码中, 我们先是把所有的日志都通过 jcmd VM.log 的方式输出到 /tmp/my.log 文件中, 然后通过 tail 命令查看最新的日志内容.

jcmd的命令中, 3499 是 Java 应用进程号, VM.logjcmd的子命令, 后面的是 VM.log 子命令的选项, 我们的注意力主要集中在选项这一块.

日志输出到哪

在这个简单的例子中, 我们设置了 output="file=/tmp/my.log", 主要用来设置输出到哪里, 我们可以设置为一个文件, 或者 stdout, stderr:

$ jcmd 3499 VM.log output="stdout" what="all=trace"
$ jcmd 3499 VM.log output="stderr" what="all=trace"

当然, 这里的 stdout 和 stderr 都是进程 3499 对应的 stdout 和 stderr(Linux系统每个进程都有自己单独的stdout, stderr伪文件), 并不是当前的控制台.

所以, 总结一下 output, 它有3种可能, 分别是:

  1. stdout
  2. stderr
  3. file=<file_name>
    当使第三种 file=<file_name> 的时候, 我们可以设置文件名里面包含%p, %t, 分别代表应用进程号和应用启动的时间.

日志文件的大小和多少

对于上面的第三种写到文件系统的, 一般都能设置rotate, 就是文件轮转. 比如最多写5个文件, 每个文件最大6M这种. JVM 统一的日志框架也支持这些设置, 它通过选项 output_options 设置. 比如:

$ jcmd 3499 VM.log output="stdout" what="all=trace" output_options="filecount=5,filesize=6M"

可以看到, 我们设置了文件最多是5个, 文件大小最大是6M. 文件大小的单位可以是 K, M, G.

那么如果设置 filecount=0 呢? 这就代表告诉系统, 不要rotate 日志文件.

写哪些模块的日志到日志文件

其实一开始到现在, 我们都没有聊选项中的 what="all=trace", 这部分选项告诉日志系统, 什么东西要写到日志文件里面. 我们给的内容是 all=trace, 那它表示什么呢?

日志的层级

通常我们写日志的方式大概是这样的:

log.info("this is a info log");
log.error("this is an error log"

这里我们分别写了一条 info level 和 一条 error level 的日志. 这里的 info, error 都是日志的级别, 同样, JVM 统一的日志框架中, 也有几个级别: off, trace, debug, info, warning, error. 这其中 off 最特别, 它其实是告诉日志框架, 全闭嘴, 相当于关掉所有层级的日志. 可以看到我们上面的例子中都是使用的 trace level, 是级别最低的, 等于输出所有的层级的日志.

日志的标签(tag)

一开始的时候, 我们说到这个统一的日志框架可以输出不同模块的日志,比如GC, 线程, classload等模块. 那么我们怎么选择那些日志我们能输出, 那些不让它输出呢?

为了让我们有选择的输出, 需要一个选择标准, 这里使用的就是标签. 日志框架在输出日志的时候, 给每一条日志都加了一个或多个标签, 我们可以选择不同的标签组合, 选择不同的日志内容输出到日志文件.

JVM 统一的日志框架写日志的方式类似于这样, 每一行日志都包含一些标签:

log.info("this is a info log", ["tag1", "tag2"]);
log.error("this is an error log", ["tag2", "tag3"]);

那么我们和统一的日志框架交互的时候, 就可以根据这些标签去选择到底哪些日志要输出. 我们可以通过命令来看当前的 JVM 支持哪些标签:

$ jcmd 3499 VM.log list 
3499:
Available log levels: off, trace, debug, info, warning, error
Available log decorators: time (t), utctime (utc), uptime (u), timemillis (tm), uptimemillis (um), timenanos (tn), uptimenanos (un), hostname (hn), pid (p), tid (ti), level (l), tags (tg)
Available log tags: add, age, alloc, annotation, arguments, attach, barrier, biasedlocking, blocks, bot, breakpoint, bytecode, cds, census, class, classhisto, cleanup, codecache, compaction, compilation, condy, constantpool, constraints, container, coops, cpu, cset, data, datacreation, dcmd, decoder, defaultmethods, director, dump, dynamic, ergo, event, exceptions, exit, fingerprint, free, freelist, gc, handshake, hashtables, heap, humongous, ihop, iklass, indy, init, inlining, install, interpreter, itables, jfr, jit, jni, jvmci, jvmti, lambda, library, liveness, load, loader, logging, malloc, map, mark, marking, membername, memops, metadata, metaspace, methodcomparator, methodhandles, mirror, mmu, module, monitorinflation, monitormismatch, nestmates, nmethod, nmt, normalize, numa, objecttagging, obsolete, oldobject, oom, oopmap, oops, oopstorage, os, owner, pagesize, parser, patch, path, perf, periodic, phases, plab, placeholders, preorder, preview, promotion, protectiondomain, ptrqueue, purge, record, redefine, ref, refine, region, reloc, remset, resolve, safepoint, sampling, scavenge, sealed, setting, smr, stackbarrier, stackmap, stacktrace, stackwalk, start, startup, startuptime, state, stats, streaming, stringdedup, stringtable, subclass, survivor, suspend, sweep, symboltable, system, table, task, thread, throttle, time, timer, tlab, tracking, unload, unshareable, update, valuebasedclasses, verification, verify, vmmutex, vmoperation, vmthread, vtables, vtablestubs, workgang
Described tag sets:
 logging: Logging for the log framework itself
Log output configuration:
 #0: stdout all=trace uptime,level,tags (reconfigured)
 #1: stderr all=off uptime,level,tags
 #2: file=/tmp/gc.log all=trace time,level,tags filecount=5,filesize=10240K,async=false (reconfigured)
 #3: file=/tmp/my.log all=trace uptime,level,tags filecount=5,filesize=20480K,async=false (reconfigured)

其中 Available log tags 包含了所有支持的tag. 而我们上面使用的 all 则表示包含所有的tags.

所以这也是 what 所表达的含义, 它通过 tags 和日志 level 一起来选择什么(what)日志应该被输出出来. 比如:
gc=debug, jfr=trace, init=info 等.

日志每行的格式

在一开始的例子中, 我们看到了如下的日志行:

[238674.318s][trace][gc,task ] G1 Service Thread (wait) 0.300s

这跟我们平时看到的日志很像, 第一个方括号里面的表示服务器从开始启动到打日志的时间, 第二个方括号里面表示日志的层级, 第三个表示日志的tags, 最后是日志的内容.

上面的输出中是默认的日志每一行的格式, 其实我们可以定制这个格式, 并且加减一些内容.

首先, 除了时间,日志level, tags, 我们还有哪些可以跟日志一块打印的东西呢? 这些可以和日志内容一块输出的叫: decorator, 从之前的jcmd <pid> VM.log list的输出中, 我们可以看到有如下的 decorators:

Available log decorators: time (t), utctime (utc), uptime (u), timemillis (tm), uptimemillis (um), timenanos (tn), uptimenanos (un), hostname (hn), pid (p), tid (ti), level (l), tags (tg)

其中括号里面的是简写的形式. 主要是各种形式的时间表示, 主机名, 进程号, 线程号, 日志层级, 标签.

所以, 到此我们可以写一个完整的, 包含上面所有涉及到的jcmd VM.log的命令:

$ jcmd 3499 VM.log output="file=/tmp/my.log" what="class=debug" decorators="t,hn,p,ti,l,tg" output_options="filecount=5,filesize=2M"

选项的默认值

对于上面的选项output, output_options, what, decorators 我们可以省略, 如果省略, 则使用的它们的默认值. 它们的默认值分别是:

  1. what: "all=info"
  2. output: "stdout"
  3. output_options: ""
  4. decorators: "uptime,level,tags"

注意上面的 what, 如果单单省略 what, 默认值是 “all=info“, 如果是使用启动参数 -Xlog, 后面没有给任何选项, 那么等价于: -Xlog:all=warning:stdout:uptime,level,tags

稍微复杂的例子

上面的选项的内容都比较简单, 要么是选择所有的tag, 要么是选择一个tag, 如果我们要选择多个tag 怎么办呢?

选择多个tags

tag 之间可以使用逗号隔开, 这样就能选择多个tags, 只要日志标签中包含任何一个这样的标签都会被输出, 比如:

$ jcmd 3499 VM.log what="gc,class,safepoint=debug"

tag 的模糊匹配

我们可以使用*来模糊匹配标签(tag), 这样匹配任何以gc开头的标签, 比如:

$ jcmd 3499 VM.log what="gc*=debug"

tag 的叠加

我们可以设置当一个日志行中包含所有我们要求的标签才能输出, 比如:

$ jcmd 3499 VM.log what="gc+oom"

这样, 当一行日志即包含gc标签, 又包含oom标签, 同时日志的level是info及以上的时候, 才会打印出来.


这里要注意: 没有被显示指明的标签(tag), 只要是warning及以上, 同样会被输出到日志文件


只输出我选择的标签

如果要关闭其它不想看到的标签日志, 则需要先使用disable=true, 然后在enable其它标签, 如下:

$ jcmd 3499 VM.log disable=true output="file=/tmp/my.log" what="gc=trace" 

多个标签不同的日志层级

如果要给不同的标签不同的日志层级, 可以使用下面的方式:

$ jcmd 3499 VM.log what="gc=trace,class=error,threa*=info,class*=off"

总结

通过上面的例子, 我们看到有3种方法与 JVM 统一的日志框架打交道:

  1. 启动参数 -Xlog 适用于启动时候设置
  2. 使用 jcmd <pid> VM.log 可以动态调整日志的输出
  3. 使用 MBean, 可以动态调整, 没有 jcmd 命令方便

打印日志的选项主要有4个:

  1. what: 选择标签(tags)和日志层级
  2. output: 选择输出到哪里 stdout, stderr 或者文件
  3. output_options: 如果选择输出到文件, 文件的一些选项, 比如大小和rotate的多少
  4. decorators: 日志行除了日志内容外, 还要加哪些信息.

如果想查看帮助和所有的选项内容, 可以尝试下面的命令:

$ jcmd <pid> help VM.log
$ jcmd <pid> VM.log list

希望帮助到需要的人.

MAC grep

MAC 上面的 grep 大部分跟 Linux 上的一致, 但也有些差异.

  1. 不能使用 -P 来使用正则, 它使用 -e

    grep -e 'Abc.\{3,5\}' my.txt

    上面的大括号前面使用反斜杠是因为 shell 的原因.

  2. 不能使用贪婪模式, 要使用egrep

    egrep -e 'Abc.*?Myrule' my.txt

SSLv2Hello 协议引发的连接拒绝

有开发人员问我, 有没有见过这个 Java 应用报出的异常消息: IO Error: Remote host terminated the handshake. 从这个message看, 这个是说无法通过握手建立连接, 单纯从这个消息看, 看不出来什么原因.

背景

这个应用最近更改了不少文件, 然后重新发布新版本, 就出现了这个错误. 出这个错误的上下文是: 这是一个连接 Oracle 数据的连接, 使用的是TSLv1.2加密连接.

他们问了DBA, DBA 说数据库完好, 问了网络, 网络也没有其它问题.

诊断

最简单的方法是抓包, 查看具体的握手失败的原因. 抓包后看到如下的 SSL client hello 协议内容, 然后服务器就拒绝了:
client_hello.png

从上面的截图我们可以看到, tcp 三次握手, 正常. 然后客户端发送 client hello, 服务器直接就发了 FIN, 要拒绝连接.

在看 client hello 的具体消息, 从消息可以看到, 这里上面写的是 SSLv2, 难道这是1995年使用的 SSL 2.0? 看上去很奇怪.

如果比较熟悉 TLS 协议, 我们可以知道, 在TLS 层, 又分为 TLS record 协议, 它内部又封装了具体的 TLS 子协议, 分别是: Application, Alert, Handshake, ChangeCipherSpec. 而 record 协议的第一个字节表示子协议的类型.

然而我们这个截图里面, 前两个字节是 80 b3, 表示内容长度, 关键是 Wireshark 认识这种格式. 太诡异了.

然后仔细查看 Wireshark 的解析, 我们看到 Wireshark 标注的是: SSLv2 Record Layer: Client Hello.

关于 SSLv2Hello

顺着这个关键字, 我们终于找到了另外一种协议: SSLv2Hello. 这是一种伪协议, 它是 Oracle 之前发明的, 并且现在已经不在使用的. 它的主要作用是在客户端发送一个SSLv2Hello消息, 试探一下服务端使用的到底是哪种协议, 是 TLS 1.1, 还是 TLS 1.2.

JDK 里面在 JDK 7 之前默认是有这种协议的, 之后 Oracle disable 了它.

-- 未完待续 --