Take the 2-minute tour ×
Database Administrators Stack Exchange is a question and answer site for database professionals who wish to improve their database skills and learn from others in the community. It's 100% free, no registration required.

I have an intermediate table for managing a many-to-many relation between tables called Expert and Subject:

   Column   |            Type             | Modifiers
------------+-----------------------------+-----------
 expert_id  | integer                     | not null
 subject_id | integer                     | not null
 created    | timestamp without time zone | not null
Indexes:
    "expert_subject_pkey" PRIMARY KEY, btree (expert_id, subject_id) CLUSTER

An index scan on my local machine is fairly fast. EXPLAIN ANALYZE gives:

-> Index Only Scan using expert_subject_pkey on expert_subject expert_subject_1  (cost=0.00..24.32 rows=10 width=8) (actual time=0.005..0.007 rows=9 loops=701)
                             Index Cond: (expert_id = expert.id)
                             Heap Fetches: 6524

.. but an index scan on the server (4gB RAM, work_mem=50mB, shared_buffers=1024mB, effective_cache_size=2500mB) takes much longer:

->  Index Only Scan using expert_subject_pkey on expert_subject expert_subject_1  (cost=0.00..24.21 rows=10 width=8) (actual time=0.006..0.021 rows=10 loops=708)
                             Index Cond: (expert_id = expert.id)
                             Heap Fetches: 7160

(The above query is part of a larger query, and it gets repeated in a loop several times. I assume that max(actual_time) * loops = useful value for practical upper bound on execution time?)

Each loop iteration seems to be 3x slower on the server. I tried putting the database on an SSD, like I have on my local machine, but max(actual_time) only improved by 0.001ms.

Ultimately, a few of these slow seq and index scans add up to result in a 5x slowdown on the server.

Any ideas on why the same scan would be slower on a different machine, given my settings?

EDIT: Here's the EXPLAIN ANALYZE from the server (takes ~350ms, local takes ~75ms):

QUERY PLAN
---------
 Aggregate  (cost=5027.10..5027.11 rows=1 width=0) (actual time=357.054..357.055 rows=1 loops=1)
   ->  Unique  (cost=5027.04..5027.09 rows=1 width=519) (actual time=345.577..356.571 rows=375 loops=1)
         ->  Sort  (cost=5027.04..5027.05 rows=1 width=519) (actual time=345.572..348.164 rows=1977 loops=1)
           Sort Key: [ removed: complete list of columns on expert table ]
           Sort Method: quicksort  Memory: 2379kB
               ->  Nested Loop  (cost=0.00..5027.03 rows=1 width=519) (actual time=0.321..100.620 rows=1977 loops=1)
                     ->  Nested Loop  (cost=0.00..5024.77 rows=8 width=523) (actual time=0.246..51.928 rows=7160 loops=1)
                       ->  Seq Scan on expert  (cost=0.00..5000.46 rows=1 width=519) (actual time=0.225..16.983 rows=708 loops=1)
                             Filter: (active AND (geog && '0101000020E6100000A50000A0748052C034FAFF5F765B4440'::geography) AND ('0101000020E6100000A50000A0748052C034FAFF5F765B4440'::geography && _st_expand(geog, 8047::double precision)) AND _st_dwithin(geog, '0101000020E6100000A50000A0748052C034FAFF5F765B4440'::geography, 8047::double precision, true))
                             Rows Removed by Filter: 14164
                       ->  Index Only Scan using expert_subject_pkey on expert_subject expert_subject_1  (cost=0.00..24.21 rows=10 width=8) (actual time=0.007..0.022 rows=10 loops=708)
                             Index Cond: (expert_id = expert.id)
                             Heap Fetches: 7160
                 ->  Index Scan using subject_pkey on subject  (cost=0.00..0.27 rows=1 width=4) (actual time=0.003..0.003 rows=0 loops=7160)
                       Index Cond: (id = expert_subject_1.subject_id)
                       Filter: (subject_category_id = 16)
                       Rows Removed by Filter: 1
Total runtime: 357.497 ms
(18 rows)

... and the EXPLAIN ANALYZE output on my local machine:

QUERY PLAN
-----------
Aggregate  (cost=5111.56..5111.57 rows=1 width=0) (actual time=77.055..77.055 rows=1 loops=1)
   ->  Unique  (cost=5111.50..5111.55 rows=1 width=521) (actual time=74.742..77.024 rows=370 loops=1)
         ->  Sort  (cost=5111.50..5111.51 rows=1 width=521) (actual time=74.741..74.903 rows=1555 loops=1)
           Sort Key: [ removed: complete list of columns on expert table ]
           Sort Method: quicksort  Memory: 1878kB
               ->  Nested Loop  (cost=0.00..5111.49 rows=1 width=521) (actual time=0.240..24.860 rows=1555 loops=1)
                     ->  Nested Loop  (cost=0.00..5109.51 rows=7 width=525) (actual time=0.218..15.531 rows=6524 loops=1)
                           ->  Seq Scan on expert  (cost=0.00..5085.09 rows=1 width=521) (actual time=0.207..10.234 rows=701 loops=1)
                             Filter: (active AND (geog && '0101000020E6100000A50000A0748052C034FAFF5F765B4440'::geography) AND ('0101000020E6100000A50000A0748052C034FAFF5F765B4440'::geography && _st_expand(geog, 8047::double precision)) AND _st_dwithin(geog, '0101000020E6100000A50000A0748052C034FAFF5F765B4440'::geography, 8047::double precision, true))
                             Rows Removed by Filter: 14110
                           ->  Index Only Scan using expert_subject_pkey on expert_subject expert_subject_1  (cost=0.00..24.32 rows=10 width=8) (actual time=0.003..0.006 rows=9 loops=701)
                             Index Cond: (expert_id = expert.id)
                             Heap Fetches: 6524
                     ->  Index Scan using subject_pkey on subject  (cost=0.00..0.27 rows=1 width=4) (actual time=0.001..0.001 rows=0 loops=6524)
                       Index Cond: (id = expert_subject_1.subject_id)
                       Filter: (subject_category_id = 16)
                       Rows Removed by Filter: 1
Total runtime: 77.156 ms
(18 rows)

UPDATE: Here's the disk utilization report for the relevant (and only major) partition on the server's hard drive, showing no thrashing problems as far as I can tell (low %util, or CPU time spent on disk I/O):

Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
xvda              0.00    11.51    0.01    2.05     0.21    54.25    52.93     0.04   21.62    3.76   21.69   0.45   0.09

Thanks.

share|improve this question

migrated from stackoverflow.com May 16 '13 at 7:47

This question came from our site for professional and enthusiast programmers.

    
Can you try to CLUSTER expert USING expert_subject_pkey. Needs exclusive lock. Be aware that it's a one-time effect that wears off over time. This should get you perfectly streamlined data on both machines. If you can't afford an exclusive lock, consider pg_repack. And try again on both machines. Run EXPLAIN ANALYZE a couple of times to exclude caching effects. If that removes the discrepancy, data distribution and table / index bloat may have been the reason. –  Erwin Brandstetter Apr 15 '13 at 20:52
    
Yes, I tried CLUSTER expert_subject_pkey ON expert_subject, but that had no effect. I just ran it again on my machine and on the server and the 'actual time' is still exactly the same on both. –  Zach Apr 15 '13 at 21:00
    
(The above query is part of a larger query, and it gets repeated in a loop several times. Are you using a cursor or a function to call the subquery repeatedly? –  wildplasser Apr 15 '13 at 21:06
1  
Data is different on server and local. Compare the number of rows in both explains. –  Clodoaldo Apr 15 '13 at 22:13
2  
What are specs of local machine and server and - most importantly - what kind of load is server under? This isn't unfamiliar situation for me: I often find that, despite better specs, queries run as a single user on my local dev box perform very differently on a moderately loaded server. –  marcj Apr 15 '13 at 23:17

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.