Second almost identical subquery takes much longer

Question

I execute an SQL Query with two almost identical subqueries like this one on a routing database with around 18mio entries:

EXPLAIN (ANALYZE, BUFFERS, VERBOSE) SELECT source.source, target.target FROM
    (SELECT source FROM at_2po_4pgr WHERE osm_source_id=380253639 LIMIT 1) as source,
    (SELECT target FROM at_2po_4pgr WHERE osm_target_id=373850046 LIMIT 1) as target

The Explain analysis returns following:

Nested Loop  (cost=0.00..491634.63 rows=1 width=8) (actual time=6437.767..6437.768 rows=1 loops=1)
   Output: at_2po_4pgr.source, at_2po_4pgr_1.target
   Buffers: shared hit=6136 read=1684402
   ->  Limit  (cost=0.00..215090.14 rows=1 width=4) (actual time=6437.740..6437.740 rows=1 loops=1)
         Output: at_2po_4pgr.source
         Buffers: shared hit=6132 read=1684402
         ->  Seq Scan on public.at_2po_4pgr  (cost=0.00..1935811.25 rows=9 width=4) (actual time=6437.738..6437.738 rows=1 loops=1)
               Output: at_2po_4pgr.source
               Filter: (at_2po_4pgr.osm_source_id = 380253639)
               Rows Removed by Filter: 17052688
               Buffers: shared hit=6132 read=1684402
   ->  Limit  (cost=0.00..276544.46 rows=1 width=4) (actual time=0.020..0.020 rows=1 loops=1)
         Output: at_2po_4pgr_1.target
         Buffers: shared hit=4
         ->  Seq Scan on public.at_2po_4pgr at_2po_4pgr_1  (cost=0.00..1935811.25 rows=7 width=4) (actual time=0.020..0.020 rows=1 loops=1)
               Output: at_2po_4pgr_1.target
               Filter: (at_2po_4pgr_1.osm_target_id = 373850046)
               Rows Removed by Filter: 94
               Buffers: shared hit=4
 Planning time: 0.109 ms
 Execution time: 6437.887 ms

In this case, the first subquery needs around 6500ms while the second one just needs 0.02ms! Sometimes it is the other way around, so that the second query is the slow one. When I run the queries as single ones, they return within 10ms. So I assume there isn't enough buffer memory provided for executing both queries, however I already increased most of the default values a lot.

My current postgresql memory settings are:

# - Memory -

shared_buffers = 12GB                   # min 128kB
                                        # (change requires restart)
#huge_pages = try                       # on, off, or try
                                        # (change requires restart)
temp_buffers = 64MB                     # min 800kB
#max_prepared_transactions = 0          # zero disables the feature
                                        # (change requires restart)
# Note:  Increasing max_prepared_transactions costs ~600 bytes of shared memory
# per transaction slot, plus lock space (see max_locks_per_transaction).
# It is not advisable to set max_prepared_transactions nonzero unless you
# actively intend to use prepared transactions.
work_mem = 256MB                                # min 64kB
maintenance_work_mem = 512MB            # min 1MB
#autovacuum_work_mem = -1               # min 1MB, or -1 to use maintenance_work_mem
#max_stack_depth = 2MB                  # min 100kB
dynamic_shared_memory_type = posix      # the default is the first option
                                        # supported by the operating system:
                                        #   posix
                                        #   sysv
                                        #   windows
                                        #   mmap
                                        # use none to disable dynamic shared memory

So I have absolutely no clue for the reason of these different execution times.

Answer 1

Not sure why you have different time. My guess is first one scan the table and second one take advantage of some cache and so take less time.

Try to invert the order of the querys and see if you have similar result or the times changes

EXPLAIN (ANALYZE, BUFFERS, VERBOSE) SELECT source.source, target.target FROM        
    (SELECT target FROM at_2po_4pgr WHERE osm_target_id=373850046 LIMIT 1) as target,
    (SELECT source FROM at_2po_4pgr WHERE osm_source_id=380253639 LIMIT 1) as source

BTW: You should create one index for target and one index for source. As you can see on the EXPLAIN the query is perfoming a SEQ SCAN

EDIT: After see the EXPLAIN message Rows Removed by Filter: 17052688 vs Rows Removed by Filter: 94 maybe the target appear sooner on the search and limit 1 stop the search making looks like is faster. Try with different ID values That is another reason why you should create one index.