Make it easier to identify NervesTime logs

lib/nerves_time/ntpd.ex

@@ -157,7 +157,7 @@ defmodule NervesTime.Ntpd do
 
   def handle_info({:EXIT, from, reason}, state) do
     # Log abnormal exits to aide debugging.
-    Logger.info("NervesTime.Ntpd: unexpected :EXIT #{inspect(from)}/#{inspect(reason)}")
+    Logger.info("[NervesTime] unexpected ntpd :EXIT #{inspect(from)}/#{inspect(reason)}")
     {:stop, reason, state}
   end
 
@@ -177,7 +177,7 @@ defmodule NervesTime.Ntpd do
           true
 
         :ok ->
-          Logger.warning("ntpd crash detected. Delaying next start...")
+          Logger.warning("[NervesTime] ntpd crash detected. Delaying next start...")
           false
       end
 
@@ -241,7 +241,7 @@ defmodule NervesTime.Ntpd do
   end
 
   defp handle_ntpd_report({"unsync", _freq_drift_ppm, _offset, _stratum, _poll_interval}, state) do
-    Logger.error("ntpd reports that it is unsynchronized; restarting")
+    Logger.error("[NervesTime] ntpd reports that it is unsynchronized; restarting")
 
     # According to the Busybox ntpd docs, if you get an `unsync` notification, then
     # you should restart ntpd to be safe. This is stated to be due to name resolution
@@ -255,7 +255,7 @@ defmodule NervesTime.Ntpd do
   end
 
   defp handle_ntpd_report(report, state) do
-    Logger.error("ntpd ignored unexpected report #{inspect(report)}")
+    Logger.error("[NervesTime] ntpd ignored unexpected report #{inspect(report)}")
     {:noreply, state}
   end
 
@@ -270,7 +270,7 @@ defmodule NervesTime.Ntpd do
     # Add "-d" and enable log_output below for more verbose prints from ntpd.
     args = ["-n", "-S", ntpd_script_path | server_args]
 
-    Logger.debug("Starting #{ntpd_path} with: #{inspect(args)}")
+    Logger.debug("[NervesTime] starting #{ntpd_path} with: #{inspect(args)}")
 
     {:ok, pid} =
       MuonTrap.Daemon.start_link(ntpd_path, args,

lib/nerves_time/system_time.ex

@@ -65,7 +65,10 @@ defmodule NervesTime.SystemTime do
   defp normalize_rtc_spec(module) when is_atom(module), do: {module, []}
 
   defp normalize_rtc_spec(other) do
-    Logger.error("Bad rtc spec '#{inspect(other)}. Reverting to '#{inspect(@default_rtc)}'")
+    Logger.error(
+      "[NervesTime] Bad rtc spec '#{inspect(other)}. Reverting to '#{inspect(@default_rtc)}'"
+    )
+
     @default_rtc
   end
 
@@ -117,7 +120,7 @@ defmodule NervesTime.SystemTime do
   @impl GenServer
   def terminate(reason, %{rtc: rtc, rtc_state: rtc_state}) do
     if rtc do
-      Logger.warning("Stopping RTC #{inspect(rtc)}: #{inspect(reason)}")
+      Logger.warning("[NervesTime] Stopping RTC #{inspect(rtc)}: #{inspect(reason)}")
       rtc.terminate(rtc_state)
     end
 
@@ -132,13 +135,16 @@ defmodule NervesTime.SystemTime do
         %{state | rtc: rtc_module, rtc_state: rtc_state}
 
       {:error, reason} ->
-        Logger.error("Cannot initialize rtc '#{inspect(state.rtc_spec)}': #{inspect(reason)}")
+        Logger.error(
+          "[NervesTime] Cannot initialize rtc '#{inspect(state.rtc_spec)}': #{inspect(reason)}"
+        )
+
         state
     end
   catch
     what, why ->
       Logger.error(
-        "Cannot initialize rtc '#{inspect(state.rtc_spec)}': #{inspect(what)}, #{inspect(why)}"
+        "[NervesTime] Cannot initialize rtc '#{inspect(state.rtc_spec)}': #{inspect(what)}, #{inspect(why)}"
       )
 
       state
@@ -149,12 +155,15 @@ defmodule NervesTime.SystemTime do
     final_rtc_state =
       case rtc.get_time(state.rtc_state) do
         {:ok, %NaiveDateTime{} = rtc_time, next_rtc_state} ->
-          Logger.info("[#{inspect(rtc)}] RTC reports that the time is #{inspect(rtc_time)}")
+          Logger.info(
+            "[NervesTime] #{inspect(rtc)} reports that the time is #{inspect(rtc_time)}"
+          )
+
           check_rtc_time_and_set(rtc, rtc_time, next_rtc_state)
 
         # Try to fix an unset or corrupt RTC
         {:unset, next_rtc_state} ->
-          Logger.info("[#{inspect(rtc)}] RTC reports that the time hasn't been set.")
+          Logger.info("[NervesTime] #{inspect(rtc)} reports that the time hasn't been set.")
           now = sane_system_time()
           rtc.set_time(next_rtc_state, now)
       end
@@ -216,12 +225,12 @@ defmodule NervesTime.SystemTime do
 
     case System.cmd("date", ["-u", "-s", string_time]) do
       {_result, 0} ->
-        Logger.info("nerves_time set system clock to #{string_time} UTC")
+        Logger.info("[NervesTime] nerves_time set system clock to #{string_time} UTC")
         :ok
 
       {message, code} ->
         Logger.error(
-          "nerves_time can't set system clock to '#{string_time}': #{code} #{inspect(message)}"
+          "[NervesTime] nerves_time can't set system clock to '#{string_time}': #{code} #{inspect(message)}"
         )
 
         :error

lib/nerves_time/waiter.ex

@@ -22,7 +22,7 @@ defmodule NervesTime.Waiter do
 
     with t when t > 0 <- timeout,
          :timeout <- NervesTime.SystemTime.await_initialization(timeout) do
-      Logger.warning("Timeout expired when waiting for system time adjustment")
+      Logger.warning("[NervesTime] Timeout expired when waiting for system time adjustment")
     end
 
     :ignore