日期:2014-05-17  浏览次数:21030 次

Hibernate+Oracle 获取数据异常——只返回10条
最近在做项目时,发现一个很奇怪的问题,请各位朋友们携手帮助下,谢谢!

现象:
使用 HQL+命名参数 进行分页查询,页大小设为19,第一页有时候出现只返回10条的情况,第二页开始均正常;只要页大小设为大于10条,均只返回10条。

环境:
Hibernate : 3.3.1.GA
ORACLE : 10.2.0.3(32位)
JDBC :ojdbc14 10.2.0.3
JDK : JRockit 1.6

DEBUG信息:
[ui:22:23:13.292] DEBUG [http-8080-5] DefaultPage.reCalcPage(449) | TotalSize=793, PageSize=19, PageCount=42, PageIndex=1
[ui:22:23:13.293] DEBUG [http-8080-5] DefaultPage.fetchPageData(246) | Fetching page data [startIndex:0, fetchCount:19]

在query.list()打断点,查看selection内firstRow=0,maxRows=19,因此数据区间设置无异常。

SQL_TRACE信息
根据上述现象,怀疑是ORACLE的问题,因此在发生现象时,分别做了以下操作来验证:
1、alter system flush shared_pool;
操作完成后,正常显示19条;

2、开启sql_trace想要监控,结果很惊讶
(1)alter system set sql_trace=true scope=both;
操作完成后,正常显示19条;
(2)alter system set sql_trace=false scope=both;
操作完成后,变成现实10条;
(3)再开启、关闭,只要开启就变正常,只要关闭就变10条;

3、启用session级别的10046事件进行监控
CREATE OR REPLACE TRIGGER SYS.SET_TRACE
AFTER LOGON ON DATABASE
WHEN (USER like 'IRP')
DECLARE
BEGIN
  EXECUTE IMMEDIATE 'alter session set statistics_level=ALL';
  EXECUTE IMMEDIATE 'alter session set max_dump_file_size=UNLIMITED';
  EXECUTE IMMEDIATE 'alter session set events ''10046 trace name context forever, level 4''';
END SET_TRACE;
/
开启以后,现象消失;

4、在第三步操作以后,将IRP用户的开启SQL_TRACE监控保留,结果等了1天,10条现象重现了
(1)拿到trc文件以后,查看绑定变量,rownum设置正确,为19;
(2)使用TKPROF分析跟踪文件
命令:tkprof orcl_ora_3248.trc 3248.txt explain=irp/irp@yh73 aggregate=no sys=no waits=yes sort=fchela
注意上面aggregate设置为no,得到tkprof分析后文件3248.txt,打开文件找对应的sql及分析结果如下:
*************************************************************************************************
SQL绑定变量共176个,1~176;

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.01 0.00 0 0 0 0
Fetch 2 0.07 0.08 0 240 0 10
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.09 0.09 0 240 0 10

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 61 (IRP)

Rows Row Source Operation
------- ---------------------------------------------------
  10 COUNT STOPKEY (cr=240 pr=0 pw=0 time=87616 us)
  10 VIEW (cr=240 pr=0 pw=0 time=87598 us)
  10 SORT ORDER BY STOPKEY (cr=240 pr=0 pw=0 time=87565 us)
  229 NESTED LOOPS OUTER (cr=240 pr=0 pw=0 time=86246 us)
  229 HASH JOIN (cr=185 pr=0 pw=0 time=84168 us)
  7526 TABLE ACCESS FULL INVEST_POOL_ITEM (cr=122 pr=0 pw=0 time=7826 us)
  5916 HASH JOIN (cr=63 pr=0 pw=0 time=43103 us)
  612 VIEW VW_SQ_1 (cr=56 pr=0 pw=0 time=34077 us)
  612 HASH UNIQUE (cr=56 pr=0 pw=0 time=32848 us)
  612 HASH JOIN (cr=56 pr=0 pw=0 time=31017 us)
  34 HASH JOIN (cr=49 pr=0 pw=0 time=29929 us)
  1058 TABLE ACCESS FULL STOCK_RESEARCHER_REL (cr=16 pr=0 pw=0 time=51 us)
  4619 MERGE JOIN CARTESIAN (cr=33 pr=0 pw=0 time=16498 us)
  1 TABLE ACCESS BY INDEX ROWID SECURITY_USER (cr=2 pr=0 pw=0 time=45 us)
  1 INDEX RANGE SCAN SECURITY_USER_INDEX_02 (cr=1 pr=0 pw=0 time=28 us)(object id 75405)
  4619