Massive I/O spikes during checkpoint

От: David Kerr
Тема: Massive I/O spikes during checkpoint
Дата: ,
Msg-id: 27C32FD4-0142-44FE-8488-9F366DC75966@mr-paradox.net
(см: обсуждение, исходный текст)
Ответы: Re: Massive I/O spikes during checkpoint  (Maxim Boguk)
Re: Massive I/O spikes during checkpoint  (Jeff Janes)
Список: pgsql-performance

Скрыть дерево обсуждения

Massive I/O spikes during checkpoint  (David Kerr, )
 Re: Massive I/O spikes during checkpoint  (Maxim Boguk, )
  Re: Massive I/O spikes during checkpoint  (David Kerr, )
   Re: Massive I/O spikes during checkpoint  (Maxim Boguk, )
    Re: Massive I/O spikes during checkpoint  (David Kerr, )
    Re: Massive I/O spikes during checkpoint  (Andres Freund, )
     Re: Massive I/O spikes during checkpoint  (Jeff Janes, )
      Re: Massive I/O spikes during checkpoint  (Andres Freund, )
 Re: Massive I/O spikes during checkpoint  (Jeff Janes, )
  Re: Massive I/O spikes during checkpoint  (David Kerr, )

Howdy!

I'm trying to figure out why checkpointing it completely pegging my I/O under moderate to high write load, 
I'm on PG9.1.1, RHEL 6.2 x64

checkpoint_completion_target = 0.7
checkpoint_timeout = 10m

Jul 10 00:32:30 perf01 postgres[52619]: [1895-1] user=,db= LOG:  checkpoint starting: time
[...]
Jul 10 00:36:47 perf01 postgres[52619]: [1896-1] user=,db= LOG:  checkpoint complete: wrote 119454 buffers (11.4%); 0 transaction log file(s) added, 0 removed

Watching my I/O with: iostat -t -d -x dm-2 5  
Which is my $PGDATA mount point (ext4). 
I get the following:
Date r/s w/s rsec/s wsec/s await svctm %util
[...]
07/10/12 00:35:36 0 69.8 0 2233.6 0.63 0.07 0.46
07/10/12 00:35:41 1.2 810 99.2 22200 4.13 0.05 4.02
07/10/12 00:35:46 0 111.6 0 5422.4 1.82 0.08 0.9
07/10/12 00:35:51 0 299.2 0 5670.4 1.27 0.04 1.24
07/10/12 00:35:56 0.8 176.6 41.6 3654.4 2.16 0.07 1.32
07/10/12 00:36:01 0 364.8 0 6670.4 1.1 0.04 1.62
07/10/12 00:36:06 0.8 334.6 12.8 5953.6 1.18 0.05 1.64
07/10/12 00:36:11 0 118.6 0 6948.8 1.82 0.07 0.82
07/10/12 00:36:16 0 8274.6 0 148764.8 10.55 0.07 61.18
07/10/12 00:36:21 0.2 8577.4 3.2 161806.4 16.68 0.12 99.62
07/10/12 00:36:26 0.8 9244.6 12.8 167841.6 15.01 0.11 99.82
07/10/12 00:36:31 0.8 9434.2 44.8 208156.8 16.22 0.11 99.7
07/10/12 00:36:36 0 9582.8 0 202508.8 14.84 0.1 99.72
07/10/12 00:36:41 0 9830.2 0 175326.4 14.42 0.1 99.5
07/10/12 00:36:46 0 8208.6 0 149372.8 17.82 0.12 99.64
07/10/12 00:36:51 3 1438.4 102.4 26748.8 8.49 0.12 18
07/10/12 00:36:56 0.6 2004.6 9.6 27400 1.25 0.03 5.74
07/10/12 00:37:01 0.6 1723 9.6 23758.4 1.85 0.03 5.08
07/10/12 00:37:06 0.4 181.2 35.2 2928 1.49 0.06 1.06

The ramp up is barely using any I/O, but then just before the checkpoint ends I get a 
flood of I/O all at once. 

I thought that the idea of checkpoint_completion_target was that we try to finish writing
out the data throughout the entire checkpoint (leaving some room to spare, in my case 30%
of the total estimated checkpoint time)

But what appears to be happening is that all of the data is being written out at the end of the checkpoint.

This happens at every checkpoint while the system is under load.

I get the feeling that this isn't the correct behavior and i've done something wrong. 

Also, I didn't see this sort of behavior in PG 8.3, however unfortunately, I don't have data to back that 
statement up.

Any suggestions. I'm willing and able to profile, or whatever.

Thanks


В списке pgsql-performance по дате сообщения:

От: Pena Kupen
Дата:
Сообщение: Fw: Re: Custom function in where clause
От: Andres Freund
Дата:
Сообщение: Re: Massive I/O spikes during checkpoint