一次ORA-942错误的跟踪（三）

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

进一步深入研究问题的产生原因。

一次ORA-942错误的跟踪（一）：http://yangtingkun.itpub.net/post/468/480559

一次ORA-942错误的跟踪（二）：http://yangtingkun.itpub.net/post/468/480671

 

 

上一篇文章中，已经将问题定位到了共享池。共享池的内存结构太过复杂，不过问题既然和个别的SQL语句有关，不妨先顺着这个思路走下去。

根据JAVA程序运行捕获的出错SQL语句，除了上面两篇文章提到的select * from usr_action 外，还有一些其他的，比如：select * from usr_module 。

由于前面做了大量的测试，都是基于USR_ACTION表的，会导致共享池中包含太多不同的SQL，所以下面的测试中使用另一个报错的SQL语句：select * from usr_module 来进行查询。查询V$SQL中的语句信息：

SQL> COL SQL_TEXT FORMAT A30
SQL> SELECT SQL_TEXT, FIRST_LOAD_TIME, LAST_LOAD_TIME
  2  FROM V$SQL
  3  WHERE SQL_TEXT = 'select * from usr_module '
  4  AND PARSING_SCHEMA_NAME = 'TJSQ_TRADE';

SQL_TEXT                       FIRST_LOAD_TIME         LAST_LOAD_TIME
------------------------------ ----------------------- --------------------
select * from usr_module       2009-03-07/07:55:56     2009-03-18/09:39:51

可以看到，这个SQL最后一次装载时间就是当前的时间，这并没有问题，但是这个SQL语句的第一次加载时间是有问题的，这个时间居然是当前时间之前10天左右。而这个用户不够才建立了两天而已：

SQL> SELECT USERNAME, CREATED
  2  FROM DBA_USERS
  3  WHERE USERNAME = 'TJSQ_TRADE';

USERNAME                       CREATED
------------------------------ -------------------
TJSQ_TRADE                     2009-03-16 14:29:32

可以看到，这个TJSQ_TRADE用户的建立时间居然要比这个SQL的FIRST_LOAD_TIME装载时间还晚，这是有问题的。当然访问的对象并不是TJSQ_TRADE用户下的，如果从这一点考虑还要检查一下TJSQ_NDMAIN用户的创建时间：

SQL> SELECT USERNAME, CREATED
  2  FROM DBA_USERS
  3  WHERE USERNAME = 'TJSQ_NDMAIN';

USERNAME                       CREATED
------------------------------ -------------------
TJSQ_NDMAIN                    2009-03-16 13:30:03

很明显，这个SQL的装载时间也远远早于TJSQ_NDMAIN用户的创建时间，这个显然就无法解释了。

在第一篇文章中提到过TJSQ_NDMAIN和TJSQ_TRADE是从BJSQ_NDMAIN和BJSQ_TRADE导入并REMAP_SCHEMA得到的，莫非这个SQL的装载时间还有BJSQ的用户有关：

SQL> SELECT USERNAME, CREATED
  2  FROM DBA_USERS
  3  WHERE USERNAME IN ('BJSQ_NDMAIN', 'BJSQ_TRADE');

USERNAME                       CREATED
------------------------------ -------------------
BJSQ_TRADE                     2009-03-06 14:57:21
BJSQ_NDMAIN                    2009-03-06 14:57:20

检查发现，这个时间果然是在BJSQ_TRADE和BJSQ_NDMAIN用户建立之后。而且从时间上看也比较接近：

SQL> SELECT SQL_TEXT, FIRST_LOAD_TIME, LAST_LOAD_TIME
  2  FROM V$SQL
  3  WHERE SQL_TEXT = 'select * from usr_module '
  4  AND PARSING_SCHEMA_NAME = 'BJSQ_TRADE';

SQL_TEXT                       FIRST_LOAD_TIME               LAST_LOAD_TIME
------------------------------ ----------------------------- ----------------------------
select * from usr_module       2009-03-07/07:55:56           2009-03-07/09:14:18

检查BJSQ_TRADE用户，同样的SQL的加载时间，可以发现居然和前面TJSQ_TRADE的加载时间是一样的，这可不太可能是巧合。

显然这里面隐藏着一个更深层次的问题。

进一步发现，同样的SQL如果在TJSQ_NDMAIN用户下执行，不会报错：

SQL> CONN TJSQ_NDMAIN
Enter password:
Connected.
SQL> set autot trace
SQL> select * from usr_action ;

594 rows selected.

Execution Plan
----------------------------------------------------------

---------------------------------------------------------------------
| Id  | Operation         | Name       | Rows  | Bytes | Cost (%CPU)|
---------------------------------------------------------------------
|   0 | SELECT STATEMENT  |            |   594 | 43956 |     4   (0)|
|   1 |  TABLE ACCESS FULL| USR_ACTION |   594 | 43956 |     4   (0)|
---------------------------------------------------------------------

Note
-----
   - 'PLAN_TABLE' is old version

Statistics
----------------------------------------------------------
          1  recursive calls
          0  db block gets
         46  consistent gets
          0  physical reads
          0  redo size
      46776  bytes sent via SQL*Net to client
        921  bytes received via SQL*Net from client
         41  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
        594  rows processed

更有趣的是，再次使用TJSQ_TRADE来进行访问，问题同样消失了。

SQL> CONN TJSQ_TRADE
Enter password:
Connected.
SQL> set autot trace
SQL> select * from usr_action ;

594 rows selected.

Execution Plan
----------------------------------------------------------
Plan hash value: 1947357366

--------------------------------------------------------------------------------
| Id  | Operation         | Name       | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |            |   594 | 43956 |     4   (0)| 00:00:01 |
|   1 |  TABLE ACCESS FULL| USR_ACTION |   594 | 43956 |     4   (0)| 00:00:01 |
--------------------------------------------------------------------------------

Statistics
----------------------------------------------------------
          0  recursive calls
          0  db block gets
         46  consistent gets
          0  physical reads
          0  redo size
      46776  bytes sent via SQL*Net to client
        921  bytes received via SQL*Net from client
         41  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
        594  rows processed

对比两个用户执行SQL的统计信息不难发现，TJSQ_NDMAIN用户执行这个SQL的时候，出现了一次递归调用，而TJSQ_TRADE用户则没有，这显然说明TJSQ_NDMAIN用户在执行这个SQL的时候重新对SQL进行了分析。由于重新分析，解决了共享池中SQL错误的问题，于是随后TJSQ_TRADE用户访问的时候，也不会再出现这个错误。

TJSQ_TRADE用户执行报错，而TJSQ_NDMAIN执行同样的SQL，Oracle通过重新分析解决了这个错误。访问同一张表，二者的区别在于，这张表是保存在TJSQ_NDMAIN用户下的，而TJSQ_TRADE用户则是同义词。看来问题和同义词还有一定的关系。

根据现在的分析结果，问题似乎和同义词有关，还与TJSQ_TRADE的模板原型用户TJSQ_TRADE用户有关。似乎问题越来越复杂了。

 

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

转载于:http://blog.itpub.net/4227/viewspace-573270/