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

xiaoxue85

　　检查一个系统，意外发现数据库的v$session_longops中时间远远超过了系统时间。
　　查询结果如下：
　　[oracle@datasd ~]$ sqlplus / as sysdba

　　SQL*Plus:>　　Copyright (c) 1982, 2006, Oracle.  All Rights Reserved.
　　Connected to:

　　Oracle Database10gEnterprise Edition>　　With the Partitioning, OLAP and Data Mining options

　　SQL>>
　　Session>　　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>>　　会话已更改。
　　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>　　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>　　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>　　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>
　　Variable>　　Database Buffers          838860800 bytes
　　Redo Buffers                1191936 bytes
　　数据库装载完毕。
　　数据库已经打开。

　　SQL>>　　会话已更改。
　　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>　　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