Ash Framework•4mo ago

Cinder.Table count timeout not working as expected

Hey @sevenseacat i saw that there was a new version with fixes for the timeout and this issue was closed (https://github.com/sevenseacat/cinder/issues/7) But i'm still getting the same error even when setting the query_opts={[timeout: :timer.seconds(20)]}

11:52:17.499 [error] Task #PID<0.16899.0> started from #PID<0.16897.0> terminating
** (stop) exited in: Task.await(%Task{mfa: {:erlang, :apply, 2}, owner: #PID<0.16899.0>, pid: #PID<0.16900.0>, ref: #Reference<0.0.2163075.2654478720.718864387.182882>}, 5000)
    ** (EXIT) time out
    (elixir 1.18.4) lib/task.ex:888: Task.await_receive/3
    (ash 3.5.23) lib/ash/actions/read/read.ex:3205: Ash.Actions.Read.maybe_await/1
    (ash 3.5.23) lib/ash/actions/read/read.ex:654: anonymous fn/8 in Ash.Actions.Read.do_read/5
    (ash 3.5.23) lib/ash/process_helpers.ex:38: anonymous fn/4 in Ash.ProcessHelpers.async/2
    (elixir 1.18.4) lib/task/supervised.ex:101: Task.Supervised.invoke_mfa/2
    (elixir 1.18.4) lib/task/supervised.ex:36: Task.Supervised.reply/4
Function: #Function<0.98117759/0 in Ash.ProcessHelpers.async/2>
    Args: [] { }

11:52:17.499 [error] Task #PID<0.16899.0> started from #PID<0.16897.0> terminating
** (stop) exited in: Task.await(%Task{mfa: {:erlang, :apply, 2}, owner: #PID<0.16899.0>, pid: #PID<0.16900.0>, ref: #Reference<0.0.2163075.2654478720.718864387.182882>}, 5000)
    ** (EXIT) time out
    (elixir 1.18.4) lib/task.ex:888: Task.await_receive/3
    (ash 3.5.23) lib/ash/actions/read/read.ex:3205: Ash.Actions.Read.maybe_await/1
    (ash 3.5.23) lib/ash/actions/read/read.ex:654: anonymous fn/8 in Ash.Actions.Read.do_read/5
    (ash 3.5.23) lib/ash/process_helpers.ex:38: anonymous fn/4 in Ash.ProcessHelpers.async/2
    (elixir 1.18.4) lib/task/supervised.ex:101: Task.Supervised.invoke_mfa/2
    (elixir 1.18.4) lib/task/supervised.ex:36: Task.Supervised.reply/4
Function: #Function<0.98117759/0 in Ash.ProcessHelpers.async/2>
    Args: [] { }

Idk how exactly the count is handled in Cinder but in Ash there is a way to automatically ask for count? Im trying to understand how it reaches the function in the stack trace, there is a Task.await without opts so that is where the timeout 5000 is coming from, these defaults https://hexdocs.pm/elixir/Task.html#await/2

Solution:

I can fix that

Jump to solution

11 Replies

sevenseacat•4mo ago

if Ash isn't respecting the timeout option we pass in, that's not good 🤔 Cinder provides pagination options when building the query, and Ash handles the rest https://github.com/sevenseacat/cinder/blob/main/lib/cinder/query_builder.ex#L83-L96 I can see the Task.await but also not sure where the task is coming from ok found it, and the opts should be getting passed through 🤔

AhrouOP•4mo ago

then the behaviour is def weird 🤔

sevenseacat•4mo ago

digging into it

ZachDaniel•4mo ago

Looks like a missing :infinity to me 🙂

AhrouOP•4mo ago

wouldnt it be better to inherit the query_opts timeout or the ash config one? otherwise if there is an issue with the DB that connection would get stuck

sevenseacat•4mo ago

this is only used for the count query, no other query though tbh a count query shouldnt be taking 5 seconds 🙈

ZachDaniel•4mo ago

Yes it should timeout similarly to the parent query

Solution

sevenseacat•4mo ago

I can fix that

AhrouOP•4mo ago

I had no idea it was taking that long either, its just a users_status_history table just did an analyze and it took 13seconds 🙈

QUERY PLAN
Finalize Aggregate  (cost=566488.77..566488.78 rows=1 width=8) (actual time=13519.753..13526.001 rows=1 loops=1)
  ->  Gather  (cost=566488.55..566488.76 rows=2 width=8) (actual time=13519.642..13525.994 rows=3 loops=1)
        Workers Planned: 2
        Workers Launched: 2
        ->  Partial Aggregate  (cost=565488.55..565488.56 rows=1 width=8) (actual time=13511.709..13511.710 rows=1 loops=3)
              ->  Parallel Index Only Scan using idx_users_status_history_created_at on users_status_history  (cost=0.43..551516.39 rows=5588866 width=0) (actual time=0.042..13209.618 rows=4467092 loops=3)
                    Heap Fetches: 5891823
Planning Time: 0.081 ms
Execution Time: 13526.056 ms

QUERY PLAN
Finalize Aggregate  (cost=566488.77..566488.78 rows=1 width=8) (actual time=13519.753..13526.001 rows=1 loops=1)
  ->  Gather  (cost=566488.55..566488.76 rows=2 width=8) (actual time=13519.642..13525.994 rows=3 loops=1)
        Workers Planned: 2
        Workers Launched: 2
        ->  Partial Aggregate  (cost=565488.55..565488.56 rows=1 width=8) (actual time=13511.709..13511.710 rows=1 loops=3)
              ->  Parallel Index Only Scan using idx_users_status_history_created_at on users_status_history  (cost=0.43..551516.39 rows=5588866 width=0) (actual time=0.042..13209.618 rows=4467092 loops=3)
                    Heap Fetches: 5891823
Planning Time: 0.081 ms
Execution Time: 13526.056 ms

sevenseacat•4mo ago

yeah that's weird

abeeshake456•4mo ago

I did not know of this package!! Thanks for asking questoin 🥳

Gaming

Programming

Cinder.Table count timeout not working as expected

Did you find this page helpful?