CKPT

antyison

数据库在一次增加虚拟内存段之后，检查点时间非常长。

日志如下，请高手指教。

====================================================
23:07:49  Fuzzy Checkpoint Completed:  duration was 0 seconds, 930 buffers not flushed.
23:07:49  Checkpoint loguniq 40842, logpos 0x5bc7370, timestamp: 0x7853ebbc

23:07:49  Maximum server connections 661
23:07:49  Buffer manager: starting coarse downgrades.
23:07:49  Buffer manager: finished coarse downgrades.
                Starting threshold adjustments.
23:07:49  Buffer manager: finished threshold adjustments.
23:08:27  Logical Log 40842 Complete, timestamp: 0x78876245.
23:08:28  Logical Log 40842 - Backup Started
23:08:33  HPUX KAIO Segment locked addr=0x10000000 size=524288000
23:08:33  HPUX KAIO Segment locked addr=0x10000000 size=524288000
23:08:33  HPUX KAIO Segment locked addr=0x10000000 size=524288000
23:08:33  HPUX KAIO Segment locked addr=0x10000000 size=524288000
23:08:33  HPUX KAIO Segment locked addr=0x10000000 size=524288000
23:08:33  HPUX KAIO Segment locked addr=0x10000000 size=524288000
23:08:33  HPUX KAIO Segment locked addr=0x10000000 size=524288000
23:08:33  HPUX KAIO Segment locked addr=0x10000000 size=524288000
23:08:33  HPUX KAIO Segment locked addr=0x10000000 size=524288000
23:08:33  HPUX KAIO Segment locked addr=0x10000000 size=524288000
23:08:33  HPUX KAIO Segment locked addr=0x10000000 size=524288000
23:08:33  HPUX KAIO Segment locked addr=0x10000000 size=524288000
23:08:33  HPUX KAIO Segment locked addr=0x10000000 size=524288000
23:08:33  Dynamically allocated new virtual shared memory segment (size 512000KB)
23:08:33  Memory sizes:resident:4194048 KB, virtual:2113004 KB, no SHMTOTAL limit
23:08:48  Logical Log 40842 - Backup Completed
23:12:55  2357 buffers dirty
23:12:55  oldest lsn loguniq 40842, logpos 0x4c53048
23:13:23  dskflush() took 28 seconds
23:13:23  wait4critex() took 0 seconds
23:13:23  1041 buffers dirty
23:13:23  oldest lsn loguniq 40843, logpos 0x278404
23:13:23  safe_dskflush() took 0 seconds
23:14:14  Fuzzy Checkpoint Completed:  duration was 78 seconds, 889 buffers not flushed.
23:14:14  Checkpoint loguniq 40843, logpos 0x11801b4, timestamp: 0x79f20c6e

23:14:14  Maximum server connections 661
23:14:14  Buffer manager: starting coarse downgrades.
23:14:14  Buffer manager: finished coarse downgrades.
                Starting threshold adjustments.
23:14:14  Buffer manager: finished threshold adjustments.
23:19:19  2025 buffers dirty
23:19:19  oldest lsn loguniq 40843, logpos 0x278404
23:19:52  dskflush() took 33 seconds
23:19:52  wait4critex() took 0 seconds
23:19:52  782 buffers dirty
23:19:52  oldest lsn loguniq 40843, logpos 0x3e0798
23:19:52  safe_dskflush() took 0 seconds
23:20:24  Fuzzy Checkpoint Completed:  duration was 64 seconds, 623 buffers not flushed.
23:20:24  Checkpoint loguniq 40843, logpos 0x19b9580, timestamp: 0x7b8ea9bd

23:20:24  Maximum server connections 661
23:20:24  Buffer manager: starting coarse downgrades.
23:20:24  Buffer manager: finished coarse downgrades.
                Starting threshold adjustments.
23:20:24  Buffer manager: finished threshold adjustments.
23:25:34  1938 buffers dirty
23:25:34  oldest lsn loguniq 40843, logpos 0x3e0798
23:26:40  dskflush() took 66 seconds
23:26:40  wait4critex() took 0 seconds
23:26:40  744 buffers dirty
23:26:40  oldest lsn loguniq 40843, logpos 0xfa1048
23:26:40  safe_dskflush() took 0 seconds
23:27:08  Fuzzy Checkpoint Completed:  duration was 93 seconds, 589 buffers not flushed.
23:27:08  Checkpoint loguniq 40843, logpos 0x23ca390, timestamp: 0x7d33cfa9

23:27:08  Maximum server connections 661
23:27:08  Buffer manager: starting coarse downgrades.
23:27:08  Buffer manager: finished coarse downgrades.
                Starting threshold adjustments.
23:27:08  Buffer manager: finished threshold adjustments.
23:32:16  2316 buffers dirty
23:32:16  oldest lsn loguniq 40843, logpos 0xfa1048
23:32:34  dskflush() took 18 seconds
23:32:34  wait4critex() took 0 seconds
23:32:34  761 buffers dirty
23:32:34  oldest lsn loguniq 40843, logpos 0x1976048
23:32:34  safe_dskflush() took 0 seconds
23:32:52  Fuzzy Checkpoint Completed:  duration was 36 seconds, 588 buffers not flushed.
23:32:52  Checkpoint loguniq 40843, logpos 0x2d064d8, timestamp: 0x7ed51e85

wolfop

dskflush() took 33 seconds
表面看就是IO问题，不过最好有更加详细的东西，比如机器配置，存储配置，数据库大小，$ONCONFIG等等。

liaosnet

dskflush用的时间点长.当然这如2楼所说是表面现像...

antyison

通过对以前该库的日志观察，发现每次数据库检查点时间恶化都是从增加虚拟内存段开始的，当数据库重新启动后恢复正常（小于1秒）。

请问这种情况下，可以做些什么呢？
IDS 940, 惠普安腾

liaosnet

原帖由 antyison 于 2010-1-21 12:26 发表
通过对以前该库的日志观察，发现每次数据库检查点时间恶化都是从增加虚拟内存段开始的，当数据库重新启动后恢复正常（小于1秒）。

请问这种情况下，可以做些什么呢？
IDS 940, 惠普安腾

为什么会增加内存段??那就是可能当然有大量数据操作写到了内存,那样可能需要很多的时间写回磁盘...

antyison

当共享内存虚拟段不够用时，数据库自动增加出一个虚拟段，这个应该是很常见的，但增加这个虚拟段之后带来对检查点的影响过大（从小于1秒到大于30秒），而且这个情况会一直持续下去，一直想不通错误会出现在哪里。。。

wtwu

数据库CKPT的时候数据库的状态(onstat -输出).CKPT那就从内存向磁盘刷新数据,两个方面一:CKPT的时候临界区有关键事物在做操作必须等待它完成.2 磁盘性能问题 3:没有CPUVP完成内存向磁盘刷新数据.4 数据库可能的BUG .还有不知道你的数据库是不是关键业务系统.如果想进一步查找原因可以在数据库发生虚拟内存段增加时同时产生长CHECKPOINT把数据库block住,然后把数据库当时运行在内存里面的内容输出出来.做进一步的分析.这个方法可能需要IBM做进一步的分析

[ 本帖最后由 wtwu 于 2010-1-21 23:37 编辑 ]

狡兔

原来我们运行在HPUX的PA系列，还比较顺，转成安腾和AIX后，问题多多。

安腾上增加内存后确实ceckpont时间会变长，是系统的bug，我们只能通过一始就分配足够的虚拟段来规避了。

liaosnet

原来我们运行在HPUX的PA系列，还比较顺，转成安腾和AIX后，问题多多。

安腾上增加内存后确实ceckpont时间 ...
狡兔 发表于 2010-05-17 09:59

    IX64上....
    AIX上問題應該更少吧~~