PatchPost become slow

Troubleshooting
1

Hi,

I noticed that the PatchPost API has become slow, but I’m uncertain about the cause. Does anyone have insights into possible reasons? For instance, could the size of the database or the size of Mattermost app data impact the performance of this API?

Here is the documentation for the PatchPost API:
https://api.mattermost.com/#tag/posts/operation/PatchPost

And I’ve observed that the loading of the channel (after close window for a while then reopening it) has become significantly slow as well. It’s unclear whether there is a connection between these two occurrences. If anyone has any insights or information regarding these performance issues, I would greatly appreciate your input.

Thanks.

2

for channel loading issue, I found some logs in postgres container:

2023-06-28 02:46:54.749 UTC [11294] ERROR:  canceling statement due to user request
2023-06-28 02:46:54.749 UTC [11294] STATEMENT:  SELECT p.*, (SELECT COUNT(*) FROM Posts WHERE Posts.RootId = (CASE WHEN p.RootId = '' THEN p.Id ELSE p.RootId END) AND Posts.DeleteAt = 0) AS ReplyCount FROM Posts p WHERE (CreateAt < (SELECT CreateAt FROM Posts WHERE Id = $1) AND p.ChannelId = $2 AND p.DeleteAt = $3) ORDER BY p.ChannelId, p.DeleteAt, p.CreateAt DESC LIMIT 30 OFFSET 0
3

Your PostgreSQL Queries seem to be slow and the error message you posted indicates that this specific query took longer than the time allowed for queries to run and has been cancled because of that.
When was the last time you vacuumed your PostgreSQL database?
How long does running this specific query take on your installation? How many posts are there in your posts table?

SELECT p.*, (SELECT COUNT(*) FROM Posts WHERE Posts.RootId = (CASE WHEN p.RootId = '' THEN p.Id ELSE p.RootId END) AND Posts.DeleteAt = 0) AS ReplyCount FROM Posts p WHERE (CreateAt < (SELECT CreateAt FROM Posts WHERE Id = 'something') AND p.ChannelId = 'something' AND p.DeleteAt = 0) ORDER BY p.ChannelId, p.DeleteAt, p.CreateAt DESC LIMIT 30 OFFSET 0;

select count(*) from posts;

The query analyzer output might also be interesting for this specific query, you could run it with explain analyze verbose so that it generates an output like this:

mattermost=# explain analyze verbose SELECT p.*, (SELECT COUNT(*) FROM Posts WHERE Posts.RootId = (CASE WHEN p.RootId = '' THEN p.Id ELSE p.RootId END) AND Posts.DeleteAt = 0) AS ReplyCount FROM Posts p WHERE (CreateAt < (SELECT CreateAt FROM Posts WHERE Id = 'something') AND p.ChannelId = 'something' AND p.DeleteAt = 0) ORDER BY p.ChannelId, p.DeleteAt, p.CreateAt DESC LIMIT 30 OFFSET 0;
                                                                                                               QUERY PLAN
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=8.58..25.24 rows=1 width=374) (actual time=0.024..0.025 rows=0 loops=1)
   Output: p.id, p.createat, p.updateat, p.deleteat, p.userid, p.channelid, p.rootid, p.originalid, p.message, p.type, p.props, p.hashtags, p.filenames, p.fileids, p.hasreactions, p.editat, p.ispinned, p.remoteid, ((SubPlan 1))
   InitPlan 2 (returns $2)
     ->  Index Scan using posts_pkey on public.posts posts_1  (cost=0.28..8.30 rows=1 width=8) (actual time=0.019..0.020 rows=0 loops=1)
           Output: posts_1.createat
           Index Cond: ((posts_1.id)::text = 'something'::text)
   ->  Index Scan Backward using idx_posts_channel_id_delete_at_create_at on public.posts p  (cost=0.28..16.94 rows=1 width=374) (actual time=0.023..0.023 rows=0 loops=1)
         Output: p.id, p.createat, p.updateat, p.deleteat, p.userid, p.channelid, p.rootid, p.originalid, p.message, p.type, p.props, p.hashtags, p.filenames, p.fileids, p.hasreactions, p.editat, p.ispinned, p.remoteid, (SubPlan 1)
         Index Cond: (((p.channelid)::text = 'something'::text) AND (p.deleteat = 0) AND (p.createat < $2))
         SubPlan 1
           ->  Aggregate  (cost=8.62..8.63 rows=1 width=8) (never executed)
                 Output: count(*)
                 ->  Index Only Scan using idx_posts_root_id_delete_at on public.posts  (cost=0.29..8.59 rows=15 width=0) (never executed)
                       Output: posts.rootid, posts.deleteat
                       Index Cond: ((posts.rootid = (CASE WHEN ((p.rootid)::text = ''::text) THEN p.id ELSE p.rootid END)::text) AND (posts.deleteat = 0))
                       Heap Fetches: 0
 Planning Time: 0.332 ms
 Execution Time: 0.066 ms
(18 rows)
4

Hi @agriesser

I’ve tuned some parameters in my postgres.conf, it worked fine since then.
I never vacuum the database, how often should I do so?

select count(*) from posts;

/*
count  |
-------+
6352944|
*/
5

Autovacuums should be configured by default, are you sure that you disabled them? Sometimes it’s necessary to start manual vacuums if the autovacuums do not finish or to recreate indices, etc. - but that always depends on the behaviour you’re experiencing and needs to be analyzed on a per-case basis.

6

Could you please provide more specific information about the setting you are referring to? (like which config file?) Thanks a lot!

7

postgresql.conf and the setting is called autovacuum (defaults to on).
But that’s not all it takes, it could well be, that auto vacuums are configured but they do not finish on your end for whatever reason, so if in doubt, a DBA should check your database.