Re: Extremely Low performance with ODBC

Richard,

Thanks for your response. I did that in the first place and found that both
explain reports where quite similar. I've got both reports: From pgadmin it
took 7288 ms, and from VFP took 6446 ms (of course, that's the time
calculated within the explain analyze, and not the real elapsed time).
That's why I assume the ODBC driver is taking its own time for parsing or
something like that- around 2 minutes actually :)
I already tried different syntax alternatives, removing and changing fields
from the Select statement, changing the order within the Where clause and
others just to find out the reason of this odd behavior.
I would change all the Inner joins to explicit ones, but in order to keep it
SQL ANSI compliant (and make it work with different RDMBS), we are not
allowed to use it that way.

This is the whole query:
SELECT "Patient"."Patient_ID"
FROM "Patient",
"PatientFamily",
"PatientFamilyRole",
"Title",
"City" AS "PatientCity",
"City" AS "PatientAltCity",
"City" AS "PatientEmployerCity",
"City" AS "PatientDoctorCity",
"Province" AS "PatientProvince",
"Province" AS "PatientAltProvince",
"Province" AS "PatientEmployerProvince",
"Province" AS "PatientDoctorProvince",
"Country" AS "PatientCountry",
"Country" AS "PatientAltCountry",
"Country" AS "PatientEmployerCountry",
"Country" AS "PatientDoctorCountry"
WHERE "Patient"."Family_ID"="PatientFamily"."Family_ID" AND
"Patient"."FamilyRole_ID"="PatientFamilyRole"."FamilyRole_ID" AND
"Patient"."Title_ID"="Title"."Title_ID" AND
"Patient"."City_ID"="PatientCity"."City_ID" AND
"Patient"."Province_ID"="PatientProvince"."Province_ID" AND
"Patient"."Country_ID"="PatientCountry"."Country_ID" AND
"Patient"."AltCity_ID"="PatientAltCity"."City_ID" AND
"Patient"."AltProvince_ID"="PatientAltProvince"."Province_ID" AND
"Patient"."AltCountry_ID"="PatientAltCountry"."Country_ID" AND
"Patient"."EmployerCity_ID"="PatientEmployerCity"."City_ID" AND

"Patient"."EmployerProvince_ID"="PatientEmployerProvince"."Province_ID" AND
"Patient"."EmployerCountry_ID"="PatientEmployerCountry"."Country_ID"
AND
"Patient"."DoctorCity_ID"="PatientDoctorCity"."City_ID" AND
"Patient"."DoctorProvince_ID"="PatientDoctorProvince"."Province_ID"
AND
"Patient"."DoctorCountry_ID"="PatientDoctorCountry"."Country_ID" AND

"Patient"."Patient_ID"=10450
ORDER BY "Patient"."UDID" ASC

and the report when I ran it from VFP (through ODBC):
Sort (cost=61.84..61.84 rows=1 width=23) (actual time=5.805..5.807 rows=1
loops=1)
Sort Key: "Patient"."UDID"
Sort Method: quicksort Memory: 17kB
-> Nested Loop (cost=39.33..61.83 rows=1 width=23) (actual
time=4.738..5.771 rows=1 loops=1)
Join Filter: ("Patient"."FamilyRole_ID" =
"PatientFamilyRole"."FamilyRole_ID")
-> Nested Loop (cost=39.33..60.56 rows=1 width=27) (actual
time=4.679..5.705 rows=1 loops=1)
Join Filter: ("Patient"."Country_ID" =
"PatientCountry"."Country_ID")
-> Nested Loop (cost=39.33..59.51 rows=1 width=31) (actual
time=4.665..5.679 rows=1 loops=1)
Join Filter: ("Patient"."AltCountry_ID" =
"PatientAltCountry"."Country_ID")
-> Nested Loop (cost=39.33..58.47 rows=1 width=35)
(actual time=4.646..5.654 rows=1 loops=1)
Join Filter: ("Patient"."EmployerCountry_ID" =
"PatientEmployerCountry"."Country_ID")
-> Nested Loop (cost=39.33..57.42 rows=1
width=39) (actual time=4.628..5.629 rows=1 loops=1)
Join Filter: ("Patient"."Title_ID" =
"Title"."Title_ID")
-> Nested Loop (cost=39.33..56.20 rows=1
width=43) (actual time=4.597..5.572 rows=1 loops=1)
-> Nested Loop (cost=39.33..47.92
rows=1 width=47) (actual time=4.576..5.544 rows=1 loops=1)
Join Filter:
("Patient"."DoctorCountry_ID" = "PatientDoctorCountry"."Country_ID")
-> Hash Join
(cost=39.33..46.87 rows=1 width=51) (actual time=4.551..5.512 rows=1
loops=1)
Hash Cond:
("PatientCity"."City_ID" = "Patient"."City_ID")
-> Seq Scan on "City"
"PatientCity" (cost=0.00..6.57 rows=257 width=4) (actual time=0.020..0.505
rows=257 loops=1)
-> Hash
(cost=39.32..39.32 rows=1 width=55) (actual time=4.501..4.501 rows=1
loops=1)
-> Hash Join
(cost=31.77..39.32 rows=1 width=55) (actual time=3.528..4.492 rows=1
loops=1)
Hash Cond:
("PatientAltCity"."City_ID" = "Patient"."AltCity_ID")
-> Seq Scan
on "City" "PatientAltCity" (cost=0.00..6.57 rows=257 width=4) (actual
time=0.005..0.486 rows=257 loops=1)
-> Hash
(cost=31.76..31.76 rows=1 width=59) (actual time=3.495..3.495 rows=1
loops=1)
-> Hash
Join (cost=24.22..31.76 rows=1 width=59) (actual time=2.515..3.486 rows=1
loops=1)

Hash Cond: ("PatientEmployerCity"."City_ID" = "Patient"."EmployerCity_ID")
->
Seq Scan on "City" "PatientEmployerCity" (cost=0.00..6.57 rows=257 width=4)
(actual time=0.004..0.486 rows=257 loops=1)
->
Hash (cost=24.20..24.20 rows=1 width=63) (actual time=2.483..2.483 rows=1
loops=1)

-> Hash Join (cost=16.66..24.20 rows=1 width=63) (actual time=1.496..2.475
rows=1 loops=1)

Hash Cond: ("PatientDoctorCity"."City_ID" = "Patient"."DoctorCity_ID")

-> Seq Scan on "City" "PatientDoctorCity" (cost=0.00..6.57 rows=257
width=4) (actual time=0.004..0.497 rows=257 loops=1)

-> Hash (cost=16.65..16.65 rows=1 width=67) (actual time=1.464..1.464
rows=1 loops=1)

-> Hash Join (cost=14.57..16.65 rows=1 width=67) (actual time=1.185..1.456
rows=1 loops=1)

Hash Cond: ("PatientProvince"."Province_ID" = "Patient"."Province_ID")

-> Seq Scan on "Province" "PatientProvince" (cost=0.00..1.78 rows=78
width=4) (actual time=0.008..0.156 rows=78 loops=1)

-> Hash (cost=14.55..14.55 rows=1 width=71) (actual time=1.131..1.131
rows=1 loops=1)

-> Hash Join (cost=12.47..14.55 rows=1 width=71) (actual time=1.072..1.122
rows=1 loops=1)

Hash Cond: ("PatientAltProvince"."Province_ID" = "Patient"."AltProvince_ID")

-> Seq Scan on "Province" "PatientAltProvince" (cost=0.00..1.78 rows=78
width=4) (actual time=0.005..0.149 rows=78 loops=1)

-> Hash (cost=12.46..12.46 rows=1 width=75) (actual time=0.733..0.733
rows=1 loops=1)

-> Hash Join (cost=10.38..12.46 rows=1 width=75) (actual time=0.675..0.725
rows=1 loops=1)

Hash Cond: ("PatientEmployerProvince"."Province_ID" =
"Patient"."EmployerProvince_ID")

-> Seq Scan on "Province" "PatientEmployerProvince" (cost=0.00..1.78
rows=78 width=4) (actual time=0.005..0.147 rows=78 loops=1)

-> Hash (cost=10.36..10.36 rows=1 width=79) (actual time=0.404..0.404
rows=1 loops=1)

-> Hash Join (cost=8.28..10.36 rows=1 width=79) (actual time=0.345..0.396
rows=1 loops=1)

Hash Cond: ("PatientDoctorProvince"."Province_ID" =
"Patient"."DoctorProvince_ID")

-> Seq Scan on "Province" "PatientDoctorProvince" (cost=0.00..1.78 rows=78
width=4) (actual time=0.005..0.150 rows=78 loops=1)

-> Hash (cost=8.27..8.27 rows=1 width=83) (actual time=0.044..0.044 rows=1
loops=1)

-> Index Scan using "Patient_pkey" on "Patient" (cost=0.00..8.27 rows=1
width=83) (actual time=0.028..0.032 rows=1 loops=1)

Index Cond: ("Patient_ID" = 10450)
-> Seq Scan on "Country"
"PatientDoctorCountry" (cost=0.00..1.02 rows=2 width=4) (actual
time=0.003..0.007 rows=2 loops=1)
-> Index Scan using
"PatientFamily_pkey" on "PatientFamily" (cost=0.00..8.27 rows=1 width=4)
(actual time=0.010..0.012 rows=1 loops=1)
Index Cond:
("PatientFamily"."Family_ID" = "Patient"."Family_ID")
-> Seq Scan on "Title" (cost=0.00..1.10
rows=10 width=4) (actual time=0.004..0.023 rows=10 loops=1)
-> Seq Scan on "Country" "PatientEmployerCountry"
(cost=0.00..1.02 rows=2 width=4) (actual time=0.003..0.007 rows=2 loops=1)
-> Seq Scan on "Country" "PatientAltCountry"
(cost=0.00..1.02 rows=2 width=4) (actual time=0.003..0.006 rows=2 loops=1)
-> Seq Scan on "Country" "PatientCountry" (cost=0.00..1.02
rows=2 width=4) (actual time=0.003..0.006 rows=2 loops=1)
-> Seq Scan on "PatientFamilyRole" (cost=0.00..1.12 rows=12
width=4) (actual time=0.004..0.026 rows=12 loops=1)
Total runtime: 6.446 ms

-----Mensaje original-----
De: pgsql-sql-owner(at)postgresql(dot)org [mailto:pgsql-sql-owner(at)postgresql(dot)org]
En nombre de Richard Broersma
Enviado el: Viernes, 23 de Mayo de 2008 05:26 p.m.
Para: Sebastian Rychter
CC: pgsql-sql(at)postgresql(dot)org
Asunto: Re: [SQL] Extremely Low performance with ODBC

On Fri, May 23, 2008 at 9:47 AM, Sebastian Rychter
<srychter(at)anvet(dot)com(dot)ar> wrote:
> Thanks.. All logs are already off and I'm just sending one query directly
> from the application (from Visual Foxpro using SQL Pass through and in
> VB.net using ado.net). I've found that the "problem" is that I'm using
> implicit joins, and when I change it to explicit Inner Joins the query
only
> takes 3 seconds (as with PgAdmin). I still can't understand if the problem
> resides on the ODBC driver, the Query Planner or it's just a mix of both.

The next step would be to turn on PostgreSQL's statement logging and
statement duration. Issue the queries from VFP and then check what
statement that PG is actually getting. If the statement that PG is
getting looks good, try executing that statement prefixed with explain
analyze from the psql command line to help identify where the
performance problem is.

--
Regards,
Richard Broersma Jr.

Visit the Los Angles PostgreSQL Users Group (LAPUG)
http://pugs.postgresql.org/lapug

--
Sent via pgsql-sql mailing list (pgsql-sql(at)postgresql(dot)org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-sql

__________ NOD32 3127 (20080523) Information __________

This message was checked by NOD32 antivirus system.
http://www.eset.com