SO: 0x5533efea0, type: 4, owner: 0x554631060, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0x554631060, name=session, file=ksu.h LINE:12624 ID:, pg=0
(session) sid: 388 ser: 1 trans: 0x0, creator: 0x554631060
flags: (0x51) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
flags2: (0x40409) -/-/INC
DID: , short-term DID:
txn branch: 0x0
oct: 3, prv: 0, sql: 0x5369ece68, psql: 0x450616048, user: 0/SYS
ksuxds FALSE at location: 0
service name: SYS$BACKGROUND
Current Wait Stack:
0: waiting for ‘enq: PV - syncstart‘
name|mode=0x50560006, 0=0x0, 0=0x0
wait_id=8642197 seq_num=64811 snap_id=1
wait times: snap=3934 min 28 sec, exc=3934 min 28 sec, total=3934 min 28 sec
wait times: max=infinite, heur=3934 min 28 sec
wait counts: calls=1088 os=1088
in_wait=1 iflags=0x15a0
There is at least one session blocking this session.
Dumping 1 direct blocker(s):
inst: 1, sid: 773, ser: 1
Dumping final blocker:
inst: 1, sid: 397, ser: 7
----------------------------------------
SO: 0x553857f80, type: 4, owner: 0x55463e8e8, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0x55463e8e8, name=session, file=ksu.h LINE:12624 ID:, pg=0
(session) sid: 773 ser: 1 trans: 0x0, creator: 0x55463e8e8
flags: (0x51) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
flags2: (0x409) -/-/INC
DID: , short-term DID:
txn branch: 0x0
oct: 0, prv: 0, sql: 0x0, psql: 0x0, user: 0/SYS
ksuxds FALSE at location: 0
service name: SYS$BACKGROUND
Current Wait Stack:
0: waiting for ‘enq: PR - contention‘
name|mode=0x50520006, 0=0x0, 0=0x0
wait_id=410416 seq_num=934 snap_id=1
wait times: snap=3934 min 29 sec, exc=3934 min 29 sec, total=3934 min 29 sec
wait times: max=infinite, heur=3934 min 29 sec
wait counts: calls=76 os=76
in_wait=1 iflags=0x15a0
There is at least one session blocking this session.
Dumping 1 direct blocker(s):
inst: 1, sid: 397, ser: 7
Dumping final blocker:
inst: 1, sid: 397, ser: 7
There are 1 sessions blocked by this session.
Dumping one waiter:
inst: 1, sid: 388, ser: 1
wait event: ‘enq: PV - syncstart‘
p1: ‘name|mode‘=0x50560006
p2: ‘0‘=0x0
p3: ‘0‘=0x0
PROCESS 45: CJQ0
----------------------------------------
SO: 0x554645d80, type: 2, owner: 0x0, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0x554645d80, name=process, file=ksu.h LINE:12616 ID:, pg=0
(process) Oracle pid:45, ser:2, calls cur/top: 0x5394a48b8/0x5394a48b8
flags : (0x2) SYSTEM
flags2: (0x0), flags3: (0x10)
intr error: 0, call error: 0, sess error: 0, txn error 0
intr queue: empty
ksudlp FALSE at location: 0
(post info) last post received: 0 0 9
last post received-location: ksq.h LINE:2014 ID:ksqrcl
last process to post me: 554631060 1 2
last post sent: 0 0 9
last post sent-location: ksq.h LINE:2014 ID:ksqrcl
last process posted by me: 554631060 1 2
(latch info) wait_event=0 bits=0
Process Group: DEFAULT, pseudo proc: 0x554a379f8
O/S info: user: oracle, term: UNKNOWN, ospid: 8914
OSD pid info: Unix process pid: 8914, image: [email protected] (CJQ0)
SO: 0x5533d4fc0, type: 4, owner: 0x554645d80, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0x554645d80, name=session, file=ksu.h LINE:12624 ID:, pg=0
(session) sid: 397 ser: 7 trans: 0x0, creator: 0x554645d80
flags: (0x51) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
flags2: (0x40409) -/-/INC
DID: , short-term DID:
txn branch: 0x0
oct: 0, prv: 0, sql: 0x0, psql: 0x450caef60, user: 0/SYS
ksuxds FALSE at location: 0
service name: SYS$BACKGROUND
Current Wait Stack:
0: waiting for ‘os thread startup‘
=0x0, =0x0, =0x0
wait_id=2782824 seq_num=30355 snap_id=1
wait times: snap=3934 min 34 sec, exc=3934 min 34 sec, total=3934 min 34 sec
wait times: max=2 min 0 sec, heur=3934 min 34 sec
wait counts: calls=77 os=77
in_wait=1 iflags=0x15a0
There are 4 sessions blocked by this session.
Dumping one waiter:
inst: 1, sid: 773, ser: 1
wait event: ‘enq: PR - contention‘
p1: ‘name|mode‘=0x50520006
p2: ‘0‘=0x0
p3: ‘0‘=0x0
row_wait_obj#: 4294967295, block#: 0, row#: 0, file# 0
min_blocked_time: 0 secs, waiter_cache_ver: 63462
Wait State:
fixed_waits=0 flags=0x22 boundary=0x0/-1
Session Wait History:
elapsed time of 0.000160 sec since current wait
0: waited for ‘enq: PR - contention‘
name|mode=0x50520006, 0=0x0, 0=0x0
wait_id=2782823 seq_num=30354 snap_id=1
wait times: snap=4 min 56 sec, exc=4 min 56 sec, total=4 min 56 sec
wait times: max=infinite
wait counts: calls=8 os=8
occurred after 2.476248 sec of elapsed time
1: waited for ‘os thread startup‘
=0x0, =0x0, =0x0
wait_id=2782822 seq_num=30353 snap_id=1
wait times: snap=41 min 57 sec, exc=41 min 57 sec, total=41 min 57 sec
wait times: max=2 min 0 sec
wait counts: calls=2 os=2
occurred after 0.000168 sec of elapsed time
2: waited for ‘enq: PR - contention‘
Dumping one waiter:
inst: 1, sid: 773, ser: 1
wait event: ‘enq: PR - contention‘
p1: ‘name|mode‘=0x50520006
p2: ‘0‘=0x0
p3: ‘0‘=0x0
row_wait_obj#: 4294967295, block#: 0, row#: 0, file# 0
min_blocked_time: 0 secs, waiter_cache_ver: 63462
数据库内部等待关系：
blocking blocker event
388 773,397 enq: PV - syncstart
773 397 enq: PR - contention
397 enq: PR - contention os thread startup：ora-445
--1
节点1 运行语句select sid,serial# from gv$session where username=‘WANQIONG‘:
失败的原因：PROCESS 53/57 两个会话运行该语句,PROCESS 20: CKPT block这两个会话
PROCESS 20 由于waiting for ‘enq: PR - contention‘ name|mode=0x50520006
0x50520006 所有者：PROCESS 45: CJQ0
根据：awk -f ass109.awk calldb1_ora_15639.trc 分析：
Resource Holder State
Enqueue PR-00000000-00000000 45: 0: waiting for ‘os thread startup‘
Enqueue PV-00000000-00000000 38: 38: is waiting for 45:
Latch 380030bc0 ??? Blocker
PROCESS 45: CJQ0 进程是罪魁祸首！该进程无法启动。
--2 节点2
节点2运行语句：select sum(bytes) from dba_segments，等待时间0: waiting for ‘gc cr request‘
cssd,crsd没有发现明显节点通讯报错，怀疑由于节点1死机引起
--3 节点1 警告日志分析
Mon Aug 11 09:45:49 2014
Archived Log entry 58557 added for thread 1 sequence 27907 ID 0x4bcd9425 dest 1:
Mon Aug 11 16:08:44 2014
Errors in file /oracle/diag/rdbms/calldb/calldb1/trace/calldb1_cjq0_8914.trc (incident=56362):
ORA-00445: background process "J000" did not start after 120 seconds
Incident details in: /oracle/diag/rdbms/calldb/calldb1/incident/incdir_56362/calldb1_cjq0_8914_i56362.trc
kkjcre1p: unable to spawn jobq slave process
Errors in file /oracle/diag/rdbms/calldb/calldb1/trace/calldb1_cjq0_8914.trc:
Mon Aug 11 16:12:25 2014
Errors in file /oracle/diag/rdbms/calldb/calldb1/trace/calldb1_mmon_8497.trc (incident=56202):
ORA-00445: background process "m000" did not start after 120 seconds
Incident details in: /oracle/diag/rdbms/calldb/calldb1/incident/incdir_56202/calldb1_mmon_8497_i56202.trc
Mon Aug 11 16:14:28 2014
awr分析内存16G
Begin End
Host Mem (MB): 15,744.0
15,744.0
SGA use (MB): 4,608.0
4,608.0
PGA use (MB): 462.5
460.1
% Host Mem used for SGA+PGA: 32.21
32.19
重启后内存12g
[[email protected] /home/oracle]$ prtconf | grep ‘Memory‘
Memory size: 12288 Megabytes
怀疑问题出在内存上：
1379200.1 根据文档可以确定：
What does this message mean ?
The message indicates that we failed to spawn a new process at the Operating System level to serve the request.
There are various causes for this issue. This typically occurs when there is a shortage or misconfiguration in
Operating System Resources, and thereby the problem should be investigated from an OS perspective. However
there are a few causes related to the Oracle Database as well.
The default 120 seconds (after which Oracle times out) can be extended dynamically (without a database restart) b
setting the following event:
OS Configuration Checks【昨天确定硬件存在故障】
Checks on Oracle Database Configuration
--数据库重启前做的dump systemstat 10
/oracle/diag/rdbms/calldb/calldb1/trace/calldb1_ora_15639.trc
select sum(bytes) from dba_segment: waiting for 'gc cr request'