Oracle技术之V$SESSION_LONGOPS超过系统时间

检查一个系统，意外发现数据库的v$session_longops中时间远远超过了系统时间。

查询结果如下：
[oracle@datasd ~]$ sqlplus / as sysdba
SQL*Plus: Release10.2.0.3.0 - Production on星期一12月20 14:57:04 2010
Copyright (c) 1982, 2006, Oracle. All Rights Reserved.

Connected to:
Oracle Database10gEnterprise Edition Release10.2.0.3.0 - 64bit Production
With the Partitioning, OLAP and Data Mining options
SQL> alter session set nls_date_format = 'yyyy-mm-dd hh24:mi:ss';
Session altered.
SQL> select sysdate from dual;
SYSDATE
-------------------
2010-12-20 14:57:22
SQL> select max(start_time), max(last_update_time)
2 from v$session_longops;
MAX(START_TIME) MAX(LAST_UPDATE_TIM
------------------- -------------------
2022-03-25 13:51:24 2022-03-25 13:51:25
从v$session_longops查询的时间比sysdate看到的时间快了20多年。看到这个现象的第一个反应是bug。
于是查询了metalink，看看有没有v$session_longops视图时间变快的记录，把整个metalink翻了个遍也没有找到有价值的信息。
SQL> select instance_name, startup_time
2 from v$instance;
INSTANCE_NAME STARTUP_TIME
---------------- -------------------
shandong 2008-01-15 15:19:28
SQL> host uptime
15:01:21 up 1069 days, 22:12, 2 users, load average: 0.00, 0.00, 0.00
进一步检查系统，发现数据库和系统的启动时间都接近3年了。
由于没有可以借鉴的信息，只能猜测可能导致问题的原因：
一、数据库的bug，导致v$session_longops记录的时间变快；
二、操作系统运行时间超过了500天，导致操作系统或Oracle数据库中某些变量溢出，从而导致了这个问题。
三、操作系统上时间曾经被手工改动过，发现修改错误后，调整回来，但是v$session_longops视图中的时间没有自动回调。
前两种的可能性并不大，因为如果是这两种情况，那么应该是比较普遍的，不太可能metalink中没有任何的记录。
第三种可能性可以自己来模拟一下：
SQL> alter session set nls_date_format = 'yyyy-mm-dd hh24:mi:ss';
会话已更改。
SQL> select sid from v$mystat where rownum = 1;
SID
----------
18
SQL> set autot trace stat
SQL> select * from ndmain.cat_product;
已选择124350行。

Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
20274 consistent gets
12867 physical reads
0 redo size
75995724 bytes sent via SQL*Net to client
91682 bytes received via SQL*Net from client
8291 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
124350 rows processed
SQL> set autot off
SQL> select max(start_time), max(last_update_time)
2 from v$session_longops
3 where sid = 18;
MAX(START_TIME) MAX(LAST_UPDATE_TIM
------------------- -------------------
2010-12-20 15:40:54 2010-12-20 15:41:06
SQL> select sysdate from dual;
SYSDATE
-------------------
2010-12-20 15:41:47
可以看到，现在v$session_longops中记录的时间和系统时间是吻合的。
下面修改操作系统的时间：
[root@localhost ~]# date
Mon Dec 20 15:42:43 CST 2010
[root@localhost ~]# date -s 20111220
Tue Dec 20 00:00:00 CST 2011
[root@localhost ~]# date -s 17:35:00
Tue Dec 20 17:35:00 CST 2011
将系统时间调快一年，然后查询系统时间，并构造长操作，检查v$session_longops中记录的时间：
SQL> select sysdate from dual;
SYSDATE
-------------------
2011-12-20 17:35:11
SQL> set autot trace stat
SQL> select * from ndmain.cat_product;
已选择124350行。

Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
20274 consistent gets
12842 physical reads
0 redo size
75995724 bytes sent via SQL*Net to client
91682 bytes received via SQL*Net from client
8291 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
124350 rows processed
SQL> set autot off
SQL> select max(start_time), max(last_update_time)
2 from v$session_longops
3 where sid = 18;
MAX(START_TIME) MAX(LAST_UPDATE_TIM
------------------- -------------------
2011-12-20 17:35:29 2011-12-20 17:35:43
由于操作系统的时间改变，因此Oracle中sysdate和v$session_longops中记录的时间都提前了一年，下面将操作系统时间复原：
[root@localhost ~]# date -s 20101220
Mon Dec 20 00:00:00 CST 2010
[root@localhost ~]# date -s 17:36:00
Mon Dec 20 17:36:00 CST 2010
再次检查操作系统时间和v$session_longops中记录的时间：
SQL> select sysdate from dual;
SYSDATE
-------------------
2010-12-20 17:36:18
SQL> set autot trace stat
SQL> select * from ndmain.cat_product;
已选择124350行。

Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
20274 consistent gets
12867 physical reads
0 redo size
75995724 bytes sent via SQL*Net to client
91682 bytes received via SQL*Net from client
8291 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
124350 rows processed
SQL> set autot off
SQL> select max(start_time), max(last_update_time)
2 from v$session_longops
3 where sid = 18;
MAX(START_TIME) MAX(LAST_UPDATE_TIM
------------------- -------------------
2011-12-21 11:15:25 2011-12-21 11:15:43
可以看到，Oracle中的sysdate和操作系统中保持一致，而v$session_longops中不仅没有回到正常时间值，反而又向前增加了。
其实这与v$session_longops视图的性能有关，Oracle不允许这个时间递增的视图出现时间回退的现象，所以这个视图记录的时间永远会增加，而不会随着sysdate时间回退而减少。
解决这个问题最好的方法就是重启数据库，由于v$session_longops是动态视图，本质是Oracle底层代码实现的SQL接口，并不是保存在数据库中的数据，因此重启后这些不正常的数据应该会被清除掉：
SQL> conn / as sysdba
已连接。
SQL> shutdown immediate
数据库已经关闭。
已经卸载数据库。
ORACLE例程已经关闭。
SQL> startup
ORACLE例程已经启动。
Total System Global Area 1192827100 bytes
Fixed Size 452828 bytes
Variable Size 352321536 bytes
Database Buffers 838860800 bytes
Redo Buffers 1191936 bytes
数据库装载完毕。
数据库已经打开。
SQL> alter session set nls_date_format = 'yyyy-mm-dd hh24:mi:ss';
会话已更改。
SQL> select sysdate from dual;
SYSDATE
-------------------
2010-12-20 17:48:19
SQL> select max(start_time), max(last_update_time)
2 from v$session_longops;
MAX(START_TIME) MAX(LAST_UPDATE_TIM
------------------- -------------------

SQL> set autot trace stat
SQL> select * from ndmain.cat_product;
已选择124350行。

Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
0 consistent gets
0 physical reads
0 redo size
0 bytes sent via SQL*Net to client
0 bytes received via SQL*Net from client
0 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
124350 rows processed
SQL> set autot off
SQL> select max(start_time), max(last_update_time)
2 from v$session_longops;
MAX(START_TIME) MAX(LAST_UPDATE_TIM
------------------- -------------------
2010-12-20 17:48:49 2010-12-20 17:49:01
SQL> select sysdate from dual;
SYSDATE
-------------------
2010-12-20 17:50:05
可以看到，重启数据库后，问题消失。

oracle视频教程请关注:http://u.youku.com/user_video/id_UMzAzMjkxMjE2.html