[20161228]奇怪log file sync等待事件.txt

--这个来自链接:http://www.itpub.net/thread-2073857-1-1.html的讨论,很奇怪的问题:

Top 10 Foreground Events by Total Wait Time
Event                                              Waits    Total Wait Time (sec)    Wait Avg(ms)    % DB time    Wait Class
log file sync                                      47,412    50K                      1054            68.2        Commit
DB CPU                                                      7250.1                                     9.9    
log file switch (private strand flush incomplete)    420    5179.7                    12333            7.1        Configuration
enq: TX - row lock contention                         46    4448.1                    96698            6.1        application
JS kgl get object wait                             3,814    1366                        358            1.9        Administrative
JS kill job wait                                   1,269    1278.1                     1007            1.7        Administrative
SQL*Net message from dblink                      286,374    602.3                         2             .8        Network
direct path write temp                            30,149    405.4                        13             .6        User I/O
buffer busy waits                                    302    376.2                      1246             .5        Concurrency
db file sequential read                           49,254    301.4                         6             .4        User I/O

--30分钟awr报表,log file sync 达到了50K sec,一般出现这个多数情况是存放redo磁盘IO很慢,或者事务非常多.硬件不堪重负.
--而仔细看db file sequential read 平均等待事件仅仅6ms,而且lz介绍数据文件与redo在同一个磁盘组.

--而看前面Load Profile

Load Profile

                 Per Second    Per Transaction    Per Exec    Per Call
DB Time(s):            36.7                1.4    0.04        0.02
DB CPU(s):              3.6                0.1    0.00        0.00
Redo size (bytes):    164,938.0        6,263.7         

--平均每秒的redo size仅仅160K.这样的量对于现在的磁盘轻松应付.而再仔细看Background Wait Events:

Background Wait Events

    ordered by wait time desc, waits desc (idle events last)
    Only events with Total Wait Time (s) >= .001 are shown
    %Timeouts: value of 0 indicates value was < .5%. Value of null is truly 0

Event                     Waits    %Time -outs    Total Wait Time (s)    Avg wait (ms)    Waits /txn    % bg time
LNS wait on SENDREQ       21,345             0                 1,826               86           0.41    37.53
LGWR-LNS wait on channel 116,328            93                 1,647               14           2.21    33.86
log file parallel write   13,220             0                   263               20           0.25    5.40

--//前面2者相加,占用大约70%的后台时间.而这个数值几乎与log file sync占用的db time 68.2% ,相互呼应.
--而dg的参数如下:

log_archive_dest_2    service="XXXX1", LGWR SYNC AFFIRM delay=0 optional compression=disable max_failure=0
max_connections=1 reopen=300 db_unique_name="XXXX1" net_timeout=30, valid_for=(all_logfiles, primary_role)
SERVICE="XXXX1" LGWR ASYNC valid_for=(all_logfiles, primary_role) DB_UNIQUE_NAME="XXXX1"

--//前面是sync,后面是async,估计应该sync.可以推测这个设置导致出现log file sync.
--//检查oracle相关文档:http://docs.oracle.com/cd/E11882_01/server.112/e41134/log_arch_dest_param.htm#SBYDB01114

SYNC and ASYNC

Specifies whether the synchronous (SYNC) or asynchronous (ASYNC) redo transport mode is to be used.

Usage Notes

The LOG_ARCHIVE_DEST_11 through LOG_ARCHIVE_DEST_31 parameters do not support the SYNC attribute.

The redo data generated by a transaction must have been received by every enabled destination that has the SYNC
attribute before that transaction can commit.

The redo data generated by a transaction need not have been received at a destination that has the ASYNC attribute
before that transaction can commit. This is the default behavior if neither SYNC or ASYNC is specified.

--//英文我就不翻译了,我估计应该是对方的网络问题导致这个问题,目前仅仅是猜测,等待对方的确认.