20180125 pro_db 数据库无法建立新的连接，已连接进程运行正常，使用sqlplus登录报错 Connected to an idle instance
查看监控，从20180125 3：20左右就没办法连接

分析：

  1. 查看alert日志
    …
Thu Jan 25 03:19:16 2018
Process W003 died, see its trace file
Thu Jan 25 03:19:18 2018
Thu Jan 25 03:19:18 2018
Process J000 died, see its trace file
kkjcre1p: unable to spawn jobq slave process 
Errors in file /u01/app/oracle/diag/rdbms/pro_dbs/pro_db/trace/pro_db_cjq0_23028.trc:

…

03：19分 W003 空间管理工作器进程down了，J000进程down了

2.查看trace日志 pro_db_w003_39912.trc 无发现，02:53后就没有日志了
查看CJQ0进程的trace文件，pro_db_cjq0_23028.trc ，发现J000进程一直无法启动，状态是 KSOSP_SPAWNED
…

*** 2018-01-25 03:19:18.985
Process J000 is dead (pid=53199 req_ver=26548 cur_ver=26548 state=KSOSP_SPAWNED).
*** 2018-01-25 03:19:32.995
Process J000 is dead (pid=53532 req_ver=26553 cur_ver=26553 state=KSOSP_SPAWNED)

…

  1. systemdump文件中应证了CJQ0进程无法启动，等待OS启动进程

Chain 1:

Oracle session identified by:
{
            instance: 1 (pro_dbs.pro_db)
               os id: 23028
          process id: 57, oracle@dghpl406 (CJQ0) <<<<这个进程是负责在数据库上启动job slave 进程的
          session id: 136
    session serial #: 3
}
is waiting for 'os thread startup' with wait info:  <<<< 这个进程在等待启动os 上的进程
{
        time in wait: 0.338422 sec
       timeout after: 1 min 59 sec 
             wait id: 330201
            blocking: 0 sessions
         current sql: <none>
         short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+178<-ksliwat()+2046<-kslwaitctx()+163<-ksoreq_wait()+508<-ksbsrv()+3982<-kkjcre1p()+159<-kkjcrenp()+233<-kkjsns()+595<-kkjcjexe()+914<-kkjssrh()+561<-ksbcti()+513<-ksbabs()+1735<-ksbrdp()+1045<-opirip()+623<-opidrv()+603<-sou2o()+103<-opimai_real()+250<-ssthrdmain()+265<-main()+201<-__libc_start_main()+253
        wait history:
          * time between current wait and wait #1: 0.000050 sec
          1.       event: 'enq: PR - contention'
             time waited: 0.109790 sec
                 wait id: 330200          p1: 'name|mode'=0x50520006
                                          p2: '0'=0x0
                                          p3: '0'=0x0
          * time between wait #1 and #2: 0.000525 sec
          2.       event: 'rdbms ipc message'
             time waited: 0.890457 sec
                 wait id: 330199          p1: 'timeout'=0x59
          * time between wait #2 and #3: 0.000527 sec
          3.       event: 'os thread startup'
             time waited: 1.000629 sec
                 wait id: 330198          
}

Chain 1 Signature: ‘os thread startup’

4.操作系统层面没有安装监控，检查/var/log/messages 没有发现凌晨有任何异常，倒是前一天晚上装了GNOME桌面安装了很多依赖的lib库

5.metalink上搜索 unable to spawn jobq slave process KSOSP_SPAWNED
根据文档描述，造成数据库CJQ0进程无法启动，不能接受新的连接的原因主要是无法分配内存（内存不够或者prelink导致虚拟内存地址变动）

Connected to an idle instance, while database instance is running (Process J000 died, see its trace file kkjcre1p: unable to spawn jobq slave process ) (Doc ID 1578491.1)
Bug 20480596 : PROCESS J000 IS DEAD ... STATE=KSOSP_SPAWNED
Why not able to allocate a more SGA than 193G on Linux 64? (Doc ID 1241284.1)

6.查看主机确实安装prelink并且在03：19运行了prelink， 查看prelink 运行日志，prelink对很多lib库进行了重定位

[root@dghpl406 ~]# rpm -qa prelink
prelink-0.4.6-3.1.el6_4.x86_64
[oracle@dgvxl2297 scripts]$ whereis prelink
prelink: /usr/sbin/prelink /etc/prelink.conf /etc/prelink.cache /usr/share/man/man8/prelink.8.gz

[root@dghpl406 ~]# ls -al /var/log/prelink/prelink.log 
-rw-r--r-- 1 root root 75324 Jan 25 03:19 /var/log/prelink/prelink.log
<<<<<<<<<<<<prelink运行日志时间正好是03：19

NOTE:
prelink是一种修改elf共享库和elf动态链接二进制文件的程序，从而显著减少动态链接程序在启动时执行重定位所需的时间。由于更少的重定位，运行时内存消耗也会减少（特别是不可共享页面的数量）。
prelink信息仅在启动时使用，如果依赖库从预链接以来没有改变;否则如果有lib库的改变（升级删除或者新装lib库）程序会重新定位lib库虚拟地址。

  1. 重新查看/var/log/messages，确认前天晚上确实安装了很多lib库，这很有可能触发了prelink进程重定位，而重定位导致SGA无法为新的连接链接到指定内存空间

小结：
通过数据库日志和prelink日志，以及metalink的相关bug和文档，prelink做lib库虚拟内存地址重定位导致SGA无法为新创建的进程分配内存的可能性最大。
如果在故障时间段对sqlplus操作执行strace，应该可以看到请求的哪一步失败，或许可以定位是否lib的内存地址变化

strace -o /tmp/output.txt sqlplus / as sysdba