search

etalab / transport-site

Rendre disponible, valoriser et améliorer les données transports
https://transport.data.gouv.fr
194 stars 30 forks source link

Mieux comprendre le souci de TTL sur Cachex #2028

Closed thbar closed 1 year ago

thbar commented 2 years ago

Je re-crée une méta-issue car le problème pourra nous affecter non seulement sur le proxy mais ailleurs.

Éléments relatifs directement sur le proxy

Eléments qui pourraient nous impacter ailleurs

Solutions alternatives

thbar commented 2 years ago

Une idée est d'aller faire du "fuzzing" en local, en enlevant le correctif, pour essayer de reproduire le souci.

AntoineAugusti commented 1 year ago

Voir https://github.com/whitfin/cachex/issues/304

thbar commented 1 year ago

Je ne sais pas si j'ai fait n'importe quoi dans ce code, et c'est bien possible, mais quelque chose m'interpelle ici (version plus réduite de ce qu'avait fait @AntoineAugusti sur https://github.com/whitfin/cachex/issues/304).

J'ai la sensation que l'appel à "expire" va attendre que les autres fetchs soient terminés avant de s'exécuter, ce qui me paraît au final un peu normal.

Mais ça semble un peu un autre problème que ce qu'on a constaté au final : le TTL serait temporairement remonté comme étant à nil, mais uniquement le temps que l'autre transaction se termine ???

Output:

❯ elixir other-repro.exs

Round...

#PID<0.203.0> - ~T[10:53:21.024554] calling fetch...
#PID<0.204.0> - ~T[10:53:21.024621] calling fetch...
#PID<0.205.0> - ~T[10:53:21.024641] calling fetch...
#PID<0.206.0> I'm computing...
#PID<0.203.0> - ~T[10:53:26.037074] commit - setting expire
#PID<0.203.0> - ~T[10:53:26.039463] commit - expire set
#PID<0.204.0> - ~T[10:53:26.038401] we have nil TTL (return is {:ok, 42})
#PID<0.205.0> - ~T[10:53:26.038444] we have nil TTL (return is {:ok, 42})
#PID<0.203.0> - ~T[10:53:26.039543] we have TTL 100000 (return is {:commit, 42})

Round...

#PID<0.208.0> - ~T[10:53:27.046076] calling fetch...
#PID<0.208.0> - ~T[10:53:27.046262] we have TTL 98993 (return is {:ok, 42})
#PID<0.209.0> - ~T[10:53:27.046323] calling fetch...
#PID<0.210.0> - ~T[10:53:27.046380] calling fetch...
#PID<0.209.0> - ~T[10:53:27.046418] we have TTL 98993 (return is {:ok, 42})
#PID<0.210.0> - ~T[10:53:27.046468] we have TTL 98993 (return is {:ok, 42})
Mix.install([{:cachex, github: "whitfin/cachex", branch: "main"}])

defmodule Test do
  require Logger

  def cache_name, do: :cache

  def func(_x) do
    :timer.sleep(5_000)
    {:commit, 42}
  end
end

Cachex.start_link(Test.cache_name(), [])

cache_key = "hello-world"

1..2
|> Enum.each(fn _ ->
  IO.puts("\nRound...\n")
  :timer.sleep(1_000)

  1..3
  |> Task.async_stream(
    fn _ ->
      IO.puts("#{self() |> inspect()} - #{Time.utc_now() |> inspect()} calling fetch...")

      result =
        with {:commit, val} <- Cachex.fetch(Test.cache_name(), cache_key, &Test.func/1) do
          IO.puts(
            "#{self() |> inspect()} - #{Time.utc_now() |> inspect()} commit - setting expire"
          )

          {:ok, true} = Cachex.expire(Test.cache_name(), cache_key, :timer.seconds(100))
          IO.puts("#{self() |> inspect()} - #{Time.utc_now() |> inspect()} commit - expire set")
          {:commit, val}
        else
          {:ok, val} ->
            {:ok, val}

          x ->
            IO.inspect(x)
            []
        end

      {:ok, ttl} = Cachex.ttl(Test.cache_name(), cache_key)

      if is_nil(ttl) do
        IO.puts(
          "#{self() |> inspect()} - #{Time.utc_now() |> inspect()} we have nil TTL (return is #{result |> inspect})"
        )
      else
        IO.puts(
          "#{self() |> inspect()} - #{Time.utc_now() |> inspect()} we have TTL #{ttl} (return is #{result |> inspect})"
        )
      end
    end,
    max_concurrency: 100,
    timeout: :infinity
  )
  |> Enum.each(fn _ -> :ok end)
end)
thbar commented 1 year ago

Petite tentative de reproduction en local avec le code de l'application, mais pour l'instant je n'aboutis pas à une situation où le TTL serait de façon permanente à nil. Je conserve toutefois le code (à démarrer avec mix run scripts/repro.exs ça servira sûrement !

# scripts/repro.exs
Logger.configure(level: :info)

defmodule Report do
  def test do
    {:ok, ttl} = Cachex.ttl(:transport, "home-index-stats")

    if is_nil(ttl) do
      IO.inspect("#{self() |> inspect} TTL=#{ttl |> inspect}")
    else
      IO.puts("TTL=#{ttl |> inspect}")
    end
  end
end

1..2_000_000
|> Task.async_stream(
  fn _ ->
    Transport.Cache.API.fetch(
      "home-index-stats",
      fn ->
        TransportWeb.PageController.compute_home_index_stats()
      end,
      :timer.seconds(1)
    )

    Report.test()
  end,
  max_concurrency: 1_0_000,
  timeout: :infinity
)
|> Enum.each(fn _ -> :ok end)
thbar commented 1 year ago

En ayant travaillé sur #2960, je retrouve bien le souci via iex, ce qui est "rassurant":

❯ clever ssh --alias prod-site   
# SNIP
iex(node@XYZ)1> Cachex.keys(:transport)
{:ok,
 ["unavailabilities_dataset_12", "home-index-stats",
  "unavailabilities_dataset_347"]}
iex(node@XYZ)2> Cachex.ttl(
ttl(cache, key, options \\ [])    
iex(node@XYZ)2> Cachex.ttl(:transport, "home-index-stats")
{:ok, nil}

Pour le déclencher en pratique il m'a "suffit" de faire un refresh de la home page plusieurs fois.

AntoineAugusti commented 1 year ago

Devrait être résolu par https://github.com/etalab/transport-site/pull/2961