How to debug elixir when run using docker (phoenix framework)

Hi,
I am trying to debug my elixir project, run using docker. But I can’t get any proper logs anywhere.

I am new to elixir. I am assigned a project that is partially completed. It uses elixir, with phoenix and postgres and uses Docker to run the application. I am new to all these languages and frameworks above. No one else in my company is familiar with elixir.

With some support from colleagues knowing docker, I got the project running and its test api’s are working fine with postman, but one I call the signup api, it returns an “unauthorised” message.

This is where I am stuck. I want to find out why its returning this message. I don’t know how to debug elixir. I am not getting any message on console once it runs. How can i do this?

if it helps, I am posting the module which contains the return message

defmodule MyApiWeb.Plug.Auth do
  @moduledoc """
  This Plug performs authentication.
  """

  import Plug.Conn

  def init(default), do: default

  def call(conn, _) do
    case Enum.find(conn.req_headers, &elem(&1, 0) == "authorization") do
      {_, token} ->

        case MyApi.Guardian.decode_and_verify(token, %{"typ" => "access"}) do
          {:ok, claims} ->

            case Guardian.DB.on_verify(claims, token) do
              {:ok, {claims, _}} ->

                user =
                  claims
                  |> MyApi.Guardian.resource_from_claims
                  |> elem(1)

                if user == nil,
                  do: halt_request(conn),
                  else: conn |> assign(:user, user)

              {:error, _} -> halt_request(conn)
            end

          {:error, _} -> halt_request(conn)
        end

      nil -> halt_request(conn)
    end
  end

  def halt_request(conn) do
    conn
      |> put_resp_content_type("application/json")
      |> send_resp(403, Poison.encode!(%{message: "not authorization"}))
      |> halt
  end

end

The

case Enum.find(conn.req_headers, &elem(&1, 0) == “authorization”)

always fails and return

not authorization

How can I know what values are getting here

conn.req_headers, &elem(&1, 0)

It looks like a json api protected by token.

It might be that the client does not send it, and You do not mention the client…

Anyway, You could modify the error message to include some reason.

|> send_resp(403, Poison.encode!(%{message: "not authorization #{inspect conn.req_headers}"}))

You could also add some reason to halt_request, to see where it fails exactly.

Your question is how to see logs in general? Or you’re having problem with logs from this plug?

How is the docker container started? docker-compose? Then you have this https://docs.docker.com/compose/reference/logs/

1 Like

What did you mean “json api protected by token”?
This is my api

http://localhost:4000/api/signup

and this is what I am passing

{
    "mailaddress": "ghostrick.kinako@gmail.com",
    "nickname": "tmy",
    "password": "asdf1234",
    "password_confirm": "asdf1234",
    "is_doctor": true,
    "doctor_profile": {
        "hospital_location": "Shinjuku",
        "last_name": "Ishizaka",
        "first_name": "Tomoya",
        "facebook": "",
        "instagram": ""
    },
    "good_treatment_ids": [
        1,2,3,10
    ]
}

after adding #{inspect conn.req_headers}. I got the following response.

{
    "message": "not authorization [{\"content-type\", \"application/json\"}, {\"user-agent\", \"PostmanRuntime/7.24.1\"}, {\"accept\", \"*/*\"}, {\"cache-control\", \"no-cache\"}, {\"postman-token\", \"607fa812-b2c2-4ea9-bba6-b14e11e490b5\"}, {\"host\", \"localhost:4000\"}, {\"accept-encoding\", \"gzip, deflate, br\"}, {\"connection\", \"keep-alive\"}, {\"content-length\", \"398\"}]"
}

I don’t think the above message is helpful for you.

Also I have replied to the other answer by @egze . Are you able to help me with any info from there?

Yes I did use docker-compose start. I used the command from the link provided, and got long list of messages. I am including part where the signup api was called.

app_1  | [info] POST /api/signup
app_1  | [debug] Processing with MyApiWeb.UserController.signup/2
app_1  |   Parameters: %{"doctor_profile" => %{"facebook" => "", "first_name" => "Tomoya", "hospital_location" => "Shinjuku", "instagram" => "", "last_name" => "Ishizaka"}, "good_treatment_ids" => [1, 2, 3, 10], "is_doctor" => true, "mailaddress" => "ghostrick.kinako@gmail.com", "nickname" => "tmy", "password" => "[FILTERED]", "password_confirm" => "[FILTERED]"}
app_1  |   Pipelines: [:api]
app_1  | [info] Sent 403 in 570µs
app_1  | [debug] MyApiWeb.UserController halted in MyApiWeb.Plug.Auth.call/2

You can see in the second line MyApiWeb.UserController.signup/2 is getting called and below is the function defenition

  def signup(conn, params) do
    with {:ok, _} <- Account.signup(params, conn.assigns.user.id),
      do: json conn, %{message: "Success"}
  end

But in that function there is call going to Account.signup(params, conn.assigns.user.id) and what might be the reason that function is not called as per the log. Is the log not showing Account.signup call or is there some error in there which you can understand. I am including the signup function from Account module below. Three of them:

  def signup(%{"is_doctor" => true} = params, user_id) do
    with {:ok, user} <- get_user(user_id),
      {:ok, resp} <- user |> create_doctor(params) |> Repo.transaction(),
      do: get_profile(resp.user.id)
  end

  def signup(%{"is_doctor" => false} = params, user_id) do
    with {:ok, user} <- get_user(user_id) do
      user
      |> User.signup_user_changeset(params)
      |> Repo.update()
    end
  end

  def signup(_) do
    {:error, %{errors: ["The parameter is invalid"]}}
  end

Why is this not getting called? Any idea?

It looks You are testing with postman, but You need to pass authorization token in headers.

And You did not answer about the frontend…

BTW This is strange that the sign_up is protected by Auth plugin, for this, You could show your router.ex file.

Using Poison show also an old version of Phoenix, You can get the verion in the mix file.

Front end is in react. But not using front end right now. Do you know how to add custom logs during each step in elixir. To print those logs into docker logs.

Change to this…

def halt_request(conn, message) do
    conn
      |> put_resp_content_type("application/json")
      |> send_resp(403, Poison.encode!(%{message: "not authorization #{message}"}))
      |> halt
  end

# And call like this

halt_request(conn, "I broke because ...")

PS: I know You are not using the frontend… I guessed. But You cannot compare You testing with postman, and front end in React, because somewhere, the real front end adds an authorization header as a JWT.

Ok. That might solve my problem. I cannot run my react project due to some other errors. I’ll try to resolve them. Thanks.

Or simply remove Auth plug in your router…

can you please elaborate on that? please

You should show your router file… as mentionned before.

This is the router file

defmodule MApiWeb.Router do
  use MyApiWeb, :router

  pipeline :browser do
    plug :accepts, ["html"]
    plug :fetch_session
    plug :fetch_flash
    plug :protect_from_forgery
    plug :put_secure_browser_headers
  end

  pipeline :admin do
    plug :put_layout, {MyApiWeb.Admin.LayoutView, :app}
  end

  pipeline :api do
    plug :accepts, ["json"]
  end

  scope "/", MyApiWeb do
    pipe_through :browser # Use the default browser stack
    # activate page
    get "/activate/:code", ActivateController, :from_web
  end

  scope "/admin", MyApiWeb.Admin do
    pipe_through [:browser, :admin]
    get "/doctor", DoctorController, :index
    get "/doctor/not_approve", DoctorController, :not_approve
    get "/doctor/already_approve", DoctorController, :already_approve
    get "/doctor/:id/approve", DoctorController, :approve
  end

  scope "/api", MyApiWeb do
    pipe_through :api

    # debug
    get "/test", TestController, :test
    get "/auth_test", TestController, :auth_test

    # user signup/signin
    post "/verify_mailaddress", UserController, :verify_mailaddress
    post "/signup", UserController, :signup
    post "/signin", UserController, :signin
    post "/refresh", UserController, :refresh
    put "/activate", ActivateController, :index
    get "/profile", UserController, :get_myprofile
    get "/profile/:user_id", UserController, :get_profile
    put "/profile/update", UserController, :update_profile
    patch "/mailaddress/update", UserController, :update_mailaddress

    put "/change_password", UserController, :change_password
    post "/generate_reset_code", UserController, :generate_reset_code
    put "/reset_password", UserController, :reset_password

    # data(static, media)
    scope "/data" do
      get "/treatment_categories", DataController, :get_treatment_categories
      post "/media", DataController, :media_upload
    end

    scope "/map" do
      get "/geometry", MapController, :get_geometry
    end

    # only CACA
    scope "/caca", Caca do

      # Question API
      scope "/question" do

        get "/user", QuestionController, :get_base_user
        get "/user/:user_id", QuestionController, :get_base_user

        post "/", QuestionController, :post
        get "/", QuestionController, :get
        get "/:id", QuestionController, :get
        put "/:id", QuestionController, :update
        delete "/:id", QuestionController, :delete

        # Answer API
        post "/:question_id/answer", QuestionController, :post_answer
        get "/:question_id/answer", QuestionController, :get_answer
        scope "/answer" do
          put "/:id", QuestionController, :update_answer
          delete "/:id", QuestionController, :delete_answer

          # Reaction API
          get "/:answer_id/reaction", QuestionController, :get_reaction
          post "/:answer_id/reaction", QuestionController, :add_reaction
          delete "/:answer_id/reaction", QuestionController, :remove_reaction
        end
      end

      scope "/notif" do
        get "/answer", NotifController, :get_answer_notif
        put "/answer/read", NotifController, :read_answer_notif
        get "/question", NotifController, :get_question_notif
        put "/question/read", NotifController, :read_question_notif
      end
    end

    # only MY
    scope "/my", My do
      scope "/user" do
        get "/stripe_source", UserController, :get_stripe_sources
        post "/stripe_source", UserController, :create_stripe_source
        post "/stripe_source/:source_id", UserController, :update_stripe_source
        delete "/stripe_source/:source_id", UserController, :delete_stripe_source
      end

      scope "/doctor" do
        post "/search", UserController, :search_doctors
        get "/random", UserController, :get_random_doctors
        get "/:id/before_after", MedicareController, :get_before_after
        get "/:id/surgery", MedicareController, :get_surgery
        get "/:id/day_surgery", CalendarController, :get_day_surgeries
      end

      scope "/counsel" do
        # /session
        get "/session", CounselController, :session_list
        post "/session", CounselController, :create_session
        post "/session/:id/reply", CounselController, :create_reply
        get "/session/:id", CounselController, :session_detail
        patch "/reply/:id/read", CounselController, :read_reply
      end

      scope "/medicare" do
        # /treatment
        post "/treatment", MedicareController, :create_treatment
        post "/treatment/search", MedicareController, :search_treatments
        get "/treatment/random", MedicareController, :get_random_treatments
        patch "/treatment/:id", MedicareController, :update_treatment
        get "/treatment/:id", MedicareController, :get_treatment

        # /appointment
        post "/appointment", MedicareController, :create_appointment
        post "/appointment/search", MedicareController, :search_appointments
        get "/appointment/:id", MedicareController, :get_appointment
        put "/appointment/:id", MedicareController, :edit_appointment
        patch "/appointment/:id/done", MedicareController, :done_appointment
        patch "/appointment/:id/cancel", MedicareController, :cancel_appointment

        # /before_after
        put "/before_after", MedicareController, :put_before_after

        # /surgery
        put "/surgery", MedicareController, :put_surgery
      end

      scope "/calendar" do
        # /event
        get "/event", CalendarController, :get_events
        post "/event", CalendarController, :create_event
        patch "/event/:id", CalendarController, :update_event
        delete "/event/:id", CalendarController, :remove_event

        # /day_surgery
        post "/day_surgery", CalendarController, :create_day_surgery
        patch "/day_surgery/:id", CalendarController, :update_day_surgery
        delete "/day_surgery/:id", CalendarController, :remove_day_surgery
      end

      scope "/bank_account" do
        get "/doctor", BankAccountController, :get_doctor_bank
        get "/clinic", BankAccountController, :get_clinic_bank
        put "/doctor", BankAccountController, :put_doctor_bank
        put "/clinic", BankAccountController, :put_clinic_bank
      end
    end
  end

end

TL;DR
You didn’t supply Authorisation header in the Postman or if you supplied it’s not valid.

To debug the issue use inspect function:
https://hexdocs.pm/elixir/IO.html#inspect/2
Just put it whenever you need it and look at the logs in the docker-compose (https://docs.docker.com/compose/reference/logs/).

There are two lines that are important here and in which you want to debug values:

  1. Checking if authorisation header is supplied:
    case Enum.find(conn.req_headers, &elem(&1, 0) == "authorization") do

To understand it read those:
https://hexdocs.pm/elixir/Enum.html#find/3
https://hexdocs.pm/plug/Plug.Conn.html#module-request-fields
https://hexdocs.pm/elixir/Kernel.html#elem/2

  1. If you supply the Authorisation header the second check will be if that token is valid with this code:
    case MyApi.Guardian.decode_and_verify(token, %{"typ" => "access"}) do

This is a function from auth library:
https://hexdocs.pm/guardian/Guardian.html#decode_and_verify/4