首页 » ORACLE 9i-23ai, 系统相关 » Troubleshooting ORA-00600 [kjucvl:!busy], [8] crash & Different datetime between RAC nodes after restart
Troubleshooting ORA-00600 [kjucvl:!busy], [8] crash & Different datetime between RAC nodes after restart
最近一套oracle 11.2.0.3 2-nodes RAC on AIX环境数据库，触发ora-600 [kjucvl:!busy] 和 ORA-00600: , : [kjuscv]后db instance crash, 但重启后使用plsql dev客户连接实例的两个节点，sysdate返回不同的时间，同时从db alert log 的时间也能发现实例重启后日志倒退了8小时，看来还是timezone问题，简单记录。
ora-600 [kjucvl:!busy]
db alert log
Fri Sep 22 06:17:18 2023 Archived Log entry 844030 added for thread 2 sequence 367216 ID 0xffffffffd6759d0b dest 1: Fri Sep 22 06:26:05 2023 Thread 2 advanced to log sequence 367218 (LGWR switch) Current log# 6 seq# 367218 mem# 0: +DATACT/anbob/onlinelog/group_6.402.1063887011 Fri Sep 22 06:26:16 2023 Archived Log entry 844032 added for thread 2 sequence 367217 ID 0xffffffffd6759d0b dest 1: Fri Sep 22 06:28:13 2023 ERROR: Unable to normalize symbol name for the following short stack (at offset 411): dbgexProcessError()+180<-dbgeExecuteForError()+72<-dbgePostErrorKGE()+2048<-dbkePostKGE_kgsf()+68<-kgeadse()+380<-kgerinv_internal()+48<-kgerinv()+48<-kserin()+76<-kjucvl()+1168<-kjuscv()+5384<-ksipcon_v()+1516<-k2qsod()+1460<-kssxdl()+472<-kssdel()+724<-kssdch()+5732<-ksuxds()+940<-kssxdl()+472<-kssdel()+724<-kssdch()+5732<-ksudlp()+792<-kssxdl()+472<-kssdel()+724<-ksuxdl()+456<-ksuxda_del_proc()+188<-IPRA.$ksucln_dpc_cleanup()+272<-IPRA.$ksucln_dpc_dfs()+268<-ksucln_dpc_main()+892<-ksucln_dpc()+36<-ksucln()+1340<-ksbrdp()+2044<-opirip()+1624<-opidrv()+608<-sou2o()+136<-opimai_real()+188<-ssthrdmain()+268<-main()+204<-__start()+112 Errors in file /u01/app/oracle/diag/rdbms/anbob/anbob2/trace/anbob2_pmon_30737378.trc (incident=457647): ORA-00600: , : [kjucvl:!busy], [8], [], [], [], [], [], [], [], [], [], [] Incident details in: /u01/app/oracle/diag/rdbms/anbob/anbob2/incident/incdir_457647/anbob2_pmon_30737378_i457647.trc Use ADRCI or Support Workbench to package the incident. See Note 411.1 at My Oracle Support for error and packaging details. Fri Sep 22 06:28:16 2023 Dumping diagnostic data in directory=[cdmp_20230922062816], requested by (instance=2, osid=30737378 (PMON)), summary=[incident=457647]. Errors in file /u01/app/oracle/diag/rdbms/anbob/anbob2/trace/anbob2_pmon_30737378.trc (incident=457648): ORA-00600: , : [kjuscv], [6], [], [], [], [], [], [], [], [], [], [] ORA-00600: , : [kjucvl:!busy], [8], [], [], [], [], [], [], [], [], [], [] Incident details in: /u01/app/oracle/diag/rdbms/anbob/anbob2/incident/incdir_457648/anbob2_pmon_30737378_i457648.trc Fri Sep 22 06:28:17 2023 Sweep [inc][457648]: completed Sweep [inc][457647]: completed Sweep [inc2][457647]: completed Use ADRCI or Support Workbench to package the incident. See Note 411.1 at My Oracle Support for error and packaging details. Errors in file /u01/app/oracle/diag/rdbms/anbob/anbob2/trace/anbob2_pmon_30737378.trc: ORA-00600: , : [kjuscv], [6], [], [], [], [], [], [], [], [], [], [] ORA-00600: , : [kjucvl:!busy], [8], [], [], [], [], [], [], [], [], [], [] PMON (ospid: 30737378): terminating the instance due to error 472 Thu Sep 21 22:28:20 2023 ORA-1092 : opitsk aborting process Thu Sep 21 22:28:20 2023 License high water mark = 468 Fri Sep 22 06:28:25 2023 Instance terminated by PMON, pid = 30737378 USER (ospid: 33685796): terminating the instance Instance terminated by USER, pid = 33685796 Thu Sep 21 22:28:47 2023 <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<ora-600 DB crash, 后时间倒退。 Adjusting the default value of parameter parallel_max_servers from 2560 to 1485 due to the value of parameter processes (1500) Starting ORACLE instance (normal) LICENSE_MAX_SESSION = 0 LICENSE_SESSIONS_WARNING = 0 Private Interface 'en4' configured from GPnP for use as a private interconnect. [name='en4', type=1, ip=169.254.248.187, mac=5c-f3-fc-ea-6c-22, net=169.254.0.0/16, mask=255.255.0.0, use=haip:cluster_interconnect/62] Public Interface 'en8' configured from GPnP for use as a public interface. [name='en8', type=1, ip=10.180.38.170, mac=5c-f3-fc-ea-6b-62, net=10.180.38.160/27, mask=255.255.255.224, use=public/1] Public Interface 'en8' configured from GPnP for use as a public interface. [name='en8', type=1, ip=10.180.38.171, mac=5c-f3-fc-ea-6b-62, net=10.180.38.160/27, mask=255.255.255.224, use=public/1] Picked latch-free SCN scheme 3 Autotune of undo retention is turned on. LICENSE_MAX_USERS = 0 SYS auditing is disabled Starting up: Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production With the Partitioning, Real Application Clusters, OLAP, Data Mining and Real Application Testing options. ORACLE_HOME = /u01/app/oracle/product
Note：
根据switch log #能判断确实是时间倒退，而不是日志输出错误。
Dump continued from file: /u01/app/oracle/diag/rdbms/yndatact/yndatact2/trace/yndatact2_pmon_30737378.trc
ORA-00600: 内部错误代码, 参数: [kjuscv], [6], [], [], [], [], [], [], [], [], [], []
ORA-00600: 内部错误代码, 参数: [kjucvl:!busy], [8], [], [], [], [], [], [], [], [], [], []
kgeasnmierr()+72 call kgerinv() 000000001 ? 000000079 ?
000000000 ? 700000000013600 ?
000000011 ? 0EF2028AA ?
10B07A5FC ? 000000258 ?
kjuscv()+9828 call kgeasnmierr() 7000009899E2958 ? 000000000 ?
1000F021C ? 100000001 ?
000000000 ? 000000006 ?
000000000 ? 10B10A390 ?
ksipcon_v()+1516 call kjuscv() 7000009899E2958 ?
500000000000000 ?
7910BE65F8 ? 000000000 ?
700000956A88F94 ? 000000000 ?
000000000 ? 000000000 ?
k2qsod()+1460 call ksipcon_v() 11065A568 ? 1106D3EA0 ?
FFFFFFFFFFF8BD0 ? 000000000 ?
7000005AE891840 ? 000000000 ?
000000000 ? 7000008506FB3C0 ?
kssxdl()+472 call k2qsod() 000000000 ? 000000000 ?
000000000 ? 000000000 ?
000000000 ? 000000000 ?
FFFFFFFFFFF88C0 ? 000000000 ?
kssdel()+724 call kssxdl() 700000956A88F18 ? 38D830190 ?
FFFFFFFFFFFFFFFF ?
10B0B01E0 ? 000000003 ?
000000000 ? 000000001 ?
10B0B0290 ?
kssdch()+5732 call kssdel() FFFFFFFFFFF8E50 ? 000000000 ?
Note:
根据错误与call stack判断是Bug 11868640 – ORA-600 [kjucvl:!busy] possible in PMON in RAC。
RAC间节点时间不一致
上面可见oracle db alert log日志输出时间不对，据客户反馈之前也发生过，使用plsql dev客户端连接Oracle RAC 两个节点，sysdate函数在节点2返回的时间比实际晚了8小时，而节点1时间正常。
# 查询实例1
#查询实例2
和本次现象较一致，同样是instance 2时间后退了8小时.
Sysdate: returns the current date and time set for the operating system on which the database server resides.
Systimestamp ：returns the current system date, including fractional seconds and time zone of the system of which the database server resides.
Localtimestamp: returns the current date and time in the session time zone
Current_date: returns the current date in the session on the Client time zone.
Dbtimezone: returns the value for the database time zone.
Sessiontimezone: return the value of the current session‘s timezone
SYSDATE 和 SYSTIMESTAMP 函数只是对服务器操作系统执行系统调用来获取时间（“gettimeofday”调用）。服务器操作系统 (Unix) 时区设置会影响操作系统传递给 Oracle 并由 SYSDATE 和 SYSTIMESTAMP 返回的时间。没有任何“Oracle 数据库”参数/init.ora 设置会影响 SYSDATE 和 SYSTIMESTAMP 时区（= 给出的结果位于操作系统时区设置之外的其他时区）。
“SYSDATE”和“SYSTIMESTAMP”不使用数据库中的 Oracle 时区信息（“Oracle RDBMS dst 补丁”）。“SYSDATE”和“SYSTIMESTAMP”不受 DBTIMEZONE / SESSIONTIMEZONE 设置的影响。
DB层查看TIMEZONE
SQL> @printtab "select sysdate,systimestamp, localtimestamp,current_date, dbtimezone,sessiontimezone from dual"; SYSDATE : 28-sep-2023 18:46:03 SYSTIMESTAMP : 28-SEP-23 06.46.03.340024 PM +08:00 LOCALTIMESTAMP : 28-SEP-23 06.46.03.340026 PM CURRENT_DATE : 28-sep-2023 18:46:03 DBTIMEZONE : +08:00 SESSIONTIMEZONE : +08:00 ----------------- PL/SQL procedure successfully completed. SQL> @printtab "select * from database_properties where PROPERTY_NAME like ''%TIME%''"; PROPERTY_NAME : NLS_TIMESTAMP_TZ_FORMAT PROPERTY_VALUE : DD-MON-RR HH.MI.SSXFF AM TZR DESCRIPTION : Timestamp with timezone format ----------------- PROPERTY_NAME : NLS_TIME_TZ_FORMAT PROPERTY_VALUE : HH.MI.SSXFF AM TZR DESCRIPTION : Time with timezone format ----------------- PROPERTY_NAME : NLS_TIMESTAMP_FORMAT PROPERTY_VALUE : DD-MON-RR HH.MI.SSXFF AM DESCRIPTION : Time stamp format ----------------- PROPERTY_NAME : NLS_TIME_FORMAT PROPERTY_VALUE : HH.MI.SSXFF AM DESCRIPTION : Time format ----------------- PROPERTY_NAME : DBTIMEZONE PROPERTY_VALUE : +08:00 DESCRIPTION : DB time zone ----------------- PL/SQL procedure successfully completed.
OS层查看TIMEZONE
[oracle@oel7db1 ~]$ timedatectl
Local time: Thu 2023-09-28 18:42:35 CST
Universal time: Thu 2023-09-28 10:42:35 UTC
RTC time: Thu 2023-09-28 10:42:35
Time zone: Asia/Shanghai (CST, +0800)
NTP enabled: yes
NTP synchronized: no
RTC in local TZ: no
DST active: n/a
[oracle@oel7db1 ~]$ date +"%Z %z"
CST +0800
修改db层time_zone
SQL> alter session set time_zone = '+00:00'; Session altered. SQL> @printtab "select sysdate,systimestamp, localtimestamp,current_date, dbtimezone,sessiontimezone from dual"; SYSDATE : 28-sep-2023 18:49:55 SYSTIMESTAMP : 28-SEP-23 06.49.55.553521 PM +08:00 LOCALTIMESTAMP : 28-SEP-23 10.49.55.553522 AM CURRENT_DATE : 28-sep-2023 10:49:55 DBTIMEZONE : +08:00 SESSIONTIMEZONE : +00:00 ----------------- PL/SQL procedure successfully completed. SQL> alter database set time_zone = '+01:00'; Database altered. SQL> @printtab "select sysdate,systimestamp, localtimestamp,current_date, dbtimezone,sessiontimezone from dual"; SYSDATE : 28-sep-2023 18:53:27 SYSTIMESTAMP : 28-SEP-23 06.53.27.542418 PM +08:00 LOCALTIMESTAMP : 28-SEP-23 06.53.27.542419 PM CURRENT_DATE : 28-sep-2023 18:53:27 DBTIMEZONE : +08:00 SESSIONTIMEZONE : +08:00 ----------------- PL/SQL procedure successfully completed. SQL> @printtab "select * from database_properties where PROPERTY_NAME like ''%TIME%''"; PROPERTY_NAME : NLS_TIMESTAMP_TZ_FORMAT PROPERTY_VALUE : DD-MON-RR HH.MI.SSXFF AM TZR DESCRIPTION : Timestamp with timezone format ----------------- PROPERTY_NAME : NLS_TIME_TZ_FORMAT PROPERTY_VALUE : HH.MI.SSXFF AM TZR DESCRIPTION : Time with timezone format ----------------- PROPERTY_NAME : NLS_TIMESTAMP_FORMAT PROPERTY_VALUE : DD-MON-RR HH.MI.SSXFF AM DESCRIPTION : Time stamp format ----------------- PROPERTY_NAME : NLS_TIME_FORMAT PROPERTY_VALUE : HH.MI.SSXFF AM DESCRIPTION : Time format ----------------- PROPERTY_NAME : DBTIMEZONE PROPERTY_VALUE : +01:00 DESCRIPTION : DB time zone ----------------- PL/SQL procedure successfully completed. SQL> startup force; ORACLE instance started. Total System Global Area 700445040 bytes Fixed Size 9138544 bytes Variable Size 599785472 bytes Database Buffers 88080384 bytes Redo Buffers 3440640 bytes Database mounted. Database opened. SQL> @printtab "select sysdate,systimestamp, localtimestamp,current_date, dbtimezone,sessiontimezone from dual"; SYSDATE : 28-sep-2023 18:56:37 SYSTIMESTAMP : 28-SEP-23 06.56.37.136747 PM +08:00 LOCALTIMESTAMP : 28-SEP-23 06.56.37.136748 PM CURRENT_DATE : 28-sep-2023 18:56:37 DBTIMEZONE : +01:00 SESSIONTIMEZONE : +08:00 ----------------- PL/SQL procedure successfully completed. SQL> @printtab "select * from database_properties where PROPERTY_NAME like ''%TIME%''"; PROPERTY_NAME : NLS_TIMESTAMP_TZ_FORMAT PROPERTY_VALUE : DD-MON-RR HH.MI.SSXFF AM TZR DESCRIPTION : Timestamp with timezone format ----------------- PROPERTY_NAME : NLS_TIME_TZ_FORMAT PROPERTY_VALUE : HH.MI.SSXFF AM TZR DESCRIPTION : Time with timezone format ----------------- PROPERTY_NAME : NLS_TIMESTAMP_FORMAT PROPERTY_VALUE : DD-MON-RR HH.MI.SSXFF AM DESCRIPTION : Time stamp format ----------------- PROPERTY_NAME : NLS_TIME_FORMAT PROPERTY_VALUE : HH.MI.SSXFF AM DESCRIPTION : Time format ----------------- PROPERTY_NAME : DBTIMEZONE PROPERTY_VALUE : +01:00 DESCRIPTION : DB time zone ----------------- PL/SQL procedure successfully completed.
Note:
修改database 与session 的time_zone不会影响sysdate 的函数返回时间。
OS配置DB server环境变量 TZ
SQL> @printtab "select sysdate,systimestamp, localtimestamp,current_date,current_timestamp, dbtimezone,sessiontimezone from dual"; SYSDATE : 07-oct-2023 11:06:00 SYSTIMESTAMP : 07-OCT-23 11.06.00.405305 AM +08:00 LOCALTIMESTAMP : 07-OCT-23 11.06.00.405307 AM CURRENT_DATE : 07-oct-2023 11:06:00 CURRENT_TIMESTAMP : 07-OCT-23 11.06.00.405307 AM +08:00 DBTIMEZONE : +08:00 SESSIONTIMEZONE : +08:00 ----------------- PL/SQL procedure successfully completed. SQL> exit Disconnected from Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production Version 19.3.0.0.0 [oracle@oel7db1 ~]$ TZ='America/Los_Angeles' export TZ [oracle@oel7db1 ~]$ date Fri Oct 6 20:25:06 PDT 2023 [oracle@oel7db1 ~]$ timedatectl Warning: Ignoring the TZ variable. Reading the system's time zone setting only. Local time: Sat 2023-10-07 11:25:38 CST Universal time: Sat 2023-10-07 03:25:38 UTC RTC time: Sat 2023-10-07 03:25:37 Time zone: Asia/Shanghai (CST, +0800) NTP enabled: yes NTP synchronized: no RTC in local TZ: no DST active: n/a [oracle@oel7db1 ~]$ ora SQL*Plus: Release 19.0.0.0.0 - Production on Fri Oct 6 20:06:45 2023 Version 19.3.0.0.0 Copyright (c) 1982, 2019, Oracle. All rights reserved. Connected to: Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production Version 19.3.0.0.0 USERNAME INST_NAME HOST_NAME I# SID SERIAL# VERSION STARTED SPID OPID CPID SADDR PADDR -------------------- -------------------- ------------------------- --- ----- -------- ---------- -------- ---------- ----- --------------- ---------------- ---------------- SYS CDB$ROOT-anbob19c oel7db1 1 98 9942 19.0.0.0.0 20231007 2822 43 2821 0000000078172F10 0000000078D05508 SQL> @printtab "select sysdate,systimestamp, localtimestamp,current_date,current_timestamp, dbtimezone,sessiontimezone from dual"; SYSDATE : 06-oct-2023 20:06:52 SYSTIMESTAMP : 06-OCT-23 08.06.52.431369 PM -07:00 LOCALTIMESTAMP : 06-OCT-23 08.06.52.431370 PM CURRENT_DATE : 06-oct-2023 20:06:52 CURRENT_TIMESTAMP : 06-OCT-23 08.06.52.431370 PM -07:00 DBTIMEZONE : +08:00 SESSIONTIMEZONE : -07:00 ----------------- PL/SQL procedure successfully completed.
Note:
上面因为是在db server查询，server与client同样受OS影响，我们换其它正常+8：00时区的客户端测试。
Note：
我们在一个+8时区的client(sql developer)可以模拟出sysdate与localtimestamp或current_date不一致的地方，如果此时我们连接的是两个节点的RAC，如果只是其中一个节点配置了TZ或相同功能的配置，可能会出现连接同一套DB RAC的两个节点使用sysdate返回不同的时间，导致业务记录时间错乱.如果此时再修改session级timezone，client一样不会影响sysdate,但会转换current_date.
上面这个案例的时间错乱问题，还是在于操作系统层的时区配置问题，对于AIX没有深入研究，但是通过使用smitty修改操作系统的TIMEZONG 后，System Environments -> Change/Show Date and Time -> Change Time Zone Using System Defined Values， 2节点的时区修复，从DB层取sysdate时间恢复正常， 节点间一致。
微信扫一扫，打赏作者吧～
对不起，这篇文章暂时关闭评论。