Hi,
I’m testing out LiveView with my website. I’m loading my Task page as a regular GET and what I would like to do is load and show related Logs after the page has loaded. Here’s what I have so far:
defmodule ZoinksWeb.LogsLive do
use Phoenix.LiveView
use Phoenix.HTML
def render(assigns) do
~L"""
<%= if @days do %>
<%= for {date, logs} <- @days do %>
<h2><%= date |> Timex.format!("{WDfull}, {Mshort} {D}") %></h2>
<ol>
<%= for log <- logs do %>
<%= log.comment %>
<% end %>
</ol>
<% end %>
<% end %>
"""
end
def mount( session, socket ) do
if connected?(socket), do: send( self(), {:fetch, session.current_user} )
{ :ok, assign(socket, :days, nil) }
end
def handle_info( {:fetch, current_user}, socket ) do
days = Logs.logs_by_day( current_user )
{ :noreply, assign( socket, :days, days ) }
end
end
Is calling send in mount/2 the right way to do this? For larger datasets it seems that render is never called (or the result is never sent to the client) - the loader animation just keeps going forever and I don’t see any errors in the log. Which makes me think that I’m doing something wrong
1 Like
I think you can save yourself the surrounding if since the for will not iterate over nil
For debugging i love to use smth like
def handle_info( {:fetch, current_user}, socket ) do
days = Logs.logs_by_day( current_user )
IO.inspect("-------")
IO.inspect(days)
IO.inspect("-------")
{ :noreply, assign( socket, days: days ) }
end
I also spoted { :noreply, assign( socket, days: days ) } please look at days: days in comparison to :days, days
See for example
1 Like
Your example looks fine, other than the unnecessary if @days as b33rduck pointed out. When you say loader animation, does it also have the error state applied? Do your logs show any errors? The loader animation should be removed as soon as the mount occurs, so in your case, the loading animation would be removed before the handle_info call, so it sounds like it may be crashing and rejoining over and over, which your logs will show.
1 Like
This is what I see. The animation is at the bottom of the screen shot:
@b33rduck I added the IO.inspect statements to handle_info and I see data returned for days. I’m using assign(socket, days: days) instead now.
@chrismccord I think you might be right about it reloading? But there are no errors. Here’s the output from my log:
2019-03-19T14:16:22.616509+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | 14:16:22.616 request_id=f8ab32101ab766ae2fe23017177fd166 [info] GET /tasks/1
2019-03-19T14:16:23.089835+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | "In render!"
2019-03-19T14:16:23.090251+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | "Render finished!"
2019-03-19T14:16:23.093905+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | 14:16:23.090 request_id=f8ab32101ab766ae2fe23017177fd166 [info] Sent 200 in 474ms
2019-03-19T14:16:23.999174+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | 14:16:23.998 [info] CONNECT Phoenix.LiveView.Socket
2019-03-19T14:16:23.999228+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | Transport: :websocket
2019-03-19T14:16:23.999261+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | Connect Info: %{}
2019-03-19T14:16:23.999321+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | Parameters: %{"vsn" => "2.0.0"}
2019-03-19T14:16:23.999391+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | 14:16:23.998 [info] Replied Phoenix.LiveView.Socket :ok
2019-03-19T14:16:29.986853+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | "In render!"
2019-03-19T14:16:29.987455+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | "Render finished!"
2019-03-19T14:16:29.987786+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | "Before days"
2019-03-19T14:16:30.031319+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | "After days"
2019-03-19T14:16:30.031502+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | "In render!"
2019-03-19T14:16:30.043650+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | "Render finished!"
2019-03-19T14:17:19.342710+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | "In render!"
2019-03-19T14:17:19.342735+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | "Render finished!"
2019-03-19T14:17:19.343061+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | "Before days"
2019-03-19T14:17:19.518573+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | "After days"
2019-03-19T14:17:19.518610+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | "In render!"
2019-03-19T14:17:19.583738+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | "Render finished!"
2019-03-19T14:18:12.910689+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | "In render!"
2019-03-19T14:18:12.910763+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | "Render finished!"
2019-03-19T14:18:12.911409+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | "Before days"
2019-03-19T14:18:13.068576+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | "After days"
2019-03-19T14:18:13.068798+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | "In render!"
2019-03-19T14:18:13.128450+00:00 sqrnut[sqrnut-813561309-kxrbq]: web.1 | "Render finished!”
Here’s the revised code with the IO.inspect calls:
defmodule ZoinksWeb.LogLive do
use Phoenix.LiveView
use Phoenix.HTML
alias Zoinks.CaptainsLog
import ZoinksWeb.ApplicationHelpers
def render(assigns) do
IO.inspect("In render!")
bob = ~L"""
<%= for {date, logs} <- @days do %>
<h2><%= date |> Timex.format!("{WDfull}, {Mshort} {D}") %></h2>
<ol>
<%= for log <- logs do %>
<%= log.comment %>
<% end %>
</ol>
<% end %>
"""
IO.inspect("Render finished!")
bob
end
def mount( session, socket ) do
if connected?(socket), do: send( self(), {:fetch, session.current_user, session.blocks} )
#{:ok, fetch(session, socket)}
{ :ok, assign(socket, days: []) }
end
def handle_info( {:fetch, current_user, blocks}, socket ) do
IO.inspect "Before days"
days = Logs.logs_by_day( current_user )
IO.inspect "After days"
{ :noreply, assign( socket, days: days ) }
end
end
does this only happen in prod (looks like heroku logs)? What does the javascript console show? It looks like the connection is dropping based on the logs since we are seeing repeated calls but no errors.
I’ve only replicated this in prod (at this stage). The logs are from Gigalixir. I need to copy my prod data to my dev machine so I can test it in a different environment - which I won’t be able to do until after work tonight.
As for the Javascript console - nothing is in there either.
After some more testing, I’ve discovered that the problem only occurs on my broadband connection at home. If I switch to 4G on my phone, then the data is successfully retrieved and it renders. The broadband connection at work is successful too. What I think is happening is that my broadband connection at home is the slowest of the three networks and some sort of timeout or disconnection happens.
It’s worth mentioning at this point that I’m on the free tier of Gigalixir - which isn’t intended for production. So maybe after a period of time the connection just terminates (even though we got to “Render finished!”)?
However, in the case that the server terminates the connection or a timeout, should I expect to see something in the Javascript console?
Also, I have Sentry hooked up to my prod server. No exceptions in there either
I was wrong about the Javascript console! Here’s the output I see when I use my dev machine at home (when accessing the prod server):
Uncaught TypeError: Cannot read property '0' of undefined
at e (app-649df31f7d3a6221653c7d3ab3cdfec8.js?vsn=d:71)
at Object.mergeDiff (app-649df31f7d3a6221653c7d3ab3cdfec8.js?vsn=d:71)
at e.value (app-649df31f7d3a6221653c7d3ab3cdfec8.js?vsn=d:71)
at Object.callback (app-649df31f7d3a6221653c7d3ab3cdfec8.js?vsn=d:71)
at e.value (app-649df31f7d3a6221653c7d3ab3cdfec8.js?vsn=d:71)
at app-649df31f7d3a6221653c7d3ab3cdfec8.js?vsn=d:71
at e.decode (app-649df31f7d3a6221653c7d3ab3cdfec8.js?vsn=d:71)
at e.value (app-649df31f7d3a6221653c7d3ab3cdfec8.js?vsn=d:71)
at WebSocket.conn.conn.onmessage (app-649df31f7d3a6221653c7d3ab3cdfec8.js?vsn=d:71)
I think I figured it out. I copied my prod database to my dev machine and the problem still occurred. Here’s the javascript error un-obfuscated:
[Error] TypeError: undefined is not an object (evaluating 'target[key]')
recursiveMerge (phoenix_live_view.js:85)
mergeDiff (phoenix_live_view.js:98)
update (phoenix_live_view.js:737)
value (phoenix.js:402)
(anonymous function) (phoenix.js:672)
value (phoenix.js:662)
After a little digging, it seems that View.update is being called before View.onJoin. In this situation, this.rendered hasn’t been set yet and mergeDiff throws an exception - which prevents rendering until the next retry. I’m assuming the sequence of events transpires because it takes a long time to retrieve the large dataset. In the case of the prod server, it’s due to my home broadband speed. In the case of my dev machine, it’s just not as fast as the prod servers.
I tried the following mod in phoenix_live_view.js:
update(diff){
// Extra check for this.rendered
if(isEmpty(diff) || isEmpty(this.rendered)){ return }
this.log("update", () => ["", JSON.stringify(diff)])
this.rendered = Rendered.mergeDiff(this.rendered, diff)
let html = Rendered.toString(this.rendered)
this.newChildrenAdded = false
DOM.patch(this, this.el, this.id, html)
if(this.newChildrenAdded){ this.joinNewChildren() }
}
In this circumstance (because the exception isn’t thrown) onJoin is called and business continues as per usual.
Turns out that it wasn’t a timeout issue or a dropped connection, it was a timing issue 
@chrismccord I’m not sure if the above is the best solution, maybe it’s useful?
It shouldn’t be possible for update to be called prior to onJoin, since you have to join the channel first before receiving the "render" event which triggers View.update. Can you do a little more digging to verify the order of things. I don’t doubt the above fixes it, but there’s something else going on to cause what you’re seeing. If it’s indeed an event arriving before the join event, it would be a bug on the channels side, but I don’t believe we’ve encountered such an issue before.
2 Likes
So it turns out that I forgot to disable the database call in my original controller(!):
def show(conn, %{"id" => id}) do
current_user = Zoinks.Guardian.Plug.current_resource(conn)
task = Tasks.get_task!(id)
logs = Logs.logs_by_day( current_user )
render(conn, "show.html", Task: task, Logs: logs)
end
The template for :show doesn’t utilise @logs (and doesn’t take very long to render). However, it did make this.channel.join() timeout. Removing logs from the render call prevents the timeout from happening:
def show(conn, %{"id" => id}) do
current_user = Zoinks.Guardian.Plug.current_resource(conn)
task = Tasks.get_task!(id)
logs = Logs.logs_by_day( current_user )
# Logs removed
render(conn, "show.html", Task: task)
end
I can confirm that this commit addresses the timeout issue. With the first verion of show (above) this.channel.join() still takes a long time to yield a result - but View.onJoin is now called before View.update.
Sorry I wasn’t much help! Thanks for putting your time into LiveView - I really like it!
1 Like
