pg.ddx.io pgsql-hackers@postgresql.org mailing list archive help / color / mirror / Atom feed From: Jonathan Rudenberg <jonathan@titanous.com>
To: Thomas Munro <thomas.munro@enterprisedb.com>
Cc: Robert Haas <robertmhaas@gmail.com>
Cc: Andreas Seltenreich <seltenreich@gmx.de>
Cc: Pg Hackers <pgsql-hackers@postgresql.org>
Subject: Re: [sqlsmith] Unpinning error in parallel worker
Date: Tue, 17 Apr 2018 19:43:50 -0400
Message-ID: <1524008630.2186289.1341689208.31A2DB11@webmail.messagingengine.com> (raw )
In-Reply-To: <CAEepm=1Hft9m2wp86++S86Yrn6C8O2sms4=B=66-scdQGQt7PA@mail.gmail.com >
References: <87h92g83t3.fsf@credativ.de >
<CAEepm=1sLjHyauGZoXM3KCT2Gv+CHPEWQcxob_1Oo0KshRp7-Q@mail.gmail.com >
<CAEepm=2VvKCVXjg-REHTikoBUOhtfvfCyiJrT=zHDJyvMNd9pw@mail.gmail.com >
<CAEepm=23=vGz=CgVurPxBGV6SeOJ7YxSaAJKr_aH+f2cV4zrow@mail.gmail.com >
<CA+TgmoZfPOu62bR71bahf90ivOUxXpYOh0RqDiue0+dVVPNrWg@mail.gmail.com >
<1523998351.1231357.1341528496.28EBAF7F@webmail.messagingengine.com >
<CAEepm=0gtExezsnVabv79hKSzn61dbdEbzWRxqyJf1nf8hzppQ@mail.gmail.com >
<1524006065.2172367.1341656968.532A8113@webmail.messagingengine.com >
<CAEepm=1Hft9m2wp86++S86Yrn6C8O2sms4=B=66-scdQGQt7PA@mail.gmail.com >
On Tue, Apr 17, 2018, at 19:31, Thomas Munro wrote:
> On Wed, Apr 18, 2018 at 11:01 AM, Jonathan Rudenberg
> <jonathan@titanous.com> wrote:
> > On Tue, Apr 17, 2018, at 18:38, Thomas Munro wrote:
> >> Thanks, that would be much appreciated, as would any clues about what
> >> workload you're running. Do you know what the query plan looks like
> >> for the queries that crashed?
> >
> > Yep, I think I know approximately what it looked like, I've attached a lightly redacted plan. All of the hung queries were running some variant of this plan as far as I can tell.
>
> Hmm, that isn't a parallel query. I was expecting to see "Gather" and
> "Parallel" in there.
Oops, I'm really sorry about that. I only have the first part of the hung queries, and there are a few variants. Here's one that's parallel.
QUERY PLAN
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Sort (cost=13229.50..13229.51 rows=2 width=4336) (actual time=23.486..23.515 rows=316 loops=1)
Sort Key: assets."position"
Sort Method: quicksort Memory: 1293kB
CTE assets
-> HashAggregate (cost=13060.31..13075.88 rows=1557 width=864) (actual time=19.064..19.601 rows=1242 loops=1)
Group Key: assets_7.id, assets_7.name, assets_7.description, assets_7.asset_key, assets_7.type, assets_7.created_at, assets_7.updated_at, assets_7.deleted_at, assets_7.redacted_id, assets_7.section_id, assets_7."position", assets_7.creator_id, assets_7.modifier_id, assets_7.data, assets_7.thumbnail_override, assets_7.availability_start, assets_7.availability_end, assets_7.availability
-> Append (cost=6383.09..12990.25 rows=1557 width=864) (actual time=6.781..17.848 rows=1242 loops=1)
-> CTE Scan on assets assets_7 (cost=6383.09..6451.83 rows=15 width=864) (actual time=6.780..8.180 rows=1242 loops=1)
Filter: (redacted_id = 32456)
CTE assets
-> HashAggregate (cost=6352.54..6383.09 rows=3055 width=864) (actual time=6.775..7.270 rows=1242 loops=1)
Group Key: assets_1.id, assets_1.name, assets_1.description, assets_1.asset_key, assets_1.type, assets_1.created_at, assets_1.updated_at, assets_1.deleted_at, assets_1.redacted_id, assets_1.section_id, assets_1."position", assets_1.creator_id, assets_1.modifier_id, assets_1.data, assets_1.thumbnail_override, assets_1.availability_start, assets_1.availability_end, assets_1.availability
-> Append (cost=1.41..6215.07 rows=3055 width=864) (actual time=0.137..5.495 rows=1261 loops=1)
-> Nested Loop (cost=1.41..1514.55 rows=1 width=248) (actual time=0.026..0.026 rows=0 loops=1)
-> Nested Loop (cost=0.98..5.71 rows=1 width=4) (actual time=0.026..0.026 rows=0 loops=1)
-> Nested Loop (cost=0.70..5.14 rows=1 width=8) (actual time=0.026..0.026 rows=0 loops=1)
-> Index Scan using index_user_id_on_permissible_type on user_permissions (cost=0.42..2.64 rows=1 width=4) (actual time=0.025..0.025 rows=0 loops=1)
Index Cond: ((user_id = 98789) AND ((permissible_type)::text = 'Organization'::text))
Filter: ((permission_level)::text = 'guest'::text)
-> Index Only Scan using organizations_pkey on organizations (cost=0.28..2.50 rows=1 width=4) (never executed)
Index Cond: (id = user_permissions.permissible_id)
Heap Fetches: 0
-> Index Scan using index_redacteds_on_organization_id on redacteds redacteds_1 (cost=0.28..0.43 rows=1 width=8) (never executed)
Index Cond: (organization_id = organizations.id)
Filter: ((deleted_at IS NULL) AND (id = 32456))
-> Index Scan using index_assets_on_redacted_id on assets assets_1 (cost=0.43..1493.79 rows=1505 width=248) (never executed)
Index Cond: (redacted_id = 32456)
Filter: (availability = 0)
-> Nested Loop (cost=1.13..1513.99 rows=1505 width=248) (actual time=0.037..0.037 rows=0 loops=1)
-> Nested Loop (cost=0.70..5.16 rows=1 width=4) (actual time=0.037..0.037 rows=0 loops=1)
-> Index Scan using redacteds_pkey on redacteds redacteds_2 (cost=0.28..2.50 rows=1 width=4) (actual time=0.017..0.017 rows=1 loops=1)
Index Cond: (id = 32456)
Filter: (deleted_at IS NULL)
-> Index Scan using unique_index_on_user_permissions on user_permissions user_permissions_1 (cost=0.42..2.65 rows=1 width=4) (actual time=0.019..0.019 rows=0 loops=1)
Index Cond: (((permissible_type)::text = 'Redacted'::text) AND (permissible_id = 32456) AND (user_id = 98789))
Filter: ((permission_level)::text = 'guest'::text)
-> Index Scan using index_assets_on_redacted_id on assets assets_2 (cost=0.43..1493.79 rows=1505 width=248) (never executed)
Index Cond: (redacted_id = 32456)
Filter: (availability = 0)
-> Nested Loop (cost=1.55..67.28 rows=1 width=248) (actual time=0.073..5.253 rows=1261 loops=1)
-> Nested Loop (cost=1.12..11.54 rows=84 width=4) (actual time=0.055..0.770 rows=1331 loops=1)
-> Nested Loop (cost=0.70..5.14 rows=1 width=8) (actual time=0.025..0.041 rows=3 loops=1)
-> Index Scan using index_user_id_on_permissible_type on user_permissions user_permissions_2 (cost=0.42..2.64 rows=1 width=4) (actual time=0.011..0.014 rows=3 loops=1)
Index Cond: ((user_id = 98789) AND ((permissible_type)::text = 'Collection'::text))
Filter: ((permission_level)::text = 'guest'::text)
-> Index Scan using collections_pkey on collections (cost=0.28..2.50 rows=1 width=4) (actual time=0.008..0.008 rows=1 loops=3)
Index Cond: (id = user_permissions_2.permissible_id)
Filter: (deleted_at IS NULL)
-> Index Scan using index_collection_asset_associations_on_collection_id on collection_asset_associations collection_asset_associations_1 (cost=0.42..4.90 rows=149 width=8) (actual time=0.015..0.198 rows=444 loops=3)
Index Cond: (collection_id = collections.id)
Filter: (((availability_start < '2018-04-17 21:06:57.643933'::timestamp without time zone) OR (availability_start IS NULL)) AND ((availability_end > '2018-04-17 21:06:57.643933'::timestamp without time zone) OR (availability_end IS NULL)))
Rows Removed by Filter: 4
-> Index Scan using assets_pkey on assets assets_3 (cost=0.43..0.66 rows=1 width=248) (actual time=0.003..0.003 rows=1 loops=1331)
Index Cond: (id = collection_asset_associations_1.asset_id)
Filter: ((redacted_id = 32456) AND (availability = 0))
Rows Removed by Filter: 0
-> Nested Loop (cost=1.41..1511.09 rows=1 width=248) (actual time=0.013..0.013 rows=0 loops=1)
-> Nested Loop (cost=0.98..5.71 rows=1 width=4) (actual time=0.013..0.013 rows=0 loops=1)
-> Nested Loop (cost=0.70..5.14 rows=1 width=8) (actual time=0.013..0.013 rows=0 loops=1)
-> Index Scan using index_user_id_on_permissible_type on user_permissions user_permissions_3 (cost=0.42..2.64 rows=1 width=4) (actual time=0.012..0.012 rows=0 loops=1)
Index Cond: ((user_id = 98789) AND ((permissible_type)::text = 'Organization'::text))
Filter: ((permission_level)::text = ANY ('{collaborator,admin,owner}'::text[]))
-> Index Only Scan using organizations_pkey on organizations organizations_1 (cost=0.28..2.50 rows=1 width=4) (never executed)
Index Cond: (id = user_permissions_3.permissible_id)
Heap Fetches: 0
-> Index Scan using index_redacteds_on_organization_id on redacteds redacteds_3 (cost=0.28..0.43 rows=1 width=8) (never executed)
Index Cond: (organization_id = organizations_1.id)
Filter: ((deleted_at IS NULL) AND (id = 32456))
-> Index Scan using index_assets_on_redacted_id on assets assets_4 (cost=0.43..1489.92 rows=1546 width=248) (never executed)
Index Cond: (redacted_id = 32456)
-> Nested Loop (cost=1.13..1510.54 rows=1546 width=248) (actual time=0.022..0.022 rows=0 loops=1)
-> Nested Loop (cost=0.70..5.16 rows=1 width=4) (actual time=0.022..0.022 rows=0 loops=1)
-> Index Scan using redacteds_pkey on redacteds redacteds_4 (cost=0.28..2.50 rows=1 width=4) (actual time=0.010..0.010 rows=1 loops=1)
Index Cond: (id = 32456)
Filter: (deleted_at IS NULL)
-> Index Scan using unique_index_on_user_permissions on user_permissions user_permissions_4 (cost=0.42..2.65 rows=1 width=4) (actual time=0.011..0.011 rows=0 loops=1)
Index Cond: (((permissible_type)::text = 'Redacted'::text) AND (permissible_id = 32456) AND (user_id = 98789))
Filter: ((permission_level)::text = ANY ('{collaborator,admin,owner}'::text[]))
-> Index Scan using index_assets_on_redacted_id on assets assets_5 (cost=0.43..1489.92 rows=1546 width=248) (never executed)
Index Cond: (redacted_id = 32456)
-> Nested Loop (cost=1.55..67.07 rows=1 width=248) (actual time=0.012..0.012 rows=0 loops=1)
-> Nested Loop (cost=1.12..11.54 rows=84 width=4) (actual time=0.011..0.011 rows=0 loops=1)
-> Nested Loop (cost=0.70..5.14 rows=1 width=8) (actual time=0.011..0.011 rows=0 loops=1)
-> Index Scan using index_user_id_on_permissible_type on user_permissions user_permissions_5 (cost=0.42..2.64 rows=1 width=4) (actual time=0.011..0.011 rows=0 loops=1)
Index Cond: ((user_id = 98789) AND ((permissible_type)::text = 'Collection'::text))
Filter: ((permission_level)::text = ANY ('{collaborator,admin,owner}'::text[]))
Rows Removed by Filter: 3
-> Index Scan using collections_pkey on collections collections_1 (cost=0.28..2.50 rows=1 width=4) (never executed)
Index Cond: (id = user_permissions_5.permissible_id)
Filter: (deleted_at IS NULL)
-> Index Scan using index_collection_asset_associations_on_collection_id on collection_asset_associations collection_asset_associations_2 (cost=0.42..4.90 rows=149 width=8) (never executed)
Index Cond: (collection_id = collections_1.id)
Filter: (((availability_start < '2018-04-17 21:06:57.649733'::timestamp without time zone) OR (availability_start IS NULL)) AND ((availability_end > '2018-04-17 21:06:57.649733'::timestamp without time zone) OR (availability_end IS NULL)))
-> Index Scan using assets_pkey on assets assets_6 (cost=0.43..0.66 rows=1 width=248) (never executed)
Index Cond: (id = collection_asset_associations_2.asset_id)
Filter: (redacted_id = 32456)
-> Nested Loop (cost=0.71..1511.34 rows=1505 width=248) (actual time=0.011..0.011 rows=0 loops=1)
-> Index Scan using redacteds_pkey on redacteds redacteds_5 (cost=0.28..2.50 rows=1 width=4) (actual time=0.011..0.011 rows=0 loops=1)
Index Cond: (id = 32456)
Filter: ((deleted_at IS NULL) AND ((privacy)::text = 'public'::text))
Rows Removed by Filter: 1
-> Index Scan using index_assets_on_redacted_id on assets assets_8 (cost=0.43..1493.79 rows=1505 width=248) (never executed)
Index Cond: (redacted_id = 32456)
Filter: (availability = 0)
-> Gather (cost=1029.60..5011.51 rows=37 width=248) (actual time=9.560..9.560 rows=0 loops=1)
Workers Planned: 1
Workers Launched: 1
-> Nested Loop (cost=29.60..4007.81 rows=22 width=248) (actual time=5.488..5.488 rows=0 loops=2)
-> Nested Loop (cost=29.32..3934.16 rows=245 width=252) (actual time=0.324..4.098 rows=889 loops=2)
-> Parallel Bitmap Heap Scan on assets assets_9 (cost=28.90..1697.87 rows=885 width=248) (actual time=0.273..1.597 rows=744 loops=2)
Recheck Cond: (redacted_id = 32456)
Filter: (availability = 0)
Heap Blocks: exact=767
-> Bitmap Index Scan on index_assets_on_redacted_id (cost=0.00..28.52 rows=1546 width=0) (actual time=0.380..0.380 rows=1487 loops=1)
Index Cond: (redacted_id = 32456)
-> Index Scan using index_collection_asset_associations_on_asset_id on collection_asset_associations collection_asset_associations_3 (cost=0.42..2.48 rows=5 width=8) (actual time=0.003..0.003 rows=1 loops=1487)
Index Cond: (asset_id = assets_9.id)
Filter: (((availability_start < '2018-04-17 21:06:57.652961'::timestamp without time zone) OR (availability_start IS NULL)) AND ((availability_end > '2018-04-17 21:06:57.652961'::timestamp without time zone) OR (availability_end IS NULL)))
Rows Removed by Filter: 0
-> Index Scan using collections_pkey on collections collections_2 (cost=0.28..0.30 rows=1 width=4) (actual time=0.001..0.001 rows=0 loops=1778)
Index Cond: (id = collection_asset_associations_3.collection_id)
Filter: ((deleted_at IS NULL) AND public)
Rows Removed by Filter: 1
-> Nested Loop Left Join (cost=2.28..153.61 rows=2 width=4336) (actual time=19.248..22.243 rows=316 loops=1)
-> Nested Loop Left Join (cost=1.85..147.61 rows=1 width=4255) (actual time=19.222..21.777 rows=51 loops=1)
-> Nested Loop Left Join (cost=1.42..147.04 rows=1 width=3400) (actual time=19.190..21.394 rows=51 loops=1)
-> Nested Loop (cost=0.99..142.82 rows=1 width=1778) (actual time=19.167..21.090 rows=50 loops=1)
-> Nested Loop (cost=0.57..140.16 rows=1 width=1778) (actual time=19.146..20.899 rows=50 loops=1)
-> Nested Loop (cost=0.28..138.75 rows=1 width=1778) (actual time=19.106..20.730 rows=50 loops=1)
-> CTE Scan on assets (cost=0.00..136.24 rows=1 width=864) (actual time=19.088..20.578 rows=50 loops=1)
Filter: ((redacted_id = 32456) AND (section_id = 679855) AND (id = ANY ('{6703952,6703955,6714907,6714913,6767146,6767723,6767758,6767764,6767858,6767864,6767866,6767938,6767945,6767999,6716005,6716007,6730106,6730107,6730128,6730145,6730146,6730147,6730676,6730677,6730176,6730177,6730201,6730204,6730207,6730199,6730214,6730267,6730216,6730217,6730218,6730220,6730221,6730222,6730223,6730225,6730226,6730227,6730228,6735195,6735197,6735200,6735202,6735236,6735241,6735247}'::integer[])))
Rows Removed by Filter: 1192
-> Index Scan using redacteds_pkey on redacteds (cost=0.28..2.50 rows=1 width=914) (actual time=0.002..0.002 rows=1 loops=50)
Index Cond: (id = 32456)
Filter: (deleted_at IS NULL)
-> Index Only Scan using sections_pkey on sections (cost=0.29..1.41 rows=1 width=4) (actual time=0.003..0.003 rows=1 loops=50)
Index Cond: (id = 163863)
Heap Fetches: 50
-> Index Scan using index_collection_assets_on_collection_id_and_asset_id on collection_asset_associations (cost=0.42..2.65 rows=1 width=4) (actual time=0.003..0.003 rows=1 loops=50)
Index Cond: ((collection_id = 67459) AND (asset_id = assets.id))
Filter: (((availability_start < '2018-04-17 21:06:57.631399'::timestamp without time zone) OR (availability_start IS NULL)) AND ((availability_end > '2018-04-17 21:06:57.631399'::timestamp without time zone) OR (availability_end IS NULL)))
-> Index Scan using index_attachments_on_asset_id on attachments (cost=0.43..4.16 rows=6 width=1622) (actual time=0.005..0.005 rows=1 loops=50)
Index Cond: (asset_id = assets.id)
-> Index Scan using index_versions_on_item_type_and_item_id on versions (cost=0.43..0.56 rows=1 width=855) (actual time=0.006..0.006 rows=1 loops=51)
Index Cond: (((item_type)::text = 'Attachment'::text) AND (item_id = attachments.id))
-> Index Scan using index_tags_on_asset_id on tags (cost=0.43..5.81 rows=19 width=81) (actual time=0.004..0.006 rows=6 loops=51)
Index Cond: (asset_id = assets.id)
Planning time: 7.210 ms
Execution time: 24.650 ms
(149 rows)
Attachments:
[text/plain] dsa_hang_plan_v2.txt (20.2K, ../1524008630.2186289.1341689208.31A2DB11@webmail.messagingengine.com/2-dsa_hang_plan_v2.txt)
download | inline:
QUERY PLAN
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Sort (cost=13229.50..13229.51 rows=2 width=4336) (actual time=23.486..23.515 rows=316 loops=1)
Sort Key: assets."position"
Sort Method: quicksort Memory: 1293kB
CTE assets
-> HashAggregate (cost=13060.31..13075.88 rows=1557 width=864) (actual time=19.064..19.601 rows=1242 loops=1)
Group Key: assets_7.id, assets_7.name, assets_7.description, assets_7.asset_key, assets_7.type, assets_7.created_at, assets_7.updated_at, assets_7.deleted_at, assets_7.redacted_id, assets_7.section_id, assets_7."position", assets_7.creator_id, assets_7.modifier_id, assets_7.data, assets_7.thumbnail_override, assets_7.availability_start, assets_7.availability_end, assets_7.availability
-> Append (cost=6383.09..12990.25 rows=1557 width=864) (actual time=6.781..17.848 rows=1242 loops=1)
-> CTE Scan on assets assets_7 (cost=6383.09..6451.83 rows=15 width=864) (actual time=6.780..8.180 rows=1242 loops=1)
Filter: (redacted_id = 32456)
CTE assets
-> HashAggregate (cost=6352.54..6383.09 rows=3055 width=864) (actual time=6.775..7.270 rows=1242 loops=1)
Group Key: assets_1.id, assets_1.name, assets_1.description, assets_1.asset_key, assets_1.type, assets_1.created_at, assets_1.updated_at, assets_1.deleted_at, assets_1.redacted_id, assets_1.section_id, assets_1."position", assets_1.creator_id, assets_1.modifier_id, assets_1.data, assets_1.thumbnail_override, assets_1.availability_start, assets_1.availability_end, assets_1.availability
-> Append (cost=1.41..6215.07 rows=3055 width=864) (actual time=0.137..5.495 rows=1261 loops=1)
-> Nested Loop (cost=1.41..1514.55 rows=1 width=248) (actual time=0.026..0.026 rows=0 loops=1)
-> Nested Loop (cost=0.98..5.71 rows=1 width=4) (actual time=0.026..0.026 rows=0 loops=1)
-> Nested Loop (cost=0.70..5.14 rows=1 width=8) (actual time=0.026..0.026 rows=0 loops=1)
-> Index Scan using index_user_id_on_permissible_type on user_permissions (cost=0.42..2.64 rows=1 width=4) (actual time=0.025..0.025 rows=0 loops=1)
Index Cond: ((user_id = 98789) AND ((permissible_type)::text = 'Organization'::text))
Filter: ((permission_level)::text = 'guest'::text)
-> Index Only Scan using organizations_pkey on organizations (cost=0.28..2.50 rows=1 width=4) (never executed)
Index Cond: (id = user_permissions.permissible_id)
Heap Fetches: 0
-> Index Scan using index_redacteds_on_organization_id on redacteds redacteds_1 (cost=0.28..0.43 rows=1 width=8) (never executed)
Index Cond: (organization_id = organizations.id)
Filter: ((deleted_at IS NULL) AND (id = 32456))
-> Index Scan using index_assets_on_redacted_id on assets assets_1 (cost=0.43..1493.79 rows=1505 width=248) (never executed)
Index Cond: (redacted_id = 32456)
Filter: (availability = 0)
-> Nested Loop (cost=1.13..1513.99 rows=1505 width=248) (actual time=0.037..0.037 rows=0 loops=1)
-> Nested Loop (cost=0.70..5.16 rows=1 width=4) (actual time=0.037..0.037 rows=0 loops=1)
-> Index Scan using redacteds_pkey on redacteds redacteds_2 (cost=0.28..2.50 rows=1 width=4) (actual time=0.017..0.017 rows=1 loops=1)
Index Cond: (id = 32456)
Filter: (deleted_at IS NULL)
-> Index Scan using unique_index_on_user_permissions on user_permissions user_permissions_1 (cost=0.42..2.65 rows=1 width=4) (actual time=0.019..0.019 rows=0 loops=1)
Index Cond: (((permissible_type)::text = 'Redacted'::text) AND (permissible_id = 32456) AND (user_id = 98789))
Filter: ((permission_level)::text = 'guest'::text)
-> Index Scan using index_assets_on_redacted_id on assets assets_2 (cost=0.43..1493.79 rows=1505 width=248) (never executed)
Index Cond: (redacted_id = 32456)
Filter: (availability = 0)
-> Nested Loop (cost=1.55..67.28 rows=1 width=248) (actual time=0.073..5.253 rows=1261 loops=1)
-> Nested Loop (cost=1.12..11.54 rows=84 width=4) (actual time=0.055..0.770 rows=1331 loops=1)
-> Nested Loop (cost=0.70..5.14 rows=1 width=8) (actual time=0.025..0.041 rows=3 loops=1)
-> Index Scan using index_user_id_on_permissible_type on user_permissions user_permissions_2 (cost=0.42..2.64 rows=1 width=4) (actual time=0.011..0.014 rows=3 loops=1)
Index Cond: ((user_id = 98789) AND ((permissible_type)::text = 'Collection'::text))
Filter: ((permission_level)::text = 'guest'::text)
-> Index Scan using collections_pkey on collections (cost=0.28..2.50 rows=1 width=4) (actual time=0.008..0.008 rows=1 loops=3)
Index Cond: (id = user_permissions_2.permissible_id)
Filter: (deleted_at IS NULL)
-> Index Scan using index_collection_asset_associations_on_collection_id on collection_asset_associations collection_asset_associations_1 (cost=0.42..4.90 rows=149 width=8) (actual time=0.015..0.198 rows=444 loops=3)
Index Cond: (collection_id = collections.id)
Filter: (((availability_start < '2018-04-17 21:06:57.643933'::timestamp without time zone) OR (availability_start IS NULL)) AND ((availability_end > '2018-04-17 21:06:57.643933'::timestamp without time zone) OR (availability_end IS NULL)))
Rows Removed by Filter: 4
-> Index Scan using assets_pkey on assets assets_3 (cost=0.43..0.66 rows=1 width=248) (actual time=0.003..0.003 rows=1 loops=1331)
Index Cond: (id = collection_asset_associations_1.asset_id)
Filter: ((redacted_id = 32456) AND (availability = 0))
Rows Removed by Filter: 0
-> Nested Loop (cost=1.41..1511.09 rows=1 width=248) (actual time=0.013..0.013 rows=0 loops=1)
-> Nested Loop (cost=0.98..5.71 rows=1 width=4) (actual time=0.013..0.013 rows=0 loops=1)
-> Nested Loop (cost=0.70..5.14 rows=1 width=8) (actual time=0.013..0.013 rows=0 loops=1)
-> Index Scan using index_user_id_on_permissible_type on user_permissions user_permissions_3 (cost=0.42..2.64 rows=1 width=4) (actual time=0.012..0.012 rows=0 loops=1)
Index Cond: ((user_id = 98789) AND ((permissible_type)::text = 'Organization'::text))
Filter: ((permission_level)::text = ANY ('{collaborator,admin,owner}'::text[]))
-> Index Only Scan using organizations_pkey on organizations organizations_1 (cost=0.28..2.50 rows=1 width=4) (never executed)
Index Cond: (id = user_permissions_3.permissible_id)
Heap Fetches: 0
-> Index Scan using index_redacteds_on_organization_id on redacteds redacteds_3 (cost=0.28..0.43 rows=1 width=8) (never executed)
Index Cond: (organization_id = organizations_1.id)
Filter: ((deleted_at IS NULL) AND (id = 32456))
-> Index Scan using index_assets_on_redacted_id on assets assets_4 (cost=0.43..1489.92 rows=1546 width=248) (never executed)
Index Cond: (redacted_id = 32456)
-> Nested Loop (cost=1.13..1510.54 rows=1546 width=248) (actual time=0.022..0.022 rows=0 loops=1)
-> Nested Loop (cost=0.70..5.16 rows=1 width=4) (actual time=0.022..0.022 rows=0 loops=1)
-> Index Scan using redacteds_pkey on redacteds redacteds_4 (cost=0.28..2.50 rows=1 width=4) (actual time=0.010..0.010 rows=1 loops=1)
Index Cond: (id = 32456)
Filter: (deleted_at IS NULL)
-> Index Scan using unique_index_on_user_permissions on user_permissions user_permissions_4 (cost=0.42..2.65 rows=1 width=4) (actual time=0.011..0.011 rows=0 loops=1)
Index Cond: (((permissible_type)::text = 'Redacted'::text) AND (permissible_id = 32456) AND (user_id = 98789))
Filter: ((permission_level)::text = ANY ('{collaborator,admin,owner}'::text[]))
-> Index Scan using index_assets_on_redacted_id on assets assets_5 (cost=0.43..1489.92 rows=1546 width=248) (never executed)
Index Cond: (redacted_id = 32456)
-> Nested Loop (cost=1.55..67.07 rows=1 width=248) (actual time=0.012..0.012 rows=0 loops=1)
-> Nested Loop (cost=1.12..11.54 rows=84 width=4) (actual time=0.011..0.011 rows=0 loops=1)
-> Nested Loop (cost=0.70..5.14 rows=1 width=8) (actual time=0.011..0.011 rows=0 loops=1)
-> Index Scan using index_user_id_on_permissible_type on user_permissions user_permissions_5 (cost=0.42..2.64 rows=1 width=4) (actual time=0.011..0.011 rows=0 loops=1)
Index Cond: ((user_id = 98789) AND ((permissible_type)::text = 'Collection'::text))
Filter: ((permission_level)::text = ANY ('{collaborator,admin,owner}'::text[]))
Rows Removed by Filter: 3
-> Index Scan using collections_pkey on collections collections_1 (cost=0.28..2.50 rows=1 width=4) (never executed)
Index Cond: (id = user_permissions_5.permissible_id)
Filter: (deleted_at IS NULL)
-> Index Scan using index_collection_asset_associations_on_collection_id on collection_asset_associations collection_asset_associations_2 (cost=0.42..4.90 rows=149 width=8) (never executed)
Index Cond: (collection_id = collections_1.id)
Filter: (((availability_start < '2018-04-17 21:06:57.649733'::timestamp without time zone) OR (availability_start IS NULL)) AND ((availability_end > '2018-04-17 21:06:57.649733'::timestamp without time zone) OR (availability_end IS NULL)))
-> Index Scan using assets_pkey on assets assets_6 (cost=0.43..0.66 rows=1 width=248) (never executed)
Index Cond: (id = collection_asset_associations_2.asset_id)
Filter: (redacted_id = 32456)
-> Nested Loop (cost=0.71..1511.34 rows=1505 width=248) (actual time=0.011..0.011 rows=0 loops=1)
-> Index Scan using redacteds_pkey on redacteds redacteds_5 (cost=0.28..2.50 rows=1 width=4) (actual time=0.011..0.011 rows=0 loops=1)
Index Cond: (id = 32456)
Filter: ((deleted_at IS NULL) AND ((privacy)::text = 'public'::text))
Rows Removed by Filter: 1
-> Index Scan using index_assets_on_redacted_id on assets assets_8 (cost=0.43..1493.79 rows=1505 width=248) (never executed)
Index Cond: (redacted_id = 32456)
Filter: (availability = 0)
-> Gather (cost=1029.60..5011.51 rows=37 width=248) (actual time=9.560..9.560 rows=0 loops=1)
Workers Planned: 1
Workers Launched: 1
-> Nested Loop (cost=29.60..4007.81 rows=22 width=248) (actual time=5.488..5.488 rows=0 loops=2)
-> Nested Loop (cost=29.32..3934.16 rows=245 width=252) (actual time=0.324..4.098 rows=889 loops=2)
-> Parallel Bitmap Heap Scan on assets assets_9 (cost=28.90..1697.87 rows=885 width=248) (actual time=0.273..1.597 rows=744 loops=2)
Recheck Cond: (redacted_id = 32456)
Filter: (availability = 0)
Heap Blocks: exact=767
-> Bitmap Index Scan on index_assets_on_redacted_id (cost=0.00..28.52 rows=1546 width=0) (actual time=0.380..0.380 rows=1487 loops=1)
Index Cond: (redacted_id = 32456)
-> Index Scan using index_collection_asset_associations_on_asset_id on collection_asset_associations collection_asset_associations_3 (cost=0.42..2.48 rows=5 width=8) (actual time=0.003..0.003 rows=1 loops=1487)
Index Cond: (asset_id = assets_9.id)
Filter: (((availability_start < '2018-04-17 21:06:57.652961'::timestamp without time zone) OR (availability_start IS NULL)) AND ((availability_end > '2018-04-17 21:06:57.652961'::timestamp without time zone) OR (availability_end IS NULL)))
Rows Removed by Filter: 0
-> Index Scan using collections_pkey on collections collections_2 (cost=0.28..0.30 rows=1 width=4) (actual time=0.001..0.001 rows=0 loops=1778)
Index Cond: (id = collection_asset_associations_3.collection_id)
Filter: ((deleted_at IS NULL) AND public)
Rows Removed by Filter: 1
-> Nested Loop Left Join (cost=2.28..153.61 rows=2 width=4336) (actual time=19.248..22.243 rows=316 loops=1)
-> Nested Loop Left Join (cost=1.85..147.61 rows=1 width=4255) (actual time=19.222..21.777 rows=51 loops=1)
-> Nested Loop Left Join (cost=1.42..147.04 rows=1 width=3400) (actual time=19.190..21.394 rows=51 loops=1)
-> Nested Loop (cost=0.99..142.82 rows=1 width=1778) (actual time=19.167..21.090 rows=50 loops=1)
-> Nested Loop (cost=0.57..140.16 rows=1 width=1778) (actual time=19.146..20.899 rows=50 loops=1)
-> Nested Loop (cost=0.28..138.75 rows=1 width=1778) (actual time=19.106..20.730 rows=50 loops=1)
-> CTE Scan on assets (cost=0.00..136.24 rows=1 width=864) (actual time=19.088..20.578 rows=50 loops=1)
Filter: ((redacted_id = 32456) AND (section_id = 679855) AND (id = ANY ('{6703952,6703955,6714907,6714913,6767146,6767723,6767758,6767764,6767858,6767864,6767866,6767938,6767945,6767999,6716005,6716007,6730106,6730107,6730128,6730145,6730146,6730147,6730676,6730677,6730176,6730177,6730201,6730204,6730207,6730199,6730214,6730267,6730216,6730217,6730218,6730220,6730221,6730222,6730223,6730225,6730226,6730227,6730228,6735195,6735197,6735200,6735202,6735236,6735241,6735247}'::integer[])))
Rows Removed by Filter: 1192
-> Index Scan using redacteds_pkey on redacteds (cost=0.28..2.50 rows=1 width=914) (actual time=0.002..0.002 rows=1 loops=50)
Index Cond: (id = 32456)
Filter: (deleted_at IS NULL)
-> Index Only Scan using sections_pkey on sections (cost=0.29..1.41 rows=1 width=4) (actual time=0.003..0.003 rows=1 loops=50)
Index Cond: (id = 163863)
Heap Fetches: 50
-> Index Scan using index_collection_assets_on_collection_id_and_asset_id on collection_asset_associations (cost=0.42..2.65 rows=1 width=4) (actual time=0.003..0.003 rows=1 loops=50)
Index Cond: ((collection_id = 67459) AND (asset_id = assets.id))
Filter: (((availability_start < '2018-04-17 21:06:57.631399'::timestamp without time zone) OR (availability_start IS NULL)) AND ((availability_end > '2018-04-17 21:06:57.631399'::timestamp without time zone) OR (availability_end IS NULL)))
-> Index Scan using index_attachments_on_asset_id on attachments (cost=0.43..4.16 rows=6 width=1622) (actual time=0.005..0.005 rows=1 loops=50)
Index Cond: (asset_id = assets.id)
-> Index Scan using index_versions_on_item_type_and_item_id on versions (cost=0.43..0.56 rows=1 width=855) (actual time=0.006..0.006 rows=1 loops=51)
Index Cond: (((item_type)::text = 'Attachment'::text) AND (item_id = attachments.id))
-> Index Scan using index_tags_on_asset_id on tags (cost=0.43..5.81 rows=19 width=81) (actual time=0.004..0.006 rows=6 loops=51)
Index Cond: (asset_id = assets.id)
Planning time: 7.210 ms
Execution time: 24.650 ms
(149 rows)
view thread (20+ messages) latest in thread
Message-ID: <1524008630.2186289.1341689208.31A2DB11@webmail.messagingengine.com>
Permalink: ../1524008630.2186289.1341689208.31A2DB11@webmail.messagingengine.com/
Also on: postgresql.org/message-id/1524008630.2186289.1341689208.31A2DB11@webmail.messagingengine.com
copy link · copy postgr.es
reply Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: pgsql-hackers@postgresql.org
Cc: jonathan@titanous.com, thomas.munro@enterprisedb.com, robertmhaas@gmail.com, seltenreich@gmx.de
Subject: Re: [sqlsmith] Unpinning error in parallel worker
In-Reply-To: <1524008630.2186289.1341689208.31A2DB11@webmail.messagingengine.com>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox