Subject: Re: performance question (something to do w/
From: Mark Lewis <mark.lewis@mir3.com>
To: Jeffrey Tenny <jeffrey.tenny@comcast.net>
Cc: pgsql-performance@postgresql.org
In-Reply-To: <445F7FF8.6070707@comcast.net>
References: <445F7FF8.6070707@comcast.net>
Content-Type: text/plain
Content-Transfer-Encoding: 7bit
Organization: MIR3, Inc.
Date: Mon, 08 May 2006 10:42:21 -0700
Message-Id: <1147110142.32369.7.camel@archimedes>
Mime-Version: 1.0

Doing a SELECT with a large list of variables inside an IN runs slowly
on every database we've tested.  We've tested mostly in Oracle and
PostgreSQL, and both get very slow very quickly (actually Oracle refuses
to process the query at all after it gets too many bind parameters).

In our case, we have a (potentially quite large) set of external values
that we want to look up in the database.  We originally thought that
doing a single select with a large IN clause was the way to go, but then
we did some performance analysis on the optimal batch size (number of
items to include per IN clause), and discovered that for most databases,
the optimal batch size was 1.  For PostgreSQL I think it was 2.

The moral of the story is that you're probably better off running a
bunch of small selects than in trying to optimize things with one
gargantuan select.

-- Mark Lewis

On Mon, 2006-05-08 at 13:29 -0400, Jeffrey Tenny wrote:
> Why does this query take so long?  (PostgreSQL 8.0.3, FC4)
> Hopefully I have provided enough information below.
> 
> LOG:  statement: SELECT * FROM x WHERE f IN 
> ($1,$2,$3,$4,$5,$6,$7,$8,$9,$10,$11,$12,$13,$14,$15,$16,$17,$18,$19,$20,$21,$22,$23,$24,\
> $25,$26,$27,$28,$29,$30,$31,$32,$33,$34,$35,$36,$37,$38,$39,$40,$41,$42,$43,$44,$45,$46,$47,$48,$49,$50,$51,$52,$53,$54,$55,$56,$57,$58,$59,$60,$61,$62,$63\
> ,$64,$65,$66,$67,$68,$69,$70,$71,$72,$73,$74,$75,$76,$77,$78,$79,$80,$81,$82,$83,$84,$85,$86,$87,$88,$89,$90,$91,$92,$93,$94,$95,$96,$97,$98,$99,$100,$101,\
> $102,$103,$104,$105,$106,$107,$108,$109,$110,$111,$112,$113,$114,$115,$116,$117,$118,$119,$120,$121,$122,$123,$124,$125,$126,$127,$128,$129,$130,$131,$132,\
> $133,$134,$135,$136,$137,$138,$139,$140,$141,$142,$143,$144,$145,$146,$147,$148,$149,$150,$151,$152,$153,$154,$155,$156,$157,$158,$159,$160,$161,$162,$163,\
> $164,$165,$166,$167,$168,$169,$170,$171,$172,$173,$174,$175,$176,$177,$178,$179,$180,$181,$182,$183,$184,$185,$186,$187,$188,$189,$190,$191,$192,$193,$194,\
> $195,$196,$197,$198,$199,$200,$201,$202,$203,$204,$205,$206,$207,$208,$209,$210,$211,$212,$213,$214,$215,$216,$217,$218,$219,$220,$221,$222,$223,$224,$225,\
> $226,$227,$228,$229,$230,$231,$232,$233,$234,$235,$236,$237,$238,$239,$240,$241,$242,$243,$244,$245,$246,$247,$248,$249,$250,$251,$252,$253,$254,$255,$256,\
> $257,$258,$259,$260,$261,$262,$263,$264,$265,$266,$267,$268,$269,$270,$271,$272,$273,$274,$275,$276,$277,$278,$279,$280,$281,$282,$283,$284,$285,$286,$287,\
> $288,$289,$290,$291,$292,$293,$294,$295,$296,$297,$298,$299,$300,$301,$302,$303,$304,$305,$306,$307,$308,$309,$310,$311,$312,$313,$314,$315,$316,$317,$318,\
> $319,$320,$321,$322,$323,$324,$325,$326,$327,$328,$329,$330,$331,$332,$333,$334,$335,$336,$337,$338,$339,$340,$341,$342,$343,$344,$345,$346,$347,$348,$349,\
> $350,$351,$352,$353,$354,$355,$356,$357,$358,$359,$360,$361,$362,$363,$364,$365,$366,$367,$368,$369,$370,$371,$372,$373,$374,$375,$376,$377,$378,$379,$380,\
> $381,$382,$383,$384,$385,$386,$387,$388,$389,$390,$391,$392,$393,$394,$395,$396,$397,$398,$399,$400,$401,$402,$403,$404,$405,$406,$407,$408,$409,$410,$411,\
> $412,$413,$414,$415,$416,$417,$418,$419,$420,$421,$422,$423,$424,$425,$426,$427,$428,$429,$430,$431,$432,$433,$434,$435,$436,$437,$438,$439,$440,$441,$442,\
> $443,$444,$445,$446,$447,$448,$449,$450,$451,$452,$453,$454,$455,$456,$457,$458,$459,$460,$461,$462,$463,$464,$465,$466,$467,$468,$469,$470,$471,$472,$473,\
> $474,$475,$476,$477,$478,$479,$480,$481,$482,$483,$484,$485,$486,$487,$488,$489,$490,$491,$492,$493,$494,$495,$496,$497,$498,$499,$500,$501,$502,$503,$504,\
> $505,$506,$507,$508,$509,$510,$511,$512,$513,$514,$515,$516,$517,$518,$519,$520,$521,$522,$523,$524,$525,$526,$527,$528,$529,$530,$531,$532,$533,$534,$535,\
> $536,$537,$538,$539,$540,$541,$542,$543,$544,$545,$546,$547,$548,$549,$550,$551,$552,$553,$554,$555,$556,$557,$558,$559,$560,$561,$562,$563,$564,$565,$566,\
> $567,$568,$569,$570,$571,$572,$573,$574,$575,$576,$577,$578,$579,$580,$581,$582,$583,$584,$585,$586,$587,$588,$589,$590,$591,$592,$593,$594,$595,$596,$597,\
> $598,$599,$600,$601,$602,$603,$604,$605,$606,$607,$608,$609,$610,$611,$612,$613,$614,$615,$616,$617,$618,$619,$620,$621,$622,$623,$624,$625,$626,$627,$628,\
> $629,$630,$631,$632,$633,$634,$635,$636,$637,$638,$639,$640,$641,$642,$643,$644,$645,$646,$647,$648,$649,$650) 
> ORDER BY f,c
> 
> LOG:  EXECUTOR STATISTICS
> DETAIL:  ! system usage stats:
>          !       10.282945 elapsed 10.234444 user 0.048992 system sec
>          !       [25.309152 user 0.500923 sys total]
>          !       0/0 [0/0] filesystem blocks in/out
>          !       0/0 [0/10397] page faults/reclaims, 0 [0] swaps
>          !       0 [0] signals rcvd, 0/0 [0/0] messages rcvd/sent
>          !       0/15 [291/55] voluntary/involuntary context switches
>          ! buffer usage stats:
>          !       Shared blocks:          0 read,          0 written, 
> buffer hit rate = 100.00%
>          !       Local  blocks:          0 read,          0 written, 
> buffer hit rate = 0.00%
>          !       Direct blocks:          0 read,          0 written
> 
> 
> Here is the table description:
> 
> Table "public.x"
>   Column |  Type   | Modifiers
> --------+---------+-----------
>   f      | integer | not null
>   c      | integer | not null
>   r      | integer | not null
>   n      | integer | not null
> Indexes:
>      "x_c_idx" btree (c)
>      "x_f_idx" btree (f)
>      "testindex2" btree (f, c)
> 
> 
> There are only 2,369 records in the X table.
> 
> I don't understand why this query should take 10 seconds in the executor 
> phase, with so little data being managed, and all relevant data already 
> in memory.  Any clues?
> 
> Maybe there are more database server debugging options I should have 
> tweaked, but I'm not sure what.  The stuff I turned on included:
> 
> log_duration = true
> log_statement = 'all'
> log_parser_stats = true
> log_planner_stats = true
> log_executor_stats = true
> 
>    (N.B. log_statement_stats = true caused the server startup failure 
> every time with no error message I could find, so was not deliberately set)
> 
> stats_start_collector = true
> stats_command_string = true
> stats_block_level = true
> stats_row_level = true
> stats_reset_on_server_start = true
> 
> 
> 
> (FYI: 10 secs is a lot only because this query is executed many times in 
> my application, and they're pretty much all bad, and the aggregate query 
> times are killing my app response).
> 
> Thanks for any tips!
> 
> ---------------------------(end of broadcast)---------------------------
> TIP 5: don't forget to increase your free space map settings