BUG #8410: out of binary heap slots

Поиск
Список
Период
Сортировка
От terje@elde.net
Тема BUG #8410: out of binary heap slots
Дата
Msg-id E1VFVaN-000679-Mj@wrigleys.postgresql.org
обсуждение исходный текст
Ответы Re: BUG #8410: out of binary heap slots  (Terje Elde <terje@elde.net>)
Re: BUG #8410: out of binary heap slots  (Andres Freund <andres@2ndquadrant.com>)
Список pgsql-bugs
The following bug has been logged on the website:

Bug reference:      8410
Logged by:          Terje Elde
Email address:      terje@elde.net
PostgreSQL version: Unsupported/Unknown
Operating system:   FreeBSD
Description:

Running:


PostgreSQL 9.3beta1 on amd64-portbld-freebsd9.1, compiled by cc (GCC) 4.2.1
20070831 patched [FreeBSD], 64-bit


I'm getting "out of binary heap slots", which offcourse spoils the fun of
the query.


I'm having trouble reproducing it, as I'm only seeing the issue in about 1
in 20 000 queries.


I can get the error, turn right around and run the same again manually, and
it'll run just fine.


I'd love to see if I can reproduce in on 9.3rc1, but seeing it is rare
enough as it is.


Slightly anonymised from the logs:


ERROR:  out of binary heap slots
CONTEXT:  PL/pgSQL function foo(integer,bigint,character[],timestamp without
time zone,integer,timestamp without time zone,integer,timestamp without time
zone,integer,inet,character varying) line 233 at FETCH
STATEMENT:  SELECT    a, b, c, d, e, f, g, h, i, j, k, l, m, n, o
FROM foo( 100, 2221::bigint, ARRAY['m', 'f', '', ' ', NULL]::char[],
'2013-07-05T19:11:41.958154'::timestamp, 30::int, NULL::timestamp, 10::int,
'2013-08-30T19:11:41.958168'::timestamp::timestamp, 100::int,
'123.123.123.123'::inet, 'FOO/1.1 CFNetwork/609.1.4 Darwin/13.0.0'::varchar
)


The FETCH-line is running off of a cursor, with a query going pretty much
like this:


        OPEN curs FOR SELECT * FROM (
            SELECT
                'n'::char AS noo, p.id, p.pub, p.details, i.hash AS foo,
p.bam, p.goo,
                e.name AS bar, p.meh, p.startt, p.endt, p.v, ps.s_likes AS
likes,
                p.last_change, ARRAY( SELECT tag FROM foo_tag WHERE barzz =
p.id ) AS tags
            FROM
                p, ps, i, e, s
            WHERE
                s.tihi         = i_cid            AND
                s.v            = True            AND
                p.pub        = s.id            AND
                p.id        = ps.id            AND
                i.id        = p.foo            AND
                e.id        = p.bar            AND
                i.baz        IS NOT NULL        AND
                p.bam        = ANY( i_bam )    AND
                endt        > NOW()            AND
                startt        < NOW() + INTERVAL '15 minutes'     AND
                p.startt    > i_newerthan
            ORDER BY p.startt DESC LIMIT i_maxnew
            FOR UPDATE OF ps ) AS newer_than
        UNION SELECT * FROM (
            SELECT
                'u'::char AS noo, p.id, p.pub, p.details, i.hash AS foo,
p.bam, p.goo,
                e.name AS bar, p.meh, p.startt, p.endt, p.v, ps.s_likes AS
likes,
                p.last_change, ARRAY( SELECT tag FROM foo_tag WHERE bazz =
p.id ) AS tags
            FROM
                p, ps, i, e, s
            WHERE
                s.tihi        = i_cid            AND
                s.v            = True            AND
                p.pub        = s.id            AND
                p.id        = ps.id            AND
                i.id        = p.foo            AND
                e.id        = p.bar            AND
                i.baz        IS NOT NULL        AND
                p.bam        = ANY( i_bam )    AND
                endt        > NOW()            AND
                startt        < NOW() + INTERVAL '15 minutes'    AND
                startt        > i_oldest        AND
                p.last_change    > i_newerthan
            ORDER BY p.last_change DESC LIMIT i_maxupdates
            FOR UPDATE OF ps ) AS updated;


Yeah, I know.  Mangled/obfuscated bits in bug-reports are no fun, but the
code isn't mine to put in a public list.


If you'd like to take a look, I can't imagine it'd be much of a problem for
me to mail you the proper query (and whole function) off-list.


This is not a crisis for us, and I've been meaning to clean up or rewrite
the query anyway, but I figured I should fire off an email anyway, just in
case there's a bug in PostgreSQL that hasn't been caught since beta1.


(again, sorry about the old version).


Explain analyze gives this plan (again anonymized a bit, but can send proper
off-list):



                                                     QUERY PLAN



-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 HashAggregate  (cost=423.84..424.15 rows=31 width=223) (actual
time=0.668..0.675 rows=30 loops=1)
   ->  Append  (cost=35.50..422.67 rows=31 width=223) (actual
time=0.123..0.608 rows=30 loops=1)
         ->  Subquery Scan on apples  (cost=35.50..412.18 rows=30 width=223)
(actual time=0.123..0.600 rows=30 loops=1)
               ->  Limit  (cost=35.50..411.88 rows=30 width=217) (actual
time=0.122..0.591 rows=30 loops=1)
                     ->  LockRows  (cost=35.50..2494.50 rows=196 width=217)
(actual time=0.121..0.584 rows=30 loops=1)
                           ->  Nested Loop  (cost=35.50..2492.54 rows=196
width=217) (actual time=0.113..0.544 rows=30 loops=1)
                                 ->  Nested Loop  (cost=35.23..410.51
rows=196 width=207) (actual time=0.085..0.343 rows=30 loops=1)
                                       ->  Nested Loop  (cost=34.95..319.23
rows=202 width=164) (actual time=0.078..0.264 rows=32 loops=1)
                                             ->  Nested Loop
(cost=34.81..263.23 rows=211 width=147) (actual time=0.073..0.203 rows=32
loops=1)
                                                   ->  Merge Append
(cost=34.66..172.40 rows=354 width=141) (actual time=0.067..0.126 rows=32
loops=1)
                                                         Sort Key: p.startt
                                                         ->  Sort
(cost=0.01..0.02 rows=1 width=669) (actual time=0.016..0.016 rows=0
loops=1)
                                                               Sort Key:
p.startt
                                                               Sort Method:
quicksort  Memory: 25kB
                                                               ->  Seq Scan
on cars p  (cost=0.00..0.00 rows=1 width=669) (actual time=0.001..0.001
rows=0 loops=1)
                                                                     Filter:
((startt > '2013-07-05 19:11:41.958154'::timestamp without time zone) AND
(endt > now()) AND (bus = ANY ('{m,f," "," ",NULL}'::character(1)[])) AND
(startt < (now() + '00:15:00'::interval)))
                                                         ->  Index Scan
Backward using cars_startt on cars_2013 p_1  (cost=0.28..129.49 rows=351
width=136) (actual time=0.043..0.096 rows=32 loops=1)
                                                               Index Cond:
((startt < (now() + '00:15:00'::interval)) AND (startt > '2013-07-05
19:11:41.958154'::timestamp without time zone))
                                                               Filter:
((endt > now()) AND (bus = ANY ('{m,f," "," ",NULL}'::character(1)[])))
                                                         ->  Sort
(cost=13.45..13.45 rows=1 width=669) (actual time=0.004..0.004 rows=0
loops=1)
                                                               Sort Key:
p_2.startt
                                                               Sort Method:
quicksort  Memory: 25kB
                                                               ->  Seq Scan
on cars_2014 p_2  (cost=0.00..13.44 rows=1 width=669) (actual
time=0.000..0.000 rows=0 loops=1)
                                                                     Filter:
((startt > '2013-07-05 19:11:41.958154'::timestamp without time zone) AND
(endt > now()) AND (bus = ANY ('{m,f," "," ",NULL}'::character(1)[])) AND
(startt < (now() + '00:15:00'::interval)))
                                                         ->  Sort
(cost=13.45..13.45 rows=1 width=669) (actual time=0.004..0.004 rows=0
loops=1)
                                                               Sort Key:
p_3.startt
                                                               Sort Method:
quicksort  Memory: 25kB
                                                               ->  Seq Scan
on cars_2015 p_3  (cost=0.00..13.44 rows=1 width=669) (actual
time=0.000..0.000 rows=0 loops=1)
                                                                     Filter:
((startt > '2013-07-05 19:11:41.958154'::timestamp without time zone) AND
(endt > now()) AND (bus = ANY ('{m,f," "," ",NULL}'::character(1)[])) AND
(startt < (now() + '00:15:00'::interval)))
                                                   ->  Index Scan using
oranges_pkey on oranges s  (cost=0.14..0.25 rows=1 width=10) (actual
time=0.002..0.002 rows=1 loops=32)
                                                         Index Cond: (id =
p.agent)
                                                         Filter: (visible
AND (carpool = 100))
                                             ->  Index Scan using
roadworkers_pkey on roadworkers e  (cost=0.14..0.26 rows=1 width=25) (actual
time=0.001..0.001 rows=1 loops=32)
                                                   Index Cond: (id =
p.employee)
                                       ->  Index Scan using bikes_pkey on
bikes i  (cost=0.28..0.44 rows=1 width=55) (actual time=0.002..0.002 rows=1
loops=32)
                                             Index Cond: (id = p.bike)
                                             Filter: (source IS NOT NULL)
                                             Rows Removed by Filter: 0
                                 ->  Index Scan using cars_stats_pkey on
cars_stats ps  (cost=0.28..0.48 rows=1 width=18) (actual time=0.003..0.003
rows=1 loops=30)
                                       Index Cond: (id = p.id)
                                 SubPlan 2
                                   ->  Index Only Scan using fruit_tags_pkey
on fruit_tags fruit_tags_1  (cost=0.28..10.14 rows=3 width=4) (actual
time=0.001..0.002 rows=2 loops=30)
                                         Index Cond: (fruit = p.id)
                                         Heap Fetches: 60
         ->  Subquery Scan on updated  (cost=10.16..10.18 rows=1 width=221)
(actual time=0.005..0.005 rows=0 loops=1)
               ->  Limit  (cost=10.16..10.17 rows=1 width=0) (actual
time=0.005..0.005 rows=0 loops=1)
                     ->  LockRows  (cost=10.16..10.17 rows=1 width=0)
(actual time=0.005..0.005 rows=0 loops=1)
                           ->  Sort  (cost=10.16..10.16 rows=1 width=0)
(actual time=0.005..0.005 rows=0 loops=1)
                                 Sort Key: last_change
                                 Sort Method: quicksort  Memory: 25kB
                                 ->  Result  (cost=0.00..10.15 rows=1
width=0) (actual time=0.000..0.000 rows=0 loops=1)
                                       One-Time Filter: false
                                       SubPlan 1
                                         ->  Index Only Scan using
fruit_tags_pkey on fruit_tags  (cost=0.28..10.14 rows=3 width=4) (never
executed)
                                               Index Cond: (fruit = id)
                                               Heap Fetches: 0
 Total runtime: 0.885 ms
(57 rows)


Terje

В списке pgsql-bugs по дате отправления:

Предыдущее
От: John R Pierce
Дата:
Сообщение: Re: BUG #8400: DB size changed after restore
Следующее
От: Terje Elde
Дата:
Сообщение: Re: BUG #8410: out of binary heap slots