Skip to content

Commit

Permalink
Periodically save the current buffers to a file, load on start
Browse files Browse the repository at this point in the history
Persist the current circular buffers every `:persist_seconds`. When
the backend starts, try to load the persisted logs and reinsert into the
configured buffers.
  • Loading branch information
oestrich authored and fhunleth committed Mar 7, 2023
1 parent 97296f4 commit 1668465
Show file tree
Hide file tree
Showing 7 changed files with 254 additions and 10 deletions.
3 changes: 3 additions & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -35,6 +35,9 @@ use Mix.Config
# Add the RingLogger backend. This removes the default :console backend.
config :logger, backends: [RingLogger]

# Periodically save logs to a file, and load logs on GenServer start from this file
config :logger, RingLogger, persist_path: "./myapp.log", persist_seconds: 300

# Save messages to one circular buffer that holds 1024 entries.
config :logger, RingLogger, max_size: 1024

Expand Down
12 changes: 11 additions & 1 deletion lib/ring_logger.ex
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,9 @@ defmodule RingLogger do
# Add the RingLogger backend. This removes the default :console backend.
config :logger, backends: [RingLogger]
# Periodically save logs to a file, and load logs on GenServer start from this file
config :logger, RingLogger, persist_path: "./myapp.log", persist_seconds: 300
# Save messages to one circular buffer that holds 1024 entries.
config :logger, RingLogger, max_size: 1024
Expand Down Expand Up @@ -56,7 +59,14 @@ defmodule RingLogger do
alias RingLogger.Server

@typedoc "Option values used by the ring logger"
@type server_option() :: {:max_size, pos_integer()}
@type server_option() ::
{:max_size, pos_integer()}
| {:buffers, %{term() => buffer()}}
| {:persist_path, String.t()}
| {:persist_seconds, pos_integer()}

@typedoc "Options to define a separate buffer based on log levels"
@type buffer() :: %{levels: [Logger.level()], max_size: pos_integer()}

@typedoc "Callback function for printing/paging tail, grep, and next output"
@type pager_fun() :: (IO.device(), IO.chardata() -> :ok | {:error, term()})
Expand Down
1 change: 1 addition & 0 deletions lib/ring_logger/client.ex
Original file line number Diff line number Diff line change
Expand Up @@ -112,6 +112,7 @@ defmodule RingLogger.Client do
{io, to_print} = GenServer.call(client_pid, :next)

pager = Keyword.get(opts, :pager, &IO.binwrite/2)

pager.(io, to_print)
end

Expand Down
24 changes: 24 additions & 0 deletions lib/ring_logger/persistence.ex
Original file line number Diff line number Diff line change
@@ -0,0 +1,24 @@
defmodule RingLogger.Persistence do
@moduledoc false

@spec load(String.t()) :: [RingLogger.entry()] | {:error, atom()}
def load(path) do
path
|> File.read!()
|> :erlang.binary_to_term()
rescue
error in File.Error ->
{:error, error.reason}

ArgumentError ->
{:error, :corrupted}
end

@spec save(String.t(), [RingLogger.entry()]) :: :ok | {:error, atom()}
def save(path, logs) do
File.write!(path, :erlang.term_to_binary(logs))
rescue
error in File.Error ->
{:error, error.reason}
end
end
86 changes: 77 additions & 9 deletions lib/ring_logger/server.ex
Original file line number Diff line number Diff line change
Expand Up @@ -9,13 +9,19 @@ defmodule RingLogger.Server do

alias RingLogger.Buffer
alias RingLogger.Client
alias RingLogger.Persistence

require Logger

@default_max_size 1024
@default_persist_seconds 300

defstruct clients: [],
buffers: %{},
default_buffer: nil,
index: 0
index: 0,
persist_path: nil,
persist_seconds: 300

@spec start_link([RingLogger.server_option()]) :: GenServer.on_start()
def start_link(opts \\ []) do
Expand Down Expand Up @@ -79,7 +85,26 @@ defmodule RingLogger.Server do

buffers = reset_buffers(Keyword.get(opts, :buffers, %{}))

{:ok, %__MODULE__{buffers: buffers, default_buffer: CircularBuffer.new(max_size)}}
state = %__MODULE__{
buffers: buffers,
default_buffer: CircularBuffer.new(max_size),
persist_path: Keyword.get(opts, :persist_path),
persist_seconds: Keyword.get(opts, :persist_seconds, @default_persist_seconds)
}

{:ok, state, {:continue, :load}}
end

@impl true
def handle_continue(:load, state) do
case !is_nil(state.persist_path) do
true ->
Process.send_after(self(), :tick, state.persist_seconds * 1000)
{:noreply, load_persist_path(state)}

false ->
{:noreply, state}
end
end

@impl GenServer
Expand Down Expand Up @@ -182,6 +207,20 @@ defmodule RingLogger.Server do
{:noreply, detach_client(pid, state)}
end

def handle_info(:tick, state) do
Process.send_after(self(), :tick, state.persist_seconds * 1000)

case Persistence.save(state.persist_path, merge_buffers(state)) do
:ok ->
{:noreply, state}

{:error, reason} ->
Logger.warn("RingLogger ran into an issue persisting the log: #{reason}")

{:noreply, state}
end
end

@impl GenServer
def terminate(_reason, state) do
Enum.each(state.clients, fn {client_pid, _ref} -> Client.stop(client_pid) end)
Expand Down Expand Up @@ -229,17 +268,12 @@ defmodule RingLogger.Server do
defp push(level, {module, message, timestamp, metadata}, state) do
index = state.index

metadata =
metadata
|> Keyword.put(:index, index)
|> Keyword.put(:monotonic_time, :erlang.monotonic_time())

log_entry = %{
level: level,
module: module,
message: message,
timestamp: timestamp,
metadata: metadata
metadata: Keyword.put(metadata, :index, index)
}

Enum.each(state.clients, &send_log(&1, log_entry))
Expand Down Expand Up @@ -271,7 +305,7 @@ defmodule RingLogger.Server do
(Enum.map(state.buffers, & &1.circular_buffer) ++ [state.default_buffer])
|> Enum.flat_map(& &1)
|> Enum.sort_by(fn %{metadata: metadata} ->
metadata[:monotonic_time]
metadata[:index]
end)
end

Expand All @@ -285,4 +319,38 @@ defmodule RingLogger.Server do
}
end)
end

defp load_persist_path(state) do
case Persistence.load(state.persist_path) do
logs when is_list(logs) ->
state =
Enum.reduce(logs, state, fn log_entry, state ->
insert_log(state, log_entry)
end)

%{state | index: Enum.count(logs)}

{:error, :corrupted} ->
timestamp = :os.system_time(:microsecond)
micro = rem(timestamp, 1_000_000)

{date, {hours, minutes, seconds}} =
:calendar.system_time_to_universal_time(timestamp, :microsecond)

log_entry = %{
level: :warn,
module: Logger,
message: "RingLogger could not load the persistence file, it is corrupt",
timestamp: {date, {hours, minutes, seconds, div(micro, 1000)}},
metadata: [index: 1]
}

state = insert_log(state, log_entry)

%{state | index: 1}

{:error, _reason} ->
state
end
end
end
73 changes: 73 additions & 0 deletions test/ring_logger/persistence_test.exs
Original file line number Diff line number Diff line change
@@ -0,0 +1,73 @@
defmodule RingLogger.PersistenceTest do
use ExUnit.Case, async: false

alias RingLogger.Persistence

test "saving logs" do
File.rm("test/persistence.log")

logs = [
%{
level: :debug,
module: Logger,
message: "Foo",
timestamp: {{2023, 2, 8}, {13, 58, 31, 343}},
metadata: []
},
%{
level: :debug,
module: Logger,
message: "Bar",
timestamp: {{2023, 2, 8}, {13, 58, 31, 343}},
metadata: []
}
]

:ok = Persistence.save("test/persistence.log", logs)

assert File.exists?("test/persistence.log")

File.rm("test/persistence.log")
end

test "loading logs" do
File.rm("test/persistence.log")

logs = [
%{
level: :debug,
module: Logger,
message: "Foo",
timestamp: {{2023, 2, 8}, {13, 58, 31, 343}},
metadata: []
},
%{
level: :debug,
module: Logger,
message: "Bar",
timestamp: {{2023, 2, 8}, {13, 58, 31, 343}},
metadata: []
}
]

:ok = Persistence.save("test/persistence.log", logs)

loaded_logs = Persistence.load("test/persistence.log")

assert logs == loaded_logs

File.rm("test/persistence.log")
end

test "file was corrupted" do
File.write!("test/persistence.log", "bad file")

assert {:error, :corrupted} = Persistence.load("test/persistence.log")

File.rm("test/persistence.log")
end

test "file doesn't exist" do
assert {:error, :enoent} = Persistence.load("test/persistence.log")
end
end
65 changes: 65 additions & 0 deletions test/ring_logger_test.exs
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,8 @@ defmodule RingLoggerTest do
doctest RingLogger

import ExUnit.CaptureIO

alias RingLogger.Persistence
alias RingLogger.TestCustomFormatter

require Logger
Expand Down Expand Up @@ -660,6 +662,69 @@ defmodule RingLoggerTest do
end
end

describe "persistence" do
test "loading the log", %{io: io} do
Logger.remove_backend(RingLogger)

logs = [
%{
level: :debug,
module: Logger,
message: "Foo",
timestamp: {{2023, 2, 8}, {13, 58, 31, 343}},
metadata: []
},
%{
level: :debug,
module: Logger,
message: "Bar",
timestamp: {{2023, 2, 8}, {13, 58, 31, 343}},
metadata: []
}
]

:ok = Persistence.save("test/persistence.log", logs)

# Start the backend with _just_ the persist_path and restore old
# config to allow other tests to run without loading a log file
old_env = Application.get_env(:logger, RingLogger)
Application.put_env(:logger, RingLogger, persist_path: "test/persistence.log")
Logger.add_backend(RingLogger)
Application.put_env(:logger, RingLogger, old_env)

Logger.add_backend(RingLogger)

:ok = RingLogger.attach(io: io)

buffer = RingLogger.get(0, 0)

assert Enum.count(buffer) == 2

File.rm!("test/persistence.log")
end

test "loading a corrupted file", %{io: io} do
Logger.remove_backend(RingLogger)

File.write!("test/persistence.log", "this is corrupt")

# Start the backend with _just_ the persist_path and restore old
# config to allow other tests to run without loading a log file
old_env = Application.get_env(:logger, RingLogger)
Application.put_env(:logger, RingLogger, persist_path: "test/persistence.log")
Logger.add_backend(RingLogger)
Application.put_env(:logger, RingLogger, old_env)

:ok = RingLogger.attach(io: io)

buffer = RingLogger.get(0, 0)

assert Enum.count(buffer) == 1

File.rm!("test/persistence.log")
end
end

defp capture_log(fun) do
capture_io(:user, fn ->
fun.()
Expand Down

0 comments on commit 1668465

Please sign in to comment.