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

2020-06-30 00:00:00 连接 报错 信息 监听 跟踪

本来正在研究Mutex的算法,发现在11.2.0.111.2.0.3之间,OracleMutex算法做出很大的调整,听闻12C发布,一时心痒,不知12CMutex又有哪些变化,马上DownSolaris版的12C,准备安装。

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

我的OSSolaris 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错误,还是连不上。

遇到这种奇怪问题,也没啥思路,我们的方法,只能是各种各样的跟踪。要想解决问题,必先了解问题出在哪个环境。要想知道问题出在哪个环节,也只能跟踪了。但是这点问题还不需要Dtracegdb/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 /nologconnect连接:

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.xmlsqlnet.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”部分有介绍。开启连接时的跟踪,两个级别值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*

差不多340M11GR2240M,大了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原理和调优及在11G12C中的变迁》。

相关文章