The same query - much different runtimes

While waiting for a query to finish (activated through a web interface), I
ran the same query using psql through a ssh-connection with much different
runtimes.

I have configured the server to log queries taking more than five seconds
and in the log the query for which I waited was logged as:

2014-04-07 12:01:38 SAST LOG: duration: 466754.684 ms plan:
Query Text: SELECT isi_alt_names.code FROM rresearch,
isi_alt_names WHERE ((((UPPER(rresearch.ny) = 'GUANGZHOU') AND\
(UPPER(rresearch.nu) = 'PEOPLES R CHINA')) AND (isi_alt_names.rsc_id =
rresearch.id)) AND (isi_alt_names.code IS NOT NULL)) \
ORDER BY rresearch.id, isi_alt_names.id LIMIT 2 OFFSET 0;
Limit (cost=384216.93..384216.94 rows=2 width=15)
-> Sort (cost=384216.93..384244.77 rows=11137 width=15)
Sort Key: rresearch.id, isi_alt_names.id
-> Nested Loop (cost=138757.99..384105.56 rows=11137
width=15)
-> Bitmap Heap Scan on rresearch
(cost=138757.99..161224.50 rows=11337 width=4)
Recheck Cond: ((upper((ny)::text) =
'GUANGZHOU'::text) AND (upper((nu)::text) = 'PEOPLES R CHINA'\
::text))
-> BitmapAnd (cost=138757.99..138757.99
rows=11337 width=0)
-> Bitmap Index Scan on
rresearch_ny_idx (cost=0.00..4930.62 rows=215233 width=0)
Index Cond: (upper((ny)::text) =
'GUANGZHOU'::text)
-> Bitmap Index Scan on
rresearch_nu_idx (cost=0.00..133821.46 rows=6229156 width=0)
Index Cond: (upper((nu)::text) =
'PEOPLES R CHINA'::text)
-> Index Scan using isi_alt_countrynames_rsc_id_idx
on isi_alt_names (cost=0.00..19.65 rows=1 width=1\
5)
Index Cond: (rsc_id = rresearch.id)
Filter: (code IS NOT NULL)

While this was going on, I only changed the query to include the schema
(the web-based query used search_path) and ran it. Query Analyze said:

"Limit (cost=384288.35..384288.36 rows=2 width=15) (actual
time=2945.338..2945.340 rows=2 loops=1)"
" Output: isi_alt_names.code, rresearch.id, isi_alt_names.id"
" Buffers: shared hit=1408146"
" -> Sort (cost=384288.35..384316.20 rows=11137 width=15) (actual
time=2945.338..2945.338 rows=2 loops=1)"
" Output: isi_alt_names.code, rresearch.id, isi_alt_names.id"
" Sort Key: rresearch.id, isi_alt_names.id"
" Sort Method: top-N heapsort Memory: 25kB"
" Buffers: shared hit=1408146"
" -> Nested Loop (cost=138757.99..384176.98 rows=11137 width=15)
(actual time=1530.875..2876.376 rows=241920 loops=1)"
" Output: isi_alt_names.code, rresearch.id, isi_alt_names.id"
" Buffers: shared hit=1408146"
" -> Bitmap Heap Scan on isi.rresearch
(cost=138757.99..161224.50 rows=11337 width=4) (actual
time=1530.848..1750.169 rows=241337 loops=1)"
" Output: rresearch.id, rresearch.cn, rresearch.nf,
rresearch.nc, rresearch.nd, rresearch.nn, rresearch.ny, rresearch.np,
rresearch.nu, rresearch.nz, rresearch.uuid, rresearch.tsv"
" Recheck Cond: ((upper((rresearch.ny)::text) =
'GUANGZHOU'::text) AND (upper((rresearch.nu)::text) = 'PEOPLES R
CHINA'::text))"
" Buffers: shared hit=195242"
" -> BitmapAnd (cost=138757.99..138757.99 rows=11337
width=0) (actual time=1484.363..1484.363 rows=0 loops=1)"
" Buffers: shared hit=31173"
" -> Bitmap Index Scan on rresearch_ny_idx
(cost=0.00..4930.62 rows=215233 width=0) (actual time=60.997..60.997
rows=241354 loops=1)"
" Index Cond: (upper((rresearch.ny)::text) =
'GUANGZHOU'::text)"
" Buffers: shared hit=1124"
" -> Bitmap Index Scan on rresearch_nu_idx
(cost=0.00..133821.46 rows=6229156 width=0) (actual time=1350.819..1350.819
rows=6434248 loops=1)"
" Index Cond: (upper((rresearch.nu)::text) =
'PEOPLES R CHINA'::text)"
" Buffers: shared hit=30049"
" -> Index Scan using isi_alt_countrynames_rsc_id_idx on
isi.isi_alt_names (cost=0.00..19.65 rows=1 width=15) (actual
time=0.003..0.004 rows=1 loops=241337)"
" Output: isi_alt_names.rsc_id, isi_alt_names.code,
isi_alt_names.id, isi_alt_names.institution"
" Index Cond: (isi_alt_names.rsc_id = rresearch.id)"
" Filter: (isi_alt_names.code IS NOT NULL)"
" Buffers: shared hit=1212904"
"Total runtime: 2945.400 ms"

I then ran the query and the result was produced in about the same time as
(2945 ms).

What can cause such a huge discrepancy? I have checked and there was no
other process blocking the query.

Regards
Johann

--
Because experiencing your loyal love is better than life itself,
my lips will praise you. (Psalm 63:3)