Phoenix didn't handle some http requests

What you are doing is nothing out of ordinary. However, you may want to post more details, like console prints, router code, etc so other people can help you.

One thing I can think of is if you are posting from another origin, you need to make sure CSRF is not in your way. In any event, there should be error message in the console; no requests should be silently dropped.

@derek-zhou, Thank you!

the code for the router is listed below:

defmodule BrTowerWebuiWeb.Router do
  use BrTowerWebuiWeb, :router

  pipeline :browser do
    plug :accepts, ["html"]
    plug :fetch_session
    plug :fetch_live_flash
    plug :put_root_layout, {BrTowerWebuiWeb.LayoutView, :root}
    plug :protect_from_forgery
    plug :put_secure_browser_headers
  end

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

  scope "/", BrTowerWebuiWeb do
    pipe_through :browser

    live "/", PageLive, :index
    get "/batches/:id", BatchController, :show

  end

  scope "/api", BrTowerWebuiWeb do
    pipe_through :api

    get "/batches/:batch_id/items/:id", ItemController, :show
  end

  scope "/webhooks", BrTowerWebuiWeb do
   pipe_through :api

   post "/nextflow", WebhookController, :nextflow
  end

  if Mix.env() in [:dev, :test] do
    import Phoenix.LiveDashboard.Router

    scope "/" do
      pipe_through :browser
      live_dashboard "/dashboard", metrics: BrTowerWebuiWeb.Telemetry
    end
  end
end

The screenshoot for the console is pasted below. Please ignore the text labelled on the figure because I thought there was no payload, but in reality payload was there.

image1434×1380 270 KB

So what is the problem? you did receive payload.

Do you have an unit test that works all the times, or that fails too?

Check the docs to implement such a test if you don’t already know how.

The problem is http requests with payload were rejected silently by Plug and didn’t reach for the corresponding controller action.

I don’t have any unit test for this case till now.

when the weird case happened, the v2ray service (sort of a proxy) was on. I suspect that the v2ray service is most likely to be the culprit. I will report back if I can determine what the cause is.

In your log after the first POST /webhooks/next/flow, there is a Sent 200 in 1 ms so at least it worked for once. If subsequent requests are not handled, it is most likely a bug in your program so your controller hangs.

If Plug decided to reject any request for whatever reason, ther will be print in the console.

The screenshot shows only a very tiny part of log info. Post requests after the part worked normally. In addition, a few GET /batches/[:batch_id] didn’t work either. I think that this has nothing to do with the code for the controller action.
The following code snippet is about the controller and the related parser. I cannot find where the bug lies indeed.

defmodule BrTowerWebuiWeb.WebhookController do
  use BrTowerWebuiWeb, :controller

  alias BrTowerWebui.WeblogParser
  alias BrTower.Core.Batch

  @topic "batch:"

  def nextflow(conn, data) do
    case WeblogParser.parse(data) do
      {:error, msg} ->
        conn
        |> put_status(:bad_request)
        |> json(%{message: "Error: #{msg}"})
      event ->
        batch = BrTower.dispatch(event)
        case batch do
          {:error, msg} ->
            conn
            |> put_status(:not_found)
            |> json(%{message: "Error: #{msg}"})
          _ ->
            item_dtos = batch.items
            |> Enum.map(fn {k, _v} -> Batch.build_item_dto(batch, k) end)
            Phoenix.PubSub.broadcast(BrTowerWebui.PubSub, @topic <> "#{batch.id}", %{id: batch.id, items: item_dtos})
            json(conn, %{message: "Event received"})
        end
    end
  end
end

defmodule BrTowerWebui.WeblogParser do
  alias BrTower.Core.Events.{BasicInfo, TaskInfo, PipelineStarted, PipelineCompleted, PipelineErrorOccurred, TaskSubmitted, TaskStarted, TaskCompleted}

  def parse(%{"runName" => run_name, "event" => event, "utcTime" => utc_time_str} = data) do
    run_id = Map.get(data, "runId")
    {:ok, utc_time, _} = DateTime.from_iso8601(utc_time_str)
    basic_info = BasicInfo.new(run_id, run_name, utc_time)

    case event do
      "started" ->
        batch_id = get_in(data, ["metadata", "parameters", "id_for_tower"])
        session_id = get_in(data, ["metadata", "workflow", "sessionId"])
        analysis_type = get_in(data, ["metadata", "parameters", "analysis_type"])
        mode = get_in(data, ["metadata", "parameters", "mode"])
               |> String.to_atom()
        case batch_id do
          nil ->
            {:error, "batch_id is missing"}
          _ ->
            PipelineStarted.new(basic_info, session_id, batch_id, analysis_type, mode)
        end
      "completed" ->
        batch_id = get_in(data, ["metadata", "parameters", "id_for_tower"])
        success = get_in(data, ["metadata", "workflow", "success"])
        analysis_type = get_in(data, ["metadata", "parameters", "analysisType"])
        case batch_id do
          nil ->
            {:error, "batch_id is missing"}
          _ ->
            batch_id = if is_nil(analysis_type), do: batch_id, else: "#{batch_id}_#{analysis_type}"
            PipelineCompleted.new(basic_info, batch_id, success)
        end
      "error" ->
        trace = Map.get(data, "trace")
        case trace do
          nil ->
            PipelineErrorOccurred.new(basic_info, nil)
          _ ->
            task_info = build_task_info(trace)
            case task_info.item_id do
              nil ->
                {:error, "item_id is missing"}
              _ ->
                PipelineErrorOccurred.new(basic_info, task_info)
            end
        end
      x when x in ["process_submitted", "process_started", "process_completed"] ->
        trace = Map.get(data, "trace")
        task_info = build_task_info(trace)
        case task_info.item_id do
          nil ->
            {:error, "item_id is missing"}
          _ ->
            case x do
              "process_submitted" ->
                TaskSubmitted.new(basic_info, task_info)
              "process_started" ->
                TaskStarted.new(basic_info, task_info)
              "process_completed" ->
                TaskCompleted.new(basic_info, task_info)
            end
        end
    end
  end

  def parse(data) do
    {:error, "invalid data: #{data}"}
  end

  defp build_task_info(trace) do
    process_name = Map.get(trace, "process")
    item_id = Map.get(trace, "tag")
    status = trace
             |> Map.get("status")
             |> String.to_atom
    TaskInfo.new(process_name, status, item_id)
  end
end

Other people cannot help you debug your code unless you can make a minimum reproducible case and put it on github.

Elixir gives you many tools to debug; you have a console, a remote iex shell, even a live dashboard. Also you will need to have some faith in Phoenix; it is much more likely the bug is in your side.

In my log, [info] POST /webhooks/nextflow was output by the Plug.Logger, and [debug] Processing with BrTowerWebuiWeb.WebhookController.nextflow/2 … was output by the phoenix_router_dispatch_start in the Phoenix.Logger. phoenix_router_dispatch_start is installed as the event handler for [:phoenix, :router_dispatch, :start]:
https://github.com/phoenixframework/phoenix/blob/60da3f0dc01b7e0eae0e5bd608431ead953ded5d/lib/phoenix/logger.ex#L128
This means dispatching a request to the corresponding controller action was not started because the related debug line was missing in my log, so I can conclude that this case is not caused by the bug that perhaps exists from my controller part.

Sorry, I cannot put my code on github because of the policy of our company, but i can give you the architectural design which is shown in the following figure:

image1780×1108 104 KB

Or, alternatively, the function you attached to :phoenix_router_dispatch_start has a problem and Telemetry removed it after that first invocation:

If the function fails (raises, exits or throws) then the handler is removed

I would start by putting some debug logs in the controller itself; Telemetry is perhaps not the best tool to rely on for debugging.