Now trying to drop the old temporary tablespace, the session hangs.

1.描述

问题描述：删除临时表空间时，会话Hangs挂起

SQL> drop tablespace TEMP_B including contents and datafiles; 

2.故障诊断思路

2.1查看alert日志：

Sun Apr 01 05:32:40 2018

ORA-1013 signalled during: drop tablespace TEMP_B including contents and datafiles...

Sun Apr 01 05:33:56 2018

drop tablespace TEMP_B including contents and datafiles

 2.2查询会话等待事件：

 

select sid,program,status,blocking_session,event from v$session where type='USER'

 

   SID PROGRAM                          STATUS    BLOCKING_SESSION EVENT

---- ------------- ---------- ---------------- ------------------------------------------------

   1 sqlplus@enmo(TNS V1-V3)  ACTIVE             13                     enq: TS - contention 

     

  40 oracle@enmo ( J001)          ACTIVE                                       jobq slave wait

     

  43 oracle@enmo (J000)           ACTIVE                                       jobq slave wait

     

  46 sqlplus@enmo(TNS V1-V3)ACTIVE                                     SQL*Net message to client

SID                       会话标识符

PROGRAM           操作系统程序名称

STATUS                正在执行的SQL会话：active

BLOCKING_SESSION  阻塞会话的标识符 sid

EVENT                       等待事件类型：

TYPE                          会话类型：用户 USER

     

#查询：会话id=13的信息：

SQL> select sid,program,status,blocking_session,event from v$session where sid=13;

 

SID PROGRAM                         STATUS     BLOCKING_SESSION EVENT

---- ------------- ---------- ---------------- ------------------------------

  13 oracle@enmo ( SMON)    ACTIVE                      smon timer

 2.3本次操作，sqlplus本地登录，查询spid

#查询spid

[oracle@enmo app]$ ps -ef|grep LOCAL=YES  本地连接会话的操作系统进程号

oracle   15576 14800  0 03:27 ?        00:00:19 oracleENMO (DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq)))

 

[oracle@enmo app]$ ps -ef|grep 14800           查询父进程：为sqlplus工具 

UID      PID     PPID

oracle   14800 14778  0 02:40 pts/1    00:00:00 sqlplus   as sysdba

oracle   15576 14800  0 03:27 ?        00:00:21 oracleENMO (DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq)))

 

 

SQL> select sid,sql_id,status,event from v$session where paddr=(select addr from v$process where spid=15576);

 

       SID SQL_ID        STATUS                 EVENT

----------------------------------------------------------------

         1 5y9u0m6wv4mch ACTIVE     enq: TS - contention

2,4:oradebug跟踪进程：

SQL> oradebug setospid 15576

Oracle pid: 19, Unix process pid: 15576, image: oracle@enmo (TNS V1-V3)

 

SQL> oradebug unlimit

Statement processed.

 

SQL> oradebug dump systemstate 258

Statement processed.

SQL> oradebug dump systemstate 258

Statement processed.

SQL> exit

 

SQL>  show parameter user_dump

/u01/app/oracle/diag/rdbms/enmo/ENMO/trace

 

[oracle@enmo trace]$ ls -lrt

-rw-r----- 1 oracle oinstall 2127846 Apr  1 05:41 ENMO_ora_15576.trc

 

sftp> get ENMO_ora_15576.trc C:\Users\Administrator\Desktop\.

2.5:trace文件查看：

[oracle@enmo trace]$ more ENMO_ora_15576.trc

Oracle Database 11g Enterprise Edition Release 11.2.0.4.0

- 64bit Production

Instance name: ENMO

Redo thread mounted by this instance: 1

Oracle process number: 19

Unix process pid: 15576, image: oracle@enmo (TNS V1-V3)

 

######根据spid查询没发现什么有效信息：

/ospid: 15576 

...skipping

    (latch info) wait_event=0 bits=0x0

    Process Group: DEFAULT, pseudo proc: 0x7ed5ac30

    O/S info: user: oracle, term: UNKNOWN, ospid: 15576

    OSD pid info: Unix process pid: 15576, image: oracle@e

nmo (TNS V1-V3)

 

#####根据：ospid: 14800 

 

----------------------------------------

SO: 0x7e892b40, type: 4, owner: 0x7ecc5220, flag: INIT/-/-/0x00 if: 0x3 c: 0x3

proc=0x7ecc5220, name=session, file=ksu.h LINE:12729, pg=0

(session) sid: 1 ser: 5 trans: 0x7ccb8a68, creator: 0x7ecc5220

flags: (0x41) USR/- flags_idl: (0x1) BSY/-/-/-/-/-

flags2: (0x48009) -/DDLT2/INC

DID: , short-term DID:

txn branch: (nil)

edition#: 100 oct: 41, prv: 0, sql: 0x7f76ef79fdf0, psql: 0x78f50ad0, user: 0/SYS

ksuxds FALSE at location: 0

service name: SYS$USERS

client details:

O/S info: user: oracle, term: pts/1, ospid: 14800

machine: enmo program: sqlplus@enmo (TNS V1-V3)

application name: sqlplus@enmo (TNS V1-V3), hash value=1501019605

Current Wait Stack:

0: waiting for 'enq: TS - contention'

name|mode=0x54530006, tablespace ID=0x1c, dba=0x1

wait_id=14569 seq_num=14571 snap_id=1

wait times: snap=7 min 28 sec, exc=7 min 28 sec, total=7 min 28 sec

wait times: max=infinite, heur=7 min 28 sec

wait counts: calls=151 os=151

in_wait=1 iflags=0x15a0

#  有一个会话被阻塞

There are 1 sessions blocked by this session.

Dumping one waiter:

inst: 1, sid: 39, ser: 153         

#等待事件

wait event: 'enq: TT - contention'

#############################根据：会话ID，查询操作系统进程号####

SQL> select spid from v$process where addr=(select paddr from v$session where sid=13);

SPID

------------------------

15542

#############根据操系统进程查询：SMON进程#####################

[root@enmo ~]# ps -ef|grep 15542

oracle   15542     1  0 03:27 ?        00:00:01 ora_smon_ENMO

 

p1: 'name|mode'=0x54540004

p2: 'tablespace ID'=0x1a

p3: 'operation'=0x0

row_wait_obj#: 4294967295, block#: 0, row#: 0, file# 0

min_blocked_time: 232 secs, waiter_cache_ver: 2576

Wait State:

fixed_waits=0 flags=0x2b boundary=0x7e894a28/0

Session Wait History:

elapsed time of 25375533 min 56 sec since current wait

0: waited for 'ksdxexeotherwait'

=0x0, =0x0, =0x0

wait_id=14585 seq_num=14587 snap_id=1

等待时间

wait times: snap=0.042447 sec, exc=0.042447 sec, total=0.042447 sec

wait times: max=30.000000 sec

wait counts: calls=0 os=0

在经过时间：s后发生

occurred after 0.000000 sec of elapsed time

等待：

1: waited for 'ksdxexeotherwait'

=0x0, =0x0, =0x0

wait_id=14584 seq_num=14586 snap_id=1

wait times: snap=0.045086 sec, exc=0.045086 sec, total=0.045086 sec

wait times: max=30.000000 sec

wait counts: calls=0 os=0

occurred after 0.000000 sec of elapsed time

2: waited for 'ksdxexeotherwait'

=0x0, =0x0, =0x0

wait_id=14583 seq_num=14585 snap_id=1

wait times: snap=0.030094 sec, exc=0.030094 sec, total=0.030094 sec

wait times: max=29.990000 sec

wait counts: calls=0 os=0

occurred after 0.000000 sec of elapsed time

3: waited for 'ksdxexeotherwait'

=0x0, =0x0, =0x0

wait_id=14582 seq_num=14584 snap_id=1

wait times: snap=0.030958 sec, exc=0.030958 sec, total=0.030958 sec

wait times: max=30.000000 sec

wait counts: calls=0 os=0

occurred after 0.000000 sec of elapsed time

4: waited for 'ksdxexeotherwait'

=0x0, =0x0, =0x0

wait_id=14581 seq_num=14583 snap_id=1

wait times: snap=0.033920 sec, exc=0.033920 sec, total=0.033920 sec

wait times: max=30.000000 sec

wait counts: calls=0 os=0

occurred after 0.000000 sec of elapsed time

5: waited for 'ksdxexeotherwait'

=0x0, =0x0, =0x0

wait_id=14580 seq_num=14582 snap_id=1

wait times: snap=0.029040 sec, exc=0.029040 sec, total=0.029040 sec

wait times: max=30.000000 sec

wait counts: calls=0 os=0

occurred after 0.000000 sec of elapsed time

6: waited for 'ksdxexeotherwait'

=0x0, =0x0, =0x0

wait_id=14579 seq_num=14581 snap_id=1

wait times: snap=0.031045 sec, exc=0.031045 sec, total=0.031045 sec

wait times: max=29.990000 sec

wait counts: calls=0 os=0

occurred after 0.000000 sec of elapsed time

7: waited for 'ksdxexeotherwait'

=0x0, =0x0, =0x0

wait_id=14578 seq_num=14580 snap_id=1

wait times: snap=0.027048 sec, exc=0.027048 sec, total=0.027048 sec

wait times: max=30.000000 sec

wait counts: calls=0 os=0

occurred after 0.000000 sec of elapsed time

8: waited for 'ksdxexeotherwait'

=0x0, =0x0, =0x0

wait_id=14577 seq_num=14579 snap_id=1

wait times: snap=0.029306 sec, exc=0.029306 sec, total=0.029306 sec

wait times: max=30.000000 sec

wait counts: calls=0 os=0

occurred after 0.000000 sec of elapsed time

9: waited for 'ksdxexeotherwait'

=0x0, =0x0, =0x0

wait_id=14576 seq_num=14578 snap_id=1

wait times: snap=0.031989 sec, exc=0.031989 sec, total=0.031989 sec

wait times: max=30.000000 sec

wait counts: calls=0 os=0

occurred after 0.000000 sec of elapsed time

#会话1，序列号5的采样会话历史记录

Sampled Session History of session 1 serial 5

---------------------------------------------------

 

匹配：

mos文章SMON Blocking Drop Temporary Tablespace (文档 ID 1500044.1)描述的现象符合

This seems to be caused by Bug 13028161:

DROP TEMP TABLESPACE HANGS DUE TO TS ENQUEUE CONTENTION which was closed as duplicate of Bug 15913577 : 

MAIN_LINUX.X64 LRG9H8 RUNS WILL BE SUSPENDED 12/02/12; TOO MANY HANGS 

#提示：是一个BUG，查询文章：SMON进程堵塞了drop tempfile的会话，会话当前等待

 

SMON Blocking Drop Temporary Tablespace (文档 ID 1500044.1)

The following steps have been performed successfully:

- Create a new temporary tablespace

- Declare as the new default temp

- Make sure that no users have the old temp as their default

 

 

#匹配

Now trying to drop the old temporary tablespace, the session hangs.

Analyzing the problem shows the following:


- Tracing the session using 10046 shows that the session is waiting for event "enq: TS - contention'"

- System state dump shows that the session is blocked by SMON

- SMON is waiting for event "SMON TIMER"


drop old temporary tablespace,session hangs故障现象符合

等待事件： TS - contention 符合

10046：跟踪，查询堵塞进程 SMON 符合

 

#故障解释说明

由bug13028161引起的：由于TS ENQUEUE CONTENTION 导致DROP TEMP TABLESPACE HANGS被关闭为Bug 15913577的副本：MAIN_LINUX.X64 LRG9H8 RUNS将暂停12/02/12; TOO MANY HANGS

#建议

如果可用于您的平台或使用以下解决方法，请安装修补程序15913577

#解决

检查前提条件是否满足：创建新的临时表空间，指定新临时表空间为默认值，确保没有用户分配使用旧临时表空间

EXIT 退出SQL*PLUS，重新登录执行

#涉及版本、操作系统：11.2.0.3以上，大部分操作系统都符合

Range of versions believed to be affected    Versions BELOW 12.2

Versions confirmed as being affected    

11.2.0.4

11.2.0.3

Platforms affected    Generic (all / most platforms affected)Fixed:

###建议操作

#如果有历史会话，使用旧的临时表空间，如下sql，找出会话信息，kill

-Change temporary tablespace of all the users to different temporary tablespace (If not yet done)

SQL> SELECT s.username,sid,serial#,contents,sql_address,extents,last_call_et

    FROM v$session s,v$tempseg_usage t;

WHERE s.saddr = t.session_addr;

 

-Kill those sessions:

alter system kill session '< sid >, < Serial# >';

#实际操作：

 

exit

[oracle@enmo ~]$ sqlplus / as sysdba

SQL> drop tablespace TEMP_B including contents and datafiles;  [OK]

 

#记录人生中遇到的第一个bug 开心