You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user-java@ibatis.apache.org by viren1 <vi...@modius.com> on 2008/10/07 23:14:38 UTC

iBaits is slow with HP nonstop

Hi,
We have ported our application "java/ibatis/jtds jdbcdriver" with MSSQL 2005
db to HP nonstop "java/ibatis/t4mx hpdriver" with SQL/MX db. The big problem
we are facing is it runs slow in HP nonstop.
I have written a junit test to check the timings using our DAO layer with
iBATIS and SimpleDataSource connection pool. In the junit test I just run a
simple query "select 1 from eg.obj where obj_id = 1", 49 times. Just to run
the single query nonstop takes 1000ms VS. windows just the 0ms. 

Any suggestions where could be the problem:

Here is the log connecting to NONSTO DB:
07 Oct 2008 13:16:08:420 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute start
07 Oct 2008 13:16:09:263 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Created connection 27978063.
07 Oct 2008 13:16:09:513 DEBUG [java.sql.Connection] - {conn-100000}
Connection
07 Oct 2008 13:16:09:513 DEBUG [java.sql.Connection] - {conn-100000}
Preparing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:16:09:763 DEBUG [java.sql.PreparedStatement] - {pstm-100001}
Executing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:16:09:763 DEBUG [java.sql.PreparedStatement] - {pstm-100001}
Parameters: []
07 Oct 2008 13:16:09:763 DEBUG [java.sql.PreparedStatement] - {pstm-100001}
Types: []
07 Oct 2008 13:16:09:967 DEBUG [java.sql.ResultSet] - {rset-100002}
ResultSet
07 Oct 2008 13:16:09:982 DEBUG [java.sql.ResultSet] - {rset-100002} Header:
[(EXPR)]
07 Oct 2008 13:16:09:982 DEBUG [java.sql.ResultSet] - {rset-100002} Result:
[1]
07 Oct 2008 13:16:11:138 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Returned connection 27978063 to pool.
07 Oct 2008 13:16:11:138 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute time[0]:2718 ms

07 Oct 2008 13:16:11:138 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute start
07 Oct 2008 13:16:11:154 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Checked out connection 27978063 from pool.
07 Oct 2008 13:16:11:357 DEBUG [java.sql.Connection] - {conn-100003}
Connection
07 Oct 2008 13:16:11:357 DEBUG [java.sql.Connection] - {conn-100003}
Preparing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:16:12:748 DEBUG [java.sql.PreparedStatement] - {pstm-100004}
Executing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:16:12:748 DEBUG [java.sql.PreparedStatement] - {pstm-100004}
Parameters: []
07 Oct 2008 13:16:12:748 DEBUG [java.sql.PreparedStatement] - {pstm-100004}
Types: []
07 Oct 2008 13:16:12:904 DEBUG [java.sql.ResultSet] - {rset-100005}
ResultSet
07 Oct 2008 13:16:12:904 DEBUG [java.sql.ResultSet] - {rset-100005} Header:
[(EXPR)]
07 Oct 2008 13:16:12:904 DEBUG [java.sql.ResultSet] - {rset-100005} Result:
[1]
07 Oct 2008 13:16:14:123 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Returned connection 27978063 to pool.
07 Oct 2008 13:16:14:123 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute time[1]:2985 ms

07 Oct 2008 13:16:14:123 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute start
07 Oct 2008 13:16:14:123 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Checked out connection 27978063 from pool.
07 Oct 2008 13:16:14:263 DEBUG [java.sql.Connection] - {conn-100006}
Connection
07 Oct 2008 13:16:14:263 DEBUG [java.sql.Connection] - {conn-100006}
Preparing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:16:14:420 DEBUG [java.sql.PreparedStatement] - {pstm-100007}
Executing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:16:14:420 DEBUG [java.sql.PreparedStatement] - {pstm-100007}
Parameters: []
07 Oct 2008 13:16:14:420 DEBUG [java.sql.PreparedStatement] - {pstm-100007}
Types: []
07 Oct 2008 13:16:14:560 DEBUG [java.sql.ResultSet] - {rset-100008}
ResultSet
07 Oct 2008 13:16:14:560 DEBUG [java.sql.ResultSet] - {rset-100008} Header:
[(EXPR)]
07 Oct 2008 13:16:14:560 DEBUG [java.sql.ResultSet] - {rset-100008} Result:
[1]
07 Oct 2008 13:16:15:123 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Returned connection 27978063 to pool.
07 Oct 2008 13:16:15:123 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute time[2]:1000 ms

07 Oct 2008 13:16:15:123 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute start
07 Oct 2008 13:16:15:123 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Checked out connection 27978063 from pool.
07 Oct 2008 13:16:15:263 DEBUG [java.sql.Connection] - {conn-100009}
Connection
07 Oct 2008 13:16:15:263 DEBUG [java.sql.Connection] - {conn-100009}
Preparing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:16:15:420 DEBUG [java.sql.PreparedStatement] - {pstm-100010}
Executing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:16:15:420 DEBUG [java.sql.PreparedStatement] - {pstm-100010}
Parameters: []
07 Oct 2008 13:16:15:420 DEBUG [java.sql.PreparedStatement] - {pstm-100010}
Types: []
07 Oct 2008 13:16:15:576 DEBUG [java.sql.ResultSet] - {rset-100011}
ResultSet
07 Oct 2008 13:16:15:576 DEBUG [java.sql.ResultSet] - {rset-100011} Header:
[(EXPR)]
07 Oct 2008 13:16:15:576 DEBUG [java.sql.ResultSet] - {rset-100011} Result:
[1]
07 Oct 2008 13:16:16:123 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Returned connection 27978063 to pool.
07 Oct 2008 13:16:16:123 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute time[3]:1000 ms

07 Oct 2008 13:16:16:123 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute start
07 Oct 2008 13:16:16:123 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Checked out connection 27978063 from pool.
07 Oct 2008 13:16:16:263 DEBUG [java.sql.Connection] - {conn-100012}
Connection
07 Oct 2008 13:16:16:263 DEBUG [java.sql.Connection] - {conn-100012}
Preparing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:16:16:404 DEBUG [java.sql.PreparedStatement] - {pstm-100013}
Executing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:16:16:404 DEBUG [java.sql.PreparedStatement] - {pstm-100013}
Parameters: []
07 Oct 2008 13:16:16:404 DEBUG [java.sql.PreparedStatement] - {pstm-100013}
Types: []
07 Oct 2008 13:16:16:545 DEBUG [java.sql.ResultSet] - {rset-100014}
ResultSet
07 Oct 2008 13:16:16:545 DEBUG [java.sql.ResultSet] - {rset-100014} Header:
[(EXPR)]
07 Oct 2008 13:16:16:545 DEBUG [java.sql.ResultSet] - {rset-100014} Result:
[1]
07 Oct 2008 13:16:17:123 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Returned connection 27978063 to pool.
07 Oct 2008 13:16:17:123 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute time[4]:1000 ms
07 Oct 2008 13:16:17:123 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute start
07 Oct 2008 13:16:17:123 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Checked out connection 27978063 from pool.
07 Oct 2008 13:16:17:310 DEBUG [java.sql.Connection] - {conn-100015}
Connection
07 Oct 2008 13:16:17:310 DEBUG [java.sql.Connection] - {conn-100015}
Preparing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:16:17:482 DEBUG [java.sql.PreparedStatement] - {pstm-100016}
Executing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:16:17:482 DEBUG [java.sql.PreparedStatement] - {pstm-100016}
Parameters: []
07 Oct 2008 13:16:17:482 DEBUG [java.sql.PreparedStatement] - {pstm-100016}
Types: []
07 Oct 2008 13:16:17:623 DEBUG [java.sql.ResultSet] - {rset-100017}
ResultSet
07 Oct 2008 13:16:17:623 DEBUG [java.sql.ResultSet] - {rset-100017} Header:
[(EXPR)]
07 Oct 2008 13:16:17:638 DEBUG [java.sql.ResultSet] - {rset-100017} Result:
[1]
07 Oct 2008 13:16:18:123 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Returned connection 27978063 to pool.
07 Oct 2008 13:16:18:123 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute time[5]:1000 ms


Log for windows connecting to MSSQL 2005:
07 Oct 2008 13:29:56:727 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute start
07 Oct 2008 13:29:56:930 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Created connection 15623809.
07 Oct 2008 13:29:56:930 DEBUG [java.sql.Connection] - {conn-100000}
Connection
07 Oct 2008 13:29:56:946 DEBUG [java.sql.Connection] - {conn-100000}
Preparing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:29:56:977 DEBUG [java.sql.PreparedStatement] - {pstm-100001}
Executing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:29:56:977 DEBUG [java.sql.PreparedStatement] - {pstm-100001}
Parameters: []
07 Oct 2008 13:29:56:977 DEBUG [java.sql.PreparedStatement] - {pstm-100001}
Types: []
07 Oct 2008 13:29:56:977 DEBUG [java.sql.ResultSet] - {rset-100002}
ResultSet
07 Oct 2008 13:29:57:008 DEBUG [java.sql.ResultSet] - {rset-100002} Header:
[]
07 Oct 2008 13:29:57:008 DEBUG [java.sql.ResultSet] - {rset-100002} Result:
[1]
07 Oct 2008 13:29:57:024 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Returned connection 15623809 to pool.
07 Oct 2008 13:29:57:024 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute time[0]:297 ms

07 Oct 2008 13:29:57:024 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute start
07 Oct 2008 13:29:57:024 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Checked out connection 15623809 from pool.
07 Oct 2008 13:29:57:024 DEBUG [java.sql.Connection] - {conn-100003}
Connection
07 Oct 2008 13:29:57:024 DEBUG [java.sql.Connection] - {conn-100003}
Preparing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:29:57:024 DEBUG [java.sql.PreparedStatement] - {pstm-100004}
Executing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:29:57:024 DEBUG [java.sql.PreparedStatement] - {pstm-100004}
Parameters: []
07 Oct 2008 13:29:57:024 DEBUG [java.sql.PreparedStatement] - {pstm-100004}
Types: []
07 Oct 2008 13:29:57:024 DEBUG [java.sql.ResultSet] - {rset-100005}
ResultSet
07 Oct 2008 13:29:57:024 DEBUG [java.sql.ResultSet] - {rset-100005} Header:
[]
07 Oct 2008 13:29:57:024 DEBUG [java.sql.ResultSet] - {rset-100005} Result:
[1]
07 Oct 2008 13:29:57:024 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Returned connection 15623809 to pool.
07 Oct 2008 13:29:57:024 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute time[1]:0 ms

07 Oct 2008 13:29:57:024 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute start
07 Oct 2008 13:29:57:024 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Checked out connection 15623809 from pool.
07 Oct 2008 13:29:57:024 DEBUG [java.sql.Connection] - {conn-100006}
Connection
07 Oct 2008 13:29:57:024 DEBUG [java.sql.Connection] - {conn-100006}
Preparing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:29:57:024 DEBUG [java.sql.PreparedStatement] - {pstm-100007}
Executing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:29:57:024 DEBUG [java.sql.PreparedStatement] - {pstm-100007}
Parameters: []
07 Oct 2008 13:29:57:024 DEBUG [java.sql.PreparedStatement] - {pstm-100007}
Types: []
07 Oct 2008 13:29:57:024 DEBUG [java.sql.ResultSet] - {rset-100008}
ResultSet
07 Oct 2008 13:29:57:024 DEBUG [java.sql.ResultSet] - {rset-100008} Header:
[]
07 Oct 2008 13:29:57:024 DEBUG [java.sql.ResultSet] - {rset-100008} Result:
[1]
07 Oct 2008 13:29:57:024 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Returned connection 15623809 to pool.
07 Oct 2008 13:29:57:024 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute time[2]:0 ms

07 Oct 2008 13:29:57:024 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute start
07 Oct 2008 13:29:57:024 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Checked out connection 15623809 from pool.
07 Oct 2008 13:29:57:024 DEBUG [java.sql.Connection] - {conn-100009}
Connection
07 Oct 2008 13:29:57:024 DEBUG [java.sql.Connection] - {conn-100009}
Preparing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:29:57:024 DEBUG [java.sql.PreparedStatement] - {pstm-100010}
Executing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:29:57:024 DEBUG [java.sql.PreparedStatement] - {pstm-100010}
Parameters: []
07 Oct 2008 13:29:57:024 DEBUG [java.sql.PreparedStatement] - {pstm-100010}
Types: []
07 Oct 2008 13:29:57:024 DEBUG [java.sql.ResultSet] - {rset-100011}
ResultSet
07 Oct 2008 13:29:57:024 DEBUG [java.sql.ResultSet] - {rset-100011} Header:
[]
07 Oct 2008 13:29:57:024 DEBUG [java.sql.ResultSet] - {rset-100011} Result:
[1]
07 Oct 2008 13:29:57:024 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Returned connection 15623809 to pool.
07 Oct 2008 13:29:57:024 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute time[3]:0 ms

07 Oct 2008 13:29:57:024 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute start
07 Oct 2008 13:29:57:024 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Checked out connection 15623809 from pool.
07 Oct 2008 13:29:57:024 DEBUG [java.sql.Connection] - {conn-100012}
Connection
07 Oct 2008 13:29:57:039 DEBUG [java.sql.Connection] - {conn-100012}
Preparing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:29:57:039 DEBUG [java.sql.PreparedStatement] - {pstm-100013}
Executing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:29:57:039 DEBUG [java.sql.PreparedStatement] - {pstm-100013}
Parameters: []
07 Oct 2008 13:29:57:039 DEBUG [java.sql.PreparedStatement] - {pstm-100013}
Types: []
07 Oct 2008 13:29:57:039 DEBUG [java.sql.ResultSet] - {rset-100014}
ResultSet
07 Oct 2008 13:29:57:039 DEBUG [java.sql.ResultSet] - {rset-100014} Header:
[]
07 Oct 2008 13:29:57:039 DEBUG [java.sql.ResultSet] - {rset-100014} Result:
[1]
07 Oct 2008 13:29:57:039 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Returned connection 15623809 to pool.
07 Oct 2008 13:29:57:039 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute time[4]:15 ms

07 Oct 2008 13:29:57:039 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute start
07 Oct 2008 13:29:57:039 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Checked out connection 15623809 from pool.
07 Oct 2008 13:29:57:039 DEBUG [java.sql.Connection] - {conn-100015}
Connection
07 Oct 2008 13:29:57:039 DEBUG [java.sql.Connection] - {conn-100015}
Preparing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:29:57:039 DEBUG [java.sql.PreparedStatement] - {pstm-100016}
Executing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:29:57:039 DEBUG [java.sql.PreparedStatement] - {pstm-100016}
Parameters: []
07 Oct 2008 13:29:57:039 DEBUG [java.sql.PreparedStatement] - {pstm-100016}
Types: []
07 Oct 2008 13:29:57:039 DEBUG [java.sql.ResultSet] - {rset-100017}
ResultSet
07 Oct 2008 13:29:57:039 DEBUG [java.sql.ResultSet] - {rset-100017} Header:
[]
07 Oct 2008 13:29:57:039 DEBUG [java.sql.ResultSet] - {rset-100017} Result:
[1]
07 Oct 2008 13:29:57:039 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Returned connection 15623809 to pool.
07 Oct 2008 13:29:57:039 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute time[5]:0 ms

07 Oct 2008 13:29:57:039 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute start
07 Oct 2008 13:29:57:039 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Checked out connection 15623809 from pool.
07 Oct 2008 13:29:57:039 DEBUG [java.sql.Connection] - {conn-100018}
Connection
07 Oct 2008 13:29:57:039 DEBUG [java.sql.Connection] - {conn-100018}
Preparing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:29:57:039 DEBUG [java.sql.PreparedStatement] - {pstm-100019}
Executing Statement:      SELECT 1 FROM EG.OBJ WHERE OBJ_ID = 1          
07 Oct 2008 13:29:57:039 DEBUG [java.sql.PreparedStatement] - {pstm-100019}
Parameters: []
07 Oct 2008 13:29:57:039 DEBUG [java.sql.PreparedStatement] - {pstm-100019}
Types: []
07 Oct 2008 13:29:57:039 DEBUG [java.sql.ResultSet] - {rset-100020}
ResultSet
07 Oct 2008 13:29:57:039 DEBUG [java.sql.ResultSet] - {rset-100020} Header:
[]
07 Oct 2008 13:29:57:039 DEBUG [java.sql.ResultSet] - {rset-100020} Result:
[1]
07 Oct 2008 13:29:57:039 DEBUG [com.ibatis.common.jdbc.SimpleDataSource] -
Returned connection 15623809 to pool.
07 Oct 2008 13:29:57:039 DEBUG [com.modius.ee.dao.sqlmap.SqlTimingTest] -
----Execute time[6]:0 ms




After enable debugging here are the logs from HP nonstop and windows
version:


-- 
View this message in context: http://www.nabble.com/iBaits-is-slow-with-HP-nonstop-tp19867433p19867433.html
Sent from the iBATIS - User - Java mailing list archive at Nabble.com.