43 积分	0 好友	1 主题

发消息

ora 0045 错误

1^#

发表于 2012-5-24 09:12:30 | 查看: 17787| 回复: 7

最近数据库多次出现这样的错误：

ORA-00445: background process "m000" did not start after 120 seconds
Thu May 24 03:35:43 2012
Errors in file d:\app\administrator\diag\rdbms\orc11g\orc11g\trace\orc11g_smco_8356.trc  (incident=58282):
ORA-00445: background process "W000" did not start after 120 seconds
Thu May 24 03:37:48 2012
Errors in file d:\app\administrator\diag\rdbms\orc11g\orc11g\trace\orc11g_mmon_11200.trc  (incident=58290):
ORA-00445: background process "m000" did not start after 120 seconds
Thu May 24 03:39:54 2012
Errors in file d:\app\administrator\diag\rdbms\orc11g\orc11g\trace\orc11g_smco_8356.trc  (incident=58283):
ORA-00445: background process "W000" did not start after 120 seconds
Thu May 24 03:42:00 2012
Errors in file d:\app\administrator\diag\rdbms\orc11g\orc11g\trace\orc11g_mmon_11200.trc  (incident=58291):
ORA-00445: background process "m000" did not start after 120 seconds
Thu May 24 03:44:05 2012

附件有日志文件，谢谢大家帮忙看下。

-------------------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
PL/SQL Release 11.2.0.1.0 - Production
CORE 11.2.0.1.0    Production
TNS for 64-bit Windows: Version 11.2.0.1.0 - Production
NLSRTL Version 11.2.0.1.0 - Production

ORA-00445.rar

192.02 KB, 下载次数: 1817

分享0

收藏0 回复只看该作者道具举报

yehc@epsoft.com

2^#

发表于 2012-5-24 09:55:34

根据日志初步判断是跟内存（或SWAP）是否够用有关系。
1、查看当前数据库内存配置情况。
SQL>create pfile='D:\spfilebak.ora' from spfile; 贴出结果

2、到d盘下查看spfilebak文件，并贴出参数设置
或者
SQL>show parameter memory_target;贴出结果

另外提出一个疑问：
Thu May 24 08:45:41 2012
Thread 1 cannot allocate new log, sequence 17805
Checkpoint not complete
  Current log# 2 seq# 17804 mem# 0: D:\DATABASE\ORC11G\REDO02.LOG
Thread 1 advanced to log sequence 17805 (LGWR switch)
  Current log# 3 seq# 17805 mem# 0: D:\DATABASE\ORC11G\REDO03.LOG
Thu May 24 08:45:54 2012
Thread 1 cannot allocate new log, sequence 17806
Checkpoint not complete
  Current log# 3 seq# 17805 mem# 0: D:\DATABASE\ORC11G\REDO03.LOG
trc  (incident=58244):
ORA-00445: background process "W000" did not start after 120 seconds
Thu May 24 01:56:36 2012
Errors in file d:\app\administrator\diag\rdbms\orc11g\orc11g\trace\orc11g_cjq0_11216.trc  (incident=58231):
ORA-00445: background process "J000" did not start after 120 seconds
kkjcre1p: unable to spawn jobq slave process

为什么你的alert log里24号的日志显示早上08:45:41 还切换过redo。而接下来又回到01:56:36时间的日志了？
是改动过系统时间？还是改过alert log日志信息？？

回复只看该作者道具举报

上海_Jeff

3^#

发表于 2012-5-24 11:36:25

spfilebak 文件内容：

orc11g.__db_cache_size=1543503872
orc11g.__java_pool_size=16777216
orc11g.__large_pool_size=16777216
orc11g.__oracle_base='D:\app\Administrator'#ORACLE_BASE set from environment
orc11g.__pga_aggregate_target=1191182336
orc11g.__sga_target=2248146944
orc11g.__shared_io_pool_size=0
orc11g.__shared_pool_size=637534208
orc11g.__streams_pool_size=0
*.audit_file_dest='D:\app\Administrator\admin\orc11g\adump'
*.audit_trail='db'
*.compatible='11.2.0.0.0'
*.control_files='D:\database\orc11g\control01.ctl','D:\app\Administrator\flash_recovery_area\orc11g\control02.ctl'
*.db_block_size=8192
*.db_domain=''
*.db_name='orc11g'
*.db_recovery_file_dest='D:\app\Administrator\flash_recovery_area'
*.db_recovery_file_dest_size=4102029312
*.diagnostic_dest='D:\app\Administrator'
*.dispatchers='(PROTOCOL=TCP) (SERVICE=orc11gXDB)'
*.job_queue_processes=2
*.memory_target=3429892096
*.open_cursors=300
*.processes=500
*.remote_login_passwordfile='EXCLUSIVE'
*.undo_tablespace='UNDOTBS1'

参数  memory_target：
SQL> show parameter memory_target;

NAME                               TYPE       VALUE
------------------------------------ ----------- ---------
memory_target                      big integer 3280M

08:45:41 还切换过redo，这个没问题，文件我从服务器拷下，里面的内容有点变化，我也很纳闷，直接复制的，跟原文件还不一样。原文件的时间顺序是正确的。

回复只看该作者道具举报

yehc@epsoft.com

4^#

发表于 2012-5-24 11:57:58

从参数来看。现在的数据库情况是：
orc11g.__sga_target=2248146944                   ~ 2.1G
orc11g.__pga_aggregate_target=1191182336 ~ 1.1G
memory_target                   big integer 3280M ~3.2G

从对应的trace来分析，
Memory (Avail/Total): Ph:3454M/8179M, Ph+PgF:11946M/16356M
个人认为：
物理内存为8G，当前使用3.4G
物理内存+交换页（SWAP）总共使用11946M（近12G），也就是说当前送交换分区调用的内存已经高达8G
我们来计算下：
Total：PgF=16356M-8179M=8177M ~8G
uesd ：PgF=11946M-3454M=8492M  >8G

可见当前的数据库对内存请求已经超出了设置的范围SWAP使用100%。

建议增加memory_target 的大小（从上述的结构来看。您采用的应该是AUTO memory技术）。

可能存在分析上的误区，建议可以试试。

回复只看该作者道具举报

whiterain

5^#

发表于 2012-5-24 12:01:10

os的日志有没？看看os的日志。

回复只看该作者道具举报

上海_Jeff

6^#

发表于 2012-5-24 14:15:45

从日志文件中可以看到：

Wed May 23 22:26:36 2012
Thread 1 cannot allocate new log, sequence 17764
Checkpoint not complete
  Current log# 3 seq# 17763 mem# 0: D:\DATABASE\ORC11G\REDO03.LOG
Thread 1 advanced to log sequence 17764 (LGWR switch)
  Current log# 1 seq# 17764 mem# 0: D:\DATABASE\ORC11G\REDO01.LOG
Wed May 23 22:32:22 2012
Errors in file d:\app\administrator\diag\rdbms\orc11g\orc11g\trace\orc11g_cjq0_11216.trc  (incident=54394):
ORA-00445: background process "J000" did not start after 120 seconds
Incident details in: d:\app\administrator\diag\rdbms\orc11g\orc11g\incident\incdir_54394\orc11g_cjq0_11216_i54394.trc
kkjcre1p: unable to spawn jobq slave process
Errors in file d:\app\administrator\diag\rdbms\orc11g\orc11g\trace\orc11g_cjq0_11216.trc:

可以看到是在 Wed May 23 22:32:22 2012  时候出现错误，

应用日志在 2012-05-23 22:00:00
Initializing PGA for process VKRM in instance orc11g.
一直到 2012-05-24 8:24:44
Audit trail: LENGTH: "221" SESSIONID:[9] "162391616" ENTRYID:[1] "1" USERID:[5] "SEDAS" ACTION:[3] "102" RETURNCODE:[1] "0" LOGOFF$PREAD:[1] "0" LOGOFF$LREAD:[2] "39" LOGOFF$LWRITE:[1] "4" LOGOFF$DEAD:[1] "0" DBID:[9] "501120418" SESSIONCPU:[1] "0".

系统日志个人感觉没问题，附件是日志事件的截图。

日志.zip

57.96 KB, 下载次数: 1616

回复只看该作者道具举报

Maclean Liu(刘相兵

7^#

发表于 2012-5-26 23:53:21

ODM DATA:

11.2.0.1.0 + windows

orc11g_mmon_11200.trc

Memory (Avail/Total): Ph:3454M/8179M, Ph+PgF:11946M/16356M

可以看到仍有较多可用物理内存

Process diagnostic dump for M000, OS id=9500
-------------------------------------------------------------------------------
Memory (Avail/Total): Ph:3454M/8179M, Ph+PgF:11946M/16356M
Stack:
------------------- Call Stack Trace ---------------------
calling location entry point arg #1 arg #2 arg #3 arg #4
------------------------------------------- ------------------------------------------- ---------------- ---------------- ---------------- ----------------
000000007767135A 0000000000000000 0000000000000005 0000000000000000 0000000000000000 0000000000000000
000007FEFDDE10DC 0000000077671350 000000002921f848 0000000000000042 000000002921fc40 000000004ba51010
sskgmfindrealm()+37 000007FEFDDE1040 000000002921fb30 0000000000000000 0005000200000000 00000000000001ac
skgmattach()+261 sskgmfindrealm() 0000000000032000 0000000000159000 ffffffffffffffff ffffffffffffffff
ksmlsge_phaseone()+395 skgmattach()+253 000000000fe800e3 0000000000000000 000000000fe80088 0000000000000049
opimai_init()+151 ksmlsge_phaseone() 0000000000000000 0000000000000000 0000000000000000 0000000000000000
opimai_real()+247 opimai_init() 01cd38f0dd595d72 0000000000000000 00160017000507dc 0003003600160020
opimai()+191 opimai_real() 0000000000000000 0000000000000000 0000000000000000 0000000000000000
BackgroundThreadStart()+693 opimai() 000000002921fe58 0000000000000001 0000000000000000 0000000000000000
0000000076F5652D BackgroundThreadStart() 000000000c2cf880 0000000000000000 0000000000000000 0000000000000000
000000007764C521 0000000076F56520 0000000000000000 0000000000000000 0000000000000000 0000000000000000
---------------- End of Call Stack Trace -----------------
Call stack acquisition performance stats:
setup time (lock acquis., memory alloc.): 0 ms
frame get time (time the target proc was suspended): 94 ms
symbol translation time: 16 ms
total time: 110 ms
-------------------------------------------------------------------------------
Process diagnostic dump actual duration=0.203000 sec
(max dump time=30.000000 sec)
*** 2012-05-23 22:33:22.200
*** 2012-05-23 22:33:37.201
Waited for process M000 to initialize for 75 seconds

复制代码

M000 stack call:

opimai => opimai_real = > opimai_init => ksmlsge_phaseone => skgmattach => sskgmfindrealm

M000在初始化 OPI 后尝试attach到 SGA上，但是超时, skgmattach From the stack trace obtained from the core dumps it appears that a
process is failing to attach to the SGA(skgmattach).

题外话是日志显示存在大量 Checkpoint not complete，考虑调整I/O或者日志文件的大小。

回复只看该作者道具举报

Maclean Liu(刘相兵

8^#

发表于 2012-5-27 00:05:00

ODM FINDING:

Bug 12344638 : ALL NEW CONNECTION REQUESTS KEEP FAILING UNTIL RESTART THE DATABASE

Hdr: 12344638 11.2.0.1 RDBMS 11.2.0.1 OSD PRODID-5 PORTID-233 9871302
Abstract: ALL NEW CONNECTION REQUESTS KEEP FAILING UNTIL RESTART THE DATABASE

PROBLEM:
--------
All new dedicated connection requests keep failing until restart the
database.

This issue occured twice in recent days.

- March 28 09:47
- April 06 16:08

Alert log shows ORA-445 in each moment.

...

DIAGNOSTIC ANALYSIS:
--------------------
The call stack trace of the cjq process is as follows.

- oppdb_cjq0_2308.trc
-----------------------
sskgmfindrealm()+37
skgmattach()+261
ksmlsge_phaseone()+328
opimai_init()+151
opimai_real()+247
opimai()+191

This is same as shown in Note:1240013.1, BUG:11839074 which are
based on BUG:9871302.

WORKAROUND:
-----------
NONE

RELATED BUGS:
-------------
BUG:9871302

REPRODUCIBILITY:
----------------
This issue occured twice in the customer's site in recent days.

- March 28 09:47
- April 06 16:08

STACK TRACE:
------------
sskgmfindrealm <- skgmattach <- ksmlsge_phaseone <- opimai_init
<- opimai_real() <- opimai()+191

stack call、症状与该 bug高度吻合，版本为 11.2.0.1 ，该问题仅发生在 Windows 平台上。

建议你升级到 11.2.0.3 或者迁移到 Linux/Unix平台上。

回复只看该作者道具举报

返回列表

		自动登录	找回密码
密码			注册