今天一网友咨询数据库宕机了,当时数据库出现用户无法登录的症状,为了了解起因,去查看了网友的告警日志alert.log,发现在晚上1
今天一网友咨询数据库宕机了,当时数据库出现用户无法登录的症状,为了了解起因,去查看了网友的告警日志alert.log,发现在晚上10:00左右出现大量的ora-00020: no more process state objects available 错误,具体错误日志如下:
fatal ni connect error 12170.
version information:
tns for linux: version 11.2.0.2.0 - production
oracle bequeath nt protocol adapter for linux: version 11.2.0.2.0 - production
tcp/ip nt protocol adapter for linux: version 11.2.0.2.0 - production
time: 11-may-2015 14:28:28
tracing not turned on.
tns error struct:
ns main err code: 12535
tns-12535: tns:operation timed out
ns secondary err code: 12560
nt main err code: 505
tns-00505: operation timed out
nt secondary err code: 110
nt os err code: 0
client address: (address=(protocol=tcp)(host=192.168.102.150)(port=50069))
mon may 11 16:21:14 2015
thread 1 cannot allocate new log, sequence 1728
private strand flush not complete
current log# 4 seq# 1727 mem# 0: /oradata/orcl/redo4.log
thread 1 advanced to log sequence 1728 (lgwr switch)
current log# 3 seq# 1728 mem# 0: /oradata/orcl/redo3.log
mon may 11 22:00:00 2015
setting resource manager plan scheduler[0x3107]:default_maintenance_plan via scheduler window
setting resource manager plan default_maintenance_plan via parameter
mon may 11 22:00:00 2015
starting background process vkrm
mon may 11 22:00:00 2015
vkrm started with pid=83, os id=27195
tue may 12 00:56:23 2015
thread 1 cannot allocate new log, sequence 1729
private strand flush not complete
current log# 3 seq# 1728 mem# 0: /oradata/orcl/redo3.log
thread 1 advanced to log sequence 1729 (lgwr switch)
current log# 1 seq# 1729 mem# 0: /oradata/orcl/redo01.log
tue may 12 02:00:00 2015
closing scheduler window
closing resource manager plan via scheduler window
clearing resource manager plan via parameter
tue may 12 10:46:48 2015
thread 1 cannot allocate new log, sequence 1730
private strand flush not complete
current log# 1 seq# 1729 mem# 0: /oradata/orcl/redo01.log
thread 1 advanced to log sequence 1730 (lgwr switch)
current log# 2 seq# 1730 mem# 0: /oradata/orcl/redo2.log
tue may 12 14:36:13 2015
thread 1 cannot allocate new log, sequence 1731
private strand flush not complete
current log# 2 seq# 1730 mem# 0: /oradata/orcl/redo2.log
thread 1 advanced to log sequence 1731 (lgwr switch)
current log# 4 seq# 1731 mem# 0: /oradata/orcl/redo4.log
tue may 12 16:27:07 2015
thread 1 cannot allocate new log, sequence 1732
private strand flush not complete
current log# 4 seq# 1731 mem# 0: /oradata/orcl/redo4.log
thread 1 advanced to log sequence 1732 (lgwr switch)
current log# 3 seq# 1732 mem# 0: /oradata/orcl/redo3.log
tue may 12 22:00:00 2015
setting resource manager plan scheduler[0x3108]:default_maintenance_plan via scheduler window
setting resource manager plan default_maintenance_plan via parameter
tue may 12 22:00:00 2015
starting background process vkrm
tue may 12 22:00:00 2015
vkrm started with pid=174, os id=25804
wed may 13 02:00:00 2015
closing scheduler window
closing resource manager plan via scheduler window
clearing resource manager plan via parameter
wed may 13 02:45:10 2015
thread 1 cannot allocate new log, sequence 1733
private strand flush not complete
current log# 3 seq# 1732 mem# 0: /oradata/orcl/redo3.log
thread 1 advanced to log sequence 1733 (lgwr switch)
current log# 1 seq# 1733 mem# 0: /oradata/orcl/redo01.log
wed may 13 09:05:36 2015
time drift detected. please check vktm trace file for more details.
wed may 13 09:15:55 2015
dm00 started with pid=352, os id=4784, job system.sys_export_schema_01
wed may 13 09:15:56 2015
dw00 started with pid=353, os id=4786, wid=1, job system.sys_export_schema_01
wed may 13 10:11:52 2015
thread 1 cannot allocate new log, sequence 1734
private strand flush not complete
current log# 1 seq# 1733 mem# 0: /oradata/orcl/redo01.log
thread 1 advanced to log sequence 1734 (lgwr switch)
current log# 2 seq# 1734 mem# 0: /oradata/orcl/redo2.log
wed may 13 13:15:38 2015
thread 1 cannot allocate new log, sequence 1735
private strand flush not complete
current log# 2 seq# 1734 mem# 0: /oradata/orcl/redo2.log
thread 1 advanced to log sequence 1735 (lgwr switch)
current log# 4 seq# 1735 mem# 0: /oradata/orcl/redo4.log
wed may 13 14:54:18 2015
thread 1 cannot allocate new log, sequence 1736
private strand flush not complete
current log# 4 seq# 1735 mem# 0: /oradata/orcl/redo4.log
thread 1 advanced to log sequence 1736 (lgwr switch)
current log# 3 seq# 1736 mem# 0: /oradata/orcl/redo3.log
wed may 13 17:39:31 2015
thread 1 cannot allocate new log, sequence 1737
private strand flush not complete
current log# 3 seq# 1736 mem# 0: /oradata/orcl/redo3.log
thread 1 advanced to log sequence 1737 (lgwr switch)
current log# 1 seq# 1737 mem# 0: /oradata/orcl/redo01.log
wed may 13 20:47:10 2015
ora-00020: no more process state objects available
ora-20 errors will not be written to the alert log for
the next minute. please look at trace files to see all
the ora-20 errors.
process m000 submission failed with error = 20
wed may 13 20:52:37 2015
ora-00020: no more process state objects available
ora-20 errors will not be written to the alert log for
the next minute. please look at trace files to see all
the ora-20 errors.
process m000 submission failed with error = 20
wed may 13 20:57:38 2015
ora-00020: no more process state objects available
ora-20 errors will not be written to the alert log for
the next minute. please look at trace files to see all
the ora-20 errors.
process m000 submission failed with error = 20
wed may 13 21:01:35 2015
ora-00020: no more process state objects available
ora-20 errors will not be written to the alert log for
the next minute. please look at trace files to see all
the ora-20 errors.
process w001 submission failed with error = 20
wed may 13 21:02:38 2015
ora-00020: no more process state objects available
ora-20 errors will not be written to the alert log for
the next minute. please look at trace files to see all
the ora-20 errors.
process m001 submission failed with error = 20
wed may 13 21:05:44 2015
ora-00020: no more process state objects available
ora-20 errors will not be written to the alert log for
the next minute. please look at trace files to see all
the ora-20 errors.
process w001 submission failed with error = 20
wed may 13 21:12:38 2015
ora-00020: no more process state objects available
ora-20 errors will not be written to the alert log for
the next minute. please look at trace files to see all
the ora-20 errors.
process m000 submission failed with error = 20
process m001 submission failed with error = 20
wed may 13 21:42:39 2015
ora-00020: no more process state objects available
ora-20 errors will not be written to the alert log for
the next minute. please look at trace files to see all
the ora-20 errors.
process m000 submission failed with error = 20
process m001 submission failed with error = 20
wed may 13 21:43:00 2015
process w001 submission failed with error = 20
wed may 13 21:51:13 2015
adjusting the default value of parameter parallel_max_servers
from 1280 to 385 due to the value of parameter processes (400)
starting oracle instance (normal)
wed may 13 21:52:40 2015
ora-00020: no more process state objects available
ora-20 errors will not be written to the alert log for
the next minute. please look at trace files to see all
the ora-20 errors.
process m000 submission failed with error = 20
wed may 13 21:53:33 2015
错误信息一般在oracle实例在创建一些辅助后台进程(如mmon的子进程m00x或者子进程w00x等)时出现进程启动失败时出现,而造成该错误的可能性有多种,包括oracle实例资源不足、操作系统资源不足等等。其中较为常见的是实例instance的process使用达到上限,可以通过查询v$resource_limit视图来了解实例生命周期内是否发生过process总数暴满的情况:
我们可以看到processes的max_utilization最大使用数目曾到过limit_value限定的400,,
sessions达到了640.
从以上v$resource_limit视图的输出来看,极有可能是processes总数达到上限导致了新的后台辅助进程创建失败,其实我们可以很方便地验证这一点:
[oracle@bntjftest ~]$ sqlplus / as sysdba
sql*plus: release 11.2.0.4.0 production on thu may 14 15:28:15 2015
copyright (c) 1982, 2013, oracle. all rights reserved.