Oracle告警日志里记录了“KILL SOFT -/-/-”会话被杀掉的信息

现象

升级到12.2数据库后，在警报日志文件中发现如下日志。

 12018-08-10T11:27:20.711173-04:00
 2KILL SESSION for sid=(291, 41855):
 3 Reason = alter system kill session
 4 Mode = KILL HARD SAFE -/-/-
 5 Requestor = USER (orapid = 419, ospid = 6236, inst = 1)
 6 Owner = N/A
 7 Result = ORA-27
 82018-08-10T11:28:23.410778-04:00
 9
10
11
12KILL SESSION for sid=(382, 30780):
13 Reason = profile limit idle_time
14 Mode = KILL SOFT -/-/-
15 Requestor = PMON (orapid = 2, ospid = 2961, inst = 1)
16 Owner = Process: USER (orapid = 164, ospid = 26147)
17 Result = ORA-0

复制

详细说明

 1-- 被杀的会话
 2
 3SQL> col tracefile format a300
 4SQL> select sid,a.serial#,b.pid,b.spid,b.TRACEFILE
 5  2    from   v$session a,v$process b
 6  3   where a.PADDR=b.ADDR
 7  4   and  a.sid='36'  ;
 8
 9       SID    SERIAL#        PID SPID                                             TRACEFILE
10---------- ---------- ---------- ------------------------------------------------ ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
11        36      11571        161 4309                                             /opt/oracle/diag/rdbms/lhrsdb/lhrsdb/trace/lhrsdb_ora_4309.trc
12
13
14-- 执行alter system kill session的会话
15
16  select sid,a.serial#,b.pid,b.spid,b.TRACEFILE 
17  from   v$session a,v$process b 
18   where a.PADDR=b.ADDR 
19   and  a.sid='68'  ;
20
21SID    SERIAL# PID SPID    TRACEFILE
2268    62973   162 4557    /opt/oracle/diag/rdbms/lhrsdb/lhrsdb/trace/lhrsdb_ora_4557.trc
23
24
25
26 select * from v$active_session_history a where a.SESSION_ID=68 and a.SESSION_SERIAL#=62973;  
27select * from dba_hist_active_sess_history a where a.SESSION_ID=68 and a.SESSION_SERIAL#=62973;
28
29
30alter system kill session '36,11571';
31
32
33
34select d.os_user,
35       d.host_name,
36       d.terminal,
37       d.authentication_type,
38       d.userid,
39       d.client_program_name,
40       d.event_timestamp,
41       d.return_code,
42       d.os_process,
43       to_char(d.sql_text) sql_text,
44       d.client_identifier,
45       d.current_user,
46       d.unified_audit_policies
47  from AUDSYS.AUD$UNIFIED d
48 where d.event_timestamp >= sysdate - 1
49   and d.system_privilege_used = 'ALTER SYSTEM';
50
51OS_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
52lhr    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
53

复制

主动执行杀会话的会话日志trace：

 1[oracle@lhrora19c trace]$ tailf alert_lhrsdb.log 
 22023-08-08T11:17:42.626761+08:00
 3KILL SESSION for sid=(36, 11571):
 4  Reason = alter system kill session
 5  Mode = KILL SOFT -/-/-
 6  Requestor = USER (orapid = 162, ospid = 4557, inst = 1)
 7  Owner = Process: USER (orapid = 161, ospid = 4309)
 8  Result = ORA-0
 9[oracle@lhrora19c trace]$ more /opt/oracle/diag/rdbms/lhrsdb/lhrsdb/trace/lhrsdb_ora_4557.trc
10Trace file /opt/oracle/diag/rdbms/lhrsdb/lhrsdb/trace/lhrsdb_ora_4557.trc
11Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
12Version 19.3.0.0.0
13Build label:    RDBMS_19.3.0.0.0DBRU_LINUX.X64_190417
14ORACLE_HOME:    /opt/oracle/product/19c/dbhome_1
15System name:    Linux
16Node name:      lhrora19c
17Release:        3.10.0-1160.80.1.el7.x86_64
18Version:        #1 SMP Tue Nov 8 15:48:59 UTC 2022
19Machine:        x86_64
20Instance name: lhrsdb
21Redo thread mounted by this instance: 1
22Oracle process number: 162
23Unix process pid: 4557, image: oracle@lhrora19c
24
25
26*** 2023-08-08T11:17:42.626523+08:00
27*** SESSION ID:(68.62973) 2023-08-08T11:17:42.626562+08:00    # 表示主动执行kill的会话信息
28*** CLIENT ID:(WORKGROUP\LHRXXT) 2023-08-08T11:17:42.626569+08:00
29*** SERVICE NAME:(lhrsdb) 2023-08-08T11:17:42.626576+08:00
30*** MODULE NAME:(PL/SQL Developer) 2023-08-08T11:17:42.626581+08:00
31*** ACTION NAME:(SQL 窗口) 2023-08-08T11:17:42.626586+08:00
32*** CLIENT DRIVER:(OCI) 2023-08-08T11:17:42.626591+08:00
33
34KILL SESSION for sid=(36, 11571):    # 表示被杀掉的会话信息
35  Reason = alter system kill session
36  Mode = KILL SOFT -/-/-
37  Requestor = USER (orapid = 162, ospid = 4557, inst = 1)   # 表示主动执行kill的进程信息
38  Owner = Process: USER (orapid = 161, ospid = 4309)    # 表示被杀掉的进程信息
39  Result = ORA-0
40[oracle@lhrora19c trace]$ more /opt/oracle/diag/rdbms/lhrsdb/lhrsdb/trace/lhrsdb_ora_4309.trc
41/opt/oracle/diag/rdbms/lhrsdb/lhrsdb/trace/lhrsdb_ora_4309.trc: No such file or directory
42[oracle@lhrora19c trace]$ 

复制

原因

当由于空闲超时而手动或由PMON终止会话后手动执行alter system kill session
时，将在警报日志中记录相关信息

这些是警报日志中与会话相关的的信息类日志。

示例

我们可以安全地忽略这些消息。请查看以下测试用例

 1SQL> conn / as sysdba
 2Connected.
 3SQL> alter system kill session '45,48410';
 4 alter system kill session '45,48410'
 5*
 6ERROR at line 1:
 7ORA-00030: User session ID does not exist.
 8
 9
10SQL> select
11 sys_context('USERENV','SID')
12from dual; 2 3
13
14SYS_CONTEXT('USERENV','SID')
15--------------------------------------------------------------------------------
1645
17
18SQL> alter system kill session '45,58610';
19 alter system kill session '45,58610'
20*
21ERROR at line 1:
22ORA-00027: cannot kill current session
23
24
25
26
272018-08-13T13:50:06.971193+00:00
28KILL SESSION for sid=(45, 48410):
29 Reason = alter system kill session
30 Mode = KILL SOFT -/-/-
31 Requestor = USER (orapid = 24, ospid = 18655, inst = 1)
32 Owner = N/A
33 Result = ORA-30
342018-08-13T13:51:47.858998+00:00
35KILL SESSION for sid=(45, 58610):
36 Reason = alter system kill session
37 Mode = KILL SOFT -/-/-
38 Requestor = USER (orapid = 24, ospid = 18655, inst = 1)
39 Owner = N/A
40 Result = ORA-27

复制

有两种信息类日志被存储到警报日志中。

1) 这些消息出现在12.2版本中，而不再是"Immediate Kill Session#: 291, Serial#: 41855"。

12018-08-10T11:27:20.711173-04:00
2KILL SESSION for sid=(291, 41855):
3 Reason = alter system kill session
4 Mode = KILL HARD SAFE -/-/-
5 Requestor = USER (orapid = 419, ospid = 6236, inst = 1)
6 Owner = N/A
7 Result = ORA-27
82018-08-10T11:28:23.410778-04:00

复制

2) 由于已达到IDLE_TIME限制，这些空闲会话被PMON杀死。

1KILL SESSION for sid=(382, 30780):
2 Reason = profile limit idle_time
3 Mode = KILL SOFT -/-/-
4 Requestor = PMON (orapid = 2, ospid = 2961, inst = 1)
5 Owner = Process: USER (orapid = 164, ospid = 26147)
6 Result = ORA-0

复制

总的来说，这些消息是信息类日志。

总结

1、查看告警日志和查看主动执行kill的会话的trace文件获取信息

2、要么执行alter system kill 要么配置了idle_time

3、可以通过查询v$active_session_history
和dba_hist_active_sess_history
获取相关信息

4、在12.2之前被杀掉的会话信息不会记录到告警日志中

5、前端会报错“ORA-00028: 您的会话已被终止”、ORA-00028: your session has been killed

6、12c之后的杀会话的操作也会被记录到统一审计AUDSYS.AUD$UNIFIED
中。

参考

与会话相关的12.2中的新警报日志条目：KILL SESSION for sid= (Doc ID 2504868.1)