為什麼資料庫中大量的server process沒有對應的session?

轉自oracle官方部落格

https://blogs.oracle.com/database4cn/%e4%b8%ba%e4%bb%80%e4%b9%88%e6%95%b0%e6%8d%ae%e5%ba%93%e4%b8%ad%e5%a4%a7%e9%87%8f%e7%9a%84server-process%e6%b2%a1%e6%9c%89%e5%af%b9%e5%ba%94%e7%9a%84session

在什麼情況下oracle server process沒有對應的session？除了px程式以外，還有沒有其他情況？下面的一個真實的案例中，有600個個server process沒有session對應，並且這樣的process越來越多，似乎永遠也不自己釋放，原因是什麼呢？

首先查詢一下v$process和v$session，觀察差異，可見差異有600多個。

select * from v$process;

1674 rows selected.

select * from v$session;

1051 rows selected.

比對了一下，v$process中除了32個px程式以外，還有大量的普通server process，並且它們已經存在了很多天了。

select * from v$process p where p.addr not in (select addr from v$process p,v$session s where s.creator_addr=p.addr) order by pid;

SPID    PROGRAM

29674    oracle@mydb01 (P000)

29820    oracle@mydb01 (P001)

29822    oracle@mydb01 (P002)

......

31415    oracle@mydb01 (P031)

31417    oracle@mydb01 (P032)

31419    oracle@mydb01 (P033)

7523    oracle@mydb01

27740    oracle@mydb01

3283    oracle@mydb01

29116    oracle@mydb01

20006    oracle@mydb01

12831    oracle@mydb01

15681    oracle@mydb01

2139    oracle@mydb01

8606    oracle@mydb01

3963    oracle@mydb01

31811    oracle@mydb01

1613    oracle@mydb01

......

先確認一下當前時間是2017年10月12日:

# date

Thu Oct 12 11:03:54 CST 2017

然後選取一個v$process中沒有session的程式，比如以上輸出中的最後一行的pid為1613的程式，透過ps來觀察其狀態:

# ps -aeo user,pid,ppid,pri,pcpu,pmem,vsize,rssize,wchan:25,s,start,cputime,command

USER       PID  PPID PRI %CPU %MEM    VSZ   RSS WCHAN                     S  STARTED     TIME COMMAND

oracle 1613 1 19 0.0 0.0 365768 27636 sk_wait_data S Oct 04 00:00:00 oraclemydb01 (LOCAL=NO)

發現以上程式在10月4日就存在了，也就是已經過了8天了。同時做一次system state dump，找到這個程式1613

PROCESS 1560:

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

SO: 0x73a3d79790, type: 2, owner: (nil), flag: INIT/-/-/0x00 if: 0x3 c: 0x3

proc=0x73a3d79790, name=process, file=ksu.h LINE:13949, pg=0 conuid=0

(process) Oracle pid:1560, ser:174, calls cur/top: (nil)/0x71232cdd70

......

Process Group: DEFAULT, pseudo proc: 0x7323de7370

O/S info: user: grid, term: UNKNOWN, ospid: 1613 <<<<<< 這裡可見程式 1613

OSD pid info:

Short stack dump:

ksedsts <- ksdxfstk <- ksdxcb <- sspuser <- __sighandler

<- read <- nttfprd <- nsbasic_brc <- nsbrecv <- nioqrc

<- opikndf2 <- opitsk <- opiino <- opiodr <- opidrv

<- sou2o <- opimai_real <- ssthrdmain <- main

可以看到以上程式的call stack都是一些網路相關的function call，既然與網路有關係，不妨取一下其開啟的tcp連線:

# lsof -p 1613 -Pnai TCP

COMMAND     PID USER   FD   TYPE DEVICE SIZE/OFF NODE NAME

oracle_16 1613 oracle 20u IPv4 1303337121 0t0 TCP 10.5.20.110:1521->10.5.70.234:23966 (ESTABLISHED)

可見server端(10.5.20.110)的確和一個client端(10.5.70.234)建立了連線，找到client端(10.5.70.234)，在client上用如下命令觀察是什麼程式建立了連線：

# lsof -Pni :5926

COMMAND   PID   USER   FD   TYPE DEVICE SIZE NODE NAME

sqlplus 29544 oracle    9u  IPv4 739424       TCP 10.5.70.234:23966->10.5.20.110:1521 (ESTABLISHED)

原來客戶端是一個sqlplus程式，程式號為29544，但是什麼情況下sqlplus連線資料庫後只有server process而沒有session？最大的可能性是這個程式正處於密碼驗證階段。

檢查一下呼叫這個sqlplus的指令碼，果然發現指令碼中指定的登入資料庫的密碼是錯誤的！

接下來在12.2.0.1的測試機上模擬一下，sqlplus故意以錯誤密碼登入，然後停住不動等1分鐘，看能否重現這個現象。

sqlplus tony/a@server_r12201

SQL*Plus: Release 12.2.0.1.0 Production on Thu Nov 2 11:50:46 2017

Copyright (c) 1982, 2016, Oracle.  All rights reserved.

ERROR:

ORA-01017: invalid username/password; logon denied

Enter user-name:   <<<<停在這裡不要動

在server上透過兩次ps定位是哪個程式被最新建立:

# ps -ef | egrep "oracleR12201 \(LOCAL=NO\)|PID" | grep -v grep

UID        PID  PPID  C STIME TTY          TIME CMD

oracle     962     1  0 Oct31 ?        00:00:04 oracleR12201 (LOCAL=NO)

# ps -ef | egrep "oracleR12201 \(LOCAL=NO\)|PID" | grep -v grep

UID        PID  PPID  C STIME TTY          TIME CMD

oracle     962     1  0 Oct31 ?        00:00:04 oracleR12201 (LOCAL=NO)

oracle   28540     1  0 11:50 ?        00:00:00 oracleR12201 (LOCAL=NO)

兩次ps對比可見新產生了程式28540，查詢v$process v$session

select * from v$process where spid=28540;

ADDR    SPID    PROGRAM

000000006A576D48    28540    oracle@testsever

select * from v$session where creator_addr='000000006A576D48';

no rows selected.

看來問題重現了，以上的程式28540在v$process中存在但是在v$session中不存在。

但是，在我們的測試中，程式28540會在大約1分鐘後自行從server端退出，並且在alert log中列印如下資訊

2017-11-02T11:51:02.509020+08:00

***********************************************************************

Fatal NI connect error 12170.

  VERSION INFORMATION:

    TNS for Linux: Version 12.2.0.1.0 - Production

    Oracle Bequeath NT Protocol Adapter for Linux: Version 12.2.0.1.0 - Production

    TCP/IP NT Protocol Adapter for Linux: Version 12.2.0.1.0 - Production

  Time: 02-NOV-2017 11:51:02

  Tracing not turned on.

  Tns error struct:

    ns main err code: 12535

    

TNS-12535: TNS:operation timed out

    ns secondary err code: 12606

    nt main err code: 0

    nt secondary err code: 0

    nt OS err code: 0

  Client address: (ADDRESS=(PROTOCOL=tcp)(HOST=10.182.211.94)(PORT=51681))

2017-11-02T11:51:02.510302+08:00

WARNING: inbound connection timed out (ORA-3136)

看到這個錯誤可能大家馬上想到了SQLNET.INBOUND_CONNECT_TIMEOUT這個Oracle*Net引數，的確，問題是這個引數引發的。在server端開啟$ORACLE_HOME/network/admin/sqlnet.ora，發現如下設定:

SQLNET.INBOUND_CONNECT_TIMEOUT=0

以上引數的含義是完成使用者驗證的最大時間，設定成0代表無限。也就是說，如果客戶端輸錯了密碼，只要客戶端不關閉，那麼對應的server process會永遠等待client。

這個時候我們終於知道這個問題的原因了: 客戶端輸錯了密碼，停留在提示輸入再次密碼的介面上，並且資料庫的server端的sqlnet.ora設定了SQLNET.INBOUND_CONNECT_TIMEOUT=0(無限時間)，導致server process一直等待客戶端輸入密碼驗證，因此永遠也不自動退出。

這個問題實際上還是比較嚴重的，它可能會導致ORA-00020錯誤發生，並且導致新的session無法連線。