背景描述:
项目是普通的java服务,以jar包的形式部署,前几天升级了一下服务,部署运行后跟踪日志发现时不时抛异常信息。
具体报错信息如下:
class="linux">[2013-09-22 17:30:53,653] - [pool-3-thread-3] - ERROR - Caught IOException decoding 1061 bytes of data java.io.InvalidClassException: com.chenzhou.test.model.VmCategoryMapper; local class incompatible: stream classdesc serialVersionUID = 1411005385568342784, local class serialVersionUID = -2356515191808014047
根据报错信息来看,是在反序列化VmCategoryMapper对象时发现serialVersionUID不一致,所以抛了IO异常。
?
我查看了一下VmCategoryMapper类的代码,具体如下(属性和方法就省略了):
package com.chenzhou.test.model; import java.io.Serializable; import java.util.List; public class VmCategoryMapper implements Serializable { /** * serialVersionUID:序列化ID. */ private static final long serialVersionUID = -2356515191808014047L; //省略了属性和方法 }
很纳闷的是,Eclipse给我自动生成的serialVersionUID就是-2356515191808014047,那异常信息声明中的反序列化得到的1411005385568342784是怎么得来的呢。
?
我通过SVN历史查看了一下VmCategoryMapper类的版本历史记录,发现历史版本中也没有使用过1411005385568342784作为serialVersionUID。
不过还是发现了一个线索,就是升级之前,VmCategoryMapper类我并没有显示地定义serialVersionUID,这次在优化代码的时候使用IDE自动生成了一个非默认的序列化ID。熟悉java序列化的人应该都了解,如果类实现了Serializable但是没有显式声明serialVersionUID,那么在程序编译时会自己生成这个版本序列化ID,所以我猜测1411005385568342784应该是我服务升级前默认生成的序列化ID。
?
但是问题依然存在,我升级后明明已经显示声明了serialVersionUID的值,为什么反序列化时会得到原来默认的值呢。我把线上的jar包中的VmCategoryMapper类的class文件进行了反编译,发现反编译出来的serialVersionUID是我代码中显示声明的值,也就是-2356515191808014047。说明jar包是正常的。
?
百思不得其解后,同事提醒我,什么时候会进行序列化和反序列化?
经他一提醒,我突然想到了对象在缓存中读取和更新时会进行序列化反序列化,很可能是缓存惹的祸,于是赶紧检查了一下缓存逻辑所在的DAO层的方法:
?
@ReadThroughSingleCache(namespace = CacheConst.VM_CATEGORY, expiration = 3600) public List<VmCategoryMapper> getVMCategorys(@ParameterValueKeyProvider String code) { //get VmCategoryMapper from db }Dao中对VmCategoryMapper的读取方法见上面的代码,我们项目中使用了simple-spring-memcached来进行缓存管理。expiration = 3600代表超时时间为1个小时。因为我在服务升级时并没有清理缓存,所以memcached中存在有未超时的缓存对象。这些缓存对象是在升级前存入缓存的,序列化时使用的是原来的默认serialVersionUID也就是1411005385568342784,当服务升级后,由于新的VmCategoryMapper中显示声明了serialVersionUID的值为-235651519180801404,所以如果当查询VmCategoryMapper时,缓存命中,取出memcached中的对象进行反序列化,就会导致serialVersionUID不一致。 定位了原因之后,我把整个memcached进行了flush_all,果然,再也没有抛出该异常了。 这个问题虽然简单,不过还是蛮有意思,值得总结。