VACUUM ANALYZE question - PostgreSQL performance tests

Hello,

   I have the question about VACUUM ANALYZE. I have try to do Postgres
performance tests for selecting large amount of records from DB.
   First I have insert 30.000 records into the 1 table. After this
insert I executed VACUUM ANALYZE query.
   I have a test that retrieves page by page (20 records per page)
all data from a table. It means I'm executing 1500 selects in the cycle
for retrieving each page and I'm retrieving also time duration of some
of this selects.

   PROBLEM IS, that when I start to retrieve records, the performance
is poor. But when I execute manually (from a DB client) query VACUUM
ANALYZE one more time (during retrieving of pages), the performance is
much better.

   Is there also neccessary to call VACUUM ANALYZE also for getting of
better performance for select query?


   Thank you for your answer,
   with best regards,

   Julian Legeny




   Here I attach log reports for 30.000 records:
   =============================================

  Here can be possible to see that time duration of executing final query is aproximately same for
  each retrieved page. And performance is not very good.
  I have applied VACUUM ANALYZE during processing test and from the page 1000 performance
  is better about 2/3.


   a.) First I insert 30.000 records into the DB.

   b.) Then I retrieve page by page all records from the DB.

     I'm executing 2 commands:

     1. Command retrieve number of all items that I want to retrieve
        page by page:

        select count(*) from BF_USER
           where BF_USER.DOMAIN_ID=19 and BF_USER.ID NOT IN(280)

        - in the log file is possible to see time duration of this
          select - it is time for "Duration for executing count
          statement".

     2. Final query for retrieving particular records specified within
     the LIMIT clause.

        select BF_USER.LOGIN_NAME,
               BF_USER.EMAIL,BF_USER.ID,
               BF_USER.MODIFICATION_DATE,
               BF_USER.SUPER_USER,
               BF_USER.GUEST_ACCESS_ENABLED
        from BF_USER
        where BF_USER.DOMAIN_ID=19 and
              BF_USER.ID NOT IN(280)
        order by BF_USER.LOGIN_NAME asc
        limit 20 offset 0


   First I execute "select COUNT(*) ..." query for retrieving number
   of all items that I will retrieve and then when I know this number,
   I can retrieve specified records (used LIMIT for this).


-----------------------------------------------------------------------------------------

INFO: Total duration to create 30000 data objects was 1:46.453 which is 281 items/sec

INFO: Duration for executing count statement for page 1 (at position 1) = 171 ms
INFO: Duration for executing final query = 641 ms
INFO: Total duration = 828 ms

INFO: Duration for executing count statement for page 2 (at position 21) = 156 ms
INFO: Duration for executing final query = 641 ms
INFO: Total duration = 797 ms

INFO: Duration for executing count statement for page 3 (at position 41) = 140 ms
INFO: Duration for executing final query = 625 ms
INFO: Total duration = 765 ms

INFO: Duration for executing count statement for page 4 (at position 61) = 141 ms
INFO: Duration for executing final query = 640 ms
INFO: Total duration = 797 ms

INFO: Duration for executing count statement for page 5 (at position 81) = 141 ms
INFO: Duration for executing final query = 625 ms
INFO: Total duration = 766 ms

INFO: Duration for executing count statement for page 100 (at position 1981) = 141 ms
INFO: Duration for executing final query = 625 ms
INFO: Total duration = 766 ms

INFO: Duration for executing count statement for page 101 (at position 2001) = 141 ms
INFO: Duration for executing final query = 625 ms
INFO: Total duration = 766 ms

INFO: Duration for executing count statement for page 102 (at position 2021) = 140 ms
INFO: Duration for executing final query = 594 ms
INFO: Total duration = 750 ms

INFO: Duration for executing count statement for page 103 (at position 2041) = 140 ms
INFO: Duration for executing final query = 625 ms
INFO: Total duration = 765 ms

INFO: Duration for executing count statement for page 104 (at position 2061) = 141 ms
INFO: Duration for executing final query = 609 ms
INFO: Total duration = 750 ms

INFO: Duration for executing count statement for page 105 (at position 2081) = 141 ms
INFO: Duration for executing final query = 625 ms
INFO: Total duration = 766 ms

INFO: Duration for executing count statement for page 200 (at position 3981) = 125 ms
INFO: Duration for executing final query = 641 ms
INFO: Total duration = 766 ms

INFO: Duration for executing count statement for page 201 (at position 4001) = 140 ms
INFO: Duration for executing final query = 641 ms
INFO: Total duration = 781 ms

INFO: Duration for executing count statement for page 202 (at position 4021) = 141 ms
INFO: Duration for executing final query = 609 ms
INFO: Total duration = 750 ms

INFO: Duration for executing count statement for page 203 (at position 4041) = 156 ms
INFO: Duration for executing final query = 625 ms
INFO: Total duration = 797 ms

INFO: Duration for executing count statement for page 204 (at position 4061) = 141 ms
INFO: Duration for executing final query = 687 ms
INFO: Total duration = 828 ms

INFO: Duration for executing count statement for page 205 (at position 4081) = 141 ms
INFO: Duration for executing final query = 640 ms
INFO: Total duration = 797 ms

INFO: Duration for executing count statement for page 300 (at position 5981) = 141 ms
INFO: Duration for executing final query = 625 ms
INFO: Total duration = 766 ms

INFO: Duration for executing count statement for page 301 (at position 6001) = 141 ms
INFO: Duration for executing final query = 625 ms
INFO: Total duration = 766 ms

INFO: Duration for executing count statement for page 302 (at position 6021) = 125 ms
INFO: Duration for executing final query = 593 ms
INFO: Total duration = 734 ms

INFO: Duration for executing count statement for page 303 (at position 6041) = 125 ms
INFO: Duration for executing final query = 594 ms
INFO: Total duration = 719 ms

INFO: Duration for executing count statement for page 304 (at position 6061) = 125 ms
INFO: Duration for executing final query = 625 ms
INFO: Total duration = 750 ms

INFO: Duration for executing count statement for page 305 (at position 6081) = 141 ms
INFO: Duration for executing final query = 594 ms
INFO: Total duration = 735 ms

INFO: Duration for executing count statement for page 400 (at position 7981) = 140 ms
INFO: Duration for executing final query = 625 ms
INFO: Total duration = 765 ms

INFO: Duration for executing count statement for page 401 (at position 8001) = 141 ms
INFO: Duration for executing final query = 609 ms
INFO: Total duration = 750 ms

INFO: Duration for executing count statement for page 402 (at position 8021) = 188 ms
INFO: Duration for executing final query = 610 ms
INFO: Total duration = 813 ms

INFO: Duration for executing count statement for page 403 (at position 8041) = 140 ms
INFO: Duration for executing final query = 625 ms
INFO: Total duration = 765 ms

INFO: Duration for executing count statement for page 404 (at position 8061) = 125 ms
INFO: Duration for executing final query = 625 ms
INFO: Total duration = 750 ms

INFO: Duration for executing count statement for page 405 (at position 8081) = 157 ms
INFO: Duration for executing final query = 656 ms
INFO: Total duration = 813 ms

INFO: Duration for executing count statement for page 800 (at position 15981) = 157 ms
INFO: Duration for executing final query = 640 ms
INFO: Total duration = 797 ms

INFO: Duration for executing count statement for page 801 (at position 16001) = 156 ms
INFO: Duration for executing final query = 641 ms
INFO: Total duration = 797 ms

INFO: Duration for executing count statement for page 802 (at position 16021) = 156 ms
INFO: Duration for executing final query = 735 ms
INFO: Total duration = 891 ms

INFO: Duration for executing count statement for page 803 (at position 16041) = 156 ms
INFO: Duration for executing final query = 703 ms
INFO: Total duration = 859 ms

INFO: Duration for executing count statement for page 804 (at position 16061) = 156 ms
INFO: Duration for executing final query = 657 ms
INFO: Total duration = 813 ms

INFO: Duration for executing count statement for page 805 (at position 16081) = 156 ms
INFO: Duration for executing final query = 625 ms
INFO: Total duration = 796 ms

INFO: Duration for executing count statement for page 900 (at position 17981) = 140 ms
INFO: Duration for executing final query = 782 ms
INFO: Total duration = 922 ms

INFO: Duration for executing count statement for page 901 (at position 18001) = 265 ms
INFO: Duration for executing final query = 719 ms
INFO: Total duration = 984 ms

INFO: Duration for executing count statement for page 902 (at position 18021) = 172 ms
INFO: Duration for executing final query = 703 ms
INFO: Total duration = 875 ms

INFO: Duration for executing count statement for page 903 (at position 18041) = 156 ms
INFO: Duration for executing final query = 688 ms
INFO: Total duration = 844 ms

INFO: Duration for executing count statement for page 904 (at position 18061) = 156 ms
INFO: Duration for executing final query = 750 ms
INFO: Total duration = 906 ms

INFO: Duration for executing count statement for page 905 (at position 18081) = 156 ms
INFO: Duration for executing final query = 672 ms
INFO: Total duration = 828 ms

INFO: Duration for executing count statement for page 1000 (at position 19981) = 125 ms
INFO: Duration for executing final query = 156 ms
INFO: Total duration = 281 ms

INFO: Duration for executing count statement for page 1001 (at position 20001) = 125 ms
INFO: Duration for executing final query = 156 ms
INFO: Total duration = 281 ms

INFO: Duration for executing count statement for page 1002 (at position 20021) = 125 ms
INFO: Duration for executing final query = 140 ms
INFO: Total duration = 265 ms

INFO: Duration for executing count statement for page 1003 (at position 20041) = 157 ms
INFO: Duration for executing final query = 171 ms
INFO: Total duration = 328 ms

INFO: Duration for executing count statement for page 1004 (at position 20061) = 141 ms
INFO: Duration for executing final query = 172 ms
INFO: Total duration = 313 ms

INFO: Duration for executing count statement for page 1005 (at position 20081) = 141 ms
INFO: Duration for executing final query = 156 ms
INFO: Total duration = 297 ms

INFO: Duration for executing count statement for page 1100 (at position 21981) = 125 ms
INFO: Duration for executing final query = 171 ms
INFO: Total duration = 296 ms

INFO: Duration for executing count statement for page 1101 (at position 22001) = 141 ms
INFO: Duration for executing final query = 172 ms
INFO: Total duration = 313 ms

INFO: Duration for executing count statement for page 1102 (at position 22021) = 141 ms
INFO: Duration for executing final query = 187 ms
INFO: Total duration = 328 ms

INFO: Duration for executing count statement for page 1103 (at position 22041) = 125 ms
INFO: Duration for executing final query = 156 ms
INFO: Total duration = 297 ms

INFO: Duration for executing count statement for page 1104 (at position 22061) = 172 ms
INFO: Duration for executing final query = 172 ms
INFO: Total duration = 344 ms

INFO: Duration for executing count statement for page 1105 (at position 22081) = 140 ms
INFO: Duration for executing final query = 172 ms
INFO: Total duration = 312 ms

INFO: Duration for executing count statement for page 1200 (at position 23981) = 125 ms
INFO: Duration for executing final query = 172 ms
INFO: Total duration = 297 ms

INFO: Duration for executing count statement for page 1201 (at position 24001) = 141 ms
INFO: Duration for executing final query = 203 ms
INFO: Total duration = 344 ms

INFO: Duration for executing count statement for page 1202 (at position 24021) = 125 ms
INFO: Duration for executing final query = 187 ms
INFO: Total duration = 312 ms

INFO: Duration for executing count statement for page 1203 (at position 24041) = 125 ms
INFO: Duration for executing final query = 172 ms
INFO: Total duration = 313 ms

INFO: Duration for executing count statement for page 1204 (at position 24061) = 140 ms
INFO: Duration for executing final query = 188 ms
INFO: Total duration = 328 ms

INFO: Duration for executing count statement for page 1205 (at position 24081) = 141 ms
INFO: Duration for executing final query = 218 ms
INFO: Total duration = 359 ms

INFO: Duration for executing count statement for page 1300 (at position 25981) = 125 ms
INFO: Duration for executing final query = 203 ms
INFO: Total duration = 328 ms

INFO: Duration for executing count statement for page 1301 (at position 26001) = 141 ms
INFO: Duration for executing final query = 203 ms
INFO: Total duration = 344 ms

INFO: Duration for executing count statement for page 1302 (at position 26021) = 140 ms
INFO: Duration for executing final query = 204 ms
INFO: Total duration = 344 ms

INFO: Duration for executing count statement for page 1303 (at position 26041) = 140 ms
INFO: Duration for executing final query = 188 ms
INFO: Total duration = 328 ms

INFO: Duration for executing count statement for page 1304 (at position 26061) = 140 ms
INFO: Duration for executing final query = 203 ms
INFO: Total duration = 343 ms

INFO: Duration for executing count statement for page 1305 (at position 26081) = 125 ms
INFO: Duration for executing final query = 250 ms
INFO: Total duration = 375 ms

INFO: Duration for executing count statement for page 1400 (at position 27981) = 125 ms
INFO: Duration for executing final query = 219 ms
INFO: Total duration = 344 ms

INFO: Duration for executing count statement for page 1401 (at position 28001) = 140 ms
INFO: Duration for executing final query = 204 ms
INFO: Total duration = 359 ms

INFO: Duration for executing count statement for page 1402 (at position 28021) = 125 ms
INFO: Duration for executing final query = 203 ms
INFO: Total duration = 344 ms

INFO: Duration for executing count statement for page 1403 (at position 28041) = 141 ms
INFO: Duration for executing final query = 203 ms
INFO: Total duration = 344 ms

INFO: Duration for executing count statement for page 1404 (at position 28061) = 140 ms
INFO: Duration for executing final query = 219 ms
INFO: Total duration = 359 ms

INFO: Duration for executing count statement for page 1405 (at position 28081) = 141 ms
INFO: Duration for executing final query = 203 ms
INFO: Total duration = 344 ms

INFO: Duration for executing count statement for page 1500 (at position 29981) = 125 ms
INFO: Duration for executing final query = 235 ms
INFO: Total duration = 360 ms


RESULTS:
=========
INFO: Total retrieved pages from first to last: 1500, number of items for page: 20
The best performance has page 948 with duration 250 ms.
The worst performance has page 731 with duration 2.922 seconds.
Average duration for page is 618 ms