怀疑有人偷偷启停库，请高手鉴别

显示全部楼层 · 2012-1-4 11:50:44

环境描述：
操作系统AIX 5.3+ORACLE10.2.0.4+ASM两个节点的RAC集群
跑得好好的库，今天接到电话过去看了alert日志，觉得在下午Mon Nov7 15:33:02 2011这个时间有人强行停止并启动过，我自己分析了下，请大家给予准确判断谢谢。日志如下：
Thread 1 advanced to log sequence 4960 (LGWR switch)
Current log# 4 seq# 4960 mem# 0: +DG_DATA01/oradata/abcde/redo04_1.log
Mon Nov7 15:30:28 2011
Thread 1 advanced to log sequence 4961 (LGWR switch)
Current log# 1 seq# 4961 mem# 0: +DG_DATA01/oradata/abcde/redo01_1.log
Mon Nov7 15:33:02 2011
-------跑得好好的库，突然有报错-----------------
Errors in file /u01/app/oracle/admin/abcde/bdump/abcde1_dbw0_471224.trc:
-----此trace见帖子
ORA-00028: your session has been killed
Mon Nov7 15:33:02 2011
DBW0: terminating instance due to error 28
Mon Nov7 15:33:02 2011
Errors in file /u01/app/oracle/admin/abcde/bdump/abcde1_lms7_508124.trc:
-----此trace见帖子
ORA-00028: your session has been killed
Mon Nov7 15:33:03 2011
System state dump is made for local instance
System State dumped to trace file /u01/app/oracle/admin/abcde/bdump/abcde1_diag_414178.trc----这个trace文件太长，基本看不懂
Mon Nov7 15:33:03 2011
------下面这几行我不确定是否为人为shutdown abort还是oracle自己终止了？
Shutting down instance (abort)
License high water mark = 416
Mon Nov7 15:33:08 2011
Instance terminated by DBW0, pid = 471224
Mon Nov7 15:33:09 2011
Instance terminated by USER, pid = 872460
Mon Nov7 15:33:19 2011
-------数据库在这里怎么显示好像是自动尝试启动了？？我个人认为很奇怪，因为我的库down之后怎么会自动启动呢？如果不认为手工发命令的话。
Starting ORACLE instance (normal)
sskgpgetexecname failed to get name
LICENSE_MAX_SESSION = 0
LICENSE_SESSIONS_WARNING = 0
Interface type 1 en5 172.31.1.0 configured from OCR for use as a cluster interconnect
Interface type 1 en4 10.188.1.0 configured from OCR for use asa public interface
Picked latch-free SCN scheme 3
Autotune of undo retention is turned on.
LICENSE_MAX_USERS = 0
SYS auditing is disabled
ksdpec: called for event 13740 prior to event group initialization
Starting up ORACLE RDBMS Version: 10.2.0.4.0.
System parameters with non-default values:
processes
= 2048
sga_max_size
= 12884901888
__shared_pool_size = 1342177280
__large_pool_size= 16777216
__java_pool_size = 16777216
__streams_pool_size= 16777216
spfile
= +DG_DATA01/oradata/abcde/spfileabcde.ora
sga_target
= 12884901888
control_files
= +DG_DATA01/oradata/abcde/control01.ctl, +DG_DATA01/oradata/abcde/control02.ctl, +DG_DATA01/oradata/abcde/control03.ctl
db_block_size
= 8192
__db_cache_size
= 11475615744
compatible
= 10.2.0.3.0
log_archive_dest_1 = LOCATION=+DG_DATA01/Backup/abcde/ArchiveLog
log_archive_format = %t_%s_%r.arc
db_file_multiblock_read_count= 16
cluster_database = TRUE
cluster_database_instances= 2
thread
= 1
instance_number
= 1
undo_management
= AUTO
undo_tablespace
= UNDOTBS1
remote_login_passwordfile= EXCLUSIVE
db_domain
=
dispatchers
= (PROTOCOL=TCP) (SERVICE=abcdeXDB)
local_listener = LISTENER_abcde1
remote_listener
= LISTENER_abcde2
job_queue_processes= 10
background_dump_dest = /u01/app/oracle/admin/abcde/bdump
user_dump_dest = /u01/app/oracle/admin/abcde/udump
core_dump_dest = /u01/app/oracle/admin/abcde/cdump
audit_file_dest
= /u01/app/oracle/admin/abcde/adump
db_name
= abcde
open_cursors
= 500
pga_aggregate_target = 6442450944
Cluster communication is configured to use the following interface(s) for this instance
172.31.1.4
Mon Nov7 15:33:20 2011
cluster interconnect IPC version:Oracle UDP/IP (generic)
IPC Vendor 1 proto 2
PMON started with pid=2, OS id=1286640
DIAG started with pid=3, OS id=1282416
PSP0 started with pid=4, OS id=848070
LMON started with pid=5, OS id=1278330
LMD0 started with pid=6, OS id=1523884
LMS0 started with pid=7, OS id=1274246
LMS1 started with pid=8, OS id=999662
LMS2 started with pid=9, OS id=1470508
LMS3 started with pid=10, OS id=495852
LMS4 started with pid=11, OS id=1270186
LMS5 started with pid=12, OS id=1249636
LMS6 started with pid=13, OS id=487484
LMS7 started with pid=14, OS id=1257948
MMAN started with pid=15, OS id=1515562
DBW0 started with pid=16, OS id=1221030
DBW1 started with pid=17, OS id=1212866
DBW2 started with pid=18, OS id=1208706
DBW3 started with pid=19, OS id=1224968
LGWR started with pid=20, OS id=1511626
CKPT started with pid=21, OS id=1486906
SMON started with pid=22, OS id=1482942
RECO started with pid=23, OS id=1200524
CJQ0 started with pid=24, OS id=1450182
MMON started with pid=25, OS id=1437770
Mon Nov7 15:33:21 2011
starting up 1 dispatcher(s) for network address '(ADDRESS=(PARTIAL=YES)(PROTOCOL=TCP))'...
MMNL started with pid=26, OS id=1429636
Mon Nov7 15:33:21 2011
starting up 1 shared server(s) ...
Mon Nov7 15:33:22 2011
lmon registered with NM - instance id 1 (internal mem no 0)
Mon Nov7 15:33:23 2011
Reconfiguration started (old inc 0, new inc 8)
List of nodes:
0 1
Global Resource Directory frozen
* allocate domain 0, invalid = TRUE
Communication channels reestablished
* domain 0 valid according to instance 1
* domain 0 valid = 1 according to instance 1
Mon Nov7 15:33:23 2011
Master broadcasted resource hash value bitmaps
Non-local Process blocks cleaned out
Mon Nov7 15:33:23 2011
LMS 0: 0 GCS shadows cancelled, 0 closed
Mon Nov7 15:33:23 2011
LMS 7: 0 GCS shadows cancelled, 0 closed
Mon Nov7 15:33:23 2011
LMS 4: 0 GCS shadows cancelled, 0 closed
Mon Nov7 15:33:23 2011
LMS 5: 0 GCS shadows cancelled, 0 closed
Mon Nov7 15:33:23 2011
LMS 6: 0 GCS shadows cancelled, 0 closed
Mon Nov7 15:33:23 2011
LMS 3: 0 GCS shadows cancelled, 0 closed
Mon Nov7 15:33:23 2011
LMS 1: 0 GCS shadows cancelled, 0 closed
Mon Nov7 15:33:23 2011
LMS 2: 0 GCS shadows cancelled, 0 closed
Set master node info
Submitted all remote-enqueue requests
Dwn-cvts replayed, VALBLKs dubious
All grantable enqueues granted
Mon Nov7 15:33:24 2011
LMS 3: 0 GCS shadows traversed, 0 replayed
Mon Nov7 15:33:24 2011
LMS 1: 0 GCS shadows traversed, 0 replayed
Mon Nov7 15:33:24 2011
LMS 6: 0 GCS shadows traversed, 0 replayed
Mon Nov7 15:33:24 2011
LMS 2: 0 GCS shadows traversed, 0 replayed
Mon Nov7 15:33:24 2011
LMS 5: 0 GCS shadows traversed, 0 replayed
Mon Nov7 15:33:24 2011
LMS 4: 0 GCS shadows traversed, 0 replayed
Mon Nov7 15:33:24 2011
LMS 7: 0 GCS shadows traversed, 0 replayed
Mon Nov7 15:33:24 2011
LMS 0: 0 GCS shadows traversed, 0 replayed
Mon Nov7 15:33:24 2011
Submitted all GCS remote-cache requests
Post SMON to start 1st pass IR
Fix write in gcs resources
Reconfiguration complete
LCK0 started with pid=29, OS id=1331634
Mon Nov7 15:33:25 2011
ALTER DATABASE MOUNT
Mon Nov7 15:33:25 2011
Starting background process ASMB
ASMB started with pid=31, OS id=1253770
Starting background process RBAL
RBAL started with pid=32, OS id=471242
Mon Nov7 15:33:30 2011
SUCCESS: diskgroup DG_DATA01 was mounted
Mon Nov7 15:33:34 2011
Setting recovery target incarnation to 1
Mon Nov7 15:33:34 2011
Successful mount of redo thread 1, with mount id 2404048923
Mon Nov7 15:33:34 2011
Database mounted in Shared Mode (CLUSTER_DATABASE=TRUE)
Completed: ALTER DATABASE MOUNT
Mon Nov7 15:33:34 2011
ALTER DATABASE OPEN
Picked broadcast on commit scheme to generate SCNs
Mon Nov7 15:33:37 2011
LGWR: STARTING ARCH PROCESSES
ARC0 started with pid=34, OS id=1261988
Mon Nov7 15:33:37 2011
ARC0: Archival started
ARC1: Archival started
LGWR: STARTING ARCH PROCESSES COMPLETE
ARC1 started with pid=35, OS id=1245582
Mon Nov7 15:33:37 2011
Thread 1 opened at log sequence 4962
Current log# 2 seq# 4962 mem# 0: +DG_DATA01/oradata/abcde/redo02_1.log
Successful open of redo thread 1
Mon Nov7 15:33:37 2011
MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set
Mon Nov7 15:33:37 2011
ARC0: Becoming the 'no FAL' ARCH
ARC0: Becoming the 'no SRL' ARCH
Mon Nov7 15:33:37 2011
ARC1: Becoming the heartbeat ARCH
Mon Nov7 15:33:37 2011
SMON: enabling cache recovery
Mon Nov7 15:33:38 2011
Successfully onlined Undo Tablespace 1.
Mon Nov7 15:33:38 2011
SMON: enabling tx recovery
Mon Nov7 15:33:38 2011
Database Characterset is ZHS16GBK
Opening with internal Resource Manager plan
where NUMA PG = 1, CPUs = 32
replication_dependency_tracking turned off (no async multimaster replication found)
Starting background process QMNC
QMNC started with pid=38, OS id=1196372
Mon Nov7 15:33:39 2011
------这里看竟然从Mon Nov7 15:33:03 2011到39秒，自己启动并打开了
Completed: ALTER DATABASE OPEN
Mon Nov7 15:33:39 2011
Running Distributed Transactions in RAC without DTP service.
Mon Nov7 17:06:49 2011
Errors in file /u01/app/oracle/admin/abcde/bdump/abcde1_dbw0_1221030.trc:
ORA-00028: your session has been killed
Mon Nov7 17:06:49 2011
DBW0: terminating instance due to error 28
Mon Nov7 17:06:49 2011
System state dump is made for local instance
System State dumped to trace file /u01/app/oracle/admin/abcde/bdump/abcde1_diag_1282416.trc
Mon Nov7 17:06:50 2011
Shutting down instance (abort)
License high water mark = 43
Mon Nov7 17:06:54 2011
Instance terminated by DBW0, pid = 1221030
Mon Nov7 17:06:56 2011
Instance terminated by USER, pid = 1482948
----------以下是手工启动此节点实例的记录，没有什么问题，所以略----------
Mon Nov7 18:37:01 2011
Starting ORACLE instance (normal)
sskgpgetexecname failed to get name
LICENSE_MAX_SESSION = 0
LICENSE_SESSIONS_WARNING = 0
Interface type 1 en5 172.31.1.0 configured from OCR for use as a cluster interconnect
Interface type 1 en4 10.188.1.0 configured from OCR for use asa public interface
Picked latch-free SCN scheme 3
Autotune of undo retention is turned on.

千问 · 2012-1-4 11:50:44

abcde1_dbw0_471224.trc内容
/u01/app/oracle/admin/abcdef/bdump/abcde1_dbw0_471224.trc
Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - 64bit Production
With the Partitioning, Real Application Clusters, OLAP, Data Mining
and Real Application Testing options
ORACLE_HOME = /u01/app/oracle/product/10.2.0/db_1
System name:
AIX
Node name:
p550a
Release:
3
Version:
5
Machine:
xxxxxxx
Instance name: abcdef1
Redo thread mounted by this instance: 1
Oracle process number: 16
Unix process pid: 471224, image: oracle@p550a (DBW0)
*** 2011-11-07 15:33:03.010
*** SERVICE NAME

SYS$BACKGROUND) 2011-11-07 15:33:03.000
*** SESSION ID

2243.1) 2011-11-07 15:33:03.000
error 28 detected in background process
ORA-00028: your session has been killed
ksuitm: waiting up to [5] seconds before killing DIAG

千问 · 2012-1-4 11:50:44

javaio 发表于 2011-11-8 00:53
abcde1_dbw0_471224.trc内容
/u01/app/oracle/admin/abcdef/bdump/abcde1_dbw0_471224.trc
Oracle Databa ...
abcde1_lms7_508124.trc内容
/u01/app/oracle/admin/abcde/bdump/abcde1_lms7_508124.trc
Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - 64bit Production
With the Partitioning, Real Application Clusters, OLAP, Data Mining
and Real Application Testing options
ORACLE_HOME = /u01/app/oracle/product/10.2.0/db_1
System name:
AIX
Node name:
p550a
Release:
3
Version:
5
Machine:
xxxxxxxxx
Instance name: abcde1
Redo thread mounted by this instance: 0
Oracle process number: 14
Unix process pid: 508124, image: oracle@p550a (LMS7)
*** SERVICE NAME

) 2011-05-18 21:42:37.873
*** SESSION ID

2245.1) 2011-05-18 21:42:37.873
0 GCS shadows cancelled, 0 closed
0 GCS resources traversed, 0 cancelled
LMS 7: 1504400 GCS resources on freelist, 1504560 on array, 1504564 allocated
0 GCS shadows traversed, 0 replayed, 0 duplicates
lms 7 finished replaying gcs resources
0 write requests issued in 0 GCS resources
0 PIs marked suspect, 0 flush PI msgs
0 write requests issued in 0 GCS resources
0 PIs marked suspect, 0 flush PI msgs
0 write requests issued in 0 GCS resources
0 PIs marked suspect, 0 flush PI msgs
0 write requests issued in 0 GCS resources
0 PIs marked suspect, 0 flush PI msgs
0 write requests issued in 0 GCS resources
0 PIs marked suspect, 0 flush PI msgs
0 write requests issued in 0 GCS resources
0 PIs marked suspect, 0 flush PI msgs
0 write requests issued in 0 GCS resources
0 PIs marked suspect, 0 flush PI msgs
0 write requests issued in 0 GCS resources
0 PIs marked suspect, 0 flush PI msgs
0 write requests issued in 0 GCS resources
0 PIs marked suspect, 0 flush PI msgs
0 write requests issued in 0 GCS resources
0 PIs marked suspect, 0 flush PI msgs
0 write requests issued in 0 GCS resources
0 PIs marked suspect, 0 flush PI msgs
0 write requests issued in 0 GCS resources
0 PIs marked suspect, 0 flush PI msgs
0 write requests issued in 0 GCS resources
0 PIs marked suspect, 0 flush PI msgs
0 write requests issued in 0 GCS resources
0 PIs marked suspect, 0 flush PI msgs
0 write requests issued in 0 GCS resources
0 PIs marked suspect, 0 flush PI msgs
0 write requests issued in 0 GCS resources
0 PIs marked suspect, 0 flush PI msgs
0 write requests issued in 0 GCS resources
0 PIs marked suspect, 0 flush PI msgs
lms 7 finished fixing gcs write protocol
*** 2011-06-01 09:22:33.601
kjdrvalidRMno: msg type 34 from node 1 dropped
FUSION MSG 110a8ed30,34 from[1,483538] ver[4,51] ln 128 sq[1,8]
CLOSE [0x25f9e7.70000, 46795] shadow [7000002f4fc52b8,97] seq 0x2 act 1

client [70000013dfc8500,11] reqid 14 ordered 0

grant 1 convert 0 role 0

pi [0x0.0x0] flags 0x0 state 0x20

disk scn 0x0.0 writereq scn 0x0.0 rreqid 0

msgRM# 51 bkt# 5948 drmbkt# 5948
pkey 46795, stat 5, masters[1, 0->1], reminc 4, RM# 50 flg 0x6
hv 115 [stat 0x0, 1->1, wm 32767, RMno 0, reminc 0, dom 0]
kjga st 0x4, step 0.32.0, cinc 4, rmno 51, flags 0x20
lb 4096, hb 6143, myb 5948, drmb 5948, apifrz 1
kjmvalidate: drm drop a message RMno 51 from 1 type 34
mver 4 myver 4 seq 0.3540482 rseq 0.3540481 flag x6d
*** 2011-06-01 22:07:50.958
kjdrvalidRMno: msg type 34 from node 1 dropped
FUSION MSG 110f20be0,34 from[1,483538] ver[4,55] ln 128 sq[1,8]
CLOSE [0x3c2f4.190000, 46452] shadow [7000002f3d7f1c8,34] seq 0x2 act 1

client [7000001b7fd7358,19] reqid 25 ordered 0

grant 1 convert 0 role 0

pi [0x0.0x0] flags 0x0 state 0x20

disk scn 0x0.0 writereq scn 0x0.0 rreqid 0

msgRM# 55 bkt# 6238 drmbkt# 6238
pkey 46452, stat 5, masters[1, 0->1], reminc 4, RM# 27 flg 0x4
hv 5 [stat 0x0, 1->1, wm 32767, RMno 0, reminc 0, dom 0]
kjga st 0x4, step 0.32.0, cinc 4, rmno 55, flags 0x20
lb 6144, hb 8191, myb 6238, drmb 6238, apifrz 1
kjmvalidate: drm drop a message RMno 55 from 1 type 34
mver 4 myver 4 seq 0.3864692 rseq 0.3864691 flag x2d
*** 2011-06-21 16:25:24.420
kjdrvalidRMno: msg type 34 from node 1 dropped
FUSION MSG 110f8cbc0,34 from[1,483538] ver[4,130] ln 128 sq[1,8]
CLOSE [0x22eb.a0000, 13248] shadow [7000002d95dd558,130] seq 0x2 act 1

client [7000000d7fca940,126] reqid 209 ordered 0

grant 1 convert 0 role 0

pi [0x0.0x0] flags 0x0 state 0x20

disk scn 0x0.0 writereq scn 0x0.0 rreqid 0

msgRM# 130 bkt# 9309 drmbkt# 9309
pkey 13248, stat 5, masters[32767, 0->1], reminc 4, RM# 130 flg 0x4
hv 69 [stat 0x0, 1->1, wm 32767, RMno 0, reminc 0, dom 0]
kjga st 0x4, step 0.32.0, cinc 4, rmno 130, flags 0x20
lb 8192, hb 10239, myb 9309, drmb 9309, apifrz 1
kjmvalidate: drm drop a message RMno 130 from 1 type 34
mver 4 myver 4 seq 0.8484648 rseq 0.8484647 flag x6d
*** 2011-06-22 06:00:43.887
kjdrvalidRMno: msg type 34 from node 1 dropped
FUSION MSG 110b0ab50,34 from[1,483538] ver[4,150] ln 128 sq[1,8]
CLOSE [0x2108f5.190000, 46533] shadow [7000002f1e2fe38,65] seq 0x2 act 1

client [700000269f8f638,57] reqid 65 ordered 0

grant 1 convert 0 role 0

pi [0x0.0x0] flags 0x0 state 0x20

disk scn 0x0.0 writereq scn 0x0.0 rreqid 0

msgRM# 150 bkt# 2334 drmbkt# 2334
pkey 46533, stat 5, masters[1, 0->1], reminc 4, RM# 114 flg 0x4
hv 17 [stat 0x0, 1->1, wm 32767, RMno 0, reminc 0, dom 0]
kjga st 0x4, step 0.32.0, cinc 4, rmno 150, flags 0x20
lb 2048, hb 4095, myb 2334, drmb 2334, apifrz 1
kjmvalidate: drm drop a message RMno 150 from 1 type 34
mver 4 myver 4 seq 0.8723839 rseq 0.8723838 flag x6d
kjdrvalidRMno: msg type 34 from node 1 dropped
FUSION MSG 110b0abd0,34 from[1,483538] ver[4,150] ln 128 sq[1,8]
CLOSE [0x1d8ffa.a0000, 46534] shadow [7000002f6bab660,94] seq 0x2 act 1

client [70000016afccf50,63] reqid 76 ordered 0

grant 1 convert 0 role 0

pi [0x0.0x0] flags 0x0 state 0x20

disk scn 0x0.0 writereq scn 0x0.0 rreqid 0

msgRM# 150 bkt# 2559 drmbkt# 2559

千问 · 2012-1-4 11:50:44

abcde1_lms7_508124.trc内容,这个日志太长，后半段如下：
pkey 46767, stat 5, masters[1, 0->1], reminc 4, RM# 964 flg 0x4
hv 41 [stat 0x0, 1->1, wm 32767, RMno 0, reminc 0, dom 0]
kjga st 0x4, step 0.32.0, cinc 4, rmno 1001, flags 0x20
lb 2048, hb 4095, myb 2717, drmb 2717, apifrz 1
kjmvalidate: drm drop a message RMno 1001 from 1 type 34
mver 4 myver 4 seq 0.82377632 rseq 0.82377630 flag x2d
*** 2011-11-07 15:33:03.011
lms abort after exception 28
KJC Communication Dump:
state 0x5flags 0x0mode 0x0inst 0inc 4
nrcv 9nsp 9nrcvbuf 1000
reg_msg: sz 456cur 165 (s:0 i:165) max 2014ini 4846
big_msg: sz 8240cur 48 (s:0 i:48) max 496ini 1934
rsv_msg: sz 8240cur 0 (s:0 i:0) max 0tot 1000
rcvr: id 1orapid 7ospid 467158
rcvr: id 7orapid 13ospid 483540
rcvr: id 8orapid 14ospid 508124
rcvr: id 2orapid 8ospid 798844
rcvr: id 6orapid 12ospid 573828
rcvr: id 3orapid 9ospid 401684
rcvr: id 5orapid 11ospid 586162
rcvr: id 4orapid 10ospid 352712
rcvr: id 0orapid 6ospid 258234
send proxy: id 1ndst 1 (1:1 )
send proxy: id 7ndst 1 (1:7 )
send proxy: id 8ndst 1 (1:8 )
send proxy: id 2ndst 1 (1:2 )
send proxy: id 6ndst 1 (1:6 )
send proxy: id 3ndst 1 (1:3 )
send proxy: id 5ndst 1 (1:5 )
send proxy: id 4ndst 1 (1:4 )
send proxy: id 0ndst 1 (1:0 )
GES resource limits:
ges resources: cur 0 max 0 ini 44442
ges enqueues: cur 0 max 0 ini 68576
ges cresources: cur 4716 max 14355
gcs resources: cur 1103796 max 1553381 ini 1504564
gcs shadows: cur 1046291 max 1495234 ini 1504564
KJCTS state: seq-check:notimeout:yeswaitticks:0x3highload no
GES destination context:
GES remote instance per receiver context:
GES destination context:
Dest 1rcvr 0inc 4state 0x10041tstate 0x0
batch-type quickbmsg 0x0tmout 0xd9466bdmsg_in_batch 0
tkt total 1000avl 750 sp_rsv 250 max_sp_rsv 250
seq wrp 0lst 19425863ack 0snt 19425863
sync seq 0.19425863inc 0sndq enq seq 0.19425863
batch snds 175820tot msgs 455979max sz 82fullload 1snd seq 175820
pbatch snds 10790403tot msgs 13430356
sndq msg tot 15253364tm (0 2170)
sndq msg 0maxlmt 1504564maxlen 32wqlen 15442768
sndq msg 0start_tm 0end_tm 0
Dest 1rcvr 1inc 4state 0x50041tstate 0x0
batch-type autobmsg 0x0tmout 0x26cea0c7msg_in_batch 0
tkt total 1000avl 750 sp_rsv 250 max_sp_rsv 250
seq wrp 0lst 117427461ack 0snt 117427461
sync seq 0.117427461inc 0sndq enq seq 0.117427461
batch snds 5927000tot msgs 51520338max sz 62fullload 1564snd seq 5927000
pbatch snds 38992674tot msgs 189018250
sndq msg tot 78320507tm (0 68479)
sndq msg 0maxlmt 1504564maxlen 222wqlen 584287516
sndq msg 0start_tm 0end_tm 0
Dest 1rcvr 2inc 4state 0x50041tstate 0x0
batch-type autobmsg 0x0tmout 0x24ced9b0msg_in_batch 0
tkt total 1000avl 750 sp_rsv 249 max_sp_rsv 250
seq wrp 0lst 98147321ack 0snt 98147321
sync seq 0.98147321inc 0sndq enq seq 0.98147321
batch snds 5545656tot msgs 51057161max sz 62fullload 1635snd seq 5545656
pbatch snds 24650185tot msgs 177660076
sndq msg tot 62953083tm (0 62888)
sndq msg 0maxlmt 1504564maxlen 257wqlen 580299762
sndq msg 0start_tm 0end_tm 0
Dest 1rcvr 3inc 4state 0x50041tstate 0x0
batch-type autobmsg 0x0tmout 0x24c7bc24msg_in_batch 0
tkt total 1000avl 749 sp_rsv 250 max_sp_rsv 250
seq wrp 0lst 98342804ack 0snt 98342803
sync seq 0.98342803inc 0sndq enq seq 0.98342803
batch snds 5553687tot msgs 50994787max sz 62fullload 1663snd seq 5553687
pbatch snds 24613345tot msgs 177544925
sndq msg tot 62839522tm (0 60694)
sndq msg 0maxlmt 1504564maxlen 257wqlen 578473288
sndq msg 0start_tm 0end_tm 0
Dest 1rcvr 4inc 4state 0x50041tstate 0x0
batch-type autobmsg 0x0tmout 0x24cd6ea9msg_in_batch 0
tkt total 1000avl 748 sp_rsv 249 max_sp_rsv 250
seq wrp 0lst 98264692ack 0snt 98264692
sync seq 0.98264692inc 0sndq enq seq 0.98264692
batch snds 5552323tot msgs 51064518max sz 62fullload 1577snd seq 5552323
pbatch snds 24586306tot msgs 177440072
sndq msg tot 62937652tm (0 56256)
sndq msg 0maxlmt 1504564maxlen 257wqlen 579900225
sndq msg 0start_tm 0end_tm 0
Dest 1rcvr 5inc 4state 0x50041tstate 0x0
batch-type autobmsg 0x0tmout 0x24aa16d8msg_in_batch 0
tkt total 1000avl 750 sp_rsv 250 max_sp_rsv 250
seq wrp 0lst 177225308ack 0snt 177225308
sync seq 0.177225308inc 0sndq enq seq 0.177225308
batch snds 11266993tot msgs 112429175max sz 65fullload 3689snd seq 11266993
pbatch snds 22303523tot msgs 160092179
sndq msg tot 127045681tm (0 113944)
sndq msg 0maxlmt 1504564maxlen 257wqlen 1295079437
sndq msg 0start_tm 0end_tm 0
Dest 1rcvr 6inc 4state 0x50041tstate 0x0
batch-type autobmsg 0x0tmout 0x230e276fmsg_in_batch 0
tkt total 1000avl 750 sp_rsv 250 max_sp_rsv 250
seq wrp 0lst 167786880ack 0snt 167786871
sync seq 0.167786880inc 0sndq enq seq 0.167786880
batch snds 11132658tot msgs 116248270max sz 62fullload 6529snd seq 11132658
pbatch snds 19210378tot msgs 159910117
sndq msg tot 128006072tm (0 111900)
sndq msg 0maxlmt 1504564maxlen 258wqlen 1412968233
sndq msg 0start_tm 0end_tm 0
Dest 1rcvr 7inc 4state 0x50041tstate 0x0
batch-type autobmsg 0x0tmout 0x2309344dmsg_in_batch 0
tkt total 1000avl 750 sp_rsv 249 max_sp_rsv 250
seq wrp 0lst 167682094ack 0snt 167682094
sync seq 0.167682094inc 0sndq enq seq 0.167682094
batch snds 11132775tot msgs 116220635max sz 63fullload 6524snd seq 11132775
pbatch snds 19178524tot msgs 159921440
sndq msg tot 127951741tm (0 120756)
sndq msg 0maxlmt 1504564maxlen 258wqlen 1414467041
sndq msg 0start_tm 0end_tm 0
Dest 1rcvr 8inc 4state 0x50041tstate 0x0
batch-type autobmsg 0x0tmout 0x231cfa30msg_in_batch 0
tkt total 1000avl 749 sp_rsv 250 max_sp_rsv 250
seq wrp 0lst 168614401ack 0snt 168614398
sync seq 0.168614400inc 0sndq enq seq 0.168614400
batch snds 11149447tot msgs 116307198max sz 63fullload 6454snd seq 11149447
pbatch snds 19178510tot msgs 159849781
sndq msg tot 128304568tm (0 126646)
sndq msg 0maxlmt 1504564maxlen 258wqlen 1414041120
sndq msg 0start_tm 0end_tm 0
GES remote instance per receiver context:
Dest 1rcvr 1inc 2state 0x3tstate 0x0 nak 4 cached 0
rcv wrp 0 seq 186711594 sync rcv seq 0.186711594 ack seq 0.0 inc 0
batch rcv seq 11266803 in work_q no nullreq_q no
cached stkts:
r0:0.x0 r1:0.x0 r2:0.x0 r3:0.x0 r4:0.x0 r5:0.x0
r6:0.x0 r7:0.x0 r8:0.x0
Dest 1rcvr 7inc 2state 0x3tstate 0x0 nak 0 cached 0
rcv wrp 0 seq 87977491 sync rcv seq 0.87977491 ack seq 0.0 inc 0
batch rcv seq 4870115 in work_q no nullreq_q no
cached stkts:
r0:0.x0 r1:0.x0 r2:0.x0 r3:0.x0 r4:0.x0 r5:0.x0
r6:0.x0 r7:0.x0 r8:0.x0
Dest 1rcvr 8inc 2state 0x3tstate 0x0 nak 4 cached 0
rcv wrp 0 seq 88682027 sync rcv seq 0.88682027 ack seq 0.0 inc 0
batch rcv seq 4902267 in work_q no nullreq_q no
cached stkts:
r0:0.x0 r1:0.x0 r2:0.x0 r3:0.x0 r4:0.x0 r5:0.x0
r6:0.x0 r7:0.x0 r8:0.x0
Dest 1rcvr 2inc 2state 0x3tstate 0x0 nak 0 cached 0
rcv wrp 0 seq 172941776 sync rcv seq 0.172941774 ack seq 0.0 inc 0
batch rcv seq 11174740 in work_q no nullreq_q no
cached stkts:
r0:0.x0 r1:0.x0 r2:0.x0 r3:0.x0 r4:0.x0 r5:0.x0
r6:0.x0 r7:0.x0 r8:0.x0
Dest 1rcvr 6inc 2state 0x3tstate 0x0 nak 3 cached 0
rcv wrp 0 seq 88207890 sync rcv seq 0.88207890 ack seq 0.0 inc 0
batch rcv seq 4872630 in work_q no nullreq_q no
cached stkts:
r0:0.x0 r1:0.x0 r2:0.x0 r3:0.x0 r4:0.x0 r5:0.x0
r6:0.x0 r7:0.x0 r8:0.x0
Dest 1rcvr 3inc 2state 0x3tstate 0x0 nak 3 cached 0
rcv wrp 0 seq 172583943 sync rcv seq 0.172583941 ack seq 0.0 inc 0
batch rcv seq 11167800 in work_q no nullreq_q no
cached stkts:
r0:0.x0 r1:0.x0 r2:0.x0 r3:0.x0 r4:0.x0 r5:0.x0
r6:0.x0 r7:0.x0 r8:0.x0
Dest 1rcvr 5inc 2state 0x3tstate 0x0 nak 7 cached 0
rcv wrp 0 seq 103056613 sync rcv seq 0.103056613 ack seq 0.0 inc 0
batch rcv seq 5376225 in work_q no nullreq_q no
cached stkts:
r0:0.x0 r1:0.x0 r2:0.x0 r3:0.x0 r4:0.x0 r5:0.x0
r6:0.x0 r7:0.x0 r8:0.x0
Dest 1rcvr 4inc 2state 0x3tstate 0x0 nak 0 cached 0
rcv wrp 0 seq 172907050 sync rcv seq 0.172907049 ack seq 0.0 inc 0
batch rcv seq 11177462 in work_q no nullreq_q no
cached stkts:
r0:0.x0 r1:0.x0 r2:0.x0 r3:0.x0 r4:0.x0 r5:0.x0
r6:0.x0 r7:0.x0 r8:0.x0
Dest 1rcvr 0inc 2state 0x3tstate 0x0 nak 1 cached 0
rcv wrp 0 seq 21451327 sync rcv seq 0.21451327 ack seq 0.0 inc 0
batch rcv seq 647707 in work_q no nullreq_q no
cached stkts:
r0:0.x0 r1:0.x0 r2:0.x0 r3:0.x0 r4:0.x0 r5:0.x0
r6:0.x0 r7:0.x0 r8:0.x0
Rcvr 1state 0x0
rbufs tot 1100in_ksxp 1100ubufs 0free 16
msgs rdyq 0watq 0nsq 0routq 1104
rmpool: alloc 1101avail 16
ibatch: 2[3233684] 3[1673986] 4[956344] 5[577583] 6[393900] 7[294447] 8[238659] 9[202689] 10[181083] 11[165446]
ibatch: 12[150460] 13[139454] 14[129961] 15[120287] 16[112874] 17[107856] 18[98207] 19[93614] 20[93123]
ibatch: 21[96810] sum 9060467
--------中间类似，看不懂
ibatch: 21[105] sum 646062

rcvs 647707 tot msgs 1611838 max sz 79 avg sz 2
pbatch: 2[151516] 3[61298] 4[38564] 5[55280] 6[21243] 7[35124] 8[10649] 9[10974] 10[6452] 11[5861]
pbatch: 12[6181] 13[4717] 14[3740] 15[3431] 16[3955] 17[2546] 18[2151] 19[1955] 20[1741]
pbatch: 21[1584] sum 428962

rcvs 8807408 tot msgs 12622853 max sz 84 avg sz 4
kjctseventdump-begin tail 153 heads 0 @ 0 153 @ -476772096
#0 id 269 exid 8879dests 00
#1 id 269 exid 8879dests 00
#2 id 269 exid 8879dests 00
#3 id 269 exid 8879dests 00
#4 id 269 exid 8879dests 00
中间都一样，略
#254 id 269 exid 8879dests 00
#255 id 269 exid 8879dests 00
kjctseventdump-end tail 153 heads 0 @ 0 153 @ -476772096
DEFER MSG QUEUE ON LMS7 IS EMPTY
SEQUENCES:
0:0.01:88682027.0
error 28 detected in background process
ORA-00028: your session has been killed

千问 · 2012-1-4 11:50:44

日志都贴出来了，目地就是想让各位帮忙判断下，这是人为的动作还是数据库自己的动作？我反正是没碰到RAC实例DOWN了后自己启动的案例。再说我的库配置全部是手动启动的，请各位给点意见。

千问 · 2012-1-4 11:50:44

javaio 发表于 2011-11-8 01:06
日志都贴出来了，目地就是想让各位帮忙判断下，这是人为的动作还是数据库自己的动作？我反正是没碰到RAC实例 ...
ora_872460.aud数据库登录审计日志：
Audit file /u01/app/oracle/admin/abcde/adump/ora_872460.aud
Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - 64bit Production
With the Partitioning, Real Application Clusters, OLAP, Data Mining
and Real Application Testing options
ORACLE_HOME = /u01/app/oracle/product/10.2.0/db_1
System name:
AIX
Node name:
p550a
Release:
3
Version:
5
Machine:
00CF5D934C00
Instance name: abcde1
Redo thread mounted by this instance: 1
Oracle process number: 0
Unix process pid: 872460, image: oracle@p550a
Mon Nov7 15:33:03 2011
LENGTH : '146'
ACTION :[7] 'CONNECT'
DATABASE USER:[1] '/'
PRIVILEGE :[6] 'SYSDBA'
CLIENT USER:[6] 'ora10g'
CLIENT TERMINAL:[13] 'Not Available'
STATUS:[1] '0'
Mon Nov7 15:33:03 2011
LENGTH : '147'
ACTION :[8] 'SHUTDOWN'
DATABASE USER:[1] '/'
PRIVILEGE :[6] 'SYSDBA'
CLIENT USER:[6] 'ora10g'
CLIENT TERMINAL:[13] 'Not Available'STATUS:[1] '0'

千问 · 2012-1-4 11:50:44

error 28 detected in background process
ORA-00028: your session has been killed
ksuitm: waiting up to [5] seconds before killing DIAG
有人kill了 dbw0的session ，dbw是关键后台进程会导致实例abort

千问 · 2012-1-4 11:50:44

maclean 发表于 2011-11-8 01:34
error 28 detected in background process
ORA-00028: your session has been killed
ksuitm: waiting up ...
这个我知道，我从aud审计日志和TRACE日志里能看出来在那个时间段有人用工具登录过并KILL过

千问 · 2012-1-4 11:50:44

我分析是这样的，
第一点：是你的数据库服务器当然时很慢，所以就有人为了提高系统性能将一占用系统资源的进程kill掉了。
第二点：是关于数据库服务器本身的问题我想你应该看一下当时系统资源怎么样。

千问 · 2012-1-4 11:50:44

对不起，楼主我对我回答的问题向你道赚。
不是有人kill这个进程，而是你的连接线出现了问题。
Running Distributed Transactions in RAC without DTP service.
从这一话可以得出一个结论是你的rac的连接出现在脑裂