···11defmodule Hobbes.Servers.BeginBuffer do
22 use GenServer
33- alias Trinity.{SimProcess, SimServer}
33+ alias Trinity.{SimProcess, SimServer, SimLogger}
44+ require SimLogger
4556 import ExUnit.Assertions, only: [assert: 1]
67···79808081 # If a TLog is locked in this generation there is an ongoing recovery,
8182 # so we may as well just die instead of trying to handle this case
8282- true -> exit(:shutdown)
8383+ true ->
8484+ SimLogger.debug "BeginBuffer (id=#{state.id}, generation=#{state.cluster.generation}): TLog reported locked in reply, exiting"
8585+ exit(:shutdown)
8386 end
8487 end
8588
+16-7
lib/servers/commit_buffer.ex
···207207208208 {commit_version, prev_commit_version} =
209209 case Sequencer.get_commit_version(seq_pid) do
210210- {:ok, {_cv, _pcv} = versions} -> versions
211211- {:error, :timeout} -> exit(:shutdown)
210210+ {:ok, {_cv, _pcv} = versions} ->
211211+ versions
212212+ {:error, :timeout} ->
213213+ SimLogger.debug "CommitBuffer (id=#{state.id}, generation=#{state.cluster.generation})): failed to get commit version, exiting"
214214+ exit(:shutdown)
212215 end
213216214217 transactions_reversed = state.buffer
···246249 [%Server{pid: resolver_pid}] = get_servers(state.cluster, Hobbes.Servers.Resolver)
247250 {txn_results_reversed, meta_log} =
248251 case Resolver.resolve_batch(resolver_pid, batch) do
249249- {:ok, result} -> result
250250- {:error, :timeout} -> exit(:shutdown)
252252+ {:ok, result} ->
253253+ result
254254+ {:error, :timeout} ->
255255+ SimLogger.debug "CommitBuffer (id=#{state.id}, generation=#{state.cluster.generation})): failed to resolve batch, exiting"
256256+ exit(:shutdown)
251257 end
252258253259 # Apply meta mutations received, including our own from this batch
···307313 case TLog.write_batch_receive(req_id) do
308314 :ok -> :noop
309315 # If a commit fails, we trigger recovery (or are already recovering)
310310- {:error, :tlog_locked} -> exit(:shutdown)
311311- {:error, :timeout} -> exit(:shutdown)
316316+ {:error, err} when err in [:tlog_locked, :timeout] ->
317317+ SimLogger.debug "CommitBuffer (id=#{state.id}, generation=#{state.cluster.generation})): failed to write batch to TLog (error=#{err}), exiting"
318318+ exit(:shutdown)
312319 end
313320 end)
314321315322 # Once all tlogs have replied (made durable), notify sequencer this version is committed
316323 case Sequencer.notify_committed(seq_pid, commit_version) do
317324 :ok -> :noop
318318- {:error, :timeout} -> exit(:shutdown)
325325+ {:error, :timeout} ->
326326+ SimLogger.debug "CommitBuffer (id=#{state.id}, generation=#{state.cluster.generation})): failed to notify sequencer of commit, exiting"
327327+ exit(:shutdown)
319328 end
320329321330 # Reply to clients
···116116 # If a transaction process in this generation has failed, shutdown immediately
117117 # so that a new Manager can be recruited
118118 if failed? do
119119+ SimLogger.debug "Manager (generation=#{state.generation}): A supervisor reported failure, exiting"
119120 exit(:shutdown)
120121 end
121122···138139 old_generations: generation_pairs,
139140 } =
140141 case Coordinator.inc_generation(state.primary_coordinator) do
141141- {:ok, result} -> result
142142- {:error, :no_config} -> exit(:shutdown)
143143- {:error, :timeout} -> exit(:shutdown)
142142+ {:ok, result} ->
143143+ result
144144+145145+ {:error, err} when err in [:no_config, :timeout] ->
146146+ SimLogger.debug "Manager failed to inc_generation (error=#{inspect(err)}), exiting"
147147+ exit(:shutdown)
144148 end
145149146150 assert is_integer(generation)
···202206203207 if elapsed_us > @supervisor_timeout_us do
204208 # If a supervisor fails to ping for too long we trigger a recovery
209209+ # TODO: log TLog id
210210+ SimLogger.debug "Manager (generation=#{state.generation}): TLog failed to ping for #{elapsed_us}us, exiting"
205211 exit(:shutdown)
206212 end
207213 end)
···581587 end)
582588 |> Enum.map(fn req_id ->
583589 case TLog.peek_all_receive(req_id) do
584584- {:ok, batches} -> batches
585585- {:error, :timeout} -> exit(:shutdown)
590590+ {:ok, batches} ->
591591+ batches
592592+ {:error, :timeout} ->
593593+ SimLogger.debug "Manager (generation=#{state.generation}): TLog peek timed out during copy, exiting"
594594+ exit(:shutdown)
586595 end
587596 end)
588597 |> Enum.concat()
···780789 {:ok, server_pid} ->
781790 server_pid
782791 {:error, err} ->
783783- SimLogger.debug("Manager failed to recruit server (generation: #{generation}, module: #{module}, error: #{err}) - exiting")
792792+ SimLogger.debug("Manager (generation=#{generation}): failed to recruit server (module: #{module}, error: #{err}), exiting")
784793 exit(:shutdown)
785794 end
786795···862871 |> then(fn {[], acc} -> acc end)
863872 |> Map.new()
864873865865- {:error, _err} -> exit(:shutdown)
874874+ {:error, _err} ->
875875+ SimLogger.debug "Manager (generation=#{state.generation}): failed to allocate ids, exiting"
876876+ exit(:shutdown)
866877 end
867878 end
868879
+8-4
lib/servers/storage.ex
···11defmodule Hobbes.Servers.Storage do
22 use GenServer
33- alias Trinity.{Sim, SimProcess, SimServer}
44- require Logger
33+ alias Trinity.{Sim, SimProcess, SimServer, SimLogger}
44+ require SimLogger
5566 import ExUnit.Assertions, only: [assert: 1]
77···382382 new_gen = cluster.tlog_generations |> Enum.map(&(&1.generation)) |> Enum.max(&>=/2, fn -> 1 end)
383383 has_recovered? = new_gen > old_gen
384384 # If there has been a recovery (a new generation > 1 appears in cluster.tlog_generations),
385385- # we purge possibly-uncommitted mutations from the in-memory KV by simply restarting
386386- if has_recovered?, do: exit(:shutdown)
385385+ # we undo any mutations that may be excluded from the new generation by restarting the server
386386+ # (these mutations are guaranteed not to be persisted via XKS.set_max_persist_version)
387387+ if has_recovered? do
388388+ SimLogger.debug "Storage (id=#{state.id}, generation=#{state.cluster.generation}): received a new TLog generation (old=#{old_gen}, new=#{new_gen}), exiting"
389389+ exit(:shutdown)
390390+ end
387391388392 state = %{state | cluster: cluster}
389393