記一次解決:TNS-12518: TNS:listener could not hand off client connection

denglt發表於2012-08-29
剛在Oracle linux 6.2 上安裝好了Oracle 11gR2 RAC(ASM)
驗證一切正常:
檢查RAC的狀態
[oracle@study1 ~]$ srvctl config database -d studydb
Database unique name: studydb
Database name: studydb
Oracle home: /u01/app/oracle/product/11.2.0/db_1
Oracle user: oracle
Spfile: +DATA/studydb/spfilestudydb.ora
Domain:
Start options: open
Stop options: immediate
Database role: PRIMARY
Management policy: AUTOMATIC
Server pools: studydb
Database instances: studydb1,studydb2
Disk Groups: DATA
Services:
Database is administrator managed
[oracle@study1 ~]$ srvctl status database -d studydb
Instance studydb1 is running on node study1
Instance studydb2 is running on node study2
通過v$active_instances試圖查詢資料庫例項的當前狀態:
[oracle@study1 ~]$ sqlplus /nolog
SQL*Plus: Release 11.2.0.1.0 Production on Mon Aug 20 10:52:36 2012
Copyright (c) 1982, 2009, Oracle.  All rights reserved.
SQL> conn / as sysdba
Connected.
SQL> SELECT inst_name FROM v$active_instances;
INST_NAME
--------------------------------------------------------------------------------
study1.dlt:studydb1
study2.dlt:studydb2

但是從遠端連線RAC的時候,每次連線上的都是二號節點,故在tnsname中指定INSTANCE_NAME = studydb1,連線時報:
SQL> conn sys/sys@studydb as sysdba
ERROR:
ORA-12502: TNS:listener received no CONNECT_DATA from client
換為INSTANCE_NAME = studydb2就可以連線
啟動listerer trace(trc_level=user)得到如下日誌:
listener.log:
 * (CONNECT_DATA=(SERVER=DEDICATED)(SERVICE_NAME=studydb)(INSTANCE_NAME=studydb1)(CID=(PROGRAM=c:\oracle\product\10.2.0\db_1\bin\sqlplus.exe)(HOST=DLT-ST)(USER=dlt))) * (ADDRESS=(PROTOCOL=tcp)(HOST=172.16.88.130)(PORT=52107)) * establish * studydb * 12518
TNS-12518: TNS:listener could not hand off client connection
 TNS-12547: TNS:lost contact
  TNS-12560: TNS:protocol adapter error
   TNS-00517: Lost contact
    Linux Error: 32: Broken pipe
   
trace log  (level=user):  
2012-08-29 10:45:49.160579 : nstoSetupTimeout:ATO enabled for ctx=0x0x92856d0, val=60000(millisecs)
2012-08-29 10:45:49.160809 : nstoUpdateActive:Active timeout is 0 (see nstotyp)
2012-08-29 10:45:49.160863 : nsopen:opening transport...
2012-08-29 10:45:49.160995 : nttcnp:getting sockname
2012-08-29 10:45:49.161047 : nttcnp:getting peername
2012-08-29 10:45:49.161100 : nttcnr:waiting to accept a connection.
2012-08-29 10:45:49.161169 : nttcnr:getting sockname
2012-08-29 10:45:49.161220 : nttcnr:connected on ipaddr 172.16.89.231
2012-08-29 10:45:49.161265 : nttvlser:Accepted Entry
2012-08-29 10:45:49.161345 : nttcon:set TCP_NODELAY on 20
2012-08-29 10:45:49.161450 : nsopen:transport is open
2012-08-29 10:45:49.161646 : nsnainit:inf->nsinfflg[0]: 0xd inf->nsinfflg[1]: 0xd
2012-08-29 10:45:49.161707 : nsopen:global context check-in (to slot 9) complete
2012-08-29 10:45:49.161779 : nsanswer:deferring connect attempt; at stage 5
2012-08-29 10:45:49.163585 : nscon:doing connect handshake...
2012-08-29 10:45:49.163783 : nscon:got NSPTCN packet
2012-08-29 10:45:49.163942 : nsevdansw:exit
2012-08-29 10:45:49.164139 : nstoClearTimeout:ATO disabled for ctx=0x0x92856d0
2012-08-29 10:45:49.164254 : nstoUpdateActive:Active timeout is -1 (see nstotyp)
2012-08-29 10:45:49.164363 : nstoControlATO:ATO disabled for ctx=0x0x92856d0
2012-08-29 10:45:49.165074 : nsglbgetRSPidx:returning ecode=0
2012-08-29 10:45:49.166230 : nsglbgetSdPidx:secondary protocol=4
2012-08-29 10:45:49.167811 : nsbeqaddr:connecting...
2012-08-29 10:45:49.168070 : nsopen:opening transport...
2012-08-29 10:45:49.174041 : sntpcall:detaching from parent with additional fork
2012-08-29 10:45:49.182667 : sntpcall:hdl[IR]=23, hdl[IW]=22
2012-08-29 10:45:49.183134 : nsopen:global context check-in (to slot 10) complete
2012-08-29 10:45:50.568116 : sntpcall:only 0 bytes read
2012-08-29 10:45:50.568367 : sntpcall:Can't read from pipe; err[1] = 32
2012-08-29 10:45:50.569337 : nserror:nsres: id=10, p=72, ns=12547, ns2=12560; nt[0]=517, nt[1]=32, nt[2]=0; ora[0]=0, ora[1]=0, ora[2]=0
2012-08-29 10:45:50.569548 : nstimarmed:no timer allocated
2012-08-29 10:45:50.569704 : nstoClearTimeout:ATO disabled for ctx=0x0x9290a68
2012-08-29 10:45:50.570030 : nstoClearTimeout:STO disabled for ctx=0x0x9290a68
2012-08-29 10:45:50.570161 : nstoClearTimeout:RTO disabled for ctx=0x0x9290a68
2012-08-29 10:45:50.570318 : nstoClearTimeout:PITO disabled for ctx=0x0x9290a68
2012-08-29 10:45:50.570935 : nstoUpdateActive:Active timeout is -1 (see nstotyp)
2012-08-29 10:45:50.572513 : nsclose:global context check-out (from slot 10) complete
2012-08-29 10:45:50.572773 : nstimarmed:no timer allocated
2012-08-29 10:45:50.573024 : nsclose:closing transport
2012-08-29 10:45:50.574769 : nsclose:global context check-out (from slot 9) complete
2012-08-29 10:45:50.575723 : nsglhe:Direct handoff errors: ns=12547, ns2=12560
2012-08-29 10:45:50.577006 : nsglhe:Deallocating cxd 0x9284bb0. 
在metalink上查到一篇文章:TNS-12518 Can Not Connect To RAC 11gR2 Database [ID 1088754.1] 
說到:
This is caused by the oracle executable not having the setuid bit on:
$ ls -l $ORACLE_HOME/bin/oracle
 -rwxrwxr-x 1 oracle dba 210824648 Mar 29 12:33 /orabin/app/oracle/product/112_dbrac/server/db_1/bin/oracle*
在節點一查詢:
[oracle@study1 ~]$ ls -l $ORACLE_HOME/bin/oracle
-r-xr-sr-x 1 oracle asmadmin 173515319 Aug 16 18:24 /u01/app/oracle/product/11.2.0/db_1/bin/oracle
在節點二查詢:
[oracle@study2 ~]$ ls -l $ORACLE_HOME/bin/oracle
-r-sr-s--x 1 oracle asmadmin 173515319 Aug 16 19:41 /u01/app/oracle/product/11.2.0/db_1/bin/oracle
兩個節點上的許可權不一致,節點一的oracle使用者真的少了setuid
把節點一的許可權修改為跟節點二一樣
[oracle@study1 bin]$ chmod u+s oracle
[oracle@study1 bin]$ chmod o-r oracle
重啟一節點資料庫(這一步不一定需要,我的是剛好節點一機器被人重啟了,資料庫沒有自動啟動)
SQL> conn sys/sys@studydb1 as sysdba
Connected.
SQL> select instance_name from v$instance;
INSTANCE_NAME
----------------
studydb1
1 row selected.
遠端連線節點一ok.

來自 “ ITPUB部落格 ” ,連結:http://blog.itpub.net/195110/viewspace-742164/,如需轉載,請註明出處,否則將追究法律責任。

相關文章