xiaoxue85 发表于 2018-9-26 10:51:31

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

  检查一个系统,意外发现数据库的v$session_longops中时间远远超过了系统时间。
  查询结果如下:
  $ 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)
  2from 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
  2from 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
  ----------------------------------------------------------
  0recursive calls
  0db block gets
  20274consistent gets
  12867physical reads

  0redo>  75995724bytes sent via SQL*Net to client
  91682bytes received via SQL*Net from client
  8291SQL*Net roundtrips to/from client
  0sorts (memory)
  0sorts (disk)
  124350rows processed
  SQL> set autot off
  SQL> select max(start_time), max(last_update_time)
  2from v$session_longops
  3where 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中记录的时间和系统时间是吻合的。
  下面修改操作系统的时间:
  # date
  Mon Dec 20 15:42:43 CST 2010
  # date -s 20111220
  Tue Dec 20 00:00:00 CST 2011
  # 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
  ----------------------------------------------------------
  0recursive calls
  0db block gets
  20274consistent gets
  12842physical reads

  0redo>  75995724bytes sent via SQL*Net to client
  91682bytes received via SQL*Net from client
  8291SQL*Net roundtrips to/from client
  0sorts (memory)
  0sorts (disk)
  124350rows processed
  SQL> set autot off
  SQL> select max(start_time), max(last_update_time)
  2from v$session_longops
  3where 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中记录的时间都提前了一年,下面将操作系统时间复原:
  # date -s 20101220
  Mon Dec 20 00:00:00 CST 2010
  # 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
  ----------------------------------------------------------
  0recursive calls
  0db block gets
  20274consistent gets
  12867physical reads

  0redo>  75995724bytes sent via SQL*Net to client
  91682bytes received via SQL*Net from client
  8291SQL*Net roundtrips to/from client
  0sorts (memory)
  0sorts (disk)
  124350rows processed
  SQL> set autot off
  SQL> select max(start_time), max(last_update_time)
  2from v$session_longops
  3where 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)
  2from v$session_longops;
  MAX(START_TIME)   MAX(LAST_UPDATE_TIM
  ------------------- -------------------
  SQL> set autot trace stat
  SQL> select * from ndmain.cat_product;
  已选择124350行。
  Statistics
  ----------------------------------------------------------
  0recursive calls
  0db block gets
  0consistent gets
  0physical reads

  0redo>  0bytes sent via SQL*Net to client
  0bytes received via SQL*Net from client
  0SQL*Net roundtrips to/from client
  0sorts (memory)
  0sorts (disk)
  124350rows processed
  SQL> set autot off
  SQL> select max(start_time), max(last_update_time)
  2from 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

页: [1]
查看完整版本: Oracle技术之V$SESSION_LONGOPS超过系统时间