postgres 11.0 partition table works unexpected in update

From: 张心灵 <zhangsilly(at)gmail(dot)com>
To: pgsql-bugs(at)postgresql(dot)org
Subject: postgres 11.0 partition table works unexpected in update
Date: 2018-10-24 09:37:01
Message-ID: CANWCfK+cziqhfSf_OgXVp39pXGZv0cWSArAF3skxWMS3ncy2xw@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-bugs

I have test postgres 11.0 just now, when I test insert, it runs perfect,
but when test update, it's too slow, and explain show it's bad planed.

My table was partioned as this:

CREATE TABLE ysy_test.user_msg
(
user_id bigint NOT NULL DEFAULT 0,
msg_id bigint NOT NULL DEFAULT 0,
status smallint NOT NULL DEFAULT 0,
create_time timestamp without time zone NOT NULL DEFAULT now(),
update_time timestamp without time zone NOT NULL DEFAULT now(),
CONSTRAINT user_msg_pkey PRIMARY KEY (user_id, msg_id)
) PARTITION BY HASH(user_id) WITH (
OIDS = FALSE
)

do language plpgsql $$
declare
i int;
begin
for i in 0..127 loop
execute 'CREATE TABLE ysy_test.user_msg_'||i||' PARTITION OF
ysy_test.user_msg FOR VALUES WITH (MODULUS 128, REMAINDER '||i||')';
end loop;
end;
$$;

Explain select works good as expect:

ysy=> explain (analyze, costs, verbose) select * from ysy_test.user_msg_114
where user_id = 14211;
QUERY PLAN

-------------------------------------------------------------------------------------------------------------------------------------------
Index Scan using user_msg_114_pkey on ysy_test.user_msg_114
(cost=0.43..11.29 rows=8 width=34) (actual time=0.028..0.044 rows=8 loops=1)
Output: user_id, msg_id, status, create_time, update_time
Index Cond: (user_msg_114.user_id = 14211)
Planning Time: 0.089 ms
Execution Time: 0.065 ms
(5 rows)

Time: 0.432 ms

But update works bad, and explain like this:

ysy=> explain (analyze, costs, verbose, buffers, timing) update
ysy_test.user_msg set status = 2 where user_id = 14211 and msg_id = 1 and
(user_id % 128) = (14211 % 128);
QUERY
PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------
Update on ysy_test.user_msg (cost=0.43..365.12 rows=128 width=40) (actual
time=1.114..1.114 rows=0 loops=1)
Update on ysy_test.user_msg_0
Update on ysy_test.user_msg_1
Update on ysy_test.user_msg_2
Update on ysy_test.user_msg_3
Update on ysy_test.user_msg_4
Update on ysy_test.user_msg_5
Update on ysy_test.user_msg_6
Update on ysy_test.user_msg_7
Update on ysy_test.user_msg_8
Update on ysy_test.user_msg_9
Update on ysy_test.user_msg_10
Update on ysy_test.user_msg_11
Update on ysy_test.user_msg_12
Update on ysy_test.user_msg_13
Update on ysy_test.user_msg_14
Update on ysy_test.user_msg_15
Update on ysy_test.user_msg_16
Update on ysy_test.user_msg_17
Update on ysy_test.user_msg_18
Update on ysy_test.user_msg_19
Update on ysy_test.user_msg_20
Update on ysy_test.user_msg_21
Update on ysy_test.user_msg_22
Update on ysy_test.user_msg_23
Update on ysy_test.user_msg_24
Update on ysy_test.user_msg_25
Update on ysy_test.user_msg_26
Update on ysy_test.user_msg_27
Update on ysy_test.user_msg_28
Update on ysy_test.user_msg_29
Update on ysy_test.user_msg_30
Update on ysy_test.user_msg_31
Update on ysy_test.user_msg_32
Update on ysy_test.user_msg_33
Update on ysy_test.user_msg_34
Update on ysy_test.user_msg_35
Update on ysy_test.user_msg_36
Update on ysy_test.user_msg_37
Update on ysy_test.user_msg_38
Update on ysy_test.user_msg_39
Update on ysy_test.user_msg_40
Update on ysy_test.user_msg_41
Update on ysy_test.user_msg_42
Update on ysy_test.user_msg_43
Update on ysy_test.user_msg_44
Update on ysy_test.user_msg_45
Update on ysy_test.user_msg_46
Update on ysy_test.user_msg_47
Update on ysy_test.user_msg_48
Update on ysy_test.user_msg_49
Update on ysy_test.user_msg_50
Update on ysy_test.user_msg_51
Update on ysy_test.user_msg_52
Update on ysy_test.user_msg_53
Update on ysy_test.user_msg_54
Update on ysy_test.user_msg_55
Update on ysy_test.user_msg_56
Update on ysy_test.user_msg_57
Update on ysy_test.user_msg_58
Update on ysy_test.user_msg_59
Update on ysy_test.user_msg_60
Update on ysy_test.user_msg_61
Update on ysy_test.user_msg_62
Update on ysy_test.user_msg_63
Update on ysy_test.user_msg_64
Update on ysy_test.user_msg_65
Update on ysy_test.user_msg_66
Update on ysy_test.user_msg_67
Update on ysy_test.user_msg_68
Update on ysy_test.user_msg_69
Update on ysy_test.user_msg_70
Update on ysy_test.user_msg_71
Update on ysy_test.user_msg_72
Update on ysy_test.user_msg_73
Update on ysy_test.user_msg_74
Update on ysy_test.user_msg_75
Update on ysy_test.user_msg_76
Update on ysy_test.user_msg_77
Update on ysy_test.user_msg_78
Update on ysy_test.user_msg_79
Update on ysy_test.user_msg_80
Update on ysy_test.user_msg_81
Update on ysy_test.user_msg_82
Update on ysy_test.user_msg_83
Update on ysy_test.user_msg_84
Update on ysy_test.user_msg_85
Update on ysy_test.user_msg_86
Update on ysy_test.user_msg_87
Update on ysy_test.user_msg_88
Update on ysy_test.user_msg_89
Update on ysy_test.user_msg_90
Update on ysy_test.user_msg_91
Update on ysy_test.user_msg_92
Update on ysy_test.user_msg_93
Update on ysy_test.user_msg_94
Update on ysy_test.user_msg_95
Update on ysy_test.user_msg_96
Update on ysy_test.user_msg_97
Update on ysy_test.user_msg_98
Update on ysy_test.user_msg_99
Update on ysy_test.user_msg_100
Update on ysy_test.user_msg_101
Update on ysy_test.user_msg_102
Update on ysy_test.user_msg_103
Update on ysy_test.user_msg_104
Update on ysy_test.user_msg_105
Update on ysy_test.user_msg_106
Update on ysy_test.user_msg_107
Update on ysy_test.user_msg_108
Update on ysy_test.user_msg_109
Update on ysy_test.user_msg_110
Update on ysy_test.user_msg_111
Update on ysy_test.user_msg_112
Update on ysy_test.user_msg_113
Update on ysy_test.user_msg_114
Update on ysy_test.user_msg_115
Update on ysy_test.user_msg_116
Update on ysy_test.user_msg_117
Update on ysy_test.user_msg_118
Update on ysy_test.user_msg_119
Update on ysy_test.user_msg_120
Update on ysy_test.user_msg_121
Update on ysy_test.user_msg_122
Update on ysy_test.user_msg_123
Update on ysy_test.user_msg_124
Update on ysy_test.user_msg_125
Update on ysy_test.user_msg_126
Update on ysy_test.user_msg_127
Buffers: shared hit=391
-> Index Scan using user_msg_0_pkey on ysy_test.user_msg_0
(cost=0.43..2.85 rows=1 width=40) (actual time=0.013..0.013 rows=0 loops=1)
Output: user_msg_0.user_id, user_msg_0.msg_id, '2'::smallint,
user_msg_0.create_time, user_msg_0.update_time, user_msg_0.ctid
Index Cond: ((user_msg_0.user_id = 14211) AND (user_msg_0.msg_id =
1))
Filter: ((user_msg_0.user_id % '128'::bigint) = 3)
Buffers: shared hit=3
-> Index Scan using user_msg_1_pkey on ysy_test.user_msg_1
(cost=0.43..2.85 rows=1 width=40) (actual time=0.009..0.009 rows=0 loops=1)
Output: user_msg_1.user_id, user_msg_1.msg_id, '2'::smallint,
user_msg_1.create_time, user_msg_1.update_time, user_msg_1.ctid
Index Cond: ((user_msg_1.user_id = 14211) AND (user_msg_1.msg_id =
1))
Filter: ((user_msg_1.user_id % '128'::bigint) = 3)
Buffers: shared hit=3
-> Index Scan using user_msg_2_pkey on ysy_test.user_msg_2
(cost=0.43..2.85 rows=1 width=40) (actual time=0.008..0.008 rows=0 loops=1)
Output: user_msg_2.user_id, user_msg_2.msg_id, '2'::smallint,
user_msg_2.create_time, user_msg_2.update_time, user_msg_2.ctid
Index Cond: ((user_msg_2.user_id = 14211) AND (user_msg_2.msg_id =
1))
Filter: ((user_msg_2.user_id % '128'::bigint) = 3)
Buffers: shared hit=3
-> Index Scan using user_msg_3_pkey on ysy_test.user_msg_3
(cost=0.43..2.85 rows=1 width=40) (actual time=0.010..0.010 rows=0 loops=1)
Output: user_msg_3.user_id, user_msg_3.msg_id, '2'::smallint,
user_msg_3.create_time, user_msg_3.update_time, user_msg_3.ctid
Index Cond: ((user_msg_3.user_id = 14211) AND (user_msg_3.msg_id =
1))
Filter: ((user_msg_3.user_id % '128'::bigint) = 3)
Buffers: shared hit=3
-> Index Scan using user_msg_4_pkey on ysy_test.user_msg_4
(cost=0.43..2.85 rows=1 width=40) (actual time=0.007..0.007 rows=0 loops=1)
Output: user_msg_4.user_id, user_msg_4.msg_id, '2'::smallint,
user_msg_4.create_time, user_msg_4.update_time, user_msg_4.ctid
Index Cond: ((user_msg_4.user_id = 14211) AND (user_msg_4.msg_id =
1))
Filter: ((user_msg_4.user_id % '128'::bigint) = 3)
Buffers: shared hit=3
-> Index Scan using user_msg_5_pkey on ysy_test.user_msg_5
(cost=0.43..2.85 rows=1 width=40) (actual time=0.008..0.008 rows=0 loops=1)
Output: user_msg_5.user_id, user_msg_5.msg_id, '2'::smallint,
user_msg_5.create_time, user_msg_5.update_time, user_msg_5.ctid
Index Cond: ((user_msg_5.user_id = 14211) AND (user_msg_5.msg_id =
1))
Filter: ((user_msg_5.user_id % '128'::bigint) = 3)
Buffers: shared hit=3
-> Index Scan using user_msg_6_pkey on ysy_test.user_msg_6
(cost=0.43..2.85 rows=1 width=40) (actual time=0.008..0.008 rows=0 loops=1)
Output: user_msg_6.user_id, user_msg_6.msg_id, '2'::smallint,
user_msg_6.create_time, user_msg_6.update_time, user_msg_6.ctid
Index Cond: ((user_msg_6.user_id = 14211) AND (user_msg_6.msg_id =
1))
Filter: ((user_msg_6.user_id % '128'::bigint) = 3)
Buffers: shared hit=3
-> Index Scan using user_msg_7_pkey on ysy_test.user_msg_7
(cost=0.43..2.85 rows=1 width=40) (actual time=0.009..0.009 rows=0 loops=1)
Time: 25.532 ms

And when doing update, almost all activities was wait for lock_manager,
it's toooo slow!

BTW: SELECT 14211 % 128 was 3, why record of HASH column user_id 14211 data
in partition of 114?

Responses

Browse pgsql-bugs by date

  From Date Subject
Next Message Ferranti, Andrea 2018-10-24 09:39:19 Re: BUG #15455: Endless lseek
Previous Message Ozan Kahramanogullari 2018-10-24 09:30:36 Re: psql on Mac