Slow query to select videos

[kontrollanten]

Describe the current behavior

Our Postgresql slow query log shows a lot of these statements:

duration: 1246.115 ms  statement: 
SELECT "video".*,
       "videochannel"."id"                                 AS "VideoChannel.id",
       "videochannel"."name"                               AS
       "VideoChannel.name",
       "videochannel"."description"                        AS
       "VideoChannel.description",
       "videochannel"."actorid"                            AS
       "VideoChannel.actorId",
       "VideoChannel->Actor"."id"                          AS
       "VideoChannel.Actor.id",
       "VideoChannel->Actor"."preferredusername"           AS
       "VideoChannel.Actor.preferredUsername",
       "VideoChannel->Actor"."url"                         AS
       "VideoChannel.Actor.url",
       "VideoChannel->Actor"."serverid"                    AS
       "VideoChannel.Actor.serverId",
       "VideoChannel->Actor->Avatars"."id"                 AS
       "VideoChannel.Actor.Avatars.id",
       "VideoChannel->Actor->Avatars"."width"              AS
       "VideoChannel.Actor.Avatars.width",
       "VideoChannel->Actor->Avatars"."filename"           AS
       "VideoChannel.Actor.Avatars.filename",
       "VideoChannel->Actor->Avatars"."type"               AS
       "VideoChannel.Actor.Avatars.type",
       "VideoChannel->Actor->Avatars"."fileurl"            AS
       "VideoChannel.Actor.Avatars.fileUrl",
       "VideoChannel->Actor->Avatars"."ondisk"             AS
       "VideoChannel.Actor.Avatars.onDisk",
       "VideoChannel->Actor->Avatars"."createdat"          AS
       "VideoChannel.Actor.Avatars.createdAt",
       "VideoChannel->Actor->Avatars"."updatedat"          AS
       "VideoChannel.Actor.Avatars.updatedAt",
       "VideoChannel->Actor->Server"."id"                  AS
       "VideoChannel.Actor.Server.id",
       "VideoChannel->Actor->Server"."host"                AS
       "VideoChannel.Actor.Server.host",
       "VideoChannel->Account"."id"                        AS
       "VideoChannel.Account.id",
       "VideoChannel->Account"."name"                      AS
       "VideoChannel.Account.name",
       "VideoChannel->Account"."actorid"                   AS
       "VideoChannel.Account.actorId",
       "VideoChannel->Account->Actor"."id"                 AS
       "VideoChannel.Account.Actor.id",
       "VideoChannel->Account->Actor"."preferredusername"  AS
       "VideoChannel.Account.Actor.preferredUsername",
       "VideoChannel->Account->Actor"."url"                AS
       "VideoChannel.Account.Actor.url",
       "VideoChannel->Account->Actor"."serverid"           AS
       "VideoChannel.Account.Actor.serverId",
       "VideoChannel->Account->Actor->Avatars"."id"        AS
       "VideoChannel.Account.Actor.Avatars.id",
       "VideoChannel->Account->Actor->Avatars"."width"     AS
       "VideoChannel.Account.Actor.Avatars.width",
       "VideoChannel->Account->Actor->Avatars"."filename"  AS
       "VideoChannel.Account.Actor.Avatars.filename",
       "VideoChannel->Account->Actor->Avatars"."type"      AS
       "VideoChannel.Account.Actor.Avatars.type",
       "VideoChannel->Account->Actor->Avatars"."fileurl"   AS
       "VideoChannel.Account.Actor.Avatars.fileUrl",
       "VideoChannel->Account->Actor->Avatars"."ondisk"    AS
       "VideoChannel.Account.Actor.Avatars.onDisk",
       "VideoChannel->Account->Actor->Avatars"."createdat" AS
       "VideoChannel.Account.Actor.Avatars.createdAt",
       "VideoChannel->Account->Actor->Avatars"."updatedat" AS
       "VideoChannel.Account.Actor.Avatars.updatedAt",
       "VideoChannel->Account->Actor->Server"."id"         AS
       "VideoChannel.Account.Actor.Server.id",
       "VideoChannel->Account->Actor->Server"."host"       AS
       "VideoChannel.Account.Actor.Server.host",
       "Thumbnails"."id"                                   AS "Thumbnails.id",
       "Thumbnails"."type"                                 AS "Thumbnails.type",
       "Thumbnails"."filename"                             AS
       "Thumbnails.filename"
FROM   (SELECT "video"."id",
               0
               AS
                      similarity,
               Coalesce("video"."originallypublishedat", "video"."publishedat")
               AS
               "publishedAtForOrder"
        FROM   "video"
               INNER JOIN "videochannel"
                       ON "videochannel"."id" = "video"."channelid"
               INNER JOIN "account"
                       ON "account"."id" = "videochannel"."accountid"
               INNER JOIN "actor" "accountActor"
                       ON "account"."actorid" = "accountActor"."id"
        WHERE  "video"."id" NOT IN (SELECT "videoblacklist"."videoid"
                                    FROM   "videoblacklist")
               AND NOT EXISTS (SELECT 1
                               FROM   "accountblocklist"
                               WHERE  "accountblocklist"."accountid" IN ( '1' )
                                      AND "accountblocklist"."targetaccountid" =
                                          "account"."id"
                              )
               AND NOT EXISTS (SELECT 1
                               FROM   "serverblocklist"
                               WHERE  "serverblocklist"."accountid" IN ( '1' )
                                      AND "serverblocklist"."targetserverid" =
                                          "accountActor"."serverid")
               AND ( "video"."state" = 1
                      OR ( "video"."state" = 2
                           AND "video"."waittranscoding" IS FALSE ) )
               AND ( EXISTS (SELECT 1
                             FROM   "videoshare"
                                    INNER JOIN "actorfollow" "actorFollowShare"
                                            ON
                                    "actorFollowShare"."targetactorid" =
                                    "videoshare"."actorid"
                                    AND "actorFollowShare"."actorid" = 1
                                    AND "actorFollowShare"."state" =
                                        'accepted'
                             WHERE  "videoshare"."videoid" = "video"."id")
                      OR EXISTS (SELECT 1
                                 FROM   "actorfollow"
                                 WHERE  ( "actorfollow"."targetactorid" =
                                          "account"."actorid"
                                           OR "actorfollow"."targetactorid" =
                                              "videochannel"."actorid" )
                                        AND "actorfollow"."actorid" = 1
                                        AND "actorfollow"."state" = 'accepted')
                      OR "video"."remote" IS FALSE )
               AND "video"."privacy" = 1
               AND "video"."nsfw" IS FALSE
        ORDER  BY "publishedatfororder" DESC,
                  "video"."id" ASC
        LIMIT  25 offset 0) AS "tmp"
       INNER JOIN "video"
               ON "tmp"."id" = "video"."id"
       INNER JOIN "videochannel" AS "VideoChannel"
               ON "video"."channelid" = "videochannel"."id"
       INNER JOIN "actor" AS "VideoChannel->Actor"
               ON "videochannel"."actorid" = "VideoChannel->Actor"."id"
       LEFT OUTER JOIN "server" AS "VideoChannel->Actor->Server"
                    ON "VideoChannel->Actor"."serverid" =
                       "VideoChannel->Actor->Server"."id"
       LEFT OUTER JOIN "actorimage" AS "VideoChannel->Actor->Avatars"
                    ON "VideoChannel->Actor"."id" =
                       "VideoChannel->Actor->Avatars"."actorid"
                       AND "VideoChannel->Actor->Avatars"."type" = 1
       INNER JOIN "account" AS "VideoChannel->Account"
               ON "videochannel"."accountid" = "VideoChannel->Account"."id"
       INNER JOIN "actor" AS "VideoChannel->Account->Actor"
               ON "VideoChannel->Account"."actorid" =
                  "VideoChannel->Account->Actor"."id"
       LEFT OUTER JOIN "server" AS "VideoChannel->Account->Actor->Server"
                    ON "VideoChannel->Account->Actor"."serverid" =
                       "VideoChannel->Account->Actor->Server"."id"
       LEFT OUTER JOIN "actorimage" AS "VideoChannel->Account->Actor->Avatars"
                    ON "VideoChannel->Account"."actorid" =
       "VideoChannel->Account->Actor->Avatars"."actorid"
       AND "VideoChannel->Account->Actor->Avatars"."type" = 1
       LEFT OUTER JOIN "thumbnail" AS "Thumbnails"
                    ON "video"."id" = "Thumbnails"."videoid"
ORDER  BY "publishedatfororder" DESC,
          "video"."id" ASC 

Steps to reproduce

Describe the expected behavior

No response

Additional information

• PeerTube instance:

  • URL:
  • Version: 6.1.0
  • NodeJS version:
  • Ffmpeg version:

• Browser name, version and platforms on which you could reproduce the bug:

• Link to browser console log if relevant:

• Link to server log if relevant (journalctl or /var/www/peertube/storage/logs/):

[Chocobozzz]

Hi,

How many videos do you have?

Can you run the query with EXPLAIN (ANALYZE, BUFFERS)?

[kontrollanten]

3 150 videos.

                                                                                                                                    QUERY PLAN                                                                                                                                    
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Nested Loop Left Join  (cost=5546.40..5910.27 rows=63 width=3166) (actual time=37.238..37.943 rows=100 loops=1)
   Buffers: shared hit=17021
   ->  Nested Loop Left Join  (cost=5546.12..5895.83 rows=25 width=3116) (actual time=37.227..37.800 rows=50 loops=1)
         Buffers: shared hit=16869
         ->  Nested Loop Left Join  (cost=5545.84..5887.07 rows=25 width=2949) (actual time=37.220..37.723 rows=50 loops=1)
               Buffers: shared hit=16769
               ->  Nested Loop  (cost=5545.70..5883.13 rows=25 width=2429) (actual time=37.216..37.689 rows=50 loops=1)
                     Buffers: shared hit=16769
                     ->  Nested Loop  (cost=5545.41..5822.72 rows=25 width=2367) (actual time=37.209..37.552 rows=50 loops=1)
                           Buffers: shared hit=16619
                           ->  Nested Loop Left Join  (cost=5545.12..5812.75 rows=25 width=2353) (actual time=37.200..37.461 rows=50 loops=1)
                                 Buffers: shared hit=16469
                                 ->  Nested Loop Left Join  (cost=5544.84..5804.71 rows=25 width=2186) (actual time=37.190..37.385 rows=25 loops=1)
                                       Buffers: shared hit=16369
                                       ->  Nested Loop  (cost=5544.70..5800.77 rows=25 width=1666) (actual time=37.185..37.366 rows=25 loops=1)
                                             Buffers: shared hit=16369
                                             ->  Nested Loop  (cost=5544.40..5728.74 rows=25 width=1604) (actual time=37.176..37.304 rows=25 loops=1)
                                                   Buffers: shared hit=16294
                                                   ->  Nested Loop  (cost=5544.12..5715.59 rows=25 width=1414) (actual time=37.167..37.247 rows=25 loops=1)
                                                         Buffers: shared hit=16219
                                                         ->  Limit  (cost=5543.84..5543.90 rows=25 width=16) (actual time=37.155..37.172 rows=25 loops=1)
                                                               Buffers: shared hit=16144
                                                               ->  Sort  (cost=5543.84..5547.50 rows=1466 width=16) (actual time=37.154..37.167 rows=25 loops=1)
                                                                     Sort Key: (COALESCE(video_1."originallyPublishedAt", video_1."publishedAt")) DESC, video_1.id
                                                                     Sort Method: top-N heapsort  Memory: 27kB
                                                                     Buffers: shared hit=16144
                                                                     ->  Nested Loop Anti Join  (cost=1149.21..5502.47 rows=1466 width=16) (actual time=19.095..36.476 rows=3024 loops=1)
                                                                           Join Filter: ("serverBlocklist"."targetServerId" = "accountActor"."serverId")
                                                                           Buffers: shared hit=16144
                                                                           ->  Nested Loop  (cost=1149.21..5478.71 rows=1513 width=24) (actual time=19.083..35.622 rows=3024 loops=1)
                                                                                 Buffers: shared hit=16143
                                                                                 ->  Hash Anti Join  (cost=1148.91..1823.12 rows=1513 width=24) (actual time=19.073..27.934 rows=3024 loops=1)
                                                                                       Hash Cond: (account.id = "accountBlocklist"."targetAccountId")
                                                                                       Buffers: shared hit=7071
                                                                                       ->  Hash Join  (cost=1138.53..1793.50 rows=1516 width=28) (actual time=19.028..27.262 rows=3024 loops=1)
                                                                                             Hash Cond: ("videoChannel"."accountId" = account.id)
                                                                                             Join Filter: ((alternatives: SubPlan 2 or hashed SubPlan 3) OR (SubPlan 4) OR (video_1.remote IS FALSE))
                                                                                             Rows Removed by Join Filter: 25
                                                                                             Buffers: shared hit=7064
                                                                                             ->  Hash Join  (cost=440.08..1091.07 rows=1519 width=29) (actual time=8.212..10.526 rows=3049 loops=1)
                                                                                                   Hash Cond: (video_1."channelId" = "videoChannel".id)
                                                                                                   Buffers: shared hit=721
                                                                                                   ->  Seq Scan on video video_1  (cost=11.75..658.75 rows=1519 width=25) (actual time=0.021..1.574 rows=3049 loops=1)
                                                                                                         Filter: ((nsfw IS FALSE) AND (NOT (hashed SubPlan 1)) AND (privacy = 1) AND ((state = 1) OR ((state = 2) AND ("waitTranscoding" IS FALSE))))
                                                                                                         Rows Removed by Filter: 101
                                                                                                         Buffers: shared hit=584
                                                                                                         SubPlan 1
                                                                                                           ->  Seq Scan on "videoBlacklist"  (cost=0.00..11.40 rows=140 width=4) (actual time=0.002..0.003 rows=0 loops=1)
                                                                                                   ->  Hash  (cost=266.48..266.48 rows=12948 width=12) (actual time=8.138..8.138 rows=12949 loops=1)
                                                                                                         Buckets: 16384  Batches: 1  Memory Usage: 685kB
                                                                                                         Buffers: shared hit=137
                                                                                                         ->  Seq Scan on "videoChannel"  (cost=0.00..266.48 rows=12948 width=12) (actual time=0.008..3.262 rows=12949 loops=1)
                                                                                                               Buffers: shared hit=137
                                                                                             ->  Hash  (cost=445.42..445.42 rows=20242 width=8) (actual time=10.687..10.688 rows=20005 loops=1)
                                                                                                   Buckets: 32768  Batches: 1  Memory Usage: 1038kB
                                                                                                   Buffers: shared hit=243
                                                                                                   ->  Seq Scan on account  (cost=0.00..445.42 rows=20242 width=8) (actual time=0.018..5.242 rows=20005 loops=1)
                                                                                                         Buffers: shared hit=243
                                                                                             SubPlan 2
                                                                                               ->  Nested Loop  (cost=0.56..17.49 rows=1 width=0) (never executed)
                                                                                                     Join Filter: ("videoShare"."actorId" = "actorFollowShare"."targetActorId")
                                                                                                     ->  Index Scan using actor_follow_actor_id_target_actor_id on "actorFollow" "actorFollowShare"  (cost=0.28..8.30 rows=1 width=4) (never executed)
                                                                                                           Index Cond: ("actorId" = 1)
                                                                                                           Filter: (state = 'accepted'::"enum_actorFollow_state")
                                                                                                     ->  Index Scan using video_share_video_id on "videoShare"  (cost=0.28..9.16 rows=2 width=4) (never executed)
                                                                                                           Index Cond: ("videoId" = video_1.id)
                                                                                             SubPlan 3
                                                                                               ->  Nested Loop  (cost=16.22..144.86 rows=2735 width=4) (actual time=0.010..0.011 rows=0 loops=1)
                                                                                                     Buffers: shared hit=2
                                                                                                     ->  Index Scan using actor_follow_actor_id_target_actor_id on "actorFollow" "actorFollowShare_1"  (cost=0.28..8.30 rows=1 width=4) (actual time=0.010..0.010 rows=0 loops=1)
                                                                                                           Index Cond: ("actorId" = 1)
                                                                                                           Filter: (state = 'accepted'::"enum_actorFollow_state")
                                                                                                           Buffers: shared hit=2
                                                                                                     ->  Bitmap Heap Scan on "videoShare" "videoShare_1"  (cost=15.94..131.84 rows=472 width=8) (never executed)
                                                                                                           Recheck Cond: ("actorId" = "actorFollowShare_1"."targetActorId")
                                                                                                           ->  Bitmap Index Scan on video_share_actor_id  (cost=0.00..15.82 rows=472 width=0) (never executed)
                                                                                                                 Index Cond: ("actorId" = "actorFollowShare_1"."targetActorId")
                                                                                             SubPlan 4
                                                                                               ->  Index Scan using actor_follow_actor_id_target_actor_id on "actorFollow"  (cost=0.28..8.30 rows=1 width=0) (actual time=0.001..0.001 rows=0 loops=3049)
                                                                                                     Index Cond: ("actorId" = 1)
                                                                                                     Filter: ((state = 'accepted'::"enum_actorFollow_state") AND (("targetActorId" = account."actorId") OR ("targetActorId" = "videoChannel"."actorId")))
                                                                                                     Buffers: shared hit=6098
                                                                                       ->  Hash  (cost=9.96..9.96 rows=34 width=4) (actual time=0.036..0.037 rows=34 loops=1)
                                                                                             Buckets: 1024  Batches: 1  Memory Usage: 10kB
                                                                                             Buffers: shared hit=7
                                                                                             ->  Bitmap Heap Scan on "accountBlocklist"  (cost=4.54..9.96 rows=34 width=4) (actual time=0.016..0.029 rows=34 loops=1)
                                                                                                   Recheck Cond: ("accountId" = 1)
                                                                                                   Heap Blocks: exact=5
                                                                                                   Buffers: shared hit=7
                                                                                                   ->  Bitmap Index Scan on account_blocklist_account_id_target_account_id  (cost=0.00..4.53 rows=34 width=0) (actual time=0.011..0.011 rows=34 loops=1)
                                                                                                         Index Cond: ("accountId" = 1)
                                                                                                         Buffers: shared hit=2
                                                                                 ->  Index Scan using actor_pkey on actor "accountActor"  (cost=0.29..2.42 rows=1 width=8) (actual time=0.002..0.002 rows=1 loops=3024)
                                                                                       Index Cond: (id = account."actorId")
                                                                                       Buffers: shared hit=9072
                                                                           ->  Materialize  (cost=0.00..1.07 rows=1 width=4) (actual time=0.000..0.000 rows=0 loops=3024)
                                                                                 Buffers: shared hit=1
                                                                                 ->  Seq Scan on "serverBlocklist"  (cost=0.00..1.06 rows=1 width=4) (actual time=0.008..0.008 rows=0 loops=1)
                                                                                       Filter: ("accountId" = 1)
                                                                                       Rows Removed by Filter: 4
                                                                                       Buffers: shared hit=1
                                                         ->  Index Scan using video_pkey on video  (cost=0.28..6.86 rows=1 width=1406) (actual time=0.002..0.002 rows=1 loops=25)
                                                               Index Cond: (id = video_1.id)
                                                               Buffers: shared hit=75
                                                   ->  Index Scan using "videoChannel_pkey" on "videoChannel" "VideoChannel"  (cost=0.29..0.53 rows=1 width=190) (actual time=0.002..0.002 rows=1 loops=25)
                                                         Index Cond: (id = video."channelId")
                                                         Buffers: shared hit=75
                                             ->  Index Scan using actor_pkey on actor "VideoChannel->Actor"  (cost=0.29..2.88 rows=1 width=62) (actual time=0.002..0.002 rows=1 loops=25)
                                                   Index Cond: (id = "VideoChannel"."actorId")
                                                   Buffers: shared hit=75
                                       ->  Index Scan using server_pkey on server "VideoChannel->Actor->Server"  (cost=0.14..0.16 rows=1 width=520) (actual time=0.000..0.000 rows=0 loops=25)
                                             Index Cond: (id = "VideoChannel->Actor"."serverId")
                                 ->  Index Scan using actor_image_actor_id_type_width on "actorImage" "VideoChannel->Actor->Avatars"  (cost=0.28..0.31 rows=1 width=171) (actual time=0.001..0.002 rows=2 loops=25)
                                       Index Cond: (("actorId" = "VideoChannel->Actor".id) AND (type = 1))
                                       Buffers: shared hit=100
                           ->  Index Scan using account_pkey on account "VideoChannel->Account"  (cost=0.29..0.40 rows=1 width=18) (actual time=0.001..0.001 rows=1 loops=50)
                                 Index Cond: (id = "VideoChannel"."accountId")
                                 Buffers: shared hit=150
                     ->  Index Scan using actor_pkey on actor "VideoChannel->Account->Actor"  (cost=0.29..2.42 rows=1 width=62) (actual time=0.002..0.002 rows=1 loops=50)
                           Index Cond: (id = "VideoChannel->Account"."actorId")
                           Buffers: shared hit=150
               ->  Index Scan using server_pkey on server "VideoChannel->Account->Actor->Server"  (cost=0.14..0.16 rows=1 width=520) (actual time=0.000..0.000 rows=0 loops=50)
                     Index Cond: (id = "VideoChannel->Account->Actor"."serverId")
         ->  Index Scan using actor_image_actor_id_type_width on "actorImage" "VideoChannel->Account->Actor->Avatars"  (cost=0.28..0.34 rows=1 width=171) (actual time=0.001..0.001 rows=0 loops=50)
               Index Cond: (("actorId" = "VideoChannel->Account"."actorId") AND (type = 1))
               Buffers: shared hit=100
   ->  Index Scan using thumbnail_video_id on thumbnail "Thumbnails"  (cost=0.28..0.56 rows=2 width=54) (actual time=0.001..0.002 rows=2 loops=50)
         Index Cond: ("videoId" = video.id)
         Buffers: shared hit=152
 Planning Time: 8.606 ms
 Execution Time: 38.293 ms
(131 rows)

[Chocobozzz]

Seems like the query is fast now. Maybe the slow queries happened at a time when PostgreSQL was busy?

[kontrollanten]

Maybe. Here's a list of the occurrences the last week:

postgresql-2024-05-10_000000.log:2024-05-10 10:09:07.696 UTC duration: 811.445 ms
postgresql-2024-05-11_000000.log:2024-05-11 06:14:21.273 UTC duration: 1358.436 ms
postgresql-2024-05-11_000000.log:2024-05-11 06:14:25.798 UTC duration: 5201.666 ms
postgresql-2024-05-12_000000.log:2024-05-12 13:29:52.424 UTC duration: 871.632 ms
postgresql-2024-05-13_000000.log:2024-05-13 11:05:50.006 UTC duration: 1156.646 ms
postgresql-2024-05-13_000000.log:2024-05-13 11:05:52.732 UTC duration: 1067.272 ms
postgresql-2024-05-13_000000.log:2024-05-13 11:05:55.049 UTC duration: 1052.869 ms
postgresql-2024-05-13_000000.log:2024-05-13 11:05:57.374 UTC duration: 1043.540 ms
postgresql-2024-05-13_000000.log:2024-05-13 11:06:03.358 UTC duration: 1118.940 ms
postgresql-2024-05-13_000000.log:2024-05-13 11:06:05.436 UTC duration: 1041.470 ms
postgresql-2024-05-13_000000.log:2024-05-13 11:06:07.509 UTC duration: 1105.826 ms
postgresql-2024-05-13_000000.log:2024-05-13 11:06:09.847 UTC duration: 1090.479 ms
postgresql-2024-05-13_000000.log:2024-05-13 11:06:11.956 UTC duration: 1095.037 ms
postgresql-2024-05-13_000000.log:2024-05-13 11:06:14.286 UTC duration: 1060.308 ms
postgresql-2024-05-13_000000.log:2024-05-13 11:06:18.576 UTC duration: 1036.300 ms
postgresql-2024-05-13_000000.log:2024-05-13 11:06:20.801 UTC duration: 1052.542 ms
postgresql-2024-05-13_000000.log:2024-05-13 11:06:22.983 UTC duration: 1045.277 ms
postgresql-2024-05-13_000000.log:2024-05-13 11:06:48.296 UTC duration: 1141.979 ms
postgresql-2024-05-13_000000.log:2024-05-13 11:07:03.858 UTC duration: 1093.593 ms
postgresql-2024-05-13_000000.log:2024-05-13 11:07:05.563 UTC duration: 1092.796 ms
postgresql-2024-05-13_000000.log:2024-05-13 14:04:11.854 UTC duration: 944.701 ms
postgresql-2024-05-14_000000.log:2024-05-14 20:35:22.295 UTC duration: 1019.773 ms
postgresql-2024-05-14_000000.log:2024-05-14 20:35:26.991 UTC duration: 617.624 ms
postgresql-2024-05-14_000000.log:2024-05-14 20:35:40.730 UTC duration: 513.603 ms
postgresql-2024-05-14_000000.log:2024-05-14 20:35:45.165 UTC duration: 462.124 ms
postgresql-2024-05-14_000000.log:2024-05-14 20:36:25.671 UTC duration: 603.303 ms
postgresql-2024-05-14_000000.log:2024-05-14 20:38:58.053 UTC duration: 1630.728 ms
postgresql-2024-05-14_000000.log:2024-05-14 20:39:07.576 UTC duration: 1120.068 ms
postgresql-2024-05-14_000000.log:2024-05-14 20:40:50.510 UTC duration: 555.220 ms
postgresql-2024-05-14_000000.log:2024-05-14 20:40:51.141 UTC duration: 642.154 ms
postgresql-2024-05-14_000000.log:2024-05-14 20:41:03.868 UTC duration: 2186.297 ms
postgresql-2024-05-14_000000.log:2024-05-14 20:41:55.383 UTC duration: 2344.708 ms
postgresql-2024-05-14_000000.log:2024-05-14 20:43:56.214 UTC duration: 2002.993 ms
postgresql-2024-05-14_000000.log:2024-05-14 20:46:51.685 UTC duration: 1571.020 ms
postgresql-2024-05-14_000000.log:2024-05-14 20:47:01.305 UTC duration: 1094.936 ms
postgresql-2024-05-14_000000.log:2024-05-14 20:48:44.426 UTC duration: 1649.080 ms
postgresql-2024-05-14_204942.log:2024-05-14 23:34:05.305 UTC duration: 838.187 ms
postgresql-2024-05-15_000000.log:2024-05-15 23:57:05.685 UTC duration: 781.050 ms
postgresql-2024-05-17_000000.log:2024-05-17 07:41:27.253 UTC duration: 654.908 ms

They seem to appear in group, that could mean that postgres has been busy while they've been slow.

[Chocobozzz]

Yes, I think it is the cause of the slow query. Closing as I don't think it's a SQL query issue (but don't hesitate to comment if you have many occurrences/more information in the future)