Re: stored proc and inserting hundreds of thousands of rows

From: Joel Reymont <joelr1(at)gmail(dot)com>
To: "Kevin Grittner" <Kevin(dot)Grittner(at)wicourts(dot)gov>
Cc: "pgsql-performance(at)postgresql(dot)org" <pgsql-performance(at)postgresql(dot)org>
Subject: Re: stored proc and inserting hundreds of thousands of rows
Date: 2011-04-30 21:15:23
Message-ID: DEBFB8EB-6F50-4462-8827-434E0CE308C7@gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance


On Apr 30, 2011, at 7:24 PM, Kevin Grittner wrote:

> If this is where most of the time is, the next thing is to run it
> with EXPLAIN ANALYZE, and post the output.

I was absolutely wrong about the calculation taking < 1s, it actually takes about 30s for 2 million rows.

Still, the difference between 5 minutes and 30s must be the insert.

SELECT (t).doc_id, (t).distance
FROM (SELECT docs_within_distance('{ 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.586099770475, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.167233562858, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667, 0.00166666666667 }', 50.0) as t) AS x;

This takes 27.44 seconds

EXPLAIN ANALYZE VERBOSE

Subquery Scan on x (cost=0.00..0.27 rows=1 width=32) (actual time=22422.418..23835.468 rows=2000002 loops=1)
Output: (t).doc_id, (t).distance
-> Result (cost=0.00..0.26 rows=1 width=0) (actual time=22422.410..23184.086 rows=2000002 loops=1)
Output: docs_within_distance(('{<array above goes here>}'::double precision[])::topics, 50::double precision)
Total runtime: 23948.563 ms

Topics is defined thusly: CREATE DOMAIN topics AS float[150];

Digging deeper into the distance function,

EXPLAIN ANALYZE VERBOSE
SELECT *
FROM (SELECT id, divergence(<array above>, topics) AS distance FROM docs) AS tab
WHERE tab.distance <= 50.0;

Subquery Scan on tab (cost=0.00..383333.00 rows=666653 width=12) (actual time=0.027..20429.299 rows=2000002 loops=1)
Output: tab.id, tab.distance
Filter: (tab.distance <= 50::double precision)
-> Seq Scan on public.docs (cost=0.00..358333.50 rows=1999960 width=36) (actual time=0.025..19908.200 rows=2000002 loops=1)
Output: docs.id, divergence((<array above>::double precision[])::topics, docs.topics)
Total runtime: 20550.019 ms

I can't dig any deeper because divergence is a C function.

Thanks, Joel

--------------------------------------------------------------------------
- for hire: mac osx device driver ninja, kernel extensions and usb drivers
---------------------+------------+---------------------------------------
http://wagerlabs.com | @wagerlabs | http://www.linkedin.com/in/joelreymont
---------------------+------------+---------------------------------------

In response to

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Joel Reymont 2011-04-30 21:22:24 Re: stored proc and inserting hundreds of thousands of rows
Previous Message Kevin Grittner 2011-04-30 18:36:46 Re: stored proc and inserting hundreds of thousands of rows