Change log level from info to notice on relevant logs (#5585)

* change log level from info to notice on relevant logs

* bump log level to notice for everything except request logger

* format

* fix choose_plan_test.exs for good (starter tier launch)

lib/mix/tasks/cancel_subscription.ex

@@ -19,6 +19,6 @@ defmodule Mix.Tasks.CancelSubscription do
     |> Subscription.changeset(%{status: Subscription.Status.deleted()})
     |> Repo.update!()
 
-    Logger.info("Successfully set the subscription status to #{Subscription.Status.deleted()}")
+    Logger.notice("Successfully set the subscription status to #{Subscription.Status.deleted()}")
   end
 end

lib/mix/tasks/download_country_database.ex

@@ -19,13 +19,13 @@ defmodule Mix.Tasks.DownloadCountryDatabase do
     last_month = last_month |> Date.to_iso8601() |> binary_part(0, 7)
     this_month_url = "https://download.db-ip.com/free/dbip-country-lite-#{this_month}.mmdb.gz"
     last_month_url = "https://download.db-ip.com/free/dbip-country-lite-#{last_month}.mmdb.gz"
-    Logger.info("Downloading #{this_month_url}")
+    Logger.notice("Downloading #{this_month_url}")
     res = HTTPoison.get!(this_month_url)
 
     res =
       case res.status_code do
         404 ->
-          Logger.info("Got 404 for #{this_month_url}, trying #{last_month_url}")
+          Logger.warning("Got 404 for #{this_month_url}, trying #{last_month_url}")
           HTTPoison.get!(last_month_url)
 
         _ ->
@@ -35,7 +35,7 @@ defmodule Mix.Tasks.DownloadCountryDatabase do
     if res.status_code == 200 do
       File.mkdir("priv/geodb")
       File.write!("priv/geodb/dbip-country.mmdb.gz", res.body)
-      Logger.info("Downloaded and saved the database successfully")
+      Logger.notice("Downloaded and saved the database successfully")
     else
       Logger.error("Unable to download and save the database. Response: #{inspect(res)}")
     end

lib/mix/tasks/pull_sandbox_subscription.ex

@@ -58,7 +58,7 @@ defmodule Mix.Tasks.PullSandboxSubscription do
           Subscription.changeset(%Subscription{}, subscription)
           |> Repo.insert!()
 
-          Logger.info("Subscription created for user #{user.id} (#{user.email})")
+          Logger.notice("Subscription created for user #{user.id} (#{user.email})")
         else
           Logger.error(body["error"])
         end

lib/plausible/cache/warmer.ex

@@ -50,7 +50,7 @@ defmodule Plausible.Cache.Warmer do
     force_start? = Keyword.get(opts, :force_start?, false)
 
     if Plausible.Cache.enabled?() or force_start? do
-      Logger.info(
+      Logger.notice(
         "#{__MODULE__} initializing #{inspect(warmer_fn)} #{cache_name} with interval #{interval}..."
       )
 
@@ -69,7 +69,7 @@ defmodule Plausible.Cache.Warmer do
     cache_name = Keyword.fetch!(opts, :cache_name)
     warmer_fn = Keyword.fetch!(opts, :warmer_fn)
 
-    Logger.info("#{__MODULE__} running #{inspect(warmer_fn)} on #{cache_name}...")
+    Logger.notice("#{__MODULE__} running #{inspect(warmer_fn)} on #{cache_name}...")
 
     warmer_fn.(opts)
 

lib/plausible/imported/buffer.ex

@@ -55,7 +55,7 @@ defmodule Plausible.Imported.Buffer do
   end
 
   def handle_call({:insert_many, table_name, records}, _from, %{buffers: buffers} = state) do
-    Logger.info("Import: Adding #{length(records)} to #{table_name} buffer")
+    Logger.notice("Import: Adding #{length(records)} to #{table_name} buffer")
 
     new_buffer = Map.get(buffers, table_name, []) ++ records
     new_state = put_in(state.buffers[table_name], new_buffer)
@@ -91,7 +91,7 @@ defmodule Plausible.Imported.Buffer do
     # sleep call slows down the flushing
     Process.sleep(flush_interval)
 
-    Logger.info("Import: Flushing #{length(records)} from #{table_name} buffer")
+    Logger.notice("Import: Flushing #{length(records)} from #{table_name} buffer")
     insert_all(table_name, records)
   end
 

lib/plausible/ingestion/write_buffer.ex

@@ -49,7 +49,7 @@ defmodule Plausible.Ingestion.WriteBuffer do
     }
 
     if state.buffer_size >= state.max_buffer_size do
-      Logger.info("#{state.name} buffer full, flushing to ClickHouse")
+      Logger.notice("#{state.name} buffer full, flushing to ClickHouse")
       Process.cancel_timer(state.timer)
       do_flush(state)
       new_timer = Process.send_after(self(), :tick, state.flush_interval_ms)
@@ -77,7 +77,7 @@ defmodule Plausible.Ingestion.WriteBuffer do
 
   @impl true
   def terminate(_reason, %{name: name} = state) do
-    Logger.info("Flushing #{name} buffer before shutdown...")
+    Logger.notice("Flushing #{name} buffer before shutdown...")
     do_flush(state)
   end
 
@@ -96,7 +96,7 @@ defmodule Plausible.Ingestion.WriteBuffer do
         nil
 
       _not_empty ->
-        Logger.info("Flushing #{buffer_size} byte(s) RowBinary from #{name}")
+        Logger.notice("Flushing #{buffer_size} byte(s) RowBinary from #{name}")
         IngestRepo.query!(insert_sql, [header | buffer], insert_opts)
     end
   end

lib/plausible/session/transfer.ex

@@ -35,7 +35,7 @@ defmodule Plausible.Session.Transfer do
 
   @impl true
   def init(nil) do
-    Logger.info(
+    Logger.notice(
       "Session transfer: ignoring, no socket base path configured (make sure ENABLE_SESSION_TRANSFER/PERSISTENT_CACHE_DIR are set)"
     )
 
@@ -65,7 +65,7 @@ defmodule Plausible.Session.Transfer do
          _until = fn ->
            result = :counters.get(given_counter, 1) > 0
 
-           Logger.info(
+           Logger.notice(
              "Session transfer delayed shut down. Checking if session takeover happened?: #{result}"
            )
 
@@ -74,7 +74,7 @@ defmodule Plausible.Session.Transfer do
         shutdown: :timer.seconds(15)
       )
 
-    Logger.info("Session transfer init: #{base_path}")
+    Logger.notice("Session transfer init: #{base_path}")
     Supervisor.init([replica, primary, alive], strategy: :one_for_one)
   end
 
@@ -84,7 +84,7 @@ defmodule Plausible.Session.Transfer do
   """
   def attempted?(transfer_sup \\ __MODULE__) do
     result = not replica_alive?(transfer_sup)
-    Logger.info("Session transfer attempted?: #{result}")
+    Logger.notice("Session transfer attempted?: #{result}")
     result
   end
 
@@ -102,7 +102,9 @@ defmodule Plausible.Session.Transfer do
   end
 
   defp handle_replica(request, parent, given_counter) do
-    Logger.info("Session transfer message received at #{node()}: #{inspect(request, limit: 10)}")
+    Logger.notice(
+      "Session transfer message received at #{node()}: #{inspect(request, limit: 10)}"
+    )
 
     case request do
       {@cmd_list_cache_names, session_version} ->
@@ -132,19 +134,19 @@ defmodule Plausible.Session.Transfer do
   end
 
   defp request_takeover(sock) do
-    Logger.info("Session transfer: requesting takeover at #{node()}")
+    Logger.notice("Session transfer: requesting takeover at #{node()}")
 
     with {:ok, names} <- TinySock.call(sock, {@cmd_list_cache_names, session_version()}) do
       tasks = Enum.map(names, fn name -> Task.async(fn -> takeover_cache(sock, name) end) end)
       Task.await_many(tasks, :timer.seconds(10))
     end
   after
-    Logger.info("Session transfer: marking takeover as done at #{node()}")
+    Logger.notice("Session transfer: marking takeover as done at #{node()}")
     TinySock.call(sock, @cmd_takeover_done)
   end
 
   defp takeover_cache(sock, cache) do
-    Logger.info("Session transfer: requesting cache #{cache} dump at #{node()}")
+    Logger.notice("Session transfer: requesting cache #{cache} dump at #{node()}")
 
     with {:ok, records} <- TinySock.call(sock, {@cmd_dump_cache, cache}) do
       Enum.each(records, fn record ->
@@ -152,7 +154,7 @@ defmodule Plausible.Session.Transfer do
         Cache.Adapter.put(:sessions, key, session)
       end)
 
-      Logger.info("Session transfer: restored cache #{cache} at #{node()}")
+      Logger.notice("Session transfer: restored cache #{cache} at #{node()}")
     end
   end
 

lib/plausible/stats/sql/where_builder.ex

@@ -161,7 +161,7 @@ defmodule Plausible.Stats.SQL.WhereBuilder do
   end
 
   defp add_filter(table, _query, filter) do
-    Logger.info("Unable to process garbage filter. No results are returned",
+    Logger.notice("Unable to process garbage filter. No results are returned",
       table: table,
       filter: filter
     )

lib/plausible_release.ex

@@ -63,7 +63,10 @@ defmodule Plausible.Release do
     streaks = migration_streaks(pending)
 
     Enum.each(streaks, fn {repo, up_to_version} ->
-      {:ok, _, _} = Ecto.Migrator.with_repo(repo, &Ecto.Migrator.run(&1, :up, to: up_to_version))
+      {:ok, _, _} =
+        Ecto.Migrator.with_repo(repo, &Ecto.Migrator.run(&1, :up, to: up_to_version),
+          log: :notice
+        )
     end)
   end
 

lib/workers/clickhouse_clean_sites.ex

@@ -37,7 +37,7 @@ defmodule Plausible.Workers.ClickhouseCleanSites do
     deleted_sites = get_deleted_sites_with_clickhouse_data()
 
     if not Enum.empty?(deleted_sites) do
-      Logger.info(
+      Logger.notice(
         "Clearing ClickHouse data for the following #{length(deleted_sites)} sites which have been deleted: #{inspect(deleted_sites)}"
       )
 

lib/workers/purge_cdn_cache.ex

@@ -53,7 +53,7 @@ defmodule Plausible.Workers.PurgeCDNCache do
 
     case Req.post("https://api.bunny.net/pullzone/#{pullzone_id}/purgeCache", options) do
       {:ok, %{status: 204}} ->
-        Logger.info("Successfully purged CDN cache for tracker script #{id}")
+        Logger.notice("Successfully purged CDN cache for tracker script #{id}")
         {:ok, :success}
 
       {:ok, %{status: status}} ->

lib/workers/set_legacy_time_on_page_cutoff.ex

@@ -23,7 +23,7 @@ defmodule Plausible.Workers.SetLegacyTimeOnPageCutoff do
     to_update = small_sites ++ large_sites
 
     if length(to_update) > 0 do
-      Logger.info(
+      Logger.notice(
         "Setting legacy_time_on_page_cutoff for #{length(to_update)} sites (#{length(small_sites)} small, #{length(large_sites)} large)"
       )
 
@@ -36,7 +36,9 @@ defmodule Plausible.Workers.SetLegacyTimeOnPageCutoff do
           set: [legacy_time_on_page_cutoff: cutoff_date]
         )
 
-      Logger.info("Successfully set legacy_time_on_page_cutoff=#{cutoff_date} for #{count} sites")
+      Logger.notice(
+        "Successfully set legacy_time_on_page_cutoff=#{cutoff_date} for #{count} sites"
+      )
     else
       Logger.debug("No sites legacy_time_on_page_cutoff needs updating")
     end

test/plausible_web/live/choose_plan_test.exs

@@ -65,17 +65,6 @@ defmodule PlausibleWeb.Live.ChoosePlanTest do
     describe "for a user with no subscription" do
       setup [:create_user, :create_site, :log_in]
 
-      setup %{user: user} do
-        {:ok, team} = Plausible.Teams.get_or_create(user)
-
-        trial_expiry_date = Plausible.Teams.Billing.starter_tier_launch() |> Date.shift(day: -30)
-
-        Ecto.Changeset.change(team, %{trial_expiry_date: trial_expiry_date})
-        |> Repo.update()
-
-        :ok
-      end
-
       test "displays basic page content", %{conn: conn} do
         {:ok, _lv, doc} = get_liveview(conn)
 
@@ -398,15 +387,7 @@ defmodule PlausibleWeb.Live.ChoosePlanTest do
       @tag :slow
       test "allows upgrade to a 100k plan with a pageview allowance margin of 0.15 when trial is active",
            %{conn: conn, site: site, user: user} do
-        {:ok, team} = Plausible.Teams.get_or_create(user)
-
-        new_trial_expiry_date =
-          Plausible.Teams.Billing.starter_tier_launch() |> Date.shift(day: 31)
-
-        # NOTE: This is temporary, making sure that the trial is treated as active,
-        # but at the same time, ineligible for seeing the old upgrade page.
-        Ecto.Changeset.change(team, %{trial_expiry_date: new_trial_expiry_date})
-        |> Repo.update!()
+        Plausible.Teams.get_or_create(user)
 
         generate_usage_for(site, 115_000)