多个eclipse插件导出同名且版本不同的包带来的问题之分析过程

原创

王新和 2013-04-07 16:20:48 博主文章分类：osgi ©著作权

©著作权归作者所有：来自51CTO博客作者王新和的原创作品，请联系作者获取转载授权，否则将追究法律责任

问题现象

    某同事中途接手为我们的一个甲方负责维护我们公司的一个平台。公司的平台是基于eclipse的rcp技术开发。公司此平台的服务器端运行在ibm jre1.4.2上，客户端运行在sun的jre1.4.2上。部分客户端上也有使用版本为1.5.x的jre。
    有一次同事根据甲方需求修改了部分旧插件，其中有一个插件会导出jna的相关包，以便其它插件调用第三方动态库时方便使用。此次同事没有调整这块的内容。在开发测试、SIT测试时都正常。
    投产部署到服务器后，客户端登录后自动更新插件到本地后，并且重启客户端。重启后，部分客户端在登录界面上提示找不到usbkey相关信息。也就是说有一部分客户端更新后用户无法使用u盾登录到系统了，但在更新前还可以使用u盾正常登录系统。
    在更新不能正常使用u盾的客户端的日志中有找到下列异常日志：
java.lang.UnsupportedClassVersionError: com/sun/jna/Native (Unsupported major.minor version 49.0)
at java.lang.ClassLoader.defineClass0(Native Method)
at java.lang.ClassLoader.defineClass(Unknown Source)
at org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.defineClass(DefaultClassLoader.java:160)
at org.eclipse.osgi.baseadaptor.loader.ClasspathManager.defineClass(ClasspathManager.java:498)
at org.eclipse.osgi.baseadaptor.loader.ClasspathManager.findClassImpl(ClasspathManager.java:468)
at org.eclipse.osgi.baseadaptor.loader.ClasspathManager.findLocalClassImpl(ClasspathManager.java:427)
at org.eclipse.osgi.baseadaptor.loader.ClasspathManager.findLocalClass(ClasspathManager.java:410)
at org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.findLocalClass(DefaultClassLoader.java:188)
at org.eclipse.osgi.framework.internal.core.BundleLoader.findLocalClass(BundleLoader.java:339)
at org.eclipse.osgi.framework.internal.core.SingleSourcePackage.loadClass(SingleSourcePackage.java:37)
at org.eclipse.osgi.framework.internal.core.BundleLoader.findClass(BundleLoader.java:379)
at org.eclipse.osgi.framework.internal.core.BundleLoader.findClass(BundleLoader.java:352)
at org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.loadClass(DefaultClassLoader.java:83)
at java.lang.ClassLoader.loadClass(Unknown Source)

    也就是说，插件调用u盾时是通过jna方式调用厂商动态库的。但是更新一个会导出jna相关包的插件（更新时只是增加其它与jna本身没有相关的内容）后，客户端竟然奇妙出现UnsupportedClassVersionError问题。
    查看更新包中com.sun.jna.Native类的主版本不是49,而是jre1.4支持的48。此插件中的com.sun.jna包中的类没有版本问题。
    同事们把有问题客户端复制到自己的机器，使用与有问题客户端的jre版本完全一致的jre运行客户端后调用u盾是正常的。
    遇到这种奇妙的问题又不能及时解决，只能先回切程序版本，放弃此次投产更新了。此次投产以失败告终。

排查过程

    甲方要求我们公司派人到现场分析。我们的另一个同事在现场分析了一天，尝试了很多方法没有找到在引发问题的直接原因。后来，甲方给我们的压力越来越大。公司派我到现场主导分析，以便尽快查找问题根源。
    一、重现问题现象
    庆幸的是，在甲方现场的一个新的机器上也可以反复重现故障。
    在测试分析过程中，发现一个有趣的现象：把有问题的客户端复制别的盘的任意目录下都能正常调用u盾，再把客户端复制到原来的位置也变得正常了。
    经过对比检查，发现一个规律:客户端运行有问题时，所在分区文件系统是FAT32,正常运行时所在分区文件系统是NTFS。
    根据这个发现，我们弄了一个文件系统类型为FAT32的u盘。把有问题客户端打包成压缩包，剪切到目标u盘中，解压后运行客户端能重现问题。
    终于可以在我们自己的电脑上能重现问题了。这是一个好的开端。
    二、分析排查过程
    (1)我们在命令行下启动客户端，添加一个eclipse的启动参数:-console。在osgi控制台，查看了各个插件bundle情况。正常情况下，前面提到的一个更新过插件的bundleID比较小。异常情况下，前面提到的一个更新的插件的bundleID比较大。
难道在异常情况下加载的Native的来源与正常时加载的Native的来源不一样吗？难道这个路径的Native类之版本号就是49吗?由于我手头上没有最新和完整的平台源码，无法从源码方向完整的搜索出哪些地方有jna相关类并且导出这些包。
    (2)我们在命令行启动客户端，使用生产的jre版本运行程序。在启动参数中，添加了-verbose:class和-XX:+TraceClassLoading两个参数。在标准输出流中能显示一个标准内库类是从哪个jar包中加载的。遗憾的是没有显示公司平台自身插件类的加载路径。
    (3)接着，我们又使用jre1.6.32，在命令行启动客户端，同样添加了两个启动参数-verbose:class和-XX:+TraceClassLoading两个参数，再加一个eclipse的参数：-console。此次终于找到问题根源了。从输出信息可以看出Native类是从bundleID为41的classpath中加载的。通过osgi的ss命令查看到bundleID为41的插件是一个不是此次投产的内容。解压此插件包，发现存在一个jna.jar，而且此插件导出了com.sun.jna相关包。Jna.jar中Native类的类版本号就是49。故障的元凶终于找到了。其实此种客户端是不需要这个导致故障的插件的。甲方同种另一用途的客户端才需要这个插件。
    三、故障复盘
    在一些没有意料的因素影响下，eclipse安装加载插件的顺序有所变化。如果引发问题插件的bundleID比前面提到的更新的插件的bundleID小，两个插件都导出了com.sun.jna相关包。此时，当通过import package方式依赖com.sun.jna包的并且调用u盾的插件需要调用通过Native类加载第三方动态库时，osgi查找加载Native类时，只会使用bundleID最小的并且导出同样类的bundle中的同名类。这样，就使用到了类版本为49的Native类。在加载Native类时没有通过类版本的检查，引发了jvm抛出unsupportedClassVersionError的错误。

反思总结

   (1)在开发时，一定要避免不同插件导出同名包的做法。这种做法可能会带来意料不到的隐患。不同的插件导出同样包，但包的版本有差异的做法带来的风险会更大。
   (2)实际项目中需要审慎地进行平台设计规划、带着敬畏心态的进行编码开发。这点如何反复强调都不过份，并且要笃行。
   (3)版本控制如何进行更有效呢？代码审查如何评审更能发挥更大的价值呢？这是需要我们去更深入研究实践的。