Lost sessions using PowPersistentSession

[danschultzer]

This is a continuation of #356 as that issue has gotten too long to keep track of it.

I believe this issue is multifaceted so there is no one way to solve it. First let's review what has been resolved.

Resolved

1. Persistent session cookie deleted

Partly resolved in #366 and fully in #390. This caused lost sessions when there was multiple simultaneous requests at once, as the first succeeds, rolls the id and sets the cookie, while subsequent requests will delete the cookie even as the cookie already was updated since they use the same cookie name.

The backend shouldn't delete any cookie in the client, it should only override it if there's a new value for it.

2. Only store or delete tokens and cookies once request is done processing

Resolved in #398. The tokens and cookies should only be stored once the request has finished processing. This is how Plug.Session works as well. I don't know enough of the internals, but believe that this prevents or greatly limits issues where a token is rolled but the response was never received due to network issue.

As some requests can be slow to process with heavy queries, some clients might cut it early instead of waiting for the response with updated cookie. This would cause the session to be lost.

3. Race condition with multiple requests

Resolved in #414. This prevents a race condition where multiple requests try to roll the token at the same time. Instead subsequent requests will just bypass the whole token logic and just assign the current user. This is a similar issue to the above where slow requests in particular would experience issues where some requests being signed in and others not.

In this issue there are no sessions being lost, but some requests might not show as authenticated.

Why does session and persistent session work this way?

For security. It shouldn't be possible to use a persistent session token more than once, and sessions has to be short-lived and renewed constantly. Old session id's shouldn't be reusable either.

It's up to the individual platforms to implement reusable tokens as it'll introduce additional attack vectors. This would be the last permanent step once everything else has been resolved.

Common scenario

This issue seems to be prevalent in scenarios where the client fires numerous simultaneous requests (e.g. AJAX). The above fixes have stopped the issue from being reproducible in my local setup.

Status

I'm still getting reports of lost sessions. I'll have to review what else can be done. Please comment if you are able to identify issues and replicate them.

[danschultzer]

So here's a potential solution for issues with sessions that might not be related to Pow. It's being deployed in derpibooru/philomena#36.

Please use this with care as it may mask underlying implementation issues that should be resolved first. It may fix any issues you got with dropped network connection or race condition.

It works in two parts:

1. The current session id and/or persistent session token is loaded before the Pow plugs. A before send hook is registered for the conn, that will check if these values have changed after the Pow plugs have been called. If changed, the token(s) along with the user is stored in a cache that expires after 60 seconds.

2. After the Pow plugs have been called and if they didn't assign a user to the conn, the session id and/or persistent session token will be used to load the user from the aforementioned cache. If found, the user will be assigned to the conn.

The plug:

defmodule MyAppWeb.Pow.InvalidatedSessionPlug do
  @moduledoc """
  This plug ensures that invalidated sessions can still be used for a short
  amount of time.

  This MAY introduce a slight timing attack vector, but in practice would be
  unlikely as all tokens expires after 60 seconds.

  ## Example

      plug MyAppWeb.PowInvalidatedSessionPlug, :pow_session
      plug MyAppWeb.PowInvalidatedSessionPlug, :pow_persistent_session
      plug Pow.Plug.Session, otp_app: :my_app
      plug PowPersistentSession.Plug.Cookie
      plug MyAppWeb.PowInvalidatedSessionPlug, :load

  """
  alias Plug.Conn
  alias Pow.{Config, Plug, Store.Backend.EtsCache}

  @store_ttl :timer.minutes(1)
  @otp_app :my_app_web
  @session_key "#{@otp_app}_auth"
  @session_signing_salt Atom.to_string(Pow.Plug.Session)
  @persistent_cookie_key "#{@otp_app}_persistent_session"
  @persistent_cookie_signing_salt Atom.to_string(PowPersistentSession.Plug.Cookie)

  def init(:load), do: :load
  def init(:pow_session) do
    [
      fetch_token: &__MODULE__.client_store_fetch_session/1,
      namespace: :session
    ]
  end
  def init(:pow_persistent_session) do
    [
      fetch_token: &__MODULE__.client_store_fetch_persistent_cookie/1,
      namespace: :persistent_session
    ]
  end
  def init({type, opts}) do
    type
    |> init()
    |> Keyword.merge(opts)
  end

  def call(conn, :load) do
    Enum.reduce(conn.private[:invalidated_session_opts], conn, fn opts, conn ->
      maybe_load_from_cache(conn, Plug.current_user(conn), opts)
    end)
  end
  def call(conn, opts) do
    fetch_fn = Keyword.fetch!(opts, :fetch_token)
    token    = fetch_fn.(conn)

    conn
    |> put_opts_in_private(opts)
    |> Conn.register_before_send(fn conn ->
      maybe_put_cache(conn, Plug.current_user(conn), token, opts)
    end)
  end

  defp maybe_load_from_cache(conn, nil, opts) do
    fetch_fn = Keyword.fetch!(opts, :fetch_token)

    case fetch_fn.(conn) do
      nil   -> conn
      token -> load_from_cache(conn, token, opts)
    end
  end
  defp maybe_load_from_cache(conn, _any, _opts), do: conn

  defp put_opts_in_private(conn, opts) do
    plug_opts = (conn.private[:invalidated_session_opts] || []) ++ [opts]

    Conn.put_private(conn, :invalidated_session_opts, plug_opts)
  end

  defp maybe_put_cache(conn, nil, _old_token, _opts), do: conn
  defp maybe_put_cache(conn, _user, nil, _opts), do: conn
  defp maybe_put_cache(conn, user, old_token, opts) do
    fetch_fn = Keyword.fetch!(opts, :fetch_token)

    # This is used to load in any session metadata you use for authorization,
    # use this with care and ensure to add tests for it.
    metadata = [] 
    # metadata =
    #    conn.private
    #    |> Map.get(:pow_session_metadata, [])
    #    |> Keyword.take([:a, :b, :c])

    case fetch_fn.(conn) do
      ^old_token -> conn
      _token     -> put_cache(conn, {user, metadata}, old_token, opts)
    end
  end

  defp put_cache(conn, user, token, opts) do
    {store, store_config} = invalidated_cache(conn, opts)

    store.put(store_config, token, user)

    conn
  end

  defp load_from_cache(conn, token, opts) do
    config                = Plug.fetch_config(conn)
    {store, store_config} = invalidated_cache(conn, opts)

    case store.get(store_config, token) do
      :not_found ->
        conn

      {user, metadata} ->
        metadata = Keyword.merge(metadata, conn.private[:pow_session_metadata] || [])

        conn
        |> Conn.put_private(:pow_session_metadata, metadata)
        |> Plug.assign_current_user(user, config)
    end
  end

  @doc false
  def client_store_fetch_session(conn) do
    conn =
      conn
      |> Plug.put_config(otp_app: @otp_app)
      |> Conn.fetch_session()

    with session_id when is_binary(session_id) <- Conn.get_session(conn, @session_key),
         {:ok, session_id}                     <- Plug.verify_token(conn, @session_signing_salt, session_id) do
      session_id
    else
      _any -> nil
    end
  end

  @doc false
  def client_store_fetch_persistent_cookie(conn) do
    conn =
      conn
      |> Plug.put_config(otp_app: @otp_app)
      |> Conn.fetch_cookies()

    with token when is_binary(token) <- conn.cookies[@persistent_cookie_key],
         {:ok, token}                <- Plug.verify_token(conn, @persistent_cookie_signing_salt, token) do
      token
    else
      _any -> nil
    end

  end

  defp invalidated_cache(conn, opts) do
    store_config = store_config(opts)
    config       = Plug.fetch_config(conn)
    store        = Config.get(config, :cache_store_backend, EtsCache)

    {store, store_config}
  end

  defp store_config(opts) do
    namespace = Keyword.fetch!(opts, :namespace)
    ttl       = Keyword.get(opts, :ttl, @store_ttl)

    [
      ttl: ttl,
      namespace: "invalidated_#{namespace}",
    ]
  end
end

Test module:

defmodule MyAppWeb.PowInvalidatedSessionPlugTest do
  use MyAppWeb.ConnCase
  doctest MyAppWeb.PowInvalidatedSessionPlug

  alias MyAppWeb.PowInvalidatedSessionPlug
  alias MyApp.{Users.User, Repo}

  @otp_app :my_app_web
  @config [otp_app: @otp_app, user: User, repo: Repo]
  @session_key "#{@otp_app}_auth"
  @cookie_key "#{@otp_app}_persistent_session"
  @invalidated_ttl 250

  alias Plug.{Conn, Test}
  alias Plug.Session, as: PlugSession
  alias Pow.Plug.Session
  alias PowPersistentSession.Plug.Cookie

  setup do
    user =
      %User{}
      |> User.changeset(%{"email" => "test@example.com", "password" => "password", "password_confirmation" => "password"})
      |> Repo.insert!()

    {:ok, user: user}
  end

  test "call/2 session id is reusable for short amount of time", %{conn: init_conn, user: user} do
    config    = Keyword.put(@config, :session_ttl_renewal, 0)
    init_conn = prepare_session_conn(init_conn, user, config)

    assert session_id =
      init_conn
      |> init_session_plug()
      |> Conn.fetch_session()
      |> Conn.get_session(@session_key)

    conn = run_plug(init_conn, config)

    assert Pow.Plug.current_user(conn).id == user.id
    assert Conn.get_session(conn, @session_key) != session_id

    :timer.sleep(100)
    conn = run_plug(init_conn, config)

    assert Pow.Plug.current_user(conn).id == user.id
    assert Conn.get_session(conn, @session_key) == session_id

    :timer.sleep(@invalidated_ttl - 100)
    conn = run_plug(init_conn)

    refute Pow.Plug.current_user(conn)
  end

  test "call/2 persistent session id is reusable", %{conn: init_conn, user: user} do
    init_conn = prepare_persistent_session_conn(init_conn, user)

    assert persistent_session_id = init_conn.req_cookies[@cookie_key]

    conn = run_plug(init_conn)

    assert Pow.Plug.current_user(conn).id == user.id
    assert conn.cookies[@cookie_key] != persistent_session_id

    :timer.sleep(100)
    conn = run_plug(init_conn)

    assert Pow.Plug.current_user(conn).id == user.id
    assert conn.cookies[@cookie_key] == persistent_session_id

    :timer.sleep(@invalidated_ttl - 100)
    conn = run_plug(init_conn)

    refute Pow.Plug.current_user(conn)
    assert conn.cookies[@cookie_key] == persistent_session_id
  end

  defp init_session_plug(conn) do
    conn
    |> Map.put(:secret_key_base, String.duplicate("abcdefghijklmnopqrstuvxyz0123456789", 2))
    |> PlugSession.call(PlugSession.init(store: :cookie, key: "foobar", signing_salt: "salt"))
  end

  defp init_plug(conn, config) do
    conn
    |> init_session_plug()
    |> PowInvalidatedSessionPlug.call(PowInvalidatedSessionPlug.init({:pow_session, ttl: @invalidated_ttl}))
    |> PowInvalidatedSessionPlug.call(PowInvalidatedSessionPlug.init({:pow_persistent_session, ttl: @invalidated_ttl}))
    |> Session.call(Session.init(config))
    |> Cookie.call(Cookie.init([]))
    |> PowInvalidatedSessionPlug.call(PowInvalidatedSessionPlug.init(:load))
  end

  defp run_plug(conn, config \\ @config) do
    conn
    |> init_plug(config)
    |> Conn.send_resp(200, "")
  end

  defp create_persistent_session(conn, user, config) do
    conn
    |> init_plug(config)
    |> Session.do_create(user, config)
    |> Cookie.create(user, config)
    |> Conn.send_resp(200, "")
  end

  defp prepare_persistent_session_conn(conn, user, config \\ @config) do
    session_conn = create_persistent_session(conn, user, config)

    :timer.sleep(100)

    no_session_conn =
      conn
      |> Test.recycle_cookies(session_conn)
      |> delete_session_from_conn(config)

    :timer.sleep(100)

    conn
    |> Test.recycle_cookies(no_session_conn)
    |> Conn.fetch_cookies()
  end

  defp delete_session_from_conn(conn, config) do
    conn
    |> init_plug(config)
    |> Session.do_delete(config)
    |> Conn.send_resp(200, "")
  end


  defp create_session(conn, user, config) do
    conn
    |> init_plug(config)
    |> Session.do_create(user, config)
    |> Conn.send_resp(200, "")
  end

  defp prepare_session_conn(conn, user, config) do
    session_conn = create_session(conn, user, config)

    :timer.sleep(100)

    Test.recycle_cookies(conn, session_conn)
  end
end

[augnustin]

👍 here

I just upgraded to 1.0.20 and it seems like I still have lost sessions issues. (Using Mnesia cache store).

As far as I'm concerned, I haven't found a way to reproduce it deterministically but will definitely investigate on this and follow this issue with much attention.

[liamwhite]

After tracing through the code for a while, here is a series of parallel requests which would cause a problem with this module (and some variation of this is probably the reason we are still seeing issues in philomena):

1. request 1 begins
2. request 1 registers a before_send for putting the Pow session into the invalidated cache
3. request 1 registers a before_send for putting the Pow persistent session into the invalidated cache
4. request 1 determines that the session must be rolled; it acquires a lock, invalidates the session and consumes the old persistent session token
5. request 2 begins
6. request 2 registers a before_send for putting the Pow session into the invalidated cache
7. request 2 registers a before_send for putting the Pow persistent session into the invalidated cache
8. request 2 determines that the session is invalid and doesn't load the user
9. request 2 attempts to load the user from the invalidated cache, fails
10. request 1 issues a write to the invalidated cache for the persistent session in its before_send callback
11. request 1 issues a write to the invalidated cache for the session in its before_send callback
12. request 1 finishes
13. request 2 finishes

The fix for this has to be to write the invalidated session data before the session/persistent session are invalidated. The naive approach of modifying this bit of the invalidated session plug from this

  def call(conn, opts) do
    fetch_fn = Keyword.fetch!(opts, :fetch_token)
    token    = fetch_fn.(conn)

    conn
    |> put_opts_in_private(opts)
    |> Conn.register_before_send(fn conn ->
      maybe_put_cache(conn, Plug.current_user(conn), token, opts)
    end)
  end

to this

  def call(conn, opts) do
    fetch_fn = Keyword.fetch!(opts, :fetch_token)
    token = fetch_fn.(conn)

    conn
    |> put_opts_in_private(opts)
    |> maybe_put_cache(Plug.current_user(conn), token, opts)
  end

obviously won't work, because the current_user isn't loaded yet.

Specifically, the write to the invalidated session store has to be done after the user is already loaded, but before the locked transaction which invalidates the old session data.

It's not clear how you could call into the Pow plug without it attempting to roll the session for you -- and I'm not sure that this behavior would desirable, anyway.

[danschultzer]

I hope that all the PR's with ultimately #650 will prevent this issue from reappearing. I'll close this for now.