feat(ScheduleController): smaller schedules_for_stop response + loggi…

…ng (#1790)

* feat(ScheduleController): add error logging

and return error response to frontend

* feat(ScheduleController): log empty schedules

* feat(ScheduleController): small schedules_for_stop

reduce response size by removing data that's unused by the frontend

apps/site/lib/site_web/controllers/schedule_controller.ex

@@ -3,6 +3,8 @@ defmodule SiteWeb.ScheduleController do
   alias Routes.Route
   alias Schedules.Schedule
 
+  require Logger
+
   plug(SiteWeb.Plugs.Route when action not in [:schedules_for_stop])
 
   @spec show(Plug.Conn.t(), map) :: Phoenix.HTML.Safe.t()
@@ -47,20 +49,41 @@ defmodule SiteWeb.ScheduleController do
 
   @spec schedules_for_stop(Plug.Conn.t(), map) :: Plug.Conn.t()
   def schedules_for_stop(conn, %{"stop_id" => stop_id} = params) do
-    schedules =
-      Schedules.Repo.schedules_for_stop(stop_id, [])
-      |> future_departures(conn, params)
-      |> omit_last_stop_departures(params)
+    case Schedules.Repo.schedules_for_stop(stop_id, []) do
+      {:error, error} ->
+        _ =
+          Logger.error(
+            "module=#{__MODULE__} fun=schedules_for_stop stop=#{stop_id} date_time=#{DateTime.to_string(date_time(conn.assigns))} error=#{inspect(error)}"
+          )
+
+        SiteWeb.ControllerHelpers.return_internal_error(conn)
+
+      data ->
+        schedules =
+          data
+          |> future_departures(conn, params)
+          |> omit_last_stop_departures(params)
+          |> trim_response()
+
+        case schedules do
+          [%Schedule{} | _] ->
+            json(conn, schedules)
+
+          _ ->
+            Logger.info(
+              "module=#{__MODULE__} fun=schedules_for_stop stop=#{stop_id} date_time=#{DateTime.to_string(date_time(conn.assigns))} no_schedules_returned"
+            )
 
-    json(conn, schedules)
+            json(conn, [])
+        end
+    end
   end
 
+  defp date_time(%{"date_time" => date_time}), do: date_time
+  defp date_time(_), do: Util.now()
+
   defp future_departures(schedules, conn, %{"future_departures" => "true"}) do
-    now =
-      case conn.assigns do
-        %{"date_time" => date_time} -> date_time
-        _ -> Util.now()
-      end
+    now = date_time(conn.assigns)
 
     # Only list schedules with departure_time in the future
     schedules
@@ -80,4 +103,12 @@ defmodule SiteWeb.ScheduleController do
   end
 
   defp omit_last_stop_departures(schedules, _), do: schedules
+
+  defp trim_response(schedules) do
+    schedules
+    |> Enum.map(&Map.drop(&1, [:stop]))
+    |> Enum.map(fn %Schedule{route: route} = schedule ->
+      %Schedule{schedule | route: Map.take(route, [:id])}
+    end)
+  end
 end

apps/site/test/site_web/controllers/schedule_controller_test.exs

@@ -307,11 +307,12 @@ defmodule SiteWeb.ScheduleControllerTest do
 
   describe "schedules_for_stop/2" do
     test "should return an array of schedules", %{conn: conn} do
-      with_mock(Schedules.Repo,
+      with_mock(Schedules.Repo, [:passthrough],
         schedules_for_stop: fn
           "TEST 1234", [] ->
             [
               %Schedules.Schedule{
+                route: %Routes.Route{id: "route"},
                 stop: %Stops.Stop{id: "TEST 1234"},
                 departure_time: ~U[2219-05-18 22:25:06.098765Z]
               }
@@ -324,24 +325,27 @@ defmodule SiteWeb.ScheduleControllerTest do
         conn = ScheduleController.schedules_for_stop(conn, %{"stop_id" => "TEST 1234"})
         body = json_response(conn, 200)
         assert Kernel.length(body) == 1
-        assert %{"stop" => %{"id" => "TEST 1234"}} = Enum.at(body, 0)
+        assert %{"departure_time" => "2219-05-18T22:25:06.098765Z"} = Enum.at(body, 0)
       end
     end
 
     test "should not return past schedules", %{conn: conn} do
-      with_mock(Schedules.Repo,
+      with_mock(Schedules.Repo, [:passthrough],
         schedules_for_stop: fn
           "TEST 1234", [] ->
             [
               %Schedules.Schedule{
+                route: %Routes.Route{id: "route"},
                 stop: %Stops.Stop{id: "TEST 1234"},
                 departure_time: ~U[2019-05-18 21:25:06.098765Z]
               },
               %Schedules.Schedule{
+                route: %Routes.Route{id: "route"},
                 stop: %Stops.Stop{id: "TEST 1234"},
                 departure_time: ~U[2219-05-18 22:25:06.098765Z]
               },
               %Schedules.Schedule{
+                route: %Routes.Route{id: "route"},
                 stop: %Stops.Stop{id: "TEST 1234"},
                 departure_time: ~U[2219-05-18 23:25:06.098765Z]
               }
@@ -359,27 +363,29 @@ defmodule SiteWeb.ScheduleControllerTest do
 
         body = json_response(conn, 200)
         assert Kernel.length(body) == 2
-        assert %{"stop" => %{"id" => "TEST 1234"}} = Enum.at(body, 0)
         assert %{"departure_time" => "2219-05-18T22:25:06.098765Z"} = Enum.at(body, 0)
       end
     end
 
     test "should not return schedules that are the last stop on its route", %{conn: conn} do
-      with_mock(Schedules.Repo,
+      with_mock(Schedules.Repo, [:passthrough],
         schedules_for_stop: fn
           "TEST 1234", [] ->
             [
               %Schedules.Schedule{
+                route: %Routes.Route{id: "route"},
                 stop: %Stops.Stop{id: "TEST 1234"},
                 departure_time: ~U[2219-05-18 22:25:06.098765Z],
                 last_stop?: false
               },
               %Schedules.Schedule{
+                route: %Routes.Route{id: "route"},
                 stop: %Stops.Stop{id: "TEST 1234"},
                 departure_time: ~U[2219-05-18 22:25:06.098765Z],
                 last_stop?: false
               },
               %Schedules.Schedule{
+                route: %Routes.Route{id: "route"},
                 stop: %Stops.Stop{id: "TEST 1234"},
                 departure_time: ~U[2219-05-18 22:25:06.098765Z],
                 last_stop?: true
@@ -401,5 +407,64 @@ defmodule SiteWeb.ScheduleControllerTest do
         assert Kernel.length(body) == 2
       end
     end
+
+    test "should report errors", %{conn: conn} do
+      with_mock(Schedules.Repo, [:passthrough],
+        schedules_for_stop: fn "TEST 1234", [] -> {:error, :not_found} end
+      ) do
+        log =
+          ExUnit.CaptureLog.capture_log(fn ->
+            conn = ScheduleController.schedules_for_stop(conn, %{"stop_id" => "TEST 1234"})
+
+            assert %{
+                     "error" => "Internal error"
+                   } = json_response(conn, 500)
+          end)
+
+        assert log =~ "[error] module=Elixir.SiteWeb.ScheduleController"
+        assert log =~ "fun=schedules_for_stop stop=TEST 1234"
+        assert log =~ "error=:not_found"
+      end
+    end
+
+    test "logs when no schedules returned", %{conn: conn} do
+      with_mock(Schedules.Repo, [:passthrough],
+        schedules_for_stop: fn "TEST 1234", [] ->
+          # will get filtered out
+          [
+            %Schedules.Schedule{
+              route: %Routes.Route{id: "route"},
+              stop: %Stops.Stop{id: "TEST 1234"},
+              departure_time: ~U[2019-05-18 22:25:06.098765Z],
+              last_stop?: true
+            }
+          ]
+        end
+      ) do
+        log =
+          ExUnit.CaptureLog.capture_log(fn ->
+            old_level = Logger.level()
+
+            on_exit(fn ->
+              Logger.configure(level: old_level)
+            end)
+
+            Logger.configure(level: :info)
+
+            conn =
+              ScheduleController.schedules_for_stop(conn, %{
+                "stop_id" => "TEST 1234",
+                "future_departures" => "true",
+                "last_stop_departures" => "false"
+              })
+
+            assert [] = json_response(conn, 200)
+          end)
+
+        assert log =~ "[info] module=Elixir.SiteWeb.ScheduleController"
+        assert log =~ "fun=schedules_for_stop stop=TEST 1234"
+        assert log =~ "no_schedules_returned"
+      end
+    end
   end
 end