Re: Performance degradation of inserts when database size grows

As near as I can tell from your test configuration description, you have
JMeter --> J2EE --> Postgres.
Have you ruled out the J2EE server as the problem? This problem may not be
the database.
I would take a look at your app server's health and look for any potential
issues there before spending too much time on the database. Perhaps there
are memory issues or excessive garbage collection on the app server?

Terry

On Tue, May 17, 2011 at 5:45 AM, Andrey Vorobiev <
andrey(dot)o(dot)vorobiev(at)gmail(dot)com> wrote:

> Hi, guys.
>
>
> I have following environment configuration
>
> - Postgres 8.4.7 with following postresql.conf settings modified:
>
> listen_addresses = '*'
>
> max_connections = 100
>
>
> shared_buffers = 2048MB
>
> max_prepared_transactions = 100
>
> wal_buffers = 1024kB
>
>
> checkpoint_segments = 64
>
> checkpoint_completion_target = 0.8
>
>
> log_checkpoints = on
>
>
> - Two databases. Let's call them db_1 and db_2
>
> - J2EE application server that performs inserts into databases defined
> above. (distribution transactions are used).
>
> - All constraints and indexes are on.
>
> - JMeter that acts as HTTP client and sends requests to server causing it
> to insert rows. (case of new users registration)
>
>
> After running scenario scenario described above (with 10 concurrent
> threads) I have observed following behavior:
>
>
> For the first time everything is fine and J2EE server handles about 700
> requests/sec (about 2500 inserts into several tables per second). But after
> some amount of time I observe performance degradation. In general it looks
> like the following:
>
>
> Total number of requests passed; Requests per second;
>
> 382000; 768;
>
> 546000; 765;
>
> 580000; 723;
>
> 650000; 700;
>
> 671000; 656;
>
> 700000; 628;
>
>
> Checkpoint logging gives me the following:
>
> 2011-05-17 18:55:51 NOVST LOG: checkpoint starting: xlog
>
> 2011-05-17 18:57:20 NOVST LOG: checkpoint complete: wrote 62861 buffers
> (24.0%); 0 transaction log file(s) added, 0 removed, 0 recycled;
> write=89.196 s, sync=0.029 s, total=89.242 s
>
> 2011-05-17 18:57:47 NOVST LOG: checkpoint starting: xlog
>
> 2011-05-17 18:59:02 NOVST LOG: checkpoint complete: wrote 83747 buffers
> (31.9%); 0 transaction log file(s) added, 0 removed, 64 recycled;
> write=75.001 s, sync=0.043 s, total=75.061 s
>
> 2011-05-17 18:59:29 NOVST LOG: checkpoint starting: xlog
>
> 2011-05-17 19:00:30 NOVST LOG: checkpoint complete: wrote 97341 buffers
> (37.1%); 0 transaction log file(s) added, 0 removed, 64 recycled;
> write=60.413 s, sync=0.050 s, total=60.479 s
>
> 2011-05-17 19:00:55 NOVST LOG: checkpoint starting: xlog
>
> 2011-05-17 19:01:48 NOVST LOG: checkpoint complete: wrote 110149 buffers
> (42.0%); 0 transaction log file(s) added, 0 removed, 64 recycled;
> write=52.285 s, sync=0.072 s, total=52.379 s
>
> 2011-05-17 19:02:11 NOVST LOG: checkpoint starting: xlog
>
> 2011-05-17 19:02:58 NOVST LOG: checkpoint complete: wrote 120003 buffers
> (45.8%); 0 transaction log file(s) added, 0 removed, 64 recycled;
> write=46.766 s, sync=0.082 s, total=46.864 s
>
> 2011-05-17 19:03:20 NOVST LOG: checkpoint starting: xlog
>
> 2011-05-17 19:04:18 NOVST LOG: checkpoint complete: wrote 122296 buffers
> (46.7%); 0 transaction log file(s) added, 0 removed, 64 recycled;
> write=57.795 s, sync=0.054 s, total=57.867 s
>
> 2011-05-17 19:04:38 NOVST LOG: checkpoint starting: xlog
>
> 2011-05-17 19:05:34 NOVST LOG: checkpoint complete: wrote 128165 buffers
> (48.9%); 0 transaction log file(s) added, 0 removed, 64 recycled;
> write=55.061 s, sync=0.087 s, total=55.188 s
>
> 2011-05-17 19:05:53 NOVST LOG: checkpoint starting: xlog
>
> 2011-05-17 19:06:51 NOVST LOG: checkpoint complete: wrote 138508 buffers
> (52.8%); 0 transaction log file(s) added, 0 removed, 64 recycled;
> write=57.919 s, sync=0.106 s, total=58.068 s
>
> 2011-05-17 19:07:08 NOVST LOG: checkpoint starting: xlog
>
> 2011-05-17 19:08:21 NOVST LOG: checkpoint complete: wrote 132485 buffers
> (50.5%); 0 transaction log file(s) added, 0 removed, 64 recycled;
> write=72.949 s, sync=0.081 s, total=73.047 s
>
> 2011-05-17 19:08:40 NOVST LOG: checkpoint starting: xlog
>
> 2011-05-17 19:09:48 NOVST LOG: checkpoint complete: wrote 139542 buffers
> (53.2%); 0 transaction log file(s) added, 0 removed, 64 recycled;
> write=68.193 s, sync=0.107 s, total=68.319 s
>
> 2011-05-17 19:10:06 NOVST LOG: checkpoint starting: xlog
>
> 2011-05-17 19:11:31 NOVST LOG: checkpoint complete: wrote 137657 buffers
> (52.5%); 0 transaction log file(s) added, 0 removed, 64 recycled;
> write=84.575 s, sync=0.047 s, total=84.640 s
>
>
> Also I observed more heavy IO from iostat utility.
>
>
> So my questions are:
>
> 1. How does database size affect insert performance?
>
> 2. Why does number of written buffers increase when database size grows?
>
> 3. How can I further analyze this problem?
>
> --
> Best regards.
>