ANSI JOINS versus , like JOINS

Hello,

I have two queries, identical except for the way the tables are joined. One
version is a mixture of ANSI joins and 'old' , like join syntax, this is
the 'mixed' query The other version is a completely ANSI JOIN syntax
query,I will call it the ANSI query from now on.
We are running postgres 9.5, PostgreSQL 9.5.3 on x86_64-pc-linux-gnu,
compiled by gcc (GCC) 4.8.5 20150623 (Red Hat 4.8.5-4), 64-bit on CentOS 7:
CentOS Linux release 7.2.1511 (Core)
It was installed from repository:

yum install postgresql95-server postgresql95-contrib --enablerepo=pgdg95
I prefer very much ANSI joins, simply because they are more readable and
less error prone (like forgetting a join condition). However, the queries
are generated via a JAVA application and the application, unfortunately,
sends the mixed query to the database.
Full details are give below but the interesting thing about these queries
is that the execution plan is not the same. The performance of the mixed
query is much worse. On a cold system, the ANSI query returns
results(approx 8 rows) in approx 2s and with caching in effect, in less
than 300ms. However the mixed query takes 45s, sometimes we get at 15s and
by rewriting a little bit we get at 3-4s.
The other interesting thing is that the execution plan of the mixed query
changes when xts_service_process_activity and tables below are added to the
join list. Without these tables, the execution plan of both queries is the
same.
In query below, id_helper is norrmally a temporary table. For debugging
purposes I have made it a permanent table with relevant data.
In attach create statements and other info.
Is there anyone who can help so that the mixed query has the same or
equivalent execution plan (performance) as the ansi query ?
Thank you.
Herwig

The server:Centos 7
Linux diana.ix.xplanation.com 3.10.0-327.18.2.el7.x86_64 #1 SMP Thu May 12
11:03:55 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux
cat /proc/meminfo |grep MemTotal
MemTotal: 8011216 kB

This is the mixed query:
explain (analyze, buffers)
select sqlxtsjoba0_.ID as col_0_0_
from TSTREAM.XTS_JOB_ACTIVITY sqlxtsjoba0_
inner join TSTREAM.XTS_ACT_IN_JOB xtsactinjo1_ on
sqlxtsjoba0_.ID=xtsactinjo1_.XTJA_ID
, id_helper3 sqlidhelpe3_
, TSTREAM.XTS_JOB_PROCESS sqlxtsjobp4_
, TSTREAM.XTS_JOB sqlxtsjob5_
, TSTREAM.XTS_STATUS sqlxtsstat6_
, TSTREAM.XTS_STATUS sqlxtsstat7_
, TSTREAM.XTS_CUSTOMER_ACTIVITY sqlxtscust8_
, TSTREAM.XTS_SERVICE_PROCESS_ACTIVITY sqlxtsserv9_
, TSTREAM.XTS_PROCESS_ACTIVITY sqlxtsproc10_
, TSTREAM.XTS_ACTIVITY sqlxtsacti11_
where set_id = 0
and sqlxtsjoba0_.ID = sqlidhelpe3_.reference_ID
and sqlxtsstat6_.CODE='RUN'
and sqlxtsstat7_.CODE='RUN'
and xtsactinjo1_.XTJP_ID=sqlxtsjobp4_.ID
and sqlxtsjobp4_.XTJO_ID=sqlxtsjob5_.ID
and sqlxtsjob5_.XPRS_ID=sqlxtsstat6_.ID
and sqlxtsjoba0_.XPRS_ID=sqlxtsstat7_.ID
and sqlxtsjoba0_.XTCA_ID=sqlxtscust8_.ID
and sqlxtscust8_.XSPA_ID=sqlxtsserv9_.ID
and sqlxtsserv9_.XPRA_ID=sqlxtsproc10_.ID
and sqlxtsproc10_.XTAC_ID=sqlxtsacti11_.ID
and sqlxtsacti11_.HANDLER='FinalDeliveryCheckHandlerSession'
order by 1;
And ii's plan:
"QUERY PLAN"
"Nested Loop (cost=19764.93..1720710.10 rows=1 width=4) (actual
time=49834.078..55288.833 rows=7 loops=1)"
" Buffers: shared hit=520154 read=376691"
" I/O Timings: read=4084.273"
" -> Nested Loop (cost=19764.79..1720709.92 rows=1 width=12) (actual
time=42345.312..55288.671 rows=17 loops=1)"
" Buffers: shared hit=520120 read=376691"
" I/O Timings: read=4084.273"
" -> Nested Loop (cost=19764.36..1720709.36 rows=1 width=12)
(actual time=42336.880..55236.649 rows=17 loops=1)"
" Buffers: shared hit=520073 read=376670"
" I/O Timings: read=4032.574"
" -> Nested Loop (cost=19763.93..1720708.91 rows=1 width=12)
(actual time=42323.227..55164.778 rows=17 loops=1)"
" Join Filter: (sqlxtsserv9_.id = sqlxtscust8_.xspa_id)"
" Rows Removed by Join Filter: 823"
" Buffers: shared hit=520025 read=376650"
" I/O Timings: read=3961.004"
" -> Nested Loop (cost=19762.19..1720701.77 rows=18
width=20) (actual time=42323.133..55152.950 rows=21 loops=1)"
" Buffers: shared hit=520016 read=376649"
" I/O Timings: read=3950.217"
" -> Nested Loop (cost=19761.76..1720693.58
rows=18 width=20) (actual time=42292.470..55029.761 rows=21 loops=1)"
" Join Filter: (sqlxtsjoba0_.xprs_id =
sqlxtsstat7_.id)"
" Rows Removed by Join Filter: 1579"
" Buffers: shared hit=519951 read=376630"
" I/O Timings: read=3827.494"
" -> Merge Join (cost=19761.76..1720666.95
rows=392 width=28) (actual time=42292.368..55027.679 rows=400 loops=1)"
" Merge Cond: (sqlxtsjoba0_.id =
sqlidhelpe3_.reference_id)"
" Buffers: shared hit=519949
read=376630"
" I/O Timings: read=3827.494"
" -> Merge Join
(cost=9187.27..1671024.74 rows=19628192 width=36) (actual
time=220.994..47852.677 rows=18610377 loops=1)"
" Merge Cond: (sqlxtsjoba0_.id =
xtsactinjo1_.xtja_id)"
" Buffers: shared hit=519948
read=376624"
" I/O Timings: read=3827.471"
" -> Index Scan using
xts_job_activity_pkey on xts_job_activity sqlxtsjoba0_
(cost=0.44..744709.37 rows=17843875 width=20) (actual
time=0.010..10119.665 rows=17079648 loops=1)"
" Buffers: shared
hit=72557 read=250737"
" I/O Timings:
read=1234.731"
" -> Index Scan using xaij_xtja
on xts_act_in_job xtsactinjo1_ (cost=0.44..636358.07 rows=19628192
width=16) (actual time=0.008..12174.828 rows=18610377 loops=1)"
" Buffers: shared
hit=447391 read=125887"
" I/O Timings:
read=2592.740"
" -> Sort (cost=565.85..566.74
rows=356 width=4) (actual time=0.450..0.658 rows=400 loops=1)"
" Sort Key:
sqlidhelpe3_.reference_id"
" Sort Method: quicksort
Memory: 43kB"
" Buffers: shared hit=1 read=6"
" I/O Timings: read=0.023"
" -> Bitmap Heap Scan on
id_helper3 sqlidhelpe3_ (cost=7.18..550.76 rows=356 width=4) (actual
time=0.065..0.248 rows=400 loops=1)"
" Recheck Cond: (set_id =
0)"
" Heap Blocks: exact=4"
" Buffers: shared hit=1
read=6"
" I/O Timings: read=0.023"
" -> Bitmap Index Scan on
id_helper_set (cost=0.00..7.09 rows=356 width=0) (actual time=0.054..0.054
rows=400 loops=1)"
" Index Cond:
(set_id = 0)"
" Buffers: shared
read=3"
" I/O Timings:
read=0.013"
" -> Materialize (cost=0.00..3.12 rows=4
width=4) (actual time=0.001..0.002 rows=4 loops=400)"
" Buffers: shared hit=2"
" -> Seq Scan on xts_status
sqlxtsstat7_ (cost=0.00..3.10 rows=4 width=4) (actual time=0.020..0.037
rows=4 loops=1)"
" Filter: ((code)::text =
'RUN'::text)"
" Rows Removed by Filter: 84"
" Buffers: shared hit=2"
" -> Index Scan using xts_customer_activity_pkey
on xts_customer_activity sqlxtscust8_ (cost=0.42..0.44 rows=1 width=12)
(actual time=5.860..5.861 rows=1 loops=21)"
" Index Cond: (id = sqlxtsjoba0_.xtca_id)"
" Buffers: shared hit=65 read=19"
" I/O Timings: read=122.723"
" -> Materialize (cost=1.74..5.80 rows=5 width=4)
(actual time=0.005..0.544 rows=40 loops=21)"
" Buffers: shared hit=9 read=1"
" I/O Timings: read=10.787"
" -> Nested Loop (cost=1.74..5.78 rows=5
width=4) (actual time=0.085..11.064 rows=40 loops=1)"
" Buffers: shared hit=9 read=1"
" I/O Timings: read=10.787"
" -> Hash Join (cost=1.60..4.97 rows=2
width=4) (actual time=0.070..0.161 rows=3 loops=1)"
" Hash Cond: (sqlxtsproc10_.xtac_id =
sqlxtsacti11_.id)"
" Buffers: shared hit=3"
" -> Seq Scan on xts_process_activity
sqlxtsproc10_ (cost=0.00..2.98 rows=98 width=12) (actual time=0.007..0.065
rows=98 loops=1)"
" Buffers: shared hit=2"
" -> Hash (cost=1.59..1.59 rows=1
width=4) (actual time=0.022..0.022 rows=1 loops=1)"
" Buckets: 1024 Batches: 1
Memory Usage: 9kB"
" Buffers: shared hit=1"
" -> Seq Scan on xts_activity
sqlxtsacti11_ (cost=0.00..1.59 rows=1 width=4) (actual time=0.014..0.018
rows=1 loops=1)"
" Filter: ((handler)::text
= 'FinalDeliveryCheckHandlerSession'::text)"
" Rows Removed by Filter:
46"
" Buffers: shared hit=1"
" -> Index Scan using xspa_xpra on
xts_service_process_activity sqlxtsserv9_ (cost=0.14..0.38 rows=2
width=12) (actual time=0.009..3.617 rows=13 loops=3)"
" Index Cond: (xpra_id =
sqlxtsproc10_.id)"
" Buffers: shared hit=6 read=1"
" I/O Timings: read=10.787"
" -> Index Scan using xts_job_process_pkey on xts_job_process
sqlxtsjobp4_ (cost=0.43..0.45 rows=1 width=12) (actual time=4.223..4.224
rows=1 loops=17)"
" Index Cond: (id = xtsactinjo1_.xtjp_id)"
" Buffers: shared hit=48 read=20"
" I/O Timings: read=71.570"
" -> Index Scan using xts_job_pkey on xts_job sqlxtsjob5_
(cost=0.43..0.55 rows=1 width=12) (actual time=3.054..3.055 rows=1
loops=17)"
" Index Cond: (id = sqlxtsjobp4_.xtjo_id)"
" Buffers: shared hit=47 read=21"
" I/O Timings: read=51.699"
" -> Index Scan using xts_status_pkey on xts_status sqlxtsstat6_
(cost=0.14..0.16 rows=1 width=4) (actual time=0.006..0.007 rows=0
loops=17)"
" Index Cond: (id = sqlxtsjob5_.xprs_id)"
" Filter: ((code)::text = 'RUN'::text)"
" Rows Removed by Filter: 1"
" Buffers: shared hit=34"
"Planning time: 7.273 ms"
"Execution time: 55288.986 ms"

Then the ANSI Query:
explain (analyze, buffers) select sqlxtsjoba0_.ID as col_0_0_
from TSTREAM.XTS_JOB_ACTIVITY sqlxtsjoba0_
inner join TSTREAM.XTS_ACT_IN_JOB xtsactinjo1_ on
sqlxtsjoba0_.ID=xtsactinjo1_.XTJA_ID
join id_helper3 sqlidhelpe3_ on sqlxtsjoba0_.ID = sqlidhelpe3_.reference_ID
and set_id = 0
join TSTREAM.XTS_JOB_PROCESS sqlxtsjobp4_ on
xtsactinjo1_.XTJP_ID=sqlxtsjobp4_.ID
join TSTREAM.XTS_JOB sqlxtsjob5_ on sqlxtsjobp4_.XTJO_ID=sqlxtsjob5_.ID
join TSTREAM.XTS_STATUS sqlxtsstat6_ on sqlxtsjob5_.XPRS_ID=sqlxtsstat6_.ID
join TSTREAM.XTS_STATUS sqlxtsstat7_ on sqlxtsjoba0_.XPRS_ID=sqlxtsstat7_.ID
join TSTREAM.XTS_CUSTOMER_ACTIVITY sqlxtscust8_ on
sqlxtsjoba0_.XTCA_ID=sqlxtscust8_.ID
join TSTREAM.XTS_SERVICE_PROCESS_ACTIVITY sqlxtsserv9_ on
sqlxtscust8_.XSPA_ID=sqlxtsserv9_.ID
join TSTREAM.XTS_PROCESS_ACTIVITY sqlxtsproc10_ on
sqlxtsserv9_.XPRA_ID=sqlxtsproc10_.ID
join TSTREAM.XTS_ACTIVITY sqlxtsacti11_ on
sqlxtsproc10_.XTAC_ID=sqlxtsacti11_.ID
where sqlxtsstat6_.CODE='RUN'
and sqlxtsstat7_.CODE='RUN'
and sqlxtsacti11_.HANDLER='FinalDeliveryCheckHandlerSession'
order by 1;

"QUERY PLAN"
"Sort (cost=3630.62..3630.63 rows=1 width=4) (actual time=7.467..7.470
rows=7 loops=1)"
" Sort Key: sqlxtsjoba0_.id"
" Sort Method: quicksort Memory: 25kB"
" Buffers: shared hit=1965"
" -> Nested Loop (cost=9.33..3630.61 rows=1 width=4) (actual
time=1.418..7.451 rows=7 loops=1)"
" Join Filter: (sqlxtsproc10_.xtac_id = sqlxtsacti11_.id)"
" Rows Removed by Join Filter: 3"
" Buffers: shared hit=1965"
" -> Nested Loop (cost=9.33..3629.01 rows=1 width=12) (actual
time=1.408..7.353 rows=10 loops=1)"
" Join Filter: (sqlxtsserv9_.xpra_id = sqlxtsproc10_.id)"
" Rows Removed by Join Filter: 970"
" Buffers: shared hit=1955"
" -> Nested Loop (cost=9.33..3624.81 rows=1 width=12)
(actual time=1.360..6.556 rows=10 loops=1)"
" Join Filter: (sqlxtscust8_.xspa_id = sqlxtsserv9_.id)"
" Rows Removed by Join Filter: 2440"
" Buffers: shared hit=1935"
" -> Nested Loop (cost=9.33..3616.29 rows=1 width=12)
(actual time=1.224..4.589 rows=10 loops=1)"
" Buffers: shared hit=1905"
" -> Nested Loop (cost=8.91..3615.84 rows=1
width=12) (actual time=1.213..4.517 rows=10 loops=1)"
" Join Filter: (sqlxtsjob5_.xprs_id =
sqlxtsstat6_.id)"
" Rows Removed by Join Filter: 74"
" Buffers: shared hit=1865"
" -> Nested Loop (cost=8.91..3611.65
rows=18 width=20) (actual time=0.197..4.394 rows=21 loops=1)"
" Buffers: shared hit=1863"
" -> Nested Loop (cost=8.48..3601.60
rows=18 width=20) (actual time=0.187..4.219 rows=21 loops=1)"
" Buffers: shared hit=1779"
" -> Nested Loop
(cost=8.05..3593.34 rows=18 width=20) (actual time=0.172..4.037 rows=21
loops=1)"
" Buffers: shared hit=1695"
" -> Nested Loop
(cost=7.62..3584.77 rows=16 width=16) (actual time=0.154..3.841 rows=21
loops=1)"
" Join Filter:
(sqlxtsjoba0_.xprs_id = sqlxtsstat7_.id)"
" Rows Removed by
Join Filter: 1579"
" Buffers: shared
hit=1611"
" -> Nested Loop
(cost=7.62..3560.30 rows=356 width=24) (actual time=0.087..2.154 rows=400
loops=1)"
" Buffers:
shared hit=1609"
" -> Bitmap
Heap Scan on id_helper3 sqlidhelpe3_ (cost=7.18..550.76 rows=356 width=4)
(actual time=0.075..0.233 rows=400 loops=1)"
"
Recheck Cond: (set_id = 0)"
" Heap
Blocks: exact=4"
"
Buffers: shared hit=7"
" ->
Bitmap Index Scan on id_helper_set (cost=0.00..7.09 rows=356 width=0)
(actual time=0.065..0.065 rows=400 loops=1)"
"
Index Cond: (set_id = 0)"
"
Buffers: shared hit=3"
" -> Index
Scan using xts_job_activity_pkey on xts_job_activity sqlxtsjoba0_
(cost=0.44..8.44 rows=1 width=20) (actual time=0.003..0.003 rows=1
loops=400)"
" Index
Cond: (id = sqlidhelpe3_.reference_id)"
"
Buffers: shared hit=1602"
" -> Materialize
(cost=0.00..3.12 rows=4 width=4) (actual time=0.000..0.002 rows=4
loops=400)"
" Buffers:
shared hit=2"
" -> Seq Scan
on xts_status sqlxtsstat7_ (cost=0.00..3.10 rows=4 width=4) (actual
time=0.007..0.016 rows=4 loops=1)"
"
Filter: ((code)::text = 'RUN'::text)"
" Rows
Removed by Filter: 84"
"
Buffers: shared hit=2"
" -> Index Scan using
xaij_xtja on xts_act_in_job xtsactinjo1_ (cost=0.44..0.52 rows=2 width=16)
(actual time=0.007..0.008 rows=1 loops=21)"
" Index Cond:
(xtja_id = sqlxtsjoba0_.id)"
" Buffers: shared
hit=84"
" -> Index Scan using
xts_job_process_pkey on xts_job_process sqlxtsjobp4_ (cost=0.43..0.45
rows=1 width=12) (actual time=0.006..0.007 rows=1 loops=21)"
" Index Cond: (id =
xtsactinjo1_.xtjp_id)"
" Buffers: shared hit=84"
" -> Index Scan using xts_job_pkey on
xts_job sqlxtsjob5_ (cost=0.43..0.55 rows=1 width=12) (actual
time=0.006..0.006 rows=1 loops=21)"
" Index Cond: (id =
sqlxtsjobp4_.xtjo_id)"
" Buffers: shared hit=84"
" -> Materialize (cost=0.00..3.12 rows=4
width=4) (actual time=0.001..0.003 rows=4 loops=21)"
" Buffers: shared hit=2"
" -> Seq Scan on xts_status
sqlxtsstat6_ (cost=0.00..3.10 rows=4 width=4) (actual time=0.014..0.024
rows=4 loops=1)"
" Filter: ((code)::text =
'RUN'::text)"
" Rows Removed by Filter: 84"
" Buffers: shared hit=2"
" -> Index Scan using xts_customer_activity_pkey
on xts_customer_activity sqlxtscust8_ (cost=0.42..0.44 rows=1 width=12)
(actual time=0.005..0.005 rows=1 loops=10)"
" Index Cond: (id = sqlxtsjoba0_.xtca_id)"
" Buffers: shared hit=40"
" -> Seq Scan on xts_service_process_activity
sqlxtsserv9_ (cost=0.00..5.45 rows=245 width=12) (actual time=0.002..0.093
rows=245 loops=10)"
" Buffers: shared hit=30"
" -> Seq Scan on xts_process_activity sqlxtsproc10_
(cost=0.00..2.98 rows=98 width=12) (actual time=0.002..0.034 rows=98
loops=10)"
" Buffers: shared hit=20"
" -> Seq Scan on xts_activity sqlxtsacti11_ (cost=0.00..1.59
rows=1 width=4) (actual time=0.004..0.008 rows=1 loops=10)"
" Filter: ((handler)::text =
'FinalDeliveryCheckHandlerSession'::text)"
" Rows Removed by Filter: 46"
" Buffers: shared hit=10"
"Planning time: 8.361 ms"
"Execution time: 7.669 ms"