How do you debug state changes using LiveViews?

I’m developing a LiveView with a somewhat complex, nested state. I’m encountering a strange bug: When handle_event is called for some events, the socket argument is filled with stale data. I find it hard to debug, as the machinery behind LiveView is pretty opaque to me.

I have struggled with this for half a day, or something like that, and feel like a junior developer again :slight_smile:

Now I wonder: how do you debug LiveViews? Are there any tools one can use?

Can I inspect the state? Since I’ve encountered a bug that seems to indicate stale data, where can I inspect the stored data? If, indeed, data is stored in several places, where? Is it stored in the view hierarchy somehow?

Another possibility is that the data is updated before the event handler with the “stale” data is
called. But I have not found any indications this is the case.

I can’t show you all the code, but below are the parts of the LiveView structure that I think are important.

def render(assigns) do
  ~H"""
  <main>
    # Could this be the source of the problem? I've thought of putting the answer_editor in a LiveView component
    # in some kind of shotgun debugging fashion. I have no idea why it would help, but maybe it would be easier to debug
    # since I could encapsulate the state changes in the component.
	# Or it would be harder to reason around because of the extra complexity.
    <%= for qa <- @question_items do %>
      <.answer_editor
        form={qa.form}
        variant={qa.variant}
        question={qa.question}
        open?={qa.open?}
        evaluation={qa.evaluation}
      />
    <% end %>
  </main>
  """
end
def answer_editor(assigns) do
  ~H"""
  <.simple_form for={@form} phx-change="update_editor" phx-submit="evaluate">
    . . .
    <.input type="textarea" field={@form[:answer]} phx-debounce="750" />
    . . .
    <.button name="action" value="evaluate_now">Bedöm</.button>
  </.simple_form>
  """
end
def handle_event(
	"evaluate",
	%{"question_id" => question_id},
	socket
	) do
  # This logs stale data
  IO.inspect(socket.assigns.interview.answers)
  . . .
end
def handle_event(
  "update_editor",
  %{"question_id" => question_id, "answer" => answer},
  socket
  ) do
  # This logs the expected data
  IO.inspect(socket.assigns.interview.answers)
  . . .
end
1 Like

Nested in terms of deeply nested maps or nested in terms of live components nested within the live view?

LiveViews run on processes, specifically they’re powered by a GenServer. So you can use all the tools you have at your disposal for inspecting what a process does over time.

Specifically I want to point at tracing (e.g. Extrace library) and :sys.get_state/1.

However outside of the callbacks you have in your live view module nothing should ever touch your assigns. So if you put e.g. logs or inspects into all of your callbacks you should also be able to trace all changes to assigns and when/how they’re modified. LV itself won’t though them (generally, e.g. streams are touched, but that’s part of their featureset).

Have you tried Live Debuger? You can inspect and trace state changes there.

2 Likes

Thanks for your swift reply.

There is a nested map interview containing questions, answers, and evaluations, which in turn are maps. From this map I derive a list of maps for each question that is used when I actually render things.

I have not used live components yet, but maybe I should? I’ve read several warnings about using them, but maybe this is a good use case?

I’ll take a look at it.

Ok, I’ve tried to do this, but I’ll make another try.

No, I’ll take a look. Looks interesting.

No, I can’t find anything that changes the state before “evaluate” is called, but it is called with stale data. Could it be that the socket data is stored in several places after all? Maybe cached?

The current solution is the result of exploring a solution for a complex problem. I’ll try to rebuild it more elegantly. But it bugs me I couldn’t find out why it doesn’t work the way I expected.

No. The socket is stored in the process heap and only the process itself has access to that. In theory the LV code running around your LV callback module would have access, but again it isn’t meant to touch assigns. It has no knowledge about the data you store anyways – it could literally be anything.

Ok, since handle_event for “evaluate” get the assigns value via socket.assigns something must have updated assigns before it is called then. Is that what you are saying?

I’m pretty sure now, that for some reason mount is called before the event_handler. I added a random value that only is added in mount, and it is added. This is why I don’t get the expected data.

That’s what I meant with tracing all your LV callbacks – not just handle_event.

Still, on further investigation, mount is not called before handle_event. I added IO.puts("PONGDONGPONG!!!!!!!!!!!!!!!!!!!!!!!") at the beginning of mount, and it’s not in the log.

This is so confusing. Something is going on that doesn’t fit my mental model.

My code is a mess. It’s hard to reason about. I’ll rebuild the view.

Thanks anyway for the help.

Maybe you have some state update that gets unintentionally discarded? I.e. you do some computation but then forget to update the socket and return the updated state.

I’ve seen it happen sometimes :grin:

Worth taking an extra look to see if that happens.

I’ve not been this lost as a developer in ages. Nothing has worked for me today.

I’ve created an example. This code is totally f*cked upp.

There is a counter that is incremented every time you edit your answers.

It is also incremented if you hit the inc button or when you hit evaluate.

But here is the strange thing. There seems to be one counter for when you edit your answers, and one for when you hit one of the buttons. So if I edit the answer 4 times, the counter will be at 4. If I on the other hand hit inc or evaluate, it starts from 0. Let’s say I hit a button 2 times, then the counter will be 2. If I edit the answer it becomes 5. If I hit a button 3 … I’m completely lost.

I am sure I am doing some stupid mistake, but I can’t see it. I’m blind.

And exhausted.

defmodule CopyWeb.StrangeEditor do
  @moduledoc false

  use CopyWeb, :live_component

  def render(assigns) do
    ~H"""
    <div class="pb flow">
      <.simple_form for={@form} phx-change="update" phx-submit="evaluate" phx-target={@myself}>
        <h2>{@question}</h2>
        <div class="wrap-grid">
          <.input type="textarea" field={@form[:answer]} phx-debounce="750" />
          <div data-ddi-variant="brand">{@evaluation}</div>
        </div>
        <.button>Evaluate</.button>
      </.simple_form>
      <.button phx-click="inc" phx-target={@myself}>Inc</.button>
    </div>
    """
  end

  def handle_event(
        "inc",
        _params,
        socket
      ) do
    send(self(), {:inc})

    {:noreply, socket}
  end

  def handle_event(
        "evaluate",
        _,
        %{assigns: %{id: id}} = socket
      ) do
    evaluation = "Score: #{:rand.uniform(10)}"

    send(self(), {:evaluate, id, evaluation})

    {:noreply, socket}
  end

  def handle_event("update", %{"answer" => answer}, %{assigns: %{id: id}} = socket) do
    send(self(), {:updated_answer, id, answer})
    {:noreply, socket}
  end
end

defmodule CopyWeb.StrangeViewLive do
  @moduledoc false

  use CopyWeb, :live_view
  alias CopyWeb.StrangeEditor

  def mount(_params, _session, socket) do
    socket =
      assign(socket,
        questionnaire: [
          %{id: "color", question: "favourite color?", form: to_form(%{"answer" => ""})},
          %{id: "food", question: "favourite food?", form: to_form(%{"answer" => ""})},
          %{id: "animal", question: "favourite animal?", form: to_form(%{"answer" => ""})}
        ],
        answers: %{},
        evaluations: %{},
        counter: 0
      )

    {:ok, socket}
  end

  def handle_info({:inc}, socket) do
    counter = Map.get(socket.assigns, :counter, 0)
    {:noreply, assign(socket, counter: counter + 1)}
  end

  def handle_info({:evaluate, question_id, evaluation}, socket) do
    counter = Map.get(socket.assigns, :counter, 0)

    socket =
      assign(socket,
        evaluations: Map.put(socket.assigns.evaluations, question_id, evaluation),
        counter: counter + 1
      )

    {:noreply, socket}
  end

  def handle_info({:updated_answer, question_id, answer}, socket) do
    counter = Map.get(socket.assigns, :counter, 0)

    {:noreply,
     assign(socket,
       answers: Map.put(socket.assigns.answers, question_id, answer),
       counter: counter + 1
     )}
  end

  def render(assigns) do
    ~H"""
    <main class="p" data-ddi-variant="normal">
      <div>counter: {@counter}</div>
      <.live_component
        :for={item <- @questionnaire}
        module={StrangeEditor}
        id={item.id}
        question={item.question}
        answer={Map.get(@answers, item.id, "")}
        form={item.form}
        evaluation={Map.get(@evaluations, item.id, "")}
      />
    </main>
    """
  end
end

I’m continuing debugging the issue. The transport_id of the socket is the same in the handle_info calls for :inc and :evaluate, but for :update_answer it is different. This confirm the suspicion somehow the button clicks are handled differently than the input change.

I don’t understand what this means though.

I’ve tried this and I don’t get this problem. Everything looks good: when I click the buttons, counter increases, when I enter text, counter increases… What am I now doing wrong? :smiley: Full repo here GitHub - kklisura/copy-web-test-app (just created new project with mix phx.new)

1 Like

First, thanks a lot for helping me! Secondly, how clever of you to create a git-repository. I should have done that as well.

The example doesn’t behave as in my original repo for some reason. In your repo, the counter is updated as it should be, and the transport_pid is the same in the socket for all handle_info calls.

Unfortunately, the text in the input is still cleared when you hit “evaluate,” though. I’ll investigate why.

I fixed some logical errors, and now everything works as it should in the repo you created.

How strange. Well, I guess I’ll continue to dig deeper into my real project.

2 Likes

Are you sure that you aren’t encountering an issue in your code and your liveview reloads (which produces a new connection id?)

I don’t think that is the issue, because it will jump between two different transport_pids, not different ones every time. And if it reload, doesn’t it create a completely new LiveView socket?