Oracle 監聽器日誌解析

標籤：listener   時間   cli   strong   listen   cat   互動   幾分鐘   service   

Oracle監聽器是駐留在Oracle執行個體所在伺服器上的獨立進程。作為用戶端進程串連執行個體的重要溝通組件，Oracle監聽器扮演著重要的地位。本篇將從監聽器日誌入手，分析閱讀監聽器日誌和日常監聽器常見行為。

 

 

1、Oracle監聽器功能

 

在筆者《說說Oracle監聽器》（http://space.itpub.net/17203031/viewspace-682627）系列中，已經比較清楚的介紹過Oracle監聽器的工作方式和體系地位。這裡簡要加以累述。

 

        Oracle監聽器是一個獨立的作業系統進程，運行在作業系統進程列表中。擁有獨立於資料庫執行個體的啟動、終止命令控制台（lsnrctl）；

        Oracle監聽器進程伺候在伺服器一個特定連接埠上（預設為1521），等待通過Oracle Net Service連入到伺服器的用戶端請求；

        另一方面，Oracle監聽器根據系統設定情況（各種環境變數）接受資料庫執行個體的服務列表。服務Service是對外提供的服務名稱，供本地命名服務依據Service名稱連入到其中。Service是對應資料庫SID，也就是指定的Oracle執行個體資料庫位置。建立和維護服務列表的過程叫做註冊register；

        註冊register過程分為兩種，靜態註冊和動態註冊。靜態註冊就是通過直接將服務名寫死在listener.ora檔案中。動態註冊是通過pmon後台進程周期性的到監聽器來註冊；

        當一個client請求通過TCP協議訪問到特定連接埠的監聽程式，Oracle監聽器會對比請求中的Service名稱和掌握的註冊Service列表。如果不匹配，就拒絕。如果匹配，就定位到了特定的執行個體，包括Oracle_home地址；

        監聽程式不負責進行使用者名稱密碼的驗證，此時會向Oracle執行個體請求一個Server Process與client Process進行你個互動；

 

 

2、Oracle監聽器狀態資訊

 

在大部分平台下，我們可以通過lsnrctl監聽器控製程序與監聽器進行互動和控制操作。其中，使用status命令，可以擷取到當前監聽器狀態資訊。

 

 

C:\Documents and Settings\Administrator>lsnrctl status

 

LSNRCTL for 32-bit Windows: Version 10.2.0.1.0 - Production on 29-6月 -2011 13:41:27

 

Copyright (c) 1991, 2005, Oracle.  All rights reserved.

正在串連到 (DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=acca-119hs63yxc)(PORT=1521)

))

LISTENER 的 STATUS

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

別名                      LISTENER

版本                      TNSLSNR for 32-bit Windows: Version 10.2.0.1.0 - Produ

ction

啟動日期                  29-6月 -2011 10:51:26

正常已耗用時間              0 天 2 小時 50 分 3 秒

追蹤層級                  off

安全性                    ON: Local OS Authentication

SNMP                      OFF

監聽程式參數檔案          C:\tool\oracle\oracle\product\10.2.0\db_1\network\admi

n\listener.ora

監聽程式記錄檔          C:\tool\oracle\oracle\product\10.2.0\db_1\network\log\listener.log

監聽端點概要...

  (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=acca-119hs63yxc)(PORT=1521)))

服務摘要..

服務 "OTSXDB" 包含 1 個常式。

  常式 "ots", 狀態 READY, 包含此服務的 1 個處理常式...

服務 "OTS_XPT" 包含 1 個常式。

  常式 "ots", 狀態 READY, 包含此服務的 1 個處理常式...

服務 "ots" 包含 1 個常式。

  常式 "ots", 狀態 READY, 包含此服務的 1 個處理常式...

命令執行成功

 

 

命令status可以查看當前監聽器的所有資訊。當前監聽器對應的服務包括三個，分別為otsxdb、otx_xpt和ots。三個服務名是對外使用的，本質上對應的Oracle執行個體都是ots。

 

監聽器進程工作都有對應的日誌資訊，在狀態顯示中，我們也可以看到記錄檔位置（C:\tool\oracle\oracle\product\10.2.0\db_1\network\log\listener.log）。下面我們從一個新的記錄檔，看監聽器工作。

 

 

3、Oracle監聽器日誌解析

 

下面是我們截取的監聽器片段，篇幅原因，有省略。

 

 

以 pid=2736 開始

監聽: (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=acca-119hs63yxc)(PORT=1521)))

Listener completed notification to CRS on start

 

TIMESTAMP * CONNECT DATA [* PROTOCOL INFO] * EVENT [* SID] * RETURN CODE

29-6月 -2011 10:51:27 * (CONNECT_DATA=(CID=(PROGRAM=)(HOST=)(USER=Administrator))(COMMAND=status)(ARGUMENTS=64)(SERVICE=LISTENER)(VERSION=169869568)) * status * 0

29-6月 -2011 10:51:39 * (CONNECT_DATA=(CID=(PROGRAM=)(HOST=)(USER=Administrator))(COMMAND=status)(ARGUMENTS=64)(SERVICE=LISTENER)(VERSION=169869568)) * status * 0

29-6月 -2011 10:52:00 * (CONNECT_DATA=(SID=OTS)(CID=(PROGRAM=C:\tool\oracle\oracle\product\10.2.0\db_1\perl\5.8.3\bin\MSWin32-x86-multi-thread\perl.exe)(HOST=ACCA-119HS63YXC)(USER=SYSTEM))) * (ADDRESS=(PROTOCOL=tcp)(HOST=10.1.39.93)(PORT=3126)) * establish * OTS * 12505

TNS-12505: TNS: 監聽程式當前無法識別串連描述符中所給出的 SID

29-6月 -2011 10:52:00 * service_register * ots * 0

29-6月 -2011 10:52:11 * (CONNECT_DATA=(CID=(PROGRAM=)(HOST=)(USER=Administrator))(COMMAND=status)(ARGUMENTS=64)(SERVICE=LISTENER)(VERSION=169869568)) * status * 0

29-6月 -2011 10:52:48 * service_update * ots * 0

29-6月 -2011 10:53:00 * service_update * ots * 0

 

（有省略。。。）

29-6月 -2011 10:53:17 * ping * 0

29-6月 -2011 10:53:18 * (CONNECT_DATA=(CID=(PROGRAM=)(HOST=)(USER=SYSTEM))(COMMAND=status)(ARGUMENTS=64)(SERVICE=(ADDRESS=(PROTOCOL=TCP)(HOST=acca-119hs63yxc)(PORT=1521)))(VERSION=169869568)) * status * 0

29-6月 -2011 10:53:29 * (CONNECT_DATA=(SID=OTS)(CID=(PROGRAM=C:\tool\oracle\oracle\product\10.2.0\db_1\perl\5.8.3\bin\MSWin32-x86-multi-thread\perl.exe)(HOST=ACCA-119HS63YXC)(USER=SYSTEM))) * (ADDRESS=(PROTOCOL=tcp)(HOST=10.1.39.93)(PORT=3141)) * establish * OTS * 0

29-6月 -2011 10:53:57 * (CONNECT_DATA=(SERVICE_NAME=ots)(CID=(PROGRAM=D:\PLSQL Developer\plsqldev.exe)(HOST=LIUZIYU-PC)(USER=Liuziyu))) * (ADDRESS=(PROTOCOL=tcp)(HOST=10.1.39.40)(PORT=1760)) * establish * ots * 0

29-6月 -2011 10:54:00 * (CONNECT_DATA=(SERVICE_NAME=ots)(CID=(PROGRAM=D:\PLSQL Developer\plsqldev.exe)(HOST=LIUZIYU-PC)(USER=Liuziyu))) * (ADDRESS=(PROTOCOL=tcp)(HOST=10.1.39.40)(PORT=1761)) * establish * ots * 0

29-6月 -2011 10:54:00 * (CONNECT_DATA=(SERVICE_NAME=ots)(CID=(PROGRAM=D:\PLSQL Developer\plsqldev.exe)(HOST=LIUZIYU-PC)(USER=Liuziyu))) * (ADDRESS=(PROTOCOL=tcp)(HOST=10.1.39.40)(PORT=1762)) * establish * ots * 0

29-6月 -2011 10:54:03 * service_update * ots * 0

29-6月 -2011 10:54:09 * service_update * ots * 0

 

日誌內容很多，我們分為重點的幾個部分。

 

在日誌頭，Oracle告知了我們日誌格式，使用*進行內容分割。

 

TIMESTAMP * CONNECT DATA [* PROTOCOL INFO] * EVENT [* SID] * RETURN CODE

 

其中包括連線時間時間，請求資料Data和其他相關事件資訊。這些可以協助我們分析日誌內容。

 

        監聽器無法找到指定服務

 

對應片段：

 

29-6月 -2011 10:52:00 * (CONNECT_DATA=(SID=OTS)(CID=(PROGRAM=C:\tool\oracle\oracle\product\10.2.0\db_1\perl\5.8.3\bin\MSWin32-x86-multi-thread\perl.exe)(HOST=ACCA-119HS63YXC)(USER=SYSTEM))) * (ADDRESS=(PROTOCOL=tcp)(HOST=10.1.39.93)(PORT=3126)) * establish * OTS * 12505

TNS-12505: TNS: 監聽程式當前無法識別串連描述符中所給出的 SID

 

 

分析日誌格式後，可以發現在這個時間（10:52），Oracle監聽器接受到程式的訪問，程式來自主機（ACCA-119HS63YXC），使用system使用者登入，程式名稱是perl.exe。由於當前系統沒有註冊Service資訊，也沒有註冊SID資訊，所以不能夠串連識別對SID=OTS請求。

 

報錯無法識別SID。

 

        執行個體主動進行動態註冊

 

此時，資料庫伺服器先於監聽程式啟動，預設要等待很長的時間才會發生動態註冊。我們使用alter system register;命令手動啟動動態註冊過程。監聽程式上發現pmon進程的註冊進程，並且記錄在日誌中。

 

 

29-6月 -2011 10:52:00 * service_register * ots * 0

 

 

將資料庫sid=ots對應的三個執行個體進行註冊。

 

 

        使用者Client串連進程

 

當出現串連請求的時候，日誌記錄。

 

 

29-6月 -2011 10:55:19 * (CONNECT_DATA=(SERVICE_NAME=ots)(CID=(PROGRAM=D:\PLSQL Developer\plsqldev.exe)(HOST=LIUZIYU-PC)(USER=Liuziyu))) * (ADDRESS=(PROTOCOL=tcp)(HOST=10.1.39.40)(PORT=1782)) * establish * ots * 0

 

根據日誌格式，可以理解為從遠程（HOST=LIUZIYU-PC，IP=10.1.39.40）主機通過TCP協議訪問到監聽程式，要求串連到ots服務上。使用的程式是pl/sql developer。

 

        周期性pmon註冊

 

動態註冊是一種經常性的註冊行為，pmon每隔幾分鐘的時間就會向監聽器進行一次註冊動作。

 

29-6月 -2011 10:55:33 * service_update * ots * 0

 

4、結論

 

監聽器是我們經常打交道的資料庫組件之一。同資料庫的alert_log一樣，監聽器日誌能夠協助我們解決很多日常故障問題。

 

Oracle 監聽器日誌解析