Compilation-warnings is logged multiple times

When I run my application with mix phx.server, I am first shown the warnings from compiling in the console, then the page loads, and then all compile-warnings for all the files (also those not edited), but without the color formatting that I get the first time. It seems like the warnings are logged in the console multiple times upon starting the application, before mounting, after mounting and one more time, but it is hard to say since I can’t scroll all the way back in the console because it is to many errors. They are also shown if I refresh the page.

I have tried to turn off all logging, but it hasn’t helped. The one thing that seems to help is to comment out code_reloader: true in dev.exs, but I would like to have that to true.

I assume there is some configs somewhere that messes it up, and that it might be related to the liveview-rendering-process, but I am not sure where or how to fix it. Help would be very much appreciated.

I don’t know what configs might be relevant to show here, so just ask.

I’m using elixir 1.14, phoenix 1.7 and phoenix liveview 0.18.

1 Like

Im not sure if this is a “new” thing or not but I noticed the same behavior when upgrading an old phoenix app I had. Upgraded Elixir to the latest and all the deps… I just went ahead and fixed all the warnings though :man_shrugging:t3:

Elixir has changed to show all warnings on every compilation. Which makes sense for the command line but perhaps it does not make sense for Phoenix apps?

It is tricky because if you have few warnings, seeing all is nice because it makes sure you didn’t miss anything, but I can see it being annoying when you have so many warnings you can’t see the actual logs. I will provide an option to switch it off.

1 Like

Can you please try Phoenix main later with this configuration? Add :reloadable_args to code server · phoenixframework/phoenix@7547df0 · GitHub Thank you!

3 Likes

I like it for Phoenix apps too, the big reason I had a bunch of warnings was that I didn’t know about them… and this new behavior surface them :slight_smile:
I agree it would be nice to be able to have the option to silence it though.

I added changed to {:phoenix, git: "https://github.com/phoenixframework/phoenix.git", override: true} in mix.exs, and updated my endpoint-configs to

  debug_errors: true,
  check_origin: false,
  code_reloader: true,
  reloadable_args: ["--no-all-warnings"],

  live_reload: [
     patterns: [
       ~r"priv/static/.*(js|css|png|jpeg|jpg|gif|svg)$",
       ~r"lib/moni/web/(live|views)/.*(ex)$",
       ~r"lib/moni/web/templates/.*(eex)$",
     ]
   ]

If I have code_reloader: true, after the first compile warnings, and connection to socket, I will get the warnings printed once or twice more, without the orange warning-color when I run mix phx.server. If I change a file and/or reload, I will se the compile warnings, the warnings without color printed twice, then mount and render, then the warnings without colors again twice, the connection to socket, and at the end the warnings without the colors again.

If I have code_reloader: false, then I only see the warnings at the first compile, with the colors.

If i add the ẁatchers-configs too, it seems like the warnings are printed even more times.

The configs you added doesn’t seem to make any difference, but it might be that it disappears in the noise of all the warnings.

Is there any reasons why the warnings would be printed without the color formatting, and multiple times right after each other?

I think I may be experiencing the same thing as you, where upon every request it seems like the code reloader is doing… something even though I’m not actively making any code changes. This seems to be a new behavior since 1.7.

example logs:

warning: variable "user" is unused (if the variable is not meant to be used, prefix it with an underscore)
  ...:55
[info] POST /_/...
[info] Sent 200 in 7ms

warning: variable "user" is unused (if the variable is not meant to be used, prefix it with an underscore)
  ...:55
[info] POST /_/...
[info] Sent 200 in 1ms

warning: variable "user" is unused (if the variable is not meant to be used, prefix it with an underscore)
  ...:55
[info] POST /_/...
[debug] Processing with ...
[info] Sent 200 in 1ms

I started noticing this because of very large slowdowns in local development. The Phoenix logs are claiming to respond within milliseconds but my NGINX proxy says its waiting for up to 5-10s on responses from the upstream.

When I set code_reloader: false, everything goes back to full speed and I don’t see warnings upon every request.

Still investigating root causes further.

1 Like

Some more data: commenting out Phoenix.Ecto.CheckRepoStatus from the code_reloading? block in the Endpoint removes most of the slowdown.

So I’m guessing that 1) for some reason the code reloading is triggering on every request and 2) Phoenix.Ecto.CheckRepoStatus is quite slow.

Not sure why #1 is occurring still however.

FWIW my entire team has been suffering from this so its not unique to my machine, but it might be something in our codebase…

Re: the log colors, I think the reason you see different behavior:

The “real” compilation warnings are formatted like [warning] while these “phantom” per-request compilation warnings are formatted like warning: which I’m assuming is not triggering the ANSI colors.

Another datapoint (red-herring?): it’s only been teammates on Apple Silicon Macs that have been impacted, those with Intel Macs have not.

Thanks for checking @teatimes.

Does any of you see this behavior in a brand new Phoenix app? I am out of ideas and I wonder if you can find a way to reproduce it so I can try to further debug if.

I’m having the same exact issue with 1.7.2 from time to time between live recompilations. I shut down and restart, then it disappears. My gut says it has something to do with the renaming of a module, as if it stays in the VM refs. I’ll be more observant now as others have experienced the same.

I created a new project with mix phx.new hello with
``
erlang 25.3
elixir 1.14.4-otp-25
nodejs 14.5.0

``
in .tool-versions.

I then created

lib/hello_web/live/dashboard_live/index.ex

defmodule HelloWeb.DashboardLive.Index do
  use HelloWeb, :live_view

  @impl true
  def mount(params, session, socket) do

    IO.inspect("Mounting dashboard")

    {:ok, socket}
  end
end

and lib/hello_web/live_dashboard_live/index.html.heex

<div class="ui container">
  <div class="ui basic segment">
    <div class="ui stackable grid">
      <div class="sixteen wide column">
        <p> This is the dashboard </p>

      </div>
      <div class="two column row">
        <p> Here there would be a component </p>

      </div>
    </div>
  </div>
</div>

I also altered the route for “/” to live "/", DashboardLive.Index, :index.

When I now run the application, I see this in the console:

Compiling 1 file (.ex)
warning: variable "params" is unused (if the variable is not meant to be used, prefix it with an underscore)
  lib/hello_web/live/dashboard_live/index.ex:5: HelloWeb.DashboardLive.Index.mount/3

warning: variable "session" is unused (if the variable is not meant to be used, prefix it with an underscore)
  lib/hello_web/live/dashboard_live/index.ex:5: HelloWeb.DashboardLive.Index.mount/3

[info] Running HelloWeb.Endpoint with cowboy 2.10.0 at 127.0.0.1:4000 (http)
[info] Access HelloWeb.Endpoint at http://localhost:4000
[watch] build finished, watching for changes...
Browserslist: caniuse-lite is outdated. Please run:
  npx update-browserslist-db@latest
  Why you should do it regularly: https://github.com/browserslist/update-db#readme

Rebuilding...

Done in 205ms.

warning: variable "params" is unused (if the variable is not meant to be used, prefix it with an underscore)
  lib/hello_web/live/dashboard_live/index.ex:5

warning: variable "session" is unused (if the variable is not meant to be used, prefix it with an underscore)
  lib/hello_web/live/dashboard_live/index.ex:5


And when I reload the page, I see this:

warning: variable "params" is unused (if the variable is not meant to be used, prefix it with an underscore)
  lib/hello_web/live/dashboard_live/index.ex:5

warning: variable "session" is unused (if the variable is not meant to be used, prefix it with an underscore)
  lib/hello_web/live/dashboard_live/index.ex:5
[info] GET /

warning: variable "params" is unused (if the variable is not meant to be used, prefix it with an underscore)
  lib/hello_web/live/dashboard_live/index.ex:5

warning: variable "session" is unused (if the variable is not meant to be used, prefix it with an underscore)
  lib/hello_web/live/dashboard_live/index.ex:5
[debug] Processing with HelloWeb.DashboardLive.Index.index/2
  Parameters: %{}
  Pipelines: [:browser]
"Mounting dashboard"
[info] Sent 200 in 47ms

warning: variable "params" is unused (if the variable is not meant to be used, prefix it with an underscore)
  lib/hello_web/live/dashboard_live/index.ex:5

warning: variable "session" is unused (if the variable is not meant to be used, prefix it with an underscore)
  lib/hello_web/live/dashboard_live/index.ex:5
[info] CONNECTED TO Phoenix.LiveView.Socket in 21µs
  Transport: :websocket
  Serializer: Phoenix.Socket.V2.JSONSerializer
  Parameters: %{"_csrf_token" => "EDUxMwYiE2AZCQI5GTg7AyFgEiw3AA1bIBAkBJUTXMOOXhaAt9fkyNX9", "_live_referer" => "undefined", "_mounts" => "0", "_track_static" => %{"0" => "http://localhost:4000/assets/app.css", "1" => "http://localhost:4000/assets/app.js"}, "vsn" => "2.0.0"}
[debug] MOUNT HelloWeb.DashboardLive.Index
  Parameters: %{}
  Session: %{"_csrf_token" => "YwpXDhF4ADMvAPZBUYtGNNUb"}
"Mounting dashboard"
[debug] Replied in 213µs

warning: variable "params" is unused (if the variable is not meant to be used, prefix it with an underscore)
  lib/hello_web/live/dashboard_live/index.ex:5

warning: variable "session" is unused (if the variable is not meant to be used, prefix it with an underscore)
  lib/hello_web/live/dashboard_live/index.ex:5


Based on this, it seems like it’s nothing in my project, per se, but something about the environment on my (and others) computers, maybe?

I am running Ubuntu 22.04 (Lenovo X1 Extreme gen 5), and installed Elixir and Erlang with `asdf. In the new project I created, I used elixir 1.14, and the other deps are

    [
      {:phoenix, "~> 1.7.2"},
      {:phoenix_ecto, "~> 4.4"},
      {:ecto_sql, "~> 3.6"},
      {:postgrex, ">= 0.0.0"},
      {:phoenix_html, "~> 3.3"},
      {:phoenix_live_reload, "~> 1.2", only: :dev},
      {:phoenix_live_view, "~> 0.18.16"},
      {:floki, ">= 0.30.0", only: :test},
      {:phoenix_live_dashboard, "~> 0.7.2"},
      {:esbuild, "~> 0.7", runtime: Mix.env() == :dev},
      {:tailwind, "~> 0.2.0", runtime: Mix.env() == :dev},
      {:swoosh, "~> 1.3"},
      {:finch, "~> 0.13"},
      {:telemetry_metrics, "~> 0.6"},
      {:telemetry_poller, "~> 1.0"},
      {:gettext, "~> 0.20"},
      {:jason, "~> 1.2"},
      {:plug_cowboy, "~> 2.5"}
    ]

Thank you so much for you help (and Elixir in general)!

2 Likes

I just tried setting {:phoenix, "== 1.7.1"} in mix.env, and that seems to solve the problem for me with the duplicated warnings.

1 Like

Perfect. I can reproduce it and I have an idea of what it might be. Thank you! :heart:

3 Likes

It should be fixed on main. Can you please give it a try?

Went back to using the main version of Phoenix, and the duplicated warnings doesn’t show anymore. I still get the compiled warnings every time I make a change or refresh. Was that supposed to happen when using reloadable_args: ["--no-all-warnings"]?

1 Like

Oh, I removed this option because I was hoping it was no longer necessary because all duplication was gone. I can add it back though. Do you have enough warnings that without this option the console logs feel useless?

I fixed most of the warnings now, but it would be nice during development to have the option to at least reduce the amount of warnings you see.

1 Like