search

plausible / analytics

Simple, open source, lightweight (< 1 KB) and privacy-friendly web analytics alternative to Google Analytics.
https://plausible.io
GNU Affero General Public License v3.0
19.93k stars 1.06k forks source link

After updating from v2, API requests time out for longer time frames #4359

Closed justrealmilk closed 2 months ago

justrealmilk commented 2 months ago

Past Issues Searched

Issue is a Bug Report

Using official Plausible Cloud hosting or self-hosting?

Self-hosting

Describe the bug

Followed upgrade instructions as per https://github.com/plausible/analytics/releases/tag/v2.1.0

The greater the time frame, the longer the request takes to fulfil. Why is it so slow?

2024-07-16T08:20:02.459404945Z Request: GET /api/stats/MY WEBSITE/countries?period=all&date=2024-07-16&filters=%7B%7D&with_imported=true&limit=300
2024-07-16T08:20:02.459409081Z ** (exit) an exception was raised:
2024-07-16T08:20:02.459413081Z     ** (Mint.TransportError) socket closed
2024-07-16T08:20:02.459416700Z         (ecto_sql 3.11.1) lib/ecto/adapters/sql.ex:1054: Ecto.Adapters.SQL.raise_sql_call_error/1
2024-07-16T08:20:02.459421322Z         (ecto_ch 0.3.5) lib/ecto/adapters/clickhouse.ex:319: Ecto.Adapters.ClickHouse.execute/5
2024-07-16T08:20:02.459426310Z         (ecto 3.11.2) lib/ecto/repo/queryable.ex:232: Ecto.Repo.Queryable.execute/4
2024-07-16T08:20:02.459431047Z         (ecto 3.11.2) lib/ecto/repo/queryable.ex:19: Ecto.Repo.Queryable.all/3
2024-07-16T08:20:02.459435469Z         (plausible 0.0.1) lib/plausible/stats/breakdown.ex:334: Plausible.Stats.Breakdown.paginate_and_execute/3
2024-07-16T08:20:02.459439686Z         (plausible 0.0.1) lib/plausible_web/controllers/api/stats_controller.ex:903: PlausibleWeb.Api.StatsController.countries/2
2024-07-16T08:20:02.459461953Z         (plausible 0.0.1) lib/plausible_web/controllers/api/stats_controller.ex:1: PlausibleWeb.Api.StatsController.action/2
2024-07-16T08:20:02.459466271Z         (plausible 0.0.1) lib/plausible_web/controllers/api/stats_controller.ex:1: PlausibleWeb.Api.StatsController.phoenix_controller_pipeline/2
2024-07-16T08:20:02.462911228Z 08:20:02.461 [error] Ch.Connection (#PID<0.4217.0>) disconnected: ** (DBConnection.ConnectionError) client #PID<0.4882.0> timed out because it queued and checked out the connection for longer than 15000ms
2024-07-16T08:20:02.462931599Z 
2024-07-16T08:20:02.462935928Z #PID<0.4882.0> was at location:
2024-07-16T08:20:02.462939821Z 
2024-07-16T08:20:02.462953875Z     :prim_inet.recv0/3
2024-07-16T08:20:02.462957768Z     (mint 1.6.0) lib/mint/core/transport/tcp.ex:67: Mint.Core.Transport.TCP.recv/3
2024-07-16T08:20:02.462961371Z     (mint 1.6.0) lib/mint/http1.ex:519: Mint.HTTP1.recv/3
2024-07-16T08:20:02.462965126Z     (ch 0.2.5) lib/ch/connection.ex:335: Ch.Connection.recv_all/3
2024-07-16T08:20:02.462968870Z     (ch 0.2.5) lib/ch/connection.ex:313: Ch.Connection.receive_full_response/2
2024-07-16T08:20:02.462972774Z     (ch 0.2.5) lib/ch/connection.ex:249: Ch.Connection.handle_execute/4
2024-07-16T08:20:02.462976490Z     (db_connection 2.6.0) lib/db_connection/holder.ex:354: DBConnection.Holder.holder_apply/4
2024-07-16T08:20:02.462980529Z     (db_connection 2.6.0) lib/db_connection.ex:1512: DBConnection.run_execute/5
2024-07-16T08:20:02.462984654Z 
2024-07-16T08:20:02.463961300Z 08:20:02.461 [error] Task #PID<0.4882.0> started from #PID<0.4874.0> terminating
2024-07-16T08:20:02.463998443Z ** (Mint.TransportError) timeout
2024-07-16T08:20:02.464003378Z     (ecto_sql 3.11.1) lib/ecto/adapters/sql.ex:1054: Ecto.Adapters.SQL.raise_sql_call_error/1
2024-07-16T08:20:02.464008384Z     (ecto_ch 0.3.5) lib/ecto/adapters/clickhouse.ex:319: Ecto.Adapters.ClickHouse.execute/5
2024-07-16T08:20:02.464012271Z     (ecto 3.11.2) lib/ecto/repo/queryable.ex:232: Ecto.Repo.Queryable.execute/4
2024-07-16T08:20:02.464016022Z     (ecto 3.11.2) lib/ecto/repo/queryable.ex:19: Ecto.Repo.Queryable.all/3
2024-07-16T08:20:02.464019946Z     (ecto 3.11.2) lib/ecto/repo/queryable.ex:154: Ecto.Repo.Queryable.one/3
2024-07-16T08:20:02.464024048Z     (elixir 1.16.0) lib/task/supervised.ex:101: Task.Supervised.invoke_mfa/2
2024-07-16T08:20:02.464027778Z     (elixir 1.16.0) lib/task/supervised.ex:36: Task.Supervised.reply/4
2024-07-16T08:20:02.464033459Z Function: &:erlang.apply/2
2024-07-16T08:20:02.464037339Z     Args: [#Function<0.16863069/1 in Plausible.ClickhouseRepo.parallel_tasks/2>, [#Function<0.22789665/0 in Plausible.Stats.Aggregate.aggregate/3>]]
2024-07-16T08:20:02.464653944Z 08:20:02.463 [error] Ranch protocol #PID<0.4874.0> of listener PlausibleWeb.Endpoint.HTTP (connection #PID<0.4873.0>, stream id 1) terminated
2024-07-16T08:20:02.464679230Z an exception was raised:
2024-07-16T08:20:02.464683234Z     ** (Mint.TransportError) timeout
2024-07-16T08:20:02.464686814Z         (ecto_sql 3.11.1) lib/ecto/adapters/sql.ex:1054: Ecto.Adapters.SQL.raise_sql_call_error/1
2024-07-16T08:20:02.464690766Z         (ecto_ch 0.3.5) lib/ecto/adapters/clickhouse.ex:319: Ecto.Adapters.ClickHouse.execute/5
2024-07-16T08:20:02.464694417Z         (ecto 3.11.2) lib/ecto/repo/queryable.ex:232: Ecto.Repo.Queryable.execute/4
2024-07-16T08:20:02.464698057Z         (ecto 3.11.2) lib/ecto/repo/queryable.ex:19: Ecto.Repo.Queryable.all/3
2024-07-16T08:20:02.464712093Z         (ecto 3.11.2) lib/ecto/repo/queryable.ex:154: Ecto.Repo.Queryable.one/3
2024-07-16T08:20:02.464715817Z         (elixir 1.16.0) lib/task/supervised.ex:101: Task.Supervised.invoke_mfa/2
2024-07-16T08:20:02.464719448Z         (elixir 1.16.0) lib/task/supervised.ex:36: Task.Supervised.reply/4
2024-07-16T08:20:02.470954166Z 08:20:02.467 [error] Ch.Connection (#PID<0.4214.0>) disconnected: ** (DBConnection.ConnectionError) client #PID<0.4885.0> timed out because it queued and checked out the connection for longer than 15000ms
2024-07-16T08:20:02.470971517Z 
2024-07-16T08:20:02.470975458Z #PID<0.4885.0> was at location:
2024-07-16T08:20:02.470979047Z 
2024-07-16T08:20:02.470991975Z     :prim_inet.recv0/3
2024-07-16T08:20:02.470995627Z     (mint 1.6.0) lib/mint/core/transport/tcp.ex:67: Mint.Core.Transport.TCP.recv/3
2024-07-16T08:20:02.471002860Z     (mint 1.6.0) lib/mint/http1.ex:519: Mint.HTTP1.recv/3
2024-07-16T08:20:02.471006868Z     (ch 0.2.5) lib/ch/connection.ex:335: Ch.Connection.recv_all/3
2024-07-16T08:20:02.471010545Z     (ch 0.2.5) lib/ch/connection.ex:313: Ch.Connection.receive_full_response/2
2024-07-16T08:20:02.471016790Z     (ch 0.2.5) lib/ch/connection.ex:249: Ch.Connection.handle_execute/4
2024-07-16T08:20:02.471020537Z     (db_connection 2.6.0) lib/db_connection/holder.ex:354: DBConnection.Holder.holder_apply/4
2024-07-16T08:20:02.471024213Z     (db_connection 2.6.0) lib/db_connection.ex:1512: DBConnection.run_execute/5
2024-07-16T08:20:02.471028049Z 
2024-07-16T08:20:02.471031545Z 08:20:02.467 [error] Task #PID<0.4885.0> started from #PID<0.4875.0> terminating
2024-07-16T08:20:02.471035564Z ** (Mint.TransportError) socket closed
2024-07-16T08:20:02.471043978Z     (ecto_sql 3.11.1) lib/ecto/adapters/sql.ex:1054: Ecto.Adapters.SQL.raise_sql_call_error/1
2024-07-16T08:20:02.471047621Z     (ecto_ch 0.3.5) lib/ecto/adapters/clickhouse.ex:319: Ecto.Adapters.ClickHouse.execute/5
2024-07-16T08:20:02.471051515Z     (ecto 3.11.2) lib/ecto/repo/queryable.ex:232: Ecto.Repo.Queryable.execute/4
2024-07-16T08:20:02.471055403Z     (ecto 3.11.2) lib/ecto/repo/queryable.ex:19: Ecto.Repo.Queryable.all/3
2024-07-16T08:20:02.471059220Z     (elixir 1.16.0) lib/task/supervised.ex:101: Task.Supervised.invoke_mfa/2
2024-07-16T08:20:02.471074106Z     (elixir 1.16.0) lib/task/supervised.ex:36: Task.Supervised.reply/4
2024-07-16T08:20:02.471078070Z Function: &:erlang.apply/2
2024-07-16T08:20:02.471081681Z     Args: [#Function<0.16863069/1 in Plausible.ClickhouseRepo.parallel_tasks/2>, [#Function<5.90381287/0 in Plausible.Stats.Timeseries.timeseries/3>]]
2024-07-16T08:20:02.471086065Z 08:20:02.469 [error] Ranch protocol #PID<0.4875.0> of listener PlausibleWeb.Endpoint.HTTP (connection #PID<0.4872.0>, stream id 1) terminated
2024-07-16T08:20:02.471090162Z an exception was raised:
2024-07-16T08:20:02.471093610Z     ** (Mint.TransportError) socket closed
2024-07-16T08:20:02.471097220Z         (ecto_sql 3.11.1) lib/ecto/adapters/sql.ex:1054: Ecto.Adapters.SQL.raise_sql_call_error/1
2024-07-16T08:20:02.471100876Z         (ecto_ch 0.3.5) lib/ecto/adapters/clickhouse.ex:319: Ecto.Adapters.ClickHouse.execute/5
2024-07-16T08:20:02.471105747Z         (ecto 3.11.2) lib/ecto/repo/queryable.ex:232: Ecto.Repo.Queryable.execute/4
2024-07-16T08:20:02.471109559Z         (ecto 3.11.2) lib/ecto/repo/queryable.ex:19: Ecto.Repo.Queryable.all/3
2024-07-16T08:20:02.471113409Z         (elixir 1.16.0) lib/task/supervised.ex:101: Task.Supervised.invoke_mfa/2
2024-07-16T08:20:02.471117373Z         (elixir 1.16.0) lib/task/supervised.ex:36: Task.Supervised.reply/4
2024-07-16T08:20:02.472951588Z 08:20:02.472 [error] Ch.Connection (#PID<0.4218.0>) disconnected: ** (DBConnection.ConnectionError) client #PID<0.4878.0> timed out because it queued and checked out the connection for longer than 15000ms
2024-07-16T08:20:02.472964361Z 
2024-07-16T08:20:02.472967979Z #PID<0.4878.0> was at location:
2024-07-16T08:20:02.472971793Z 
2024-07-16T08:20:02.472975141Z     :prim_inet.recv0/3
2024-07-16T08:20:02.472978698Z     (mint 1.6.0) lib/mint/core/transport/tcp.ex:67: Mint.Core.Transport.TCP.recv/3
2024-07-16T08:20:02.472982444Z     (mint 1.6.0) lib/mint/http1.ex:519: Mint.HTTP1.recv/3
2024-07-16T08:20:02.472985984Z     (ch 0.2.5) lib/ch/connection.ex:335: Ch.Connection.recv_all/3
2024-07-16T08:20:02.472989646Z     (ch 0.2.5) lib/ch/connection.ex:313: Ch.Connection.receive_full_response/2
2024-07-16T08:20:02.472993464Z     (ch 0.2.5) lib/ch/connection.ex:249: Ch.Connection.handle_execute/4
2024-07-16T08:20:02.473005606Z     (db_connection 2.6.0) lib/db_connection/holder.ex:354: DBConnection.Holder.holder_apply/4
2024-07-16T08:20:02.473009423Z     (db_connection 2.6.0) lib/db_connection.ex:1512: DBConnection.run_execute/5
2024-07-16T08:20:02.473013019Z

Expected behavior

A successful API request as per the previous version!

Screenshots

No response

Environment

No response