Elixir + Phoenix still logging when level set to info (with LoggerFileBackend)

vivekmalhotragithub

developing my Elixir + Phoenix with these settings

config/dev.exs

config :logger,
  backends: [{LoggerFileBackend, :info}]

   config :logger, :info,
   path: "log/push_app2_test.log",
   level: :info

the logger in phoenix channel is set to

defmodule PushApp2Web.XYZChannel do
  use Phoenix.Channel, log_join: :debug, log_handle_in: false

Now while testing elixir app with tsung where it creates 50K plus connections I am getting these messages in log.

`13:45:05.939 [warn] Logger has stopped discarding messages

13:45:05.967 [warn] Logger has 1001 messages in its queue, which is above :discard_threshold. Messages will be discarded until the message queue goes back to 75% of the threshold size
13:45:05.968 [warn] Logger has stopped discarding messages`

I also tried to log message with zero arity function as:

`Logger.debug(fn -> "the meaning of life" end)`

I thought all debug messages are not logged. What is happening here and how to fix this??

4 comments

/phoenix #logging #logger

0 3185 4

2018-09-01 23:11:55 UTC

Showing Posts 1 to 4

Show Best Posts
Show All (oldest first)
Show All (newest first)

rjk

isn’t config/dev.exs or config/prod.exs also defining your logger level? (which will then override the one you set in config/config.exs).

To debug which level it is you could start your server with
iex -S mix phx.server # or other arguments you used/need

Then in the console that opens you can see the actual Logger level with: Logger.level

And possibly Mix.env() can show you which environment config file is overwriting your config.exs.

Hope this will help you a bit further.

Cheers,

Redmar

BTW given that everything works i can imagine that the file logger could slow things down during the benchmark. To assert this I would also do a tsung run without logging anything just to see it’s impact on your benchmark.

Post #1

rjk

Just created an empty app with phx.new, added a channel to it and added your config lines that you stated above. It seems to work because it doesn’t log a thing. Only the (info) line that the server is started. If i join the channel with a tool like wsta, nothing gets logged. (even if join it multiple times with that discard_threshold level very low). Maybe try a full rebuild by removing the _build dir?

Post #2

vivekmalhotragithub

I will correct it in my post but the content of the config was indeed from config/dev.exs. However i checked Logger.level in console and it was :debug. Moved the level: :info up in the first config :logger and now it set to :info

    # use LoggerFileBackend to log to an external file
config :logger,
      level: :info,
      backends: [{LoggerFileBackend, :info}]
      ##compile_time_purge_matching: [[level_lower_than: :info]]
   # Do not include metadata nor timestamps in development logs
config :logger, :info,
       path: "log/push_app2_test.log"

This fixed it! Thanks for your response

Post #3

axelson

Scenic Core Team

Also you should do any benchmarking in the prod environment since the code reloader is looking for any changes in all your files when running in Dev which greatly impacts the performance.

Post #4

— All posts loaded —