使用strace診斷奇怪的sqlplus登入問題

今天剛到公司，印度同事就開始急忙找我，說客戶有一個環境sqlplus連不上了。我第一反應是資料庫是不是停了，連線資源滿了等等，趕緊查收郵件，看到報錯資訊還是比較生疏的。

> sqlplus CHIDB7/xxxx@TDB1

SQL*Plus: Release 11.2.0.3.0 Production on Thu May 7 09:31:19 2015

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

ERROR:

ORA-21561: OID generation failed

這個錯誤還是比較生疏的，看了oerr的提示，更糊塗了。
21561, 00000, "OID generation failed"
// *Cause:  The handles passed in may not be valid
// *Action: Check the validity of the env, svc handles

首先登入到客戶端復現這個問題，問題還在，使用tnsping沒有問題。
然後登入到資料庫服務端，使用tnsping,sqlplus連線都沒問題。
>tnsping uatdb1
TNS Ping Utility for Linux: Version 11.2.0.3.0 - Production on 07-MAY-2015 10:28:20
Used TNSNAMES adapter to resolve the alias
Attempting to contact (description=(address=(protocol=tcp)(host=guatdb01)(port=1521))(connect_data=(sid=TDB1)))
OK (0 msec)

檢視metalink中有一篇文章 Ora-21561: OID Generation Failed (Doc ID 1335327.1)
說應該是/etc/hosts裡面的配置錯誤。官方的解釋如下：
Cause

This could be caused by not having the host name for the target database fully qualified in the hosts file.
To verify if you are hitting this issue, the following symptoms should be met:

- ORA-21561: OID generation failed.
- Hosts file has un-fully qualified entry for the target database host:

127.0.0.1 loopback localhost # loopback (lo0) name/address
10.210.9.111 dbhost

In this sample, dbhost is the target db host.

但是我的印象中/etc/hosts這種檔案我們也沒有許可權去修改配置，都是由專門的unix team去配置的。
自己也檢視了下/etc/hosts中的內容，裡面有上百個配置，檢視要連線的那臺機器，配置如下，實在沒看出有什麼問題。
10.xxxxx.xxx.12           guatdb01        gpnuatndb01.xxxx.com  gpnuatndb01 

檢視 tnsnames.ora的內容，沒有問題。
這個問題陷入了僵局，但是客戶那邊催的還是蠻緊的。最後開始試試用strace來看看有什麼收穫吧。
使用的命令如下： strace sqlplus CHIDB7/xxxx@TDB1
得到的內容是相當的多，看起來確實很費勁，裡面會有呼叫的一些細節資訊，列印出來的內容有1000多行，自己嘗試從後往前看，看了一會就放棄了，內容實在是太多了，有些引用的連結庫可能不是必須的，如果報錯，自己就得再上面琢磨一下，逐個排除。
試了一會就放棄了，為了更加高效，自己在另外一個客戶端中使用sqlplus可以正常連線，也做了一個strace的報告，第二個報告在900多行，使用文字比較工具來看就能看出很多端倪了。
看到一半的時候發現了一個關鍵的地方，就是網路相關的錯誤。


在有問題的客戶端中，內容如下：
socket(PF_INET6, SOCK_DGRAM, IPPROTO_IP) = -1 EAFNOSUPPORT (Address family not supported by protocol)
access("/etc/sqlnet.ora", F_OK)         = -1 ENOENT (No such file or directory)
access("/oravl01/oracle/11.2.0.3/network/admin/sqlnet.ora", F_OK) = 0

在一切正常的客戶端中，內容如下：
socket(PF_INET6, SOCK_DGRAM, IPPROTO_IP) = 6
bind(6, {sa_family=AF_INET6, sin6_port=htons(0), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28) = 0
close(6)

有了這些資訊，也算是有了進展，我記得metalink的文章(Doc ID 1335327.1)提到的檔案配置問題，在檢視了一些帖子之後，有的朋友碰到的主機名問題是在/etc/sysconfig/network中。
帶著試試看的態度對比了一下，發現還真是有一處不一樣。
有問題的客戶端中network明顯是在昨晚修改過。

> ll network

-rw-r--r-- 1 root root 91 May  6 23:09 network

> cat network

NETWORKING=yes

HOSTNAME=gpnchianap01

NETWORKING_IPV6=no

NOZEROCONF=yes

GATEWAY=10.235.60.1

但是在其它客戶端中的內容如下：
> cat /etc/sysconfig/network

NETWORKING=yes

NETWORKING_IPV6=no

HOSTNAME=gpnuatndb01

GATEWAY=10.235.103.1

一個明顯的不同就是多了NOZEROCONF=yes
帶著這個疑問去諮詢unix 組的人，得到的反饋那個配置和sqlplus的問題應該沒有關係。
不過帶著這個問題的進展，他們也去做了分析，最後他們發現是host的配置問題。
這個結果讓我有些意外，向他們討教，才算明白問題的癥結。
修改前
.
# grep gpnchiaapp01 /etc/hosts 
10.235.60.7             gchiaap01       gpnchianap01.globetel.com       gpnchianap01
.
修改後，追加了一個主機配置，他們發現真正的主機名沒有加入到/etc/hosts裡面，原有的gpnchianap01  是一個主機別名
.
10.235.60.7             gchiaap01       gpnchianap01.globetel.com       gpnchianap01  gpnchiaapp01

好了，問題的原因不是出在要連線的資料庫伺服器在/etc/hosts中的配置，而是當前主機名的配置問題。
可是這種問題怎麼會發生呢，既然已經執行很久了，很多測試環境都在用。得到的反饋是昨晚對這臺伺服器升級了kernel，這個配置應該是人為配錯導致的。
這個案例帶給我的其實就是strace在手足無措的時候還是能夠定位到一些問題，但是不要過分去依賴，如果在知道了問題的緣由之後再去看相關的日誌就能發現一些端倪了。但是在這個案例中自己也沒有足夠的理性去全面思考，兩個network檔案的配置不同不一定是最終的問題癥結，所以在這個問題的排查上自己也迷失了方向。
最後的問題原因還是主機名的配置，不過這個主機名配置不是要連線的資料庫伺服器配置，竟然是本地的主機名問題導致的。如果明白了問題的大環境，很多問題的解釋就行得通了。看來這些問題背景的掌握也是很重要的，有些時候問題發生的時候還是需要多問幾句，可以避免很多擠牙膏似的被動。
最後來做一次事後諸葛亮，看看在有問題的strace日誌中報錯前的幾行日誌。似乎問題一下子明朗起來，日誌中已經去查詢主機名gpnchiaapp01了，當時去/etc/hosts中確實是沒有的。
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 8
connect(8, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("0.0.0.0")}, 28) = 0
fcntl(8, F_GETFL)                       = 0x2 (flags O_RDWR)
fcntl(8, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
poll([{fd=8, events=POLLOUT}], 1, 0)    = 1 ([{fd=8, revents=POLLOUT}])
sendto(8, "\220\305\1\0\0\1\0\0\0\0\0\0\fgpnchiaapp01\0\0\1\0\1", 30, MSG_NOSIGNAL, NULL, 0) = 30
poll([{fd=8, events=POLLIN}], 1, 5000)  = 1 ([{fd=8, revents=POLLERR}])
close(8)                                = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 8
connect(8, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("0.0.0.0")}, 28) = 0
fcntl(8, F_GETFL)                       = 0x2 (flags O_RDWR)
fcntl(8, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
poll([{fd=8, events=POLLOUT}], 1, 0)    = 1 ([{fd=8, revents=POLLOUT}])
sendto(8, "\220\305\1\0\0\1\0\0\0\0\0\0\fgpnchiaapp01\0\0\1\0\1", 30, MSG_NOSIGNAL, NULL, 0) = 30
poll([{fd=8, events=POLLIN}], 1, 5000)  = 1 ([{fd=8, revents=POLLERR}])
close(8)                                = 0
open("/oravl01/oracle/11.2.0.3/rdbms/mesg/oraus.msb", O_RDONLY) = 8