12C安装历险记----ORA-12560和ORA-12537的解决方案

本来正在研究Mutex的算法，发现在11.2.0.1到11.2.0.3之间，Oracle对Mutex算法做出很大的调整，听闻12C发布，一时心痒，不知12C中Mutex又有哪些变化，马上Down下Solaris版的12C，准备安装。

声明下，之所以要装Solaris下的12C，并非我独立特行，看过我以前文章的Puber一定知道，是因为Dtrace的原故。这个简单的工具可以帮助我们掀开Oracle重重黑幕，一窥Oracle内部原理。

我的OS是Solaris 10，以下是我的Solaris版本信息：

bash-3.2$ uname -r

5.10

bash-3.2$ cat release

Oracle Solaris 10 8/11 s10x_u10wos_17b X86

Copyright (c) 1983, 2011, Oracle and/or its affiliates. All rights reserved.

Assembled 23 August 2011

我的Solaris是默认安装，没有使用Customs方式，安装非常简单，不需描述。下面说说12C的安装过程。

其实和11GR2也差不太多，非常简单，只在条件检查这里，报如下错误： 

Swap空间期望是3G，我只有500M。还有/tmp空间，我的是1G。这两个原来装11GR2时也报错，不过最后安装也是成功的，这里我毫不犹豫选择“忽略”。最后一个，缺少SUNWeu8os包，本来是想解决一下的，但简单百度了一下，没有找到装这个包的相关信息。心急之下，把它也忽略了。

接下来安装也还算顺利，就是在最后装的百分之八十几时，报了一个错，Retry一下无效，还是报错，只能跳过。然后就没有报错了，安装过程还算顺利的完成了。

急不可待的sqlplus / as sysdba，准备手动建个库玩玩。但是，报如下错误：

bash-3.2$ sqlplus / as sysdba

SQL*Plus: Release 12.1.0.1.0 Production on Thu Jun 27 16:33:23 2013

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

ERROR:

ORA-12560: TNS:protocol adapter error

Enter user-name:

ORA-12560这种情况在Windows下比较常见，也比较容易解决，但在其他系统中遇到，就比较棘手了。

本来想绕过去，不让我本地连接，我就通过监听连接。于是配置了监听，生成了密码文件，还有tnsnames.ora，然后通过监听连接，依然报错，错误信息如下：

bash-3.2$ sqlplus sys/oracle@prod as sysdba

SQL*Plus: Release 12.1.0.1.0 Production on Thu Jun 27 17:09:54 2013

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

ERROR:

ORA-12537: TNS:connection closed

变成了ORA-12537错误，还是连不上。

遇到这种奇怪问题，也没啥思路，我们的方法，只能是各种各样的跟踪。要想解决问题，必先了解问题出在哪个环境。要想知道问题出在哪个环节，也只能跟踪了。但是这点问题还不需要Dtrace和gdb/mdb，先用Truss试试就行，看看连接时有什么系统调用。

先不连接进入Sqlplus：

bash-3.2$ sqlplus /nolog

SQL*Plus: Release 12.1.0.1.0 Production on Thu Jun 27 17:24:00 2013

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

SQL>

然后查一下sqlplus的进程号：

bash-3.2$ ps -ef|grep sql

oracle 969 872 0 17:24:01 pts/2 0:00 sqlplus /nolog

接着跟踪969进程，并将结果写到/tmp/sqlplus.log中：

bash-3.2$ truss -o /tmp/sqlplus.log -p 969

然后在sqlplus /nolog中connect连接：

SQL> conn / as sysdba

ERROR:

ORA-12560: TNS:protocol adapter error

查看跟踪结果，没发现太有用的信息，但也有些收获，发现有很多这样的信息：

stat("/export/home/oradb/diag/clients/user_oracle/host_1667750511_80/alert/log.xml", 0xFFFFFD7FFFDE8320) = 0

open("/export/home/oradb/diag/clients/user_oracle/host_1667750511_80/trace/sqlnet.log", O_WRONLY|O_APPEND|O_CREAT|O_LARGEFILE, 0660) = 11

chown("/export/home/oradb/diag/clients/user_oracle/host_1667750511_80/trace/sqlnet.log", 4294967295, 101) = 0

stat("/export/home/oradb/diag/clients/user_oracle/host_1667750511_80/trace/sqlnet.log", 0xFFFFFD7FFFDEAAA0) = 0

chmod("/export/home/oradb/diag/clients/user_oracle/host_1667750511_80/trace/sqlnet.log", 0640) = 0

从这些可以看到，虽然我并没有通过监听连接，但SQLPLUS还是要向监听日志和sqlnet.log日志中写信息。马上打开log.xml和sqlnet.log，看一下是否有更详细的信息。

它们两个中的信息类似，以sqlnet.log为例，找到一些报错：

Fatal NI connect error 12560, connecting to:

(DESCRIPTION=(ADDRESS=(PROTOCOL=beq)(PROGRAM=/export/home/oradb/product/12.1.0/bin/oracle)(ARGV0=oracleh3)(ARGS='(DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq)))')(DETACH=NO))(CONNECT_DATA=(CID=(PROGRAM=sqlplus@h3)(HOST=h3)(USER=oracle))))

VERSION INFORMATION:

TNS for Solaris: Version 12.1.0.1.0 - Production

Oracle Bequeath NT Protocol Adapter for Solaris: Version 12.1.0.1.0 - Production

Time: 27-JUN-2013 17:49:37

Tracing not turned on.

Tns error struct:

ns main err code: 12560

TNS-12560: TNS:protocol adapter error

ns secondary err code: 0

nt main err code: 530

TNS-00530: Protocol adapter error

nt secondary err code: 8

nt OS err code: 0

除了TNS-12560，它和ORA-12560对应。还有个TNS-00530，这个不知道是干吗的，也算有点收获。GooGle、百度一下，没发现太有用的信息。这个新发现的TNS-00530，对解决问题没啥太大帮助。

接下来怎么办？既然Sqlplus会向sqlnet.log中写日志，只要提高日志的级别，让它输出更详细的信息，说不定可以找到更详细的信息定位问题。马上动手，还是原来的位置：$ORACLE_HOME/network/admin，创建sqlnet.ora文件，我输入的内容如下：

bash-3.2$ cat sqlnet.ora

DIAG_ADR_ENABLED=on

ADR_BASE=/export/home/oracle/trace

TRACE_LEVEL_CLIENT=16

TRACE_LEVEL_SERVER=16

关于这几个参数，在12C的文档“Net Services Reference”章节中sqlnet.ora配置小节，“ADR Diagnostic Parameters in sqlnet.ora”部分有介绍。开启QQ转让平台连接时的跟踪，两个级别值16，已经是最高的级别了。文档中有介绍的：

TRACE_LEVEL_CLIENT

Purpose

To turn client tracing on at a specified level or to turn it off. This parameter is also applicable when non-ADR tracing is used.

Default

off or 0

Values

• off or 0 for no trace output
• user or 4 for user trace information
• admin or 10 for administration trace information
• support or 16 for Oracle Support Services trace information

Example

TRACE_LEVEL_CLIENT=user

其他参数我不再粘了，你自己查阅吧。

还有，参数“ADR_BASE=/export/home/oracle/trace”中的目录：trace，一定要创建下。

好，再用sqlplus / as sysdba连接下，错误当然还是依旧了。到/export/home/oracle/trace目录中查看，Oracle建了好多层目录，在/export/home/oracle/trace/oradiag_oracle/diag/clients/user_oracle/host_1667750511_80/trace目录中，用“ls –lFrt”查询日志最新的trc文件，就是跟踪结果了。

跟踪结果非常详细，有Sqlplus希望在sqlnet.ora中读取的参数等等，想了解进程连接过程的，可以好好研究下这份跟踪文件。先不管这些，在跟踪结果中找一下错误信息，有这样一段报错：

2013-06-27 22:20:02.380430 : sntpcall:entry

2013-06-27 22:20:02.380477 : sntpcall:not detaching from parent with additional fork

2013-06-27 22:20:02.380506 : sntpcall:waiting for OS to spawn process /export/home/oradb/product/12.1.0/bin/oracle

2013-06-27 22:20:02.386670 : sntpcall:process forked.

2013-06-27 22:20:02.387077 : sntpcall:hdl[IR]=16, hdl[IW]=15

2013-06-27 22:20:02.387144 : sntpcall:spawned process initialized in 0 csec.

2013-06-27 22:20:02.387181 : sntpcall:result string is NTP8 0

2013-06-27 22:20:02.387241 : sntpcall:Can't read from pipe; err[1] = 8

2013-06-27 22:20:02.387293 : sntpcall:exit

2013-06-27 22:20:02.387373 : ntpcon:exit

2013-06-27 22:20:02.387431 : nserror:entry

2013-06-27 22:20:02.387469 : nserror:nsres: id=0, op=65, ns=12560, ns2=0; nt[0]=530, nt[1]=8, nt[2]=0; ora[0]=0, ora[1]=0, ora[2]=0

2013-06-27 22:20:02.387517 : nsopen:unable to open transport

2013-06-27 22:20:02.387552 : nstoClearTimeout:entry

2013-06-27 22:20:02.387582 : nstoClearTimeout:ATO disabled for ctx=0x558520

2013-06-27 22:20:02.387642 : nstoClearTimeout:STO disabled for ctx=0x558520

2013-06-27 22:20:02.387672 : nstoClearTimeout:RTO disabled for ctx=0x558520

2013-06-27 22:20:02.387698 : nstoClearTimeout:PITO disabled for ctx=0x558520

2013-06-27 22:20:02.387726 : nstoUpdateActive:entry

2013-06-27 22:20:02.387754 : nstoUpdateActive:Active timeout is -1 (see nstotyp

“sntpcall:waiting for OS to spawn process /export/home/oradb/product/12.1.0/bin/oracle”这行，说明这是要执行Oracle的可执行文件。它下面没几行，有个报错：“sntpcall:Can't read from pipe; err[1] = 8”，这说明很有可能是Oracle可执行文件执行有问题，导致官道异常。

这些信息说明，十有八九是Oracle可执行文件执行出了问题。我找了一个11GR2的测试环境，试了一下Sqlplus / as sysdba时的Trc文件，也有类似步骤，但没有“sntpcall:Can't read from pipe; err[1] = 8”。

接下来，会是什么导致Oracle可执行文件异常呢？我先到$ORACLE_HOME/bin下，查看下Oracle可执行文件的信息：

bash-3.2$ ls -lFrt /export/home/oradb/product/12.1.0/bin/oracle

-rwxr-x--x 1 oracle oinstall 0 Jun 27 16:33 /export/home/oradb/product/12.1.0/bin/oracle*

查看的结果如上，问题已经一目了然了。

它的权限不对，还有文件的长度竞然是0字节。0字节的可执行文件，当然执行异常了。

具体的原因是什么我也不清楚，极有可能是缺少SUNWeu8os包引发安装过程异常导致的。接下来解决方案，用Relink all尝试一下，如果不行，先将SUNWeu8os包问题搞搞定，再重装一次。

退出sqlplus，到$ORACLE_HOME/bin下，./relink all了一下。Relink时的日志是“$ORACLE_HOME/install/relink.log”，查看Relink日志，Relink期间没有报错，最后一步是：

chmod 6751 /export/home/oradb/product/12.1.0/bin/oracle

这一步是将可执行文件的权限改成 6751 。如果权限不对，执行Oracle也是会有问题。Relink后，再次查看文件状态：

bash-3.2$ ls -lFrt oracle

-rwsr-s--x 1 oracle oinstall 341926760 Jun 27 16:30 oracle*

差不多340M，11GR2是240多M，大了100M。再次连接：

bash-3.2$ sqlplus / as sysdba

SQL*Plus: Release 12.1.0.1.0 Production on Thu Jun 27 23:40:57 2013

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

Connected to an idle instance.

终于不再报错，成功连接，对应的服务器进程也已经启动：

bash-3.2$ ps -ef|grep LOCAL

oracle 1076 1075 0 23:40:58 ? 0:00 oracleh3 (DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq)))

好，开始我的12C探索之旅。预告下先，下周将如期发布，《Mutex原理和调优及在11G、12C中的变迁》。