V$SESSION_LONGOPS超過系統時間

yangtingkun發表於2010-12-29

檢查一個系統,意外發現資料庫的v$session_longops中時間遠遠超過了系統時間。

 

 

查詢結果如下:

[oracle@datasd ~]$ sqlplus / as sysdba

SQL*Plus: Release 10.2.0.3.0 - Production on 星期一 12 20 14:57:04 2010

Copyright (c) 1982, 2006, Oracle.  All Rights Reserved.


Connected to:
Oracle Database 10g Enterprise Edition Release 10.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

由於作業系統的時間改變,因此Oraclesysdatev$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

可以看到,重啟資料庫後,問題消失。

 

來自 “ ITPUB部落格 ” ,連結:http://blog.itpub.net/4227/viewspace-682840/,如需轉載,請註明出處,否則將追究法律責任。

相關文章