我有一些中间件java代码在服务器机器上运行,该机器在远程机器上的Postgresql数据库(9.1)中调用存储过程insertMessageOne
。
PreparedStatement sendOne = con.prepareStatement(
"SELECT insertMessageOne(?, ?, ?, ?, ?, ?)");
// Following is the call to Stored procedure through PreparedStatement sendOne
long start = System.nanoTime();
ResultSet rs = sendOne.executeQuery();
long end = System.nanoTime();
long elapsed = (end - start)/1000000;
fileLog.write(System.currentTimeMillis() + ": " + "sendOne.executeQuery(): " + elapsed + "n");
从日志中,我可以看到executeQuery需要几十毫秒的时间。
1385732177920: sendOne.executeQuery(): 13
1385732178331: sendOne.executeQuery(): 20
1385732178436: sendOne.executeQuery(): 23
但是,对于存储过程insertMessageOne(代码如下):
CREATE OR REPLACE FUNCTION insertMessageOne(sender_id INT, receiver_id INT, queue_id INT, context INT, priority INT, text varchar(2000))
RETURNS BOOLEAN
AS $$
DECLARE
start timestamp;
stop timestamp;
BEGIN
start = clock_timestamp();
INSERT INTO message(sender_id, receiver_id, queue_id, context, priority, text) VALUES($1,$2,$3,$4,$5,$6);
stop = clock_timestamp();
RAISE NOTICE 'Timestamp: (%) senderId: (%) insertMessageOne: (%)', stop, sender_id, stop - start;
RETURN TRUE;
EXCEPTION
WHEN OTHERS THEN
RAISE NOTICE 'EXCEPTION: INSERT SINGLE-Q MESSAGE FAILED';
RETURN FALSE;
END;
$$ LANGUAGE plpgsql;
在日志中看到的存储过程的执行时间非常短(小于1-2ms):
NOTICE: Timestamp: (2013-11-29 15:29:06.012125) senderId: (49) insertMessageOne: (00:00:00.000684)
NOTICE: Timestamp: (2013-11-29 15:29:06.012848) senderId: (16) insertMessageOne: (00:00:00.000702)
NOTICE: Timestamp: (2013-11-29 15:29:06.013465) senderId: (10) insertMessageOne: (00:00:00.000617)
为什么executeQuery的执行时间与存储过程的相应执行时间相比如此之大?在这种情况下,网络延迟/带宽不应该是一个问题,因为代码是在集群中的机器上运行的(彼此直接连接)。是否有一些步骤(在executeQuery()
调用和存储过程insertMessageOne()
的实际执行之间)需要我考虑?
从函数内部测量的INSERT持续时间不包括提交,因为postgres从不在函数内部隐式提交(甚至显式提交,如果尝试,commit语句会在函数内部引发错误)。
如果JDBC连接处于autoCommit模式,这意味着从服务器的角度来看,客户端没有发出启动事务的SQL BEGIN
,那么postgres将在查询期间为自己创建一个"内部"事务,并在其结束时提交。
10-20ms是在普通磁盘上提交所需的典型时间,因此它似乎可以解释您所看到的时间差。
如果您将一系列INSERT分组在一个事务中,则延迟应该要低得多(仍有评论中讨论的网络开销)