对RmiJdbc的二次开发

接到一个任务，需要对项目中用到的JDBC进行改造，需求如下：

不要将实际数据库的连接方式（包括url,user,password）暴露给客户端

记录每个执行的sql内容，包括sql及其执行参数

尽可能少的降低代码修改**

性能上不能与直接使用jdbc有很大差距

按此需求，需要实现以下几点：

sql是一定要放在server端的

需要将sql记录到日志中

客户端仍然需要使用jdbc的方式，才能保证尽可能少的修改

性能要高

这不就是将jdbc也使用客户端-服务器的方式吗？而且要求高性能？

JDBC接口的实现

代码尽可能少的改动，这就要求必须在客户端实现JDBC的接口，然后在客户端的jdbc实现中调用服务器上的服务完成业务的处理。

这样在客户端仅需替换jdbc驱动的jar包，然后代码中替换相应的驱动代码即可。

这样又回到了面向服务的SOA设计中来了，可以提供给多个客户端使用。

按此思路，就想到了最常用的几种方式：

1. soap/restful webservice

显然，用webservice的缺点就是性能太低，马上予以排除。

2. 直接使用socket变成实现

实现复杂，对技术要求高，待定。

3. java rmi

EJB中使用的通信技术，效率不错，可以考虑。

在开源的时代，开源框架是加快项目进度的利器，所以我也是首先找找开源框架。

别说，还真有，就是RmiJdbc，那就是你啦。

大体看了一下源码，已经是非常完善可以作为产品使用了，感谢作者大神的工作。

既然如此，只需要把写日志功能加上就好了，马上开始修改吧

第一步，记录SQL

这个算是比较简单的了。

1.在RJStatementServer中声明一个List，用来记录sql

为什么要用List？主要是因为会有batch执行的情况。

2.针对Statement，在RJStatementServer的executeQuery,execute,addBatch等方法中，把需要执行的sql保存到List

3.针对PreparedStatement，在RJConnectionServer中，preparedStatement方法中把sql保存到List

第二步，记录日志

增加一个记录日志的类RJLog

public class RJLog {

public static void saveLog(List<String> sqlList) {
String sql = Arrays.toString(sqlList.toArray());
String execTime = DateTime.now().toString(DateTimeFormat
.forPattern("yyyy-MM-dd HH:mm:ss"));//此处使用joda-time2.2.jar
//以下是记录日志的方法，详见后面
......
}
}

日志的设计与实现

目前的要求是将日志存入数据库中。

由于访问量没那么大，因此产生的日志不会很多，大概一天上万条左右。高峰时期估计每秒产生几十条日志。

日志的写入，也分为同步写入、log4j的半异步写入和完全的异步写入三种。

同步写入数据库

没什么好说的，在执行完成sql之后，直接将sql通过jdbc写入日志数据库中，也就是说，产生一个日志记录，就要写入一次。

缺点：效率低，非常低。创建数据库连接是非常耗时的，如果一个业务执行过程中有大量的sql，那就积少成多影响体验了。

log4j的半异步

说到日志，首先想到的就是log4j，可以写入文件，也可以写入数据库，并且还能异步写入！

由于一开始要求能够支持jdk1.5，因此只能使用log4j-1.x版本，此处用的是1.2.17版。后来虽然改为jdk1.6，但是也没有使用log4j2.x

log4j.properties配置

使用log4j将日志写入数据库比较简单，网上有很多配置实例，唯一需要注意的地方是，log4j也是可以异步记录日志的，通过配置参数，设置累积多少条记录一次。

举个log4j配置的栗子：

log4j.appender.db=org.apache.log4j.jdbc.JDBCAppender #使用JDBCAppender ，这样才能写入库

log4j.appender.db.BufferSize=10 #此数据值代表每次累积到10条sql就写入数据

log4j.appender.db.driver=oracle.jdbc.driver.OracleDriver #jdbc驱动

log4j.appender.db.URL=jdbc:oracle:thin:@10.xx.xx.xx:1521:orcl #数据库连接，此处是oracle

log4j.appender.db.user=xxxx #数据库user

log4j.appender.db.password=xxxx #数据库password

log4j.appender.db.sql=insert into LOG_INFO (sql,createTime) values (‘%X{sql}’,’%X{exectime}’) #写日志的sql

log4j.appender.db.layout=org.apache.log4j.PatternLayout

改造日志类RJLog

如下，就能把日志信息记录下来了

public class RJLog {
static Logger logger = LoggerFactory.getLogger(RJLog.class);
public static void saveLog(List<String> sqlList) {
String sql = Arrays.toString(sqlList.toArray());
String execTime = DateTime.now().toString(DateTimeFormat
.forPattern("yyyy-MM-dd HH:mm:ss"));//此处使用joda-time2.2.jar
//使用MDC
MDC.put("sql",sql);
MDC.put("exectime",execTime);
logger.info("sql executed!");
}
}

修正log4j1.2.17的小bug

log4j1.2.17有个bug，就是日志会重复记录一次。

发现这个问题后，把log4j的源码找出来看了一下，找到了问题所在，修改记录如下：

类：org.apache.log4j.Category 205行

原来代码

if(c.aai != null)

修改后代码

if(c.aai != null && !(c instanceof org.apache.log4j.spi.RootLogger) )

总之，大概意思就是，原来的代码在走到根节点的时候，又重复了一次记日志的操作。

log4j的问题：

1）只能算是半个异步，在真正写入库的时候，还是同步执行的

2）偶尔会有漏掉的情况，具体原因还没找到。

缓存+线程的异步

直接写日志和log4j都不是那么完美后，只能是异步来处理日志了。

虽然现在动不动就分布式，但用在这个这个简单的日志功能上合适吗？从目前情况来看，没有那么大的业务量，因此不需要做的这么复杂，有点儿大材小用了的感觉。

不想用分布式，那就把分布式放在一台机器上，改用多线程吧，也算是异步的效果，就这么办。

缓存选择ehcache

用什么样的缓存呢？其实memcache,redis,ehcache都可以

为什么选ehcache？主要还是为了简单，因为不用部署，直接就可以用哇

1.定义缓存配置文件

<?xml version="1.0" encoding="UTF-8"?>

<ehcache name="rmi">
<defaultCache
maxElementsInMemory="10000"
eternal="false"
timeToIdleSeconds="120"
timeToLiveSeconds="120"
overflowToDisk="true"
diskSpoolBufferSizeMB="30"
maxElementsOnDisk="10000000"
diskPersistent="false"
diskExpiryThreadIntervalSeconds="120"
memoryStoreEvictionPolicy="LRU"/>

<cache name="rmijdbc"
maxElementsInMemory="10000"
maxElementsOnDisk="10000000"
eternal="true"
timeToIdleSeconds="120"
timeToLiveSeconds="0"
memoryStoreEvictionPolicy="LFU">
</cache>
</ehcache>

2.定义缓存工具类

public class EhcacheUtil {

/*
* ehcache配置文件
*/
private static final String path = "/rmijdbc-ehcache.xml";

private CacheManager cacheManager;

private static EhcacheUtil ehCache;

private EhcacheUtil(String path) {
cacheManager = CacheManager.create(getClass().getResource(path));
}

/*
* 静态工厂
*/
public static EhcacheUtil getInstance() {
if (ehCache == null) {
ehCache = new EhcacheUtil(path);
}
return ehCache;
}

/*
* 将map写入缓存
*/
public void setCacheObj(String key, Object obj) {
getCache().put(new Element(key, obj));
}

/*
* 获取指定key缓存的map
*/
public Map<String, String> getDataMap(String key) {
Element elem = getCache().get(key);
if (elem == null) {
return null;
}
return (Map<String, String>) elem.getValue();
}

private Ehcache getCache() {
return cacheManager.getEhcache("rmijdbc");
}

/*
* 按前缀获取缓存的key list
*/
public List<String> getKeys(String prefix) {
List<String> list = getCache().getKeys();
if (null == prefix || "".equals(prefix))
return list;
for (int i = list.size() - 1; i >= 0; i--) {
if (!list.get(i).startsWith(prefix)) {
list.remove(i);
}
}
return list;
}

/*
* 批量删除缓存
*/
public void clearListCache(List<String> list) {
for (String key : list) {
clearOneCache(key);
}
}

/*
* 清空缓存
*/
public void clearCache() {
getCache().removeAll();
}

/*
* 删除指定key的缓存
*/
public void clearOneCache(String key) {
getCache().remove(key);
}
}

改造日志类RJLog

public class RJLog {

public void saveLog(List<String> sqlList) {
//数据放入map
Map<String, String> map = new HashMap<String, String>();
map.put("sql", Arrays.toString(sqlList.toArray()));
map.put("exetime", DateTime.now().toString(DateTimeFormat
.forPattern("yyyy-MM-dd HH:mm:ss")));
//map放入缓存，缓存的key并以rmijdbc开头
EhcacheUtil.getInstance().setCacheObj("rmijdbc" + UUID.randomUUID(), map);
}
}

写日志的线程

现在，日志都已经写入缓存了，那么就开始多线程的任务吧

为了降低数据库压力，提高执行效率，假设日志线程每分钟执行一次

代码如下：

public class RmiJdbcLogThread implements Runnable {
private String name;
final String sql = "insert into csl_auditjdbc_log(sql, createtime) values( ?, ?)";

public RmiJdbcLogThread(String name) {
this.name = name;
}

public void run() {
Thread.currentThread().setName("rmijdbclog");
EhcacheUtil ehcache = EhcacheUtil.getInstance();
while (true) {
//找到rmijdbc前缀的缓存
List<String> sqlList = ehcache.getKeys("rmijdbc");
//没有数据，就暂停60秒
if (sqlList == null || sqlList.size() == 0) {
try {
Thread.sleep(60 * 1000);
} catch (InterruptedException e) {
// TODO Auto-generated catch block
e.printStackTrace();
}
}

Connection conn = getConnection();
PreparedStatement pstmt = null;
try {
pstmt = conn.prepareStatement(sql);
} catch (SQLException e1) {
// TODO Auto-generated catch block
e1.printStackTrace();
}
//批量执行，提高效率
for (String key : sqlList) {
Map<String, String> map = ehcache.getDataMap(key);
try {
pstmt.setString(1, map.get("sql"));
pstmt.setString(2, map.get("exetime"));
pstmt.addBatch();
} catch (SQLException e) {
try {
pstmt.clearParameters();
} catch (SQLException e1) {
// TODO Auto-generated catch block
e1.printStackTrace();
}
}
}
try {
pstmt.executeBatch();
} catch (SQLException e) {
// TODO Auto-generated catch block
e.printStackTrace();
} finally {
ehcache.clearListCache(sqlList);
try {
pstmt.close();
} catch (SQLException e) {
pstmt = null;
}
try {
conn.close();
} catch (SQLException e) {
conn = null;
}
}
}
}

public Connection getConnection() {
Connection conn = null;
try {
Class.forName("oracle.jdbc.driver.OracleDriver");
} catch (ClassNotFoundException e1) {
// TODO Auto-generated catch block
e1.printStackTrace();
}
try {
conn = DriverManager.getConnection("jdbc:oracle:thin:@10.xx.xx.xx:1521:orcl",
"user", "password");
} catch (SQLException e2) {
// TODO Auto-generated catch block
e2.printStackTrace();
}
return conn;
}

}

至此，基本就改造完成了，那么到底能不能正常用起来？

功能测试

1. 直接连接数据库进行测试

参考RmiJdbc中已有的例子，测试正常。

2. 使用c3p0连接池进行测试

遇到的异常：

java.rmi.ServerException: RemoteException occurred in server thread; nested exception is:
java.rmi.UnmarshalException: error unmarshalling arguments; nested exception is:
java.lang.ClassNotFoundException: com.mchange.v2.c3p0.impl.AuthMaskingProperties (no security manager: RMI class loader disabled)
at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:334)
......

原因：server端缺少c3p0的jar中的类com.mchange.v2.c3p0.impl.AuthMaskingProperties

解决方案：把c3p0的jar加入server端工程即可。

3. 使用dbcp连接池进行测试

遇到的异常：

java.lang.IllegalAccessError: tried to access class org.objectweb.rmijdbc.RJDatabaseMetaDataInterface from class com.sun.proxy.$Proxy1
at com.sun.proxy.$Proxy1.getMetaData(Unknown Source)
at org.objectweb.rmijdbc.RJConnection.getMetaData(Unknown Source)
at org.apache.commons.dbcp.DelegatingConnection.getMetaData(DelegatingConnection.java:345)
at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.getMetaData(PoolingDataSource.java:245)
......

原因：server端找不到类

解决方案：把给客户端的rmi的jar加入server端工程即可。（这个确实很诡异啊）

性能测试

1. 直接使用jdbc连接数据库进行测试

测试用例：使用实际项目的一个简单功能，执行一次查询，获取15条数据，每条数据有5个字段

测试代码：从建立连接，到createStatement,到resultset操作，最后关闭连接

使用RmiJdbc执行1000次的平均查询时间：324ms

不使用RmiJdbc执行1000次的平均查询时间：72ms

性能大幅度降低，已经是用户忍受的极限。

2. 使用spring+dbcp+RmiJdbc进行测试

测试用例：使用实际项目的一个简单功能，执行一次查询，获取15条数据，每条数据有5个字段

测试代码：使用jdbcTemplate.queryForList(sql);

使用RmiJdbc执行1000次的平均查询时间：1089ms

不使用RmiJdbc执行1000次的平均查询时间：92ms

效率严重低下，在用户体验方面无法忍受。

最后结论

即使对spring和dbcp进行源码上的优化，也不会获得很大的性能提升。

因此，放弃使用RmiJdbc，改用其他方式。

PS:改造+测试用时三天，与预想中相差甚远。

RMI调用耗时是不多的，但是由于所有过程都使用RMI，对网络的稳定性要求较高，导致用时太多。

RMI不适用于此种场景。