title: Losing conn.assigns in the middle of a test
body: <p>I struggle troubleshooting a failed test where conn.assigns are both part of the same test statement, but emptied in between two lines of the test.</p>
  
  <p>I'm reading "Programming Phoenix", and reworking code to make it work with Phoenix 1.3. In 3 of the tests, the :current_user stored in conn.assigns is lost in the middle of the test, for example just in between a delete and a get in controller tests.</p>
  
  <p><strong>The code of the test is:</strong></p>
  
  <pre><code>  describe "delete video" do
      setup [:login_user, :create_video]
  
      test "deletes chosen video", %{conn: conn, video: video} do
        conn = delete conn, video_path(conn, :delete, video)
        assert redirected_to(conn) == video_path(conn, :index)
        assert_error_sent 404, fn -&gt;
          Logger.warn("Before get: #{inspect(conn.assigns)}")
          conn = get conn, video_path(conn, :show, video)
          Logger.warn("After get: #{inspect(conn.assigns)}")
          conn
        end
      end
    end
  </code></pre>
  
  <p>I added Logger.warn instructions to inspect the connection before and after the get request. In the "Before get:" log I still have a conn.assigns with :current_user key, but in the subsequent "After get" log, it's gone.</p>
  
  <p>I initially thought my authentication mechanism was responsible for this, but I then created a Logging Plug to inspect the pipeline, and I can see that from the start of the pipeline for the call to get, the current_user is missing from assigns.</p>
  
  <p><strong>This is the test output showing the logging at start/end of pipeline as well as logs from test above.</strong></p>
  
  <pre><code>ubuntu@ubuntu-xenial:~/rumbl$ MIX_ENV=test mix test test/rumbl_web/controllers/video_controller_test.exs:98
  [info] Already up
  Including tags: [line: "98"]
  Excluding tags: [:test]
  
  warning: module attribute @update_attrs was set but never used
    test/rumbl_web/controllers/video_controller_test.exs:10
  
  [debug] QUERY OK db=1.2ms
  begin []
  [debug] QUERY OK db=2.7ms
  INSERT INTO "users" ("name","password_hash","username","inserted_at","updated_at") VALUES ($1,$2,$3,$4,$5) RETURNING "id" ["Some User", "$2b$12$0VvTPna8JMdSXcbNz2uvwOdhYWF/3ibhQ.gntdXqsb8v1TSeCZ0.K", "max", {{2017, 9, 22}, {10, 56, 53, 527902}}, {{2017, 9, 22}, {10, 56, 53, 529912}}]
  [debug] QUERY OK db=0.1ms
  commit []
  [debug] QUERY OK db=0.1ms
  begin []
  [debug] QUERY OK db=1.1ms
  INSERT INTO "videos" ("description","title","url","user_id","inserted_at","updated_at") VALUES ($1,$2,$3,$4,$5,$6) RETURNING "id" ["some description", "some title", "some url", 351, {{2017, 9, 22}, {10, 56, 53, 544069}}, {{2017, 9, 22}, {10, 56, 53, 544075}}]
  [debug] QUERY OK db=0.1ms
  commit []
  [info] DELETE /manage/videos/274
  [warn] Start of pipeline: %{current_user: %RumblWeb.User{__meta__: #Ecto.Schema.Metadata&lt;:loaded, "users"&gt;, id: 351, inserted_at: ~N[2017-09-22 10:56:53.527902], name: "Some User", password: "supersecret", password_hash: "$2b$12$0VvTPna8JMdSXcbNz2uvwOdhYWF/3ibhQ.gntdXqsb8v1TSeCZ0.K", updated_at: ~N[2017-09-22 10:56:53.529912], username: "max", videos: #Ecto.Association.NotLoaded&lt;association :videos is not loaded&gt;}}
  [warn] End of pipeline: %{current_user: %RumblWeb.User{__meta__: #Ecto.Schema.Metadata&lt;:loaded, "users"&gt;, id: 351, inserted_at: ~N[2017-09-22 10:56:53.527902], name: "Some User", password: "supersecret", password_hash: "$2b$12$0VvTPna8JMdSXcbNz2uvwOdhYWF/3ibhQ.gntdXqsb8v1TSeCZ0.K", updated_at: ~N[2017-09-22 10:56:53.529912], username: "max", videos: #Ecto.Association.NotLoaded&lt;association :videos is not loaded&gt;}}
  [warn] Start of authenticate_user: %{current_user: %RumblWeb.User{__meta__: #Ecto.Schema.Metadata&lt;:loaded, "users"&gt;, id: 351, inserted_at: ~N[2017-09-22 10:56:53.527902], name: "Some User", password: "supersecret", password_hash: "$2b$12$0VvTPna8JMdSXcbNz2uvwOdhYWF/3ibhQ.gntdXqsb8v1TSeCZ0.K", updated_at: ~N[2017-09-22 10:56:53.529912], username: "max", videos: #Ecto.Association.NotLoaded&lt;association :videos is not loaded&gt;}}
  [debug] Processing with RumblWeb.VideoController.delete/2
    Parameters: %{"id" =&gt; "274"}
    Pipelines: [:browser, :authenticate_user]
  [debug] QUERY OK source="videos" db=0.9ms
  SELECT v0."id", v0."description", v0."title", v0."url", v0."user_id", v0."category_id", v0."inserted_at", v0."updated_at" FROM "videos" AS v0 WHERE (v0."user_id" = $1) AND (v0."id" = $2) [351, 274]
  [debug] QUERY OK db=0.1ms
  begin []
  [debug] QUERY OK db=0.3ms
  DELETE FROM "videos" WHERE "id" = $1 [274]
  [debug] QUERY OK db=0.0ms
  commit []
  [info] Sent 302 in 46ms
  [warn] Before get: %{current_user: %RumblWeb.User{__meta__: #Ecto.Schema.Metadata&lt;:loaded, "users"&gt;, id: 351, inserted_at: ~N[2017-09-22 10:56:53.527902], name: "Some User", password: "supersecret", password_hash: "$2b$12$0VvTPna8JMdSXcbNz2uvwOdhYWF/3ibhQ.gntdXqsb8v1TSeCZ0.K", updated_at: ~N[2017-09-22 10:56:53.529912], username: "max", videos: #Ecto.Association.NotLoaded&lt;association :videos is not loaded&gt;}}
  [info] GET /manage/videos/274
  [warn] Start of pipeline: %{}
  [warn] End of pipeline: %{current_user: nil}
  [warn] Start of authenticate_user: %{current_user: nil}
  [info] Sent 302 in 2ms
  [warn] After get: %{current_user: nil}
  
  
    1) test delete video deletes chosen video (RumblWeb.VideoControllerTest)
       test/rumbl_web/controllers/video_controller_test.exs:98
       expected error to be sent as 404 status, but response sent 302 without error
       code: assert_error_sent 404, fn -&gt;
       stacktrace:
         (phoenix) lib/phoenix/test/conn_test.ex:600: Phoenix.ConnTest.assert_error_sent/2
         test/rumbl_web/controllers/video_controller_test.exs:101: (test)
  
  
  
  Finished in 0.6 seconds
  8 tests, 1 failure, 7 skipped
  
  Randomized with seed 982730
  </code></pre>
  
  <p>The authentication mechanism follows the book's advice, and passes authentication if there is a :current_user in conn.assigns. The setup login_user does just this, injecting a user in conn.assigns under :current_user key. In my test, and for whatever reason, as the conn.assigns is empty at some point in the get request, authentication fails, and the user is redirected to the home page.</p>
  
  <p>I'm not sure how to troubleshoot what happens in between the delete statement and subsequent get. I looked at the pipeline, but as showing in log statements the conn.assigns is blanked before even entering the pipeline. I was expecting that conn would not change across the whole test statement, maybe that's a wrong assumption.</p>
  
  <p><strong>In reply to Dogbert's comment:</strong></p>
  
  <p>login_user function in the controller test:</p>
  
  <pre><code>  defp login_user(_) do
      user = insert_user(username: "max")
      conn = assign(build_conn(), :current_user, user)
      {:ok, conn: conn, user: user}
    end
  </code></pre>
  
  <p>call function in the auth controller:</p>
  
  <pre><code>  def call(conn, repo) do
      user_id = get_session(conn, :user_id)
  
      cond do
        user = conn.assigns[:current_user] -&gt;
          conn
        user    = user_id &amp;&amp; repo.get(RumblWeb.User, user_id) -&gt;
          assign(conn, :current_user, user)
        true -&gt;
          assign(conn, :current_user, nil)
      end
    end
  </code></pre>