日志
在上一篇文章中介绍了raft选举原理与实现细节，不论你是否跑通2A部分的测试案例，你都大概率会有这样一个烦恼----日志好乱！
下图是执行2A测试案例的日志，可以看到我们已经非常规范地编写了日志。每行日志的第一列是时间戳，第二列是日志类型，第三行开始才是真正的日志。虽然我们的日志很规范，但是我们仍然难以一眼鉴别当前行日志是哪一个raft节点发出的日志。
别担心，作为一个程序员，咱们得善用手边的工具，先来看下经过优化后的日志效果。
在新的日志中我们为每个raft节点起了一列日志，并且使用不同的颜色展示了不同类型的日志，相较于原本的日志，我们可以快速定位日志。此外，不难看出，新的日志是将原本的日志通过管道输出给一个python脚本实现的。
核心代码如下，简单的讲下逻辑就是
- 日志按行处理，每行日志分成3列，时间戳、日志类型、日志内容
- 按照日志类型为日志染色
- 按照日志内容的第二个字符，为日志取行号（要求我们日志内容的第二个字符需要标记raft节点号）
def main(
file: typer.FileText = typer.Argument(None, help="File to read, stdin otherwise"),
colorize: bool = typer.Option(True, "--no-color"),
n_columns: Optional[int] = typer.Option(None, "--columns", "-c"),
ignore: Optional[str] = typer.Option(None, "--ignore", "-i", callback=list_topics),
just: Optional[str] = typer.Option(None, "--just", "-j", callback=list_topics),
):
topics = list(TOPICS)
# We can take input from a stdin (pipes) or from a file
input_ = file if file else sys.stdin
# Print just some topics or exclude some topics (good for avoiding verbose ones)
if just:
topics = just
if ignore:
topics = [lvl for lvl in topics if lvl not in set(ignore)]
topics = set(topics)
console = Console()
width = console.size.width
panic = False
for line in input_:
try:
time, topic, *msg = line.strip().split(" ")
# To ignore some topics
if topic not in topics:
continue
msg = " ".join(msg)
# Debug calls from the test suite aren't associated with
# any particular peer. Otherwise we can treat second column
# as peer id
if topic != "TEST":
i = int(msg[1])
# Colorize output by using rich syntax when needed
if colorize and topic in TOPICS:
color = TOPICS[topic]
msg = f"[{color}]{msg}[/{color}]"
# Single column printing. Always the case for debug stmts in tests
if n_columns is None or topic == "TEST":
print(time, msg)
# Multi column printing, timing is dropped to maximize horizontal
# space. Heavylifting is done through rich.column.Columns object
else:
cols = ["" for _ in range(n_columns)]
msg = "" + msg
cols[i] = msg
col_width = int(width / n_columns)
cols = Columns(cols, width=col_width - 1, equal=True, expand=True)
print(cols)
except:
# Code from tests or panics does not follow format
# so we print it as is
if line.startswith("panic"):
panic = True
# Output from tests is usually important so add a
# horizontal line with hashes to make it more obvious
if not panic:
print("#" * console.width)
print(line, end="")
测试案例
在编写并发相关代码时，让我们最为头痛的一个点可能就是偶发性，不是所有错误都能够轻易观察到的。为了能够尽可能地去触发错误情况，我们可能要成百上千次地运行测试案例，来保证我们代码的可靠性。
对于我们实现的raft算法也是一样的，虽然我们能够保证通过一次测试案例，但是我们能够保证我们的代码没有偶发性，或者一些极限条件下的bug吗？
为此你可能会编写一些脚本，重复性多次循环执行测试案例。比如以下脚本：
#!/bin/bash
# 接收用户输入的测试用例名称
read -p "Enter the test case to run (e.g., TestFunctionName): " test_case
# 接收用户输入的执行次数
read -p "Enter the number of times to run the test: " iterations
# 创建日志文件目录
timestamp=$(date +%Y%m%d_%H%M%S)
log_dir="logs_$timestamp"
mkdir -p "$log_dir"
# 循环执行测试用例
for ((i = 1; i <= iterations; i++)); do
echo "Running iteration $i..."
log_file="$log_dir/${test_case}_iteration_${i}.log"
# 执行测试并保存日志
go test -run "^$test_case$" ./... > "$log_file" 2>&1
# 检查测试结果
if grep -q "FAIL" "$log_file"; then
echo "Iteration $i: Test FAILED. See log: $log_file"
else
echo "Iteration $i: Test PASSED."
fi
done
echo "All iterations completed. Check logs in the directory: $log_dir"
但是，上面脚本也存在一些问题：一次只能运行一个测试案例，不支持并发运行。假设你需要跑通2A的所有测试案例，你需要重复调用多次，并等待比较长的时间。
为了解决上面的问题，同样适用python实现一个简单个测试框架，能够支持多线程并发运行，并且支持同时跑多个测试案例。
核心的代码逻辑是：
- 根据输入创建测试案例任务
- 创建线程池，将测试任务提交到线程池
- 保存结果
def run_tests(
tests: List[str],
sequential: bool = typer.Option(False, '--sequential', '-s', help='Run all test of each group in order'),
workers: int = typer.Option(1, '--workers', '-p', help='Number of parallel tasks'),
iterations: int = typer.Option(10, '--iter', '-n', help='Number of iterations to run'),
output: Optional[Path] = typer.Option(None, '--output', '-o', help='Output path to use'),
verbose: int = typer.Option(0, '--verbose', '-v', help='Verbosity level', count=True),
archive: bool = typer.Option(False, '--archive', '-a', help='Save all logs intead of only failed ones'),
race: bool = typer.Option(False, '--race/--no-race', '-r/-R', help='Run with race checker'),
loop: bool = typer.Option(False, '--loop', '-l', help='Run continuously'),
growth: int = typer.Option(10, '--growth', '-g', help='Growth ratio of iterations when using --loop'),
timing: bool = typer.Option(False, '--timing', '-t', help='Report timing, only works on macOS'),
# fmt: on
):
if output is None:
timestamp = datetime.datetime.now().strftime("%Y%m%d_%H%M%S")
output = Path(timestamp)
if race:
print("[yellow]Running with the race detector\n[/yellow]")
if verbose > 0:
print(f"[yellow] Verbosity level set to {verbose}[/yellow]")
os.environ['VERBOSE'] = str(verbose)
while True:
total = iterations * len(tests)
completed = 0
results = {test: defaultdict(StatsMeter) for test in tests}
if sequential:
test_instances = itertools.chain.from_iterable(itertools.repeat(test, iterations) for test in tests)
else:
test_instances = itertools.chain.from_iterable(itertools.repeat(tests, iterations))
test_instances = iter(test_instances)
total_progress = Progress(
"[progress.description]{task.description}",
BarColumn(),
TimeRemainingColumn(),
"[progress.percentage]{task.percentage:>3.0f}%",
TimeElapsedColumn(),
)
total_task = total_progress.add_task("[yellow]Tests[/yellow]", total=total)
task_progress = Progress(
"[progress.description]{task.description}",
SpinnerColumn(),
BarColumn(),
"{task.completed}/{task.total}",
)
tasks = {test: task_progress.add_task(test, total=iterations) for test in tests}
progress_table = Table.grid()
progress_table.add_row(total_progress)
progress_table.add_row(Panel.fit(task_progress))
with Live(progress_table, transient=True) as live:
def handler(_, frame):
live.stop()
print('\n')
print_results(results)
sys.exit(1)
signal.signal(signal.SIGINT, handler)
with ThreadPoolExecutor(max_workers=workers) as executor:
futures = []
while completed < total:
n = len(futures)
if n < workers:
for test in itertools.islice(test_instances, workers-n):
futures.append(executor.submit(run_test, test, race, timing))
done, not_done = wait(futures, return_when=FIRST_COMPLETED)
for future in done:
test, path, rc, runtime = future.result()
results[test]['completed'].add(1)
results[test]['time'].add(runtime)
task_progress.update(tasks[test], advance=1)
dest = (output / f"{test}_{completed}.log").as_posix()
if rc != 0:
print(f"Failed test {test} - {dest}")
task_progress.update(tasks[test], description=f"[red]{test}[/red]")
results[test]['failed'].add(1)
else:
if results[test]['completed'].n == iterations and results[test]['failed'].n == 0:
task_progress.update(tasks[test], description=f"[green]{test}[/green]")
if rc != 0 or archive:
output.mkdir(exist_ok=True, parents=True)
shutil.copy(path, dest)
if timing:
line = last_line(path)
real, _, user, _, system, _ = line.replace(' '*8, '').split(' ')
results[test]['real_time'].add(float(real))
results[test]['user_time'].add(float(user))
results[test]['system_time'].add(float(system))
os.remove(path)
completed += 1
total_progress.update(total_task, advance=1)
futures = list(not_done)
print_results(results, timing)
if loop:
iterations *= growth
print(f"[yellow]Increasing iterations to {iterations}[/yellow]")
else:
break
在执行测试案例时也能够查看到相应的进度
在执行完成后会输出测试案例通过情况。
思考
其实这篇文章并不是一篇原创，而是转载自Mit6.824一位学生的作品，他的文章如下
写这篇文章的目的，一方面是想给大家在做raft相关实验的时候，安利一下好用的工具。另一方面，也是想提醒下自己，不要真正地成为了真正意义上的“码农“，不要只会完成工作的任务，缺乏创造性，希望自己有更多的思考，不论是为自己、家人、社会创造更大价值。
回想学习生涯，我学过python，c++，java各种语言。总是走马观花地学习下基本语言的语法，应付下当时的问题，从来没有去思考过这些语言工具能够为我解决什么问题，创造什么价值。在自己实现raft算法时，我从来没想过一个简单的python脚本能够帮我解决日志过于复杂杂乱的问题。
在生活中，我总为新技术的出现，自己还不会而焦虑，总为未来看不清感到烦恼。但是却忽略了自己曾经拥有的和当下拥有的，我似乎会很多东西，我却又似乎不曾学会，我渴望未来，却又惧怕未来。希望今后的自己能够减轻这种焦虑，好好把握当下拥有的，再去展望未来。
