Oracle告警日志里记录了“KILL SOFT -/-/-”会话被杀掉的信息
Tags： kill sessionOracle告警日志杀会话
👉 本文共约714个字，系统预计阅读时间或需3分钟。
现象
升级到12.2数据库后，在警报日志文件中发现如下日志。
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 | 2018-08-10T11:27:20.711173-04:00 KILL SESSION for sid=(291, 41855): Reason = alter system kill session Mode = KILL HARD SAFE -/-/- Requestor = USER (orapid = 419, ospid = 6236, inst = 1) Owner = N/A Result = ORA-27 2018-08-10T11:28:23.410778-04:00 KILL SESSION for sid=(382, 30780): Reason = profile limit idle_time Mode = KILL SOFT -/-/- Requestor = PMON (orapid = 2, ospid = 2961, inst = 1) Owner = Process: USER (orapid = 164, ospid = 26147) Result = ORA-0 |
详细说明
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 | -- 被杀的会话 SQL> col tracefile format a300 SQL> select sid,a.serial#,b.pid,b.spid,b.TRACEFILE 2 from v$session a,v$process b 3 where a.PADDR=b.ADDR 4 and a.sid='36' ; SID SERIAL# PID SPID TRACEFILE ---------- ---------- ---------- ------------------------------------------------ ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------ 36 11571 161 4309 /opt/oracle/diag/rdbms/lhrsdb/lhrsdb/trace/lhrsdb_ora_4309.trc -- 执行alter system kill session的会话 select sid,a.serial#,b.pid,b.spid,b.TRACEFILE from v$session a,v$process b where a.PADDR=b.ADDR and a.sid='68' ; SID SERIAL# PID SPID TRACEFILE 68 62973 162 4557 /opt/oracle/diag/rdbms/lhrsdb/lhrsdb/trace/lhrsdb_ora_4557.trc select * from v$active_session_history a where a.SESSION_ID=68 and a.SESSION_SERIAL#=62973; select * from dba_hist_active_sess_history a where a.SESSION_ID=68 and a.SESSION_SERIAL#=62973; alter system kill session '36,11571'; select d.os_user, d.host_name, d.terminal, d.authentication_type, d.userid, d.client_program_name, d.event_timestamp, d.return_code, d.os_process, to_char(d.sql_text) sql_text, d.client_identifier, d.current_user, d.unified_audit_policies from AUDSYS.AUD$UNIFIED d where d.event_timestamp >= sysdate - 1 and d.system_privilege_used = 'ALTER SYSTEM'; OS_USER HOST_NAME TERMINAL AUTHENTICATION_TYPE USERID CLIENT_PROGRAM_NAME EVENT_TIMESTAMP RETURN_CODE OS_PROCESS SQL_TEXT CLIENT_IDENTIFIER CURRENT_USER UNIFIED_AUDIT_POLICIES lhr WORKGROUP\LHRXXT LHRXXT (TYPE=(DATABASE));(CLIENT ADDRESS=((ADDRESS=(PROTOCOL=tcp)(HOST=192.168.26.245)(PORT=63840)))); LHR plsqldev.exe 08-AUG-23 03.17.42.627167 AM 0 4557 " alter system kill session '36,11571'" WORKGROUP\LHRXXT LHR ORA_SECURECONFIG |
主动执行杀会话的会话日志trace：
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 | [oracle@lhrora19c trace]$ tailf alert_lhrsdb.log 2023-08-08T11:17:42.626761+08:00 KILL SESSION for sid=(36, 11571): Reason = alter system kill session Mode = KILL SOFT -/-/- Requestor = USER (orapid = 162, ospid = 4557, inst = 1) Owner = Process: USER (orapid = 161, ospid = 4309) Result = ORA-0 [oracle@lhrora19c trace]$ more /opt/oracle/diag/rdbms/lhrsdb/lhrsdb/trace/lhrsdb_ora_4557.trc Trace file /opt/oracle/diag/rdbms/lhrsdb/lhrsdb/trace/lhrsdb_ora_4557.trc Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production Version 19.3.0.0.0 Build label: RDBMS_19.3.0.0.0DBRU_LINUX.X64_190417 ORACLE_HOME: /opt/oracle/product/19c/dbhome_1 System name: Linux Node name: lhrora19c Release: 3.10.0-1160.80.1.el7.x86_64 Version: #1 SMP Tue Nov 8 15:48:59 UTC 2022 Machine: x86_64 Instance name: lhrsdb Redo thread mounted by this instance: 1 Oracle process number: 162 Unix process pid: 4557, image: oracle@lhrora19c *** 2023-08-08T11:17:42.626523+08:00 *** SESSION ID:(68.62973) 2023-08-08T11:17:42.626562+08:00 # 表示主动执行kill的会话信息 *** CLIENT ID:(WORKGROUP\LHRXXT) 2023-08-08T11:17:42.626569+08:00 *** SERVICE NAME:(lhrsdb) 2023-08-08T11:17:42.626576+08:00 *** MODULE NAME:(PL/SQL Developer) 2023-08-08T11:17:42.626581+08:00 *** ACTION NAME:(SQL 窗口) 2023-08-08T11:17:42.626586+08:00 *** CLIENT DRIVER:(OCI) 2023-08-08T11:17:42.626591+08:00 KILL SESSION for sid=(36, 11571): # 表示被杀掉的会话信息 Reason = alter system kill session Mode = KILL SOFT -/-/- Requestor = USER (orapid = 162, ospid = 4557, inst = 1) # 表示主动执行kill的进程信息 Owner = Process: USER (orapid = 161, ospid = 4309) # 表示被杀掉的进程信息 Result = ORA-0 [oracle@lhrora19c trace]$ more /opt/oracle/diag/rdbms/lhrsdb/lhrsdb/trace/lhrsdb_ora_4309.trc /opt/oracle/diag/rdbms/lhrsdb/lhrsdb/trace/lhrsdb_ora_4309.trc: No such file or directory [oracle@lhrora19c trace]$ |
原因
当由于空闲超时而手动或由PMON终止会话后手动执行alter system kill session时，将在警报日志中记录相关信息
这些是警报日志中与会话相关的的信息类日志。
示例
我们可以安全地忽略这些消息。请查看以下测试用例
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 | SQL> conn / as sysdba Connected. SQL> alter system kill session '45,48410'; alter system kill session '45,48410' * ERROR at line 1: ORA-00030: User session ID does not exist. SQL> select sys_context('USERENV','SID') from dual; 2 3 SYS_CONTEXT('USERENV','SID') -------------------------------------------------------------------------------- 45 SQL> alter system kill session '45,58610'; alter system kill session '45,58610' * ERROR at line 1: ORA-00027: cannot kill current session 2018-08-13T13:50:06.971193+00:00 KILL SESSION for sid=(45, 48410): Reason = alter system kill session Mode = KILL SOFT -/-/- Requestor = USER (orapid = 24, ospid = 18655, inst = 1) Owner = N/A Result = ORA-30 2018-08-13T13:51:47.858998+00:00 KILL SESSION for sid=(45, 58610): Reason = alter system kill session Mode = KILL SOFT -/-/- Requestor = USER (orapid = 24, ospid = 18655, inst = 1) Owner = N/A Result = ORA-27 |
有两种信息类日志被存储到警报日志中。
1) 这些消息出现在12.2版本中，而不再是"Immediate Kill Session#: 291, Serial#: 41855"。
1 2 3 4 5 6 7 8 | 2018-08-10T11:27:20.711173-04:00 KILL SESSION for sid=(291, 41855): Reason = alter system kill session Mode = KILL HARD SAFE -/-/- Requestor = USER (orapid = 419, ospid = 6236, inst = 1) Owner = N/A Result = ORA-27 2018-08-10T11:28:23.410778-04:00 |
2) 由于已达到IDLE_TIME限制，这些空闲会话被PMON杀死。
1 2 3 4 5 6 | KILL SESSION for sid=(382, 30780): Reason = profile limit idle_time Mode = KILL SOFT -/-/- Requestor = PMON (orapid = 2, ospid = 2961, inst = 1) Owner = Process: USER (orapid = 164, ospid = 26147) Result = ORA-0 |
总的来说，这些消息是信息类日志。
总结
1、查看告警日志和查看主动执行kill的会话的trace文件获取信息
2、要么执行alter system kill 要么配置了idle_time
3、可以通过查询v$active_session_history和dba_hist_active_sess_history获取相关信息
本人提供Oracle(OCP、OCM)、MySQL(OCP)、PostgreSQL(PGCA、PGCE、PGCM)等数据库的培训和考证业务，私聊QQ646634621或微信db_bao，谢谢！
