Fix & improve survey logger tests (#2358)

* Remove unnecessary checks on SurveyLogEntries on tests

* add SurveyLogEntry.changeset mode normalization tests

* Add SurveyLogger tests

test/ask/runtime/survey_broker_test.exs

@@ -1219,7 +1219,6 @@ defmodule Ask.Runtime.SurveyBrokerTest do
       assert respondent.state == :failed
       assert respondent.disposition == :failed
 
-      assert_disposition_changed(respondent.id, "queued", "failed")
     end
 
     test "contacted respondents are marked as unresponsive" do
@@ -1263,8 +1262,6 @@ defmodule Ask.Runtime.SurveyBrokerTest do
       respondent = Repo.get(Respondent, respondent.id)
       assert respondent.state == :failed
       assert respondent.disposition == :unresponsive
-
-      assert_disposition_changed(respondent.id, "contacted", "unresponsive")
     end
 
     test "started respondents are marked as breakoff" do
@@ -1318,8 +1315,6 @@ defmodule Ask.Runtime.SurveyBrokerTest do
       respondent = Repo.get(Respondent, respondent.id)
       assert respondent.state == :failed
       assert respondent.disposition == :breakoff
-
-      assert_disposition_changed(respondent.id, "started", "breakoff")
     end
 
     test "interim partial respondents are kept as partial (SMS)" do
@@ -1360,8 +1355,6 @@ defmodule Ask.Runtime.SurveyBrokerTest do
       respondent = Repo.get(Respondent, respondent.id)
       assert respondent.state == :failed
       assert respondent.disposition == :partial
-
-      assert_disposition_changed(respondent.id, "interim partial", "partial")
     end
   end
 

test/ask/runtime/survey_logger_test.exs

@@ -0,0 +1,62 @@
+defmodule SurveyLoggerTest do
+    use ExUnit.Case
+    use Ask.Model
+    alias Ask.Runtime.SurveyLogger
+    alias Ask.{Repo, SurveyLogEntry}
+
+    describe "SurveyLogger" do
+
+        # Test that the public API sends the right message to the mailbox
+        test "log should send log message" do
+            logger_pid = start_logger()
+            timestamp = DateTime.utc_now()
+
+            SurveyLogger.log(
+                1,
+                "sms",
+                2,
+                "1234",
+                3,
+                "queued",
+                :contact,
+                "Enqueueing call",
+                timestamp
+            )
+            assert_logger_received(logger_pid, {:log, 1, "sms", 2, "1234", 3, "queued", :contact, "Enqueueing call", timestamp})
+        end
+
+        # Test that the side-effect of processing a :log message is the expected one
+        test "logging registers entry on db" do
+            start_logger()
+            timestamp = DateTime.utc_now()
+
+            SurveyLogger.handle_cast({:log, 1, "sms", 2, "1234", 3, "queued", :contact, "Enqueueing call", timestamp}, nil)
+
+            entry = Repo.one!(from s in SurveyLogEntry, where: s.respondent_id == 2, order_by: [desc: s.id], limit: 1)
+            assert entry.survey_id == 1
+            assert entry.mode == "SMS" # normalized mode
+            assert entry.respondent_hashed_number == "1234"
+            assert entry.channel_id == 3
+            assert entry.disposition == "queued"
+            assert entry.action_type == "contact"
+            assert entry.action_data == "Enqueueing call"
+            assert entry.timestamp == DateTime.truncate(timestamp, :second)
+        end
+    end
+
+    def start_logger() do
+        {:ok, logger_pid} = SurveyLogger.start_link()
+        :erlang.trace(logger_pid, true, [:receive])
+        logger_pid
+    end
+
+    def assert_logger_received(logger_pid, message) do
+        assert_receive {
+            :trace, 
+            ^logger_pid, 
+            :receive,
+            {:"$gen_cast", ^message}
+        }
+    end
+
+end

test/ask/runtime/survey_test.exs

@@ -2484,7 +2484,6 @@ defmodule Ask.Runtime.SurveyTest do
 
       assert_respondent(respondent_id, %{
         current_state: :active,
-        previous_disposition: :queued,
         current_disposition: :contacted,
         user_stopped: false
       })
@@ -2496,7 +2495,6 @@ defmodule Ask.Runtime.SurveyTest do
 
       assert_respondent(respondent_id, %{
         current_state: :failed,
-        previous_disposition: :contacted,
         current_disposition: :refused,
         user_stopped: true
       })
@@ -2509,7 +2507,6 @@ defmodule Ask.Runtime.SurveyTest do
 
       assert_respondent(respondent_id, %{
         current_state: :failed,
-        previous_disposition: :started,
         current_disposition: :breakoff,
         user_stopped: true
       })
@@ -2522,7 +2519,6 @@ defmodule Ask.Runtime.SurveyTest do
 
       assert_respondent(respondent_id, %{
         current_state: :failed,
-        previous_disposition: :queued,
         current_disposition: :refused,
         user_stopped: true
       })
@@ -3642,7 +3638,6 @@ defmodule Ask.Runtime.SurveyTest do
   defp start_test(steps) do
     [survey, _, _, respondent, _] = create_running_survey_with_channel_and_respondent(steps)
     SurveyBroker.start_link()
-    SurveyLogger.start_link()
     [survey, respondent]
   end
 
@@ -3655,7 +3650,6 @@ defmodule Ask.Runtime.SurveyTest do
 
   defp assert_respondent(respondent_id, %{
          current_state: current_state,
-         previous_disposition: previous_disposition,
          current_disposition: current_disposition,
          user_stopped: user_stopped
        }) do
@@ -3665,7 +3659,6 @@ defmodule Ask.Runtime.SurveyTest do
     assert respondent.disposition == current_disposition
     assert respondent.user_stopped == user_stopped
     assert_last_history_disposition_is(respondent.id, current_disposition)
-    assert_disposition_changed(respondent.id, previous_disposition, current_disposition)
   end
 
   defp respondent_sends_stop(respondent_id) do

test/ask/survey_log_entry_test.exs

@@ -19,4 +19,27 @@ defmodule Ask.SurveyLogEntryTest do
     changeset = SurveyLogEntry.changeset(%SurveyLogEntry{}, @valid_attrs)
     assert changeset.valid?
   end
+
+  test "changeset normalizes sms mode" do
+    changes = %{@valid_attrs | mode: "sms"}
+    changeset = SurveyLogEntry.changeset(%SurveyLogEntry{}, changes)
+    assert changeset.changes.mode == "SMS"
+  end
+
+  test "changeset normalizes ivr mode" do
+    changes = %{@valid_attrs | mode: "Ivr"}
+    changeset = SurveyLogEntry.changeset(%SurveyLogEntry{}, changes)
+    assert changeset.changes.mode == "IVR"
+  end
+
+  test "changeset normalizes mobileweb mode" do
+    changes = %{@valid_attrs | mode: "mobileWEB"}
+    changeset = SurveyLogEntry.changeset(%SurveyLogEntry{}, changes)
+    assert changeset.changes.mode == "Mobile Web"
+  end
+
+  test "changeset leaves unrecognized mode as it is" do
+    changeset = SurveyLogEntry.changeset(%SurveyLogEntry{}, @valid_attrs)
+    assert changeset.changes.mode == "some content"
+  end
 end

test/support/test_helpers.ex

@@ -154,15 +154,6 @@ defmodule Ask.TestHelpers do
         assert p == pending
       end
 
-      def assert_disposition_changed(respondent_id, old_disposition, new_disposition) do
-        case Repo.one(from log in SurveyLogEntry, where: log.respondent_id == ^respondent_id, where: log.action_type == "disposition changed", order_by: [desc: :id], limit: 1) do
-          nil -> raise "No 'disposition changed' SurveyLogEntry for respondent (id: #{respondent_id})"
-          last_entry -> 
-            assert last_entry.disposition == to_string(old_disposition)
-            assert last_entry.action_data == upcaseFirst(new_disposition)
-        end
-      end
-
       defp upcaseFirst(value) when is_atom(value), do: to_string(value) |> upcaseFirst
       defp upcaseFirst(<<first::utf8, rest::binary>>), do: String.upcase(<<first::utf8>>) <> rest