ITPub博客

首页 > Linux操作系统 > Linux操作系统 > 一次ORA-942错误的跟踪(一)

一次ORA-942错误的跟踪(一)

原创 Linux操作系统 作者:yangtingkun 时间:2009-03-18 23:06:18 0 删除 编辑

今天碰到一个很有意思的错误,通过JAVA程序连接数据库,运行程序时报错,错误信息就是ORA-00942: table or view does not exist

简单描述错误现象和问题初步诊断。

 

 

根据程序员的描述,SQL运行时报错ORA-942,如果将SQL语句中的表名改为大写,就不会报错了。

听到这个现象描述,第一个反应就是表名大小写的问题。

不过现在现象有点奇怪,表名小写的时候并没有加上双引号。那么Oracle自动会将这个语句转化为大写,所以应该和表名大写的SQL没有区别才对。

观察了一下程序的执行,当程序执行到select * from usr_action语句的时候,出现了这个ORA-942错误。而如果将SQL改为select * from USR_ACTION,则不会有问题,这个SQL可以顺利的执行。

更奇怪的是,这个问题似乎只对JAVA程序才会出现,在sqlplussqldeveloper中,不会出现同样的问题。

看来问题不是简单的表名大小写的问题,问题显然要复杂得多。

下面简单描述一下当前的环境,由于这个环境恰好是一个同事在我指导下完成的,所以我对这个环境还比较了解。

程序连接的用户是TJSQ_TRADE,程序访问的表包括两部分,一部分就是TJSQ_TRADE这个SCHEMA中的表,另一部分是TJSQ_NDMAIN用户中的表,这部分表在TJSQ_TRADE中建立同义词,并有TJSQ_NDMAIN用户将这些表的访问权限赋给了TJSQ_TRADE用户。

下面在说说这两个用户是怎样建立的,在这两个用户建立之前,系统中建立过结构完全相同的用户:BJSQ_TRADEBJSQ_NDMAIN。这次要新建结构完全相同的两个用户,于是采用了数据泵的方式导出BJSQ_TRADEBJSQ_NDMAIN两个用户的源数据,并采用REMAP_TABLESPACEREMAP_SCHEMA方式导入到TJSQ_TRADETJSQ_NDMAIN用户中。

无论是程序还是数据结构都是相同的,那么同样的问题没有发生在BJSQ_TRADE用户中,而发生在TJSQ_TRADE中,说明问题很可能和这个用户的生成方式有关系。不过数据泵REMAP_SCHEMA方式以前也做过很多次,从来没有碰到过类似的问题,虽然这次并不是我自己动手操作的,但是大部分关键步骤都是在我指导下进行的,应该不会有什么大问题。如果问题确实与用户的生成方式有关,那么不是当前的环境的特殊性导致的问题,就是数据泵导出导入过程中和以往有一些小的差异,从而导致了问题的产生。

通过DBMS_METADATA获取源数据的方法,对比了BJSQ_TRADETJSQ_TRADE的同义词,以及BJSQ_NDMAINTJSQ_NDMAIN方案下的表,没有发现任何的区别。看来至少当前环境中,新建用户TJSQ_NDMAINTJSQ_TRADE与老用户BJSQ_NDMAINBJSQ_TRADE没有区别。对比环境的不同找不到什么线索,那么看看能否从错误信息着手。

对于这种错误,最简单的办法是通过TRACE的方式来看看Oracle在运行这个SQL的时候到底发生了什么。不过由于在SQLPLUS中没有重现错误,导致诊断问题变得很麻烦,必须配合JAVA程序一起联合进行诊断。由于JAVA程序使用了连接池,导致一旦程序启动,就会有多个会话同时连接到数据库中,因此很难判断到底哪个会话会执行出错的SQL语句。当然可以修改程序,在运行出错的SQL前面运行ALTER SESSION SET SQL_TRACE = TRUE。但是还是由于连接池的特性,无法保证ALTER SESSION语句与随后的select语句在同一个会话上执行。随意修改程序的方法是行不通的。还有一个办法,就是修改中间件连接池,使得程序只有一个会话连接到Oracle数据库中。不过现在还没有定位问题的真正原因,且目前来看问题似乎和JAVA程序有关,现在还无法排除中间件的问题,直接贸然修改其他的配置和可能会导致测试结果改变。

如果在数据库级设置SQL_TRACE,不但会产生大量的无用trace,也会给进一步分析问题带来麻烦。配合JAVA程序的断点单步调试,利用DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION过程最为合适:

SQL> SELECT SID, SERIAL#
  2  FROM V$SESSION
  3  WHERE USERNAME = 'TJSQ_TRADE'
  4  AND MACHINE = 'kylin-TinkPad';

       SID    SERIAL#
---------- ----------
       129       2494
       130        224
       147      14635

SQL> SELECT SPID FROM V$PROCESS
  2  WHERE ADDR IN (SELECT PADDR FROM V$SESSION WHERE SID IN (129, 130, 147));

SPID
------------
595
744
746

SQL> EXEC DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION(129, 2494, TRUE)

PL/SQL procedure successfully completed.

SQL> EXEC DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION(130, 224, TRUE)

PL/SQL procedure successfully completed.

SQL> EXEC DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION(147, 14635, TRUE)

PL/SQL procedure successfully completed.

通过查询V$SESSION,并指定应用服务器的连接的主机名和连接用户名称,定位JAVA程序连接到Oracle的会话,为了方便查找生成的trace文件,这里还查询对应操作系统的进程ID

随后分别为3个会话设置SQL_TRACE,然后运行JAVA程序继续运行,执行报错的SQL语句:select * from usr_action。神奇的事情发生了,这次JAVA程序中没有报错。而检查后台对应trace文件,也可以看到这个语句成功执行了:

$ more newdemo_ora_744.trc
/data/oracle/admin/newdemo/udump/newdemo_ora_744.trc
Oracle Database 10g Enterprise Edition Release 10.2.0.3.0 - 64bit Production
With the Partitioning, OLAP and Data Mining options
ORACLE_HOME = /data/oracle/product/10.2
System name:    Linux
Node name:      yans2
Release:        2.6.9-42.0.0.0.1.ELsmp
Version:        #1 SMP Sun Oct 15 15:13:57 PDT 2006
Machine:        x86_64
Instance name: newdemo
Redo thread mounted by this instance: 1
Oracle process number: 37
Unix process pid: 744, image: oraclenewdemo@yans2

*** 2009-03-18 09:47:08.552
*** SERVICE NAME:(SYS$USERS) 2009-03-18 09:47:08.552
*** SESSION ID:(147.14635) 2009-03-18 09:47:08.552
=====================
PARSING IN CURSOR #2 len=25 dep=0 uid=104 ct=3 lid=104 tim=1208340652883521 hv=1367961303 ad='6ee009b0'
select * from usr_action
END OF STMT
PARSE #2:c=0,e=188,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=1208340652883516
EXEC #2:c=0,e=35,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=1208340652883819
FETCH #2:c=0,e=127,p=0,cr=3,cu=0,mis=0,r=10,dep=0,og=1,tim=1208340652897864
*** 2009-03-18 09:55:14.856
FETCH #2:c=0,e=77,p=0,cr=1,cu=0,mis=0,r=10,dep=0,og=1,tim=1208341127789416
FETCH #2:c=0,e=44,p=0,cr=1,cu=0,mis=0,r=10,dep=0,og=1,tim=1208341127805165
FETCH #2:c=0,e=34,p=0,cr=1,cu=0,mis=0,r=10,dep=0,og=1,tim=1208341127819547
FETCH #2:c=0,e=35,p=0,cr=1,cu=0,mis=0,r=10,dep=0,og=1,tim=1208341127831599
FETCH #2:c=0,e=31,p=0,cr=1,cu=0,mis=0,r=10,dep=0,og=1,tim=1208341127843581
.
.
.
FETCH #2:c=0,e=34,p=0,cr=1,cu=0,mis=0,r=10,dep=0,og=1,tim=1208341128460244
FETCH #2:c=0,e=30,p=0,cr=1,cu=0,mis=0,r=10,dep=0,og=1,tim=1208341128473093
FETCH #2:c=0,e=47,p=0,cr=2,cu=0,mis=0,r=4,dep=0,og=1,tim=1208341128485355
STAT #2 id=1 cnt=594 pid=0 pos=1 bj=120997 p='TABLE ACCESS FULL USR_ACTION (cr=65 pr=0 pw=0 time=670 us)'
=====================

没有想到的是,由于TRACE的出现,居然改变了SQL语句行为,使得原本报错的SQL,现在可以顺利执行了。为了验证是否确实是TRACE影响了测试的结果,关闭会话的SQL_TRACE,再次运行JAVA程序,错误再次出现。根据上面的方法再次设置SQL_TRACE,错误又再次消失了。

这个问题太神奇了,如果你想通过数据库的一些手段来观察、监测它,它就不出现了。而你去掉监测的方法,它又冒出来了。

 

 

来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/4227/viewspace-571488/,如需转载,请注明出处,否则将追究法律责任。

请登录后发表评论 登录
全部评论
暂无介绍

注册时间:2007-12-29

  • 博文量
    1955
  • 访问量
    10438726