暂无图片
暂无图片
暂无图片
暂无图片
暂无图片

生产环境完成一次checkpiont非常慢

原创 问题归档 2019-05-22
1990

问题描述

alter system switch logfile 频繁时,14组redolog很快撑满,检查后台日志发现切换日志时checkpoint并没有完成,需要等2-3分钟才能完成。

手工执行alter system checkpoint也需要等3分钟左右才能完成。

Beginning global checkpoint up to RBA [0x8639.16c8cb.10], SCN: 7934011180
Fri Apr 26 16:32:56 2019
Thread 1 cannot allocate new log, sequence 34362
Private strand flush not complete
  Current log# 13 seq# 34361 mem# 0: /home/opt/11g/oracle/oradata/orcl/redo13.log
Fri Apr 26 16:33:11 2019
Beginning log switch checkpoint up to RBA [0x863a.2.10], SCN: 7934155570
Thread 1 advanced to log sequence 34362 (LGWR switch)
  Current log# 6 seq# 34362 mem# 0: /home/opt/11g/oracle/oradata/orcl/redo06.log
Fri Apr 26 16:36:09 2019
Completed checkpoint up to RBA [0x8637.2.10], SCN: 7932927739
Fri Apr 26 16:36:13 2019
Thread 1 cannot allocate new log, sequence 34363
Private strand flush not complete
  Current log# 6 seq# 34362 mem# 0: /home/opt/11g/oracle/oradata/orcl/redo06.log
Beginning log switch checkpoint up to RBA [0x863b.2.10], SCN: 7934640980
Thread 1 advanced to log sequence 34363 (LGWR switch)
  Current log# 9 seq# 34363 mem# 0: /home/opt/11g/oracle/oradata/orcl/redo09.log
Fri Apr 26 16:37:51 2019
Completed checkpoint up to RBA [0x8638.2.10], SCN: 7933190148
Fri Apr 26 16:38:06 2019
Completed checkpoint up to RBA [0x8639.2.10], SCN: 7933593612
Completed checkpoint up to RBA [0x8639.16c8cb.10], SCN: 7934011180
Fri Apr 26 16:38:39 2019
Completed checkpoint up to RBA [0x863a.2.10], SCN: 7934155570
Fri Apr 26 16:39:43 2019
Thread 1 cannot allocate new log, sequence 34364
Private strand flush not complete
  Current log# 9 seq# 34363 mem# 0: /home/opt/11g/oracle/oradata/orcl/redo09.log
Beginning log switch checkpoint up to RBA [0x863c.2.10], SCN: 7935058947
Thread 1 advanced to log sequence 34364 (LGWR switch)
  Current log# 7 seq# 34364 mem# 0: /home/opt/11g/oracle/oradata/orcl/redo07.log
Fri Apr 26 16:41:35 2019
Completed checkpoint up to RBA [0x863b.2.10], SCN: 7934640980
Fri Apr 26 16:42:03 2019
Thread 1 cannot allocate new log, sequence 34365
Private strand flush not complete
  Current log# 7 seq# 34364 mem# 0: /home/opt/11g/oracle/oradata/orcl/redo07.log
Beginning log switch checkpoint up to RBA [0x863d.2.10], SCN: 7935547884
Thread 1 advanced to log sequence 34365 (LGWR switch)
  Current log# 4 seq# 34365 mem# 0: /home/opt/11g/oracle/oradata/orcl/redo04.log
Fri Apr 26 16:42:35 2019
Thread 1 cannot allocate new log, sequence 34366

执行命令iostat -Xdm 2 100命令,结果显示如下,是不是表示硬盘IO性能极差?

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await  svctm  %util
sda               0.07    59.36    2.65   14.06     0.10     0.29    47.75     0.04    2.16   2.45   4.09
dm-0              0.00     0.00    0.03    0.81     0.00     0.00     8.75     0.01   15.24   1.69   0.14
dm-1              0.00     0.00    0.07    0.06     0.00     0.00     8.00     0.02  154.25   1.88   0.02
dm-2              0.00     0.00    2.62   72.55     0.10     0.28    10.51     0.02    0.27   0.53   3.99
Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await  svctm  %util
sda               4.50  1908.50    1.00  577.00     0.01     9.94    35.27    19.65   33.64   1.73 100.00
dm-0              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
dm-1              0.00     0.00    6.50    0.00     0.03     0.00     8.00     0.57   30.62  13.31   8.65
dm-2              0.00     0.00    0.00 2485.50     0.00     9.71     8.00   202.26   81.82   0.40  99.95
Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await  svctm  %util
sda               0.00  2363.00    2.50  531.00     0.04    11.29    43.49    18.55   35.55   1.87 100.00
dm-0              0.00     0.00    0.00    2.50     0.00     0.01     8.00     0.04   14.80   6.40   1.60
dm-1              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.10    0.00   0.00   1.25
dm-2              0.00     0.00    2.00 2894.50     0.03    11.31     8.01   194.74   69.90   0.35 100.00
Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await  svctm  %util
sda               0.00  3090.50    2.50  486.50     0.02    13.64    57.23    19.05   35.37   2.04 100.00
dm-0              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
dm-1              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
dm-2              0.00     0.00    2.00 3575.00     0.02    13.96     8.00   274.78   63.99   0.28 100.05


专家解答

1、log switches (derived): 43.84   一小时切换次数过高,是否日志文件过小?可以适当增加日志大小和增加日志组

2、%WIO: 10.2和db file scattered read: Avg wait (ms) 12.0、log file parallel write: Avg wait (ms) 59.0、control file parallel write: Avg wait (ms) 33.0说明目前系统本身IO有比较严重的问题

3、_use_adaptive_log_file_sync参数未设置,Oracle 默认启用 _use_adaptive_log_file_sync 参数,使得 LGWR 进程写日志的方式能自动在 post/wait 和 polling 两种方式之间进行取舍,可能会导致比较严重的写日志等待(log file sync的平均单次等待时间较高),建议关闭此功能。
参考命令:alter system set "_use_adaptive_log_file_sync"=FALSE #INSTANCE#;   


另外,磁盘的 IO 能力极差,写日志遇到了严重的瓶颈。检查日志所在的存储。看看能不能分散日志到其他磁盘

「喜欢这篇文章,您的关注和赞赏是给作者最好的鼓励」
关注作者
【版权声明】本文为墨天轮用户原创内容,转载时必须标注文章的来源(墨天轮),文章链接,文章作者等基本信息,否则作者和墨天轮有权追究责任。如果您发现墨天轮中有涉嫌抄袭或者侵权的内容,欢迎发送邮件至:contact@modb.pro进行举报,并提供相关证据,一经查实,墨天轮将立刻删除相关内容。

评论