ora 0045 错误

上海_Jeff

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

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

yehc@epsoft.com

根据日志初步判断是跟内存（或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

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

从参数来看。现在的数据库情况是：
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

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

上海_Jeff

从日志文件中可以看到：

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".


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

Maclean Liu(刘相兵

ODM DATA:

11.2.0.1.0 + windows

orc11g_mmon_11200.trc

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

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

1. Process diagnostic dump for M000, OS id=9500
   
2. -------------------------------------------------------------------------------
   
3. Memory (Avail/Total): Ph:3454M/8179M, Ph+PgF:11946M/16356M
   
4.                                                                               
   
5. Stack:
   
6. ------------------- Call Stack Trace ---------------------
   
7. calling location                                                 entry point                                                      arg #1           arg #2           arg #3           arg #4         
   
8. -------------------------------------------                      -------------------------------------------                      ---------------- ---------------- ---------------- ----------------
   
9. 000000007767135A                                                 0000000000000000                                                 0000000000000005 0000000000000000 0000000000000000 0000000000000000
   
10. 000007FEFDDE10DC                                                 0000000077671350                                                 000000002921f848 0000000000000042 000000002921fc40 000000004ba51010
    
11. sskgmfindrealm()+37                                              000007FEFDDE1040                                                 000000002921fb30 0000000000000000 0005000200000000 00000000000001ac
    
12. skgmattach()+261                                                 sskgmfindrealm()                                                 0000000000032000 0000000000159000 ffffffffffffffff ffffffffffffffff
    
13. ksmlsge_phaseone()+395                                           skgmattach()+253                                                 000000000fe800e3 0000000000000000 000000000fe80088 0000000000000049
    
14. opimai_init()+151                                                ksmlsge_phaseone()                                               0000000000000000 0000000000000000 0000000000000000 0000000000000000
    
15. opimai_real()+247                                                opimai_init()                                                    01cd38f0dd595d72 0000000000000000 00160017000507dc 0003003600160020
    
16. opimai()+191                                                     opimai_real()                                                    0000000000000000 0000000000000000 0000000000000000 0000000000000000
    
17. BackgroundThreadStart()+693                                      opimai()                                                         000000002921fe58 0000000000000001 0000000000000000 0000000000000000
    
18. 0000000076F5652D                                                 BackgroundThreadStart()                                          000000000c2cf880 0000000000000000 0000000000000000 0000000000000000
    
19. 000000007764C521                                                 0000000076F56520                                                 0000000000000000 0000000000000000 0000000000000000 0000000000000000
    
20. ---------------- End of Call Stack Trace -----------------
    
21. Call stack acquisition performance stats:
    
22.   setup time (lock acquis., memory alloc.): 0 ms
    
23.   frame get time (time the target proc was suspended): 94 ms
    
24.   symbol translation time: 16 ms
    
25.   total time: 110 ms
    
26. 
    
27. -------------------------------------------------------------------------------
    
28. Process diagnostic dump actual duration=0.203000 sec
    
29.   (max dump time=30.000000 sec)
    
30. 
    
31. *** 2012-05-23 22:33:22.200
    
32. 
    
33. *** 2012-05-23 22:33:37.201
    
34. 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(刘相兵

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平台上。