Merge pull request #54 from lambdaclass/bench-analysis

Improves logging and plots benchmark information

README.md

@@ -118,3 +118,25 @@ To compare the outputs, you can use the following scripts. Some of them required
    ```bash
    > ./scripts/delta_state_dumps.sh
    ```
+
+### Plotting
+
+In the `plotting` directory, you can find python scripts to plot relevant information. Before using them, you must first execute the replay with the `structured_logging` feature, and redirect the output to a file. You should do it with both Native execution and VM execution.
+
+Make sure to erase the `compiled_programs` directory, then run:
+
+```bash
+cargo run --features structured_logging block mainnet 724000 | tee native-logs
+cargo run --features structured_logging,only_cairo_vm block mainnet 724000 | tee vm-logs
+```
+
+Once you have done this, you can use the plotting scripts:
+
+- `python ./plotting/plot_compilation_memory.py native-logs`: Size of the compiled native libraries, by contract class.
+- `python ./plotting/plot_compilation_memory_corr.py native-logs vm-logs`: Size of the compiled native libraries, by the associated Casm contract size.
+- `python ./plotting/plot_compilation_memory_trend.py native-logs vm-logs`: Size of the compiled native and casm contracts, by the sierra contract size.
+- `python ./plotting/plot_compilation_time.py native-logs`: Native compilation time, by contract class
+- `python ./plotting/plot_compilation_time_trend.py native-logs vm-logs`: Native and Casm compilation time, by the sierra contract size.
+- `python ./plotting/plot_execution_time.py native-logs vm-logs`: Plots the execution time of Native vs VM, by contract class. This is best used with the benchmark feature, as it ignores compilation and RPC calls.
+- `python ./plotting/plot_compilation_time_finer.py native-logs`: Native compilation time, with fine-grained stage separation, by contract class. It requires a specific [Cairo Native branch](https://github.com/lambdaclass/cairo_native/tree/time-compilation) (as it need finer logging)
+

plotting/plot_compilation_memory.py

@@ -0,0 +1,47 @@
+from argparse import ArgumentParser
+
+argument_parser = ArgumentParser('Stress Test Plotter')
+argument_parser.add_argument("native_logs_path")
+arguments = argument_parser.parse_args()
+
+import matplotlib.pyplot as plt
+import pandas as pd
+import seaborn as sns
+
+dataset = pd.read_json(arguments.native_logs_path, lines=True, typ="series")
+
+def canonicalize_compilation_time(event):
+    if "contract compilation finished" not in event["fields"]["message"]:
+        return None
+
+    compilation_span = find_span(event, "contract compilation")
+    if compilation_span is None:
+        return None
+
+    return {
+        "class hash": compilation_span["class_hash"],
+        "size": event["fields"]["size"] / (1024 * 1024),
+    }
+
+def find_span(event, name):
+    for span in event["spans"]:
+        if name in span["name"]:
+            return span
+    return None
+
+def format_hash(class_hash):
+    return f"0x{class_hash[:6]}..."
+
+
+dataset = dataset.apply(canonicalize_compilation_time).dropna().apply(pd.Series)
+
+figure, ax = plt.subplots()
+
+sns.set_color_codes("bright")
+sns.barplot(ax=ax, y="class hash", x="size", data=dataset, formatter=format_hash) # type: ignore
+
+ax.set_xlabel("Library Size (MiB)")
+ax.set_ylabel("Class Hash")
+ax.set_title("Library Size by Contract")
+
+plt.show()

plotting/plot_compilation_memory_corr.py

@@ -0,0 +1,71 @@
+from argparse import ArgumentParser
+
+argument_parser = ArgumentParser('Stress Test Plotter')
+argument_parser.add_argument("native_logs_path")
+argument_parser.add_argument("vm_logs_path")
+arguments = argument_parser.parse_args()
+
+import matplotlib.pyplot as plt
+import pandas as pd
+import seaborn as sns
+
+dataset_native = pd.read_json(arguments.native_logs_path, lines=True, typ="series")
+dataset_vm = pd.read_json(arguments.vm_logs_path, lines=True, typ="series")
+
+def canonicalize_compilation_time(event):
+    if "contract compilation finished" not in event["fields"]["message"]:
+        return None
+
+    compilation_span = find_span(event, "contract compilation")
+    if compilation_span is None:
+        return None
+
+    return {
+        "class hash": compilation_span["class_hash"],
+        "size": event["fields"]["size"] / 1024,
+    }
+
+def find_span(event, name):
+    for span in event["spans"]:
+        if name in span["name"]:
+            return span
+    return None
+
+def format_hash(class_hash):
+    return f"0x{class_hash[:6]}..."
+
+
+dataset_native = dataset_native.apply(canonicalize_compilation_time).dropna().apply(pd.Series)
+dataset_vm = dataset_vm.apply(canonicalize_compilation_time).dropna().apply(pd.Series)
+
+dataset_native = dataset_native.set_index("class hash")
+dataset_vm = dataset_vm.set_index("class hash")
+
+dataset = dataset_native.join(dataset_vm, lsuffix="_native", rsuffix="_casm")
+
+figure, ax = plt.subplots()
+
+sns.set_color_codes("bright")
+
+sns.regplot(
+    x="size_native",
+    y="size_casm",
+    label = "Native (<1000)",
+    data=dataset[dataset["size_native"] < 1000],
+    ax = ax,
+)
+sns.regplot(
+    x="size_native",
+    y="size_casm",
+    label = "Native (>=1000)",
+    data=dataset[dataset["size_native"] >= 1000],
+    ax = ax,
+)
+
+ax.set_xlabel("Native Compilation Size (KiB)")
+ax.set_ylabel("Casm Compilation Size (KiB)")
+ax.set_title("Compilation Size Correlation")
+
+ax.legend()
+
+plt.show()

plotting/plot_compilation_memory_trend.py

@@ -0,0 +1,76 @@
+from argparse import ArgumentParser
+
+argument_parser = ArgumentParser('Stress Test Plotter')
+argument_parser.add_argument("native_logs_path")
+argument_parser.add_argument("vm_logs_path")
+arguments = argument_parser.parse_args()
+
+import matplotlib.pyplot as plt
+import pandas as pd
+import seaborn as sns
+
+dataset_native = pd.read_json(arguments.native_logs_path, lines=True, typ="series")
+dataset_vm = pd.read_json(arguments.vm_logs_path, lines=True, typ="series")
+
+def canonicalize_compilation_time(event):
+    if "contract compilation finished" not in event["fields"]["message"]:
+        return None
+
+    compilation_span = find_span(event, "contract compilation")
+    if compilation_span is None:
+        return None
+
+    return {
+        "class hash": compilation_span["class_hash"],
+        "length": compilation_span["length"] / 1024,
+        "size": event["fields"]["size"] / 1024,
+    }
+
+def find_span(event, name):
+    for span in event["spans"]:
+        if name in span["name"]:
+            return span
+    return None
+
+def format_hash(class_hash):
+    return f"0x{class_hash[:6]}..."
+
+
+dataset_native = dataset_native.apply(canonicalize_compilation_time).dropna().apply(pd.Series)
+dataset_vm = dataset_vm.apply(canonicalize_compilation_time).dropna().apply(pd.Series)
+
+figure, ax = plt.subplots()
+
+sns.set_color_codes("bright")
+
+sns.regplot(
+    x="length",
+    y="size",
+    label = "Native (<1000)",
+    data=dataset_native[dataset_native["size"] < 1000],
+    ax = ax,
+)
+sns.regplot(
+    x="length",
+    y="size",
+    label = "Native (>=1000)",
+    data=dataset_native[dataset_native["size"] >= 1000],
+    ax = ax,
+)
+sns.regplot(
+    x="length",
+    y="size",
+    label = "Casm",
+    data=dataset_vm,
+    ax = ax,
+)
+
+ax.set_xlabel("Sierra size (KiB)")
+ax.set_ylabel("Compiled size (KiB)")
+ax.set_title("Compilation Size Trend")
+ax.ticklabel_format(style="plain")
+
+
+ax.legend()
+
+plt.show()

plotting/plot_compilation_time.py

@@ -0,0 +1,47 @@
+from argparse import ArgumentParser
+
+argument_parser = ArgumentParser('Stress Test Plotter')
+argument_parser.add_argument("native_logs_path")
+arguments = argument_parser.parse_args()
+
+import matplotlib.pyplot as plt
+import pandas as pd
+import seaborn as sns
+
+dataset = pd.read_json(arguments.native_logs_path, lines=True, typ="series")
+
+def canonicalize_compilation_time(event):
+    # keep contract compilation finished logs
+    if "contract compilation finished" not in event["fields"]["message"]:
+        return None
+
+    compilation_span = find_span(event, "contract compilation")
+    if compilation_span is None:
+        return None
+
+    return {
+        "class hash": compilation_span["class_hash"],
+        "time": float(event["fields"]["time"]),
+    }
+
+def find_span(event, name):
+    for span in event["spans"]:
+        if name in span["name"]:
+            return span
+    return None
+
+def format_hash(class_hash):
+    return f"0x{class_hash[:6]}..."
+
+dataset = dataset.apply(canonicalize_compilation_time).dropna().apply(pd.Series)
+
+figure, ax = plt.subplots()
+
+sns.set_color_codes("bright")
+sns.barplot(ax=ax, y="class hash", x="time", data=dataset, formatter=format_hash) # type: ignore
+
+ax.set_xlabel("Compilation Time (ms)")
+ax.set_ylabel("Class Hash")
+ax.set_title("Native Compilation Time")
+
+plt.show()

plotting/plot_compilation_time_finer.py

@@ -0,0 +1,112 @@
+from argparse import ArgumentParser
+import matplotlib.pyplot as plt
+import pandas as pd
+import seaborn as sns
+import numpy as np
+
+argument_parser = ArgumentParser("Stress Test Plotter")
+argument_parser.add_argument("native_logs_path")
+arguments = argument_parser.parse_args()
+
+
+dataset = pd.read_json(arguments.native_logs_path, lines=True, typ="series")
+
+
+def canonicalize_compilation_time(event):
+    # keep contract compilation finished logs
+    compilation_span = find_span(event, "contract compilation")
+    if compilation_span is None:
+        return None
+
+    class_hash = compilation_span["class_hash"]
+    class_length = compilation_span["length"]
+
+    if "contract compilation finished" in event["fields"]["message"]:
+        return {
+            "class hash": class_hash,
+            "length": class_length,
+            "type": "Total",
+            "time": float(event["fields"]["time"]),
+        }
+    elif "sierra to mlir compilation finished" in event["fields"]["message"]:
+        return {
+            "class hash": class_hash,
+            "length": class_length,
+            "type": "Sierra to MLIR",
+            "time": float(event["fields"]["time"]),
+        }
+    elif "mlir passes finished" in event["fields"]["message"]:
+        return {
+            "class hash": class_hash,
+            "length": class_length,
+            "type": "MLIR passes",
+            "time": float(event["fields"]["time"]),
+        }
+    elif "mlir to llvm finished" in event["fields"]["message"]:
+        return {
+            "class hash": class_hash,
+            "length": class_length,
+            "type": "MLIR to LLVM",
+            "time": float(event["fields"]["time"]),
+        }
+    elif "llvm passes finished" in event["fields"]["message"]:
+        return {
+            "class hash": class_hash,
+            "length": class_length,
+            "type": "LLVM passes",
+            "time": float(event["fields"]["time"]),
+        }
+    elif "llvm to object compilation finished" in event["fields"]["message"]:
+        return {
+            "class hash": class_hash,
+            "length": class_length,
+            "type": "LLVM to object",
+            "time": float(event["fields"]["time"]),
+        }
+    elif "linking finished" in event["fields"]["message"]:
+        return {
+            "class hash": class_hash,
+            "length": class_length,
+            "type": "Linking",
+            "time": float(event["fields"]["time"]),
+        }
+    return None
+
+
+def find_span(event, name):
+    for span in event["spans"]:
+        if name in span["name"]:
+            return span
+    return None
+
+
+def format_hash(class_hash):
+    return f"0x{class_hash[:6]}..."
+
+
+dataset = dataset.apply(canonicalize_compilation_time).dropna().apply(pd.Series)
+dataset = dataset.pivot(index = ["class hash"], columns = "type", values = "time")
+
+pd.set_option('display.max_columns', None)
+
+figure, ax = plt.subplots()
+
+sns.set_color_codes("pastel")
+sns.barplot(data=dataset, y="class hash", x="Total", label="Other", ax=ax, formatter=format_hash)
+
+bottom = np.zeros(len(dataset))
+sections = ["Linking", "LLVM to object", "LLVM passes", "MLIR to LLVM", "MLIR passes", "Sierra to MLIR"]
+
+for section in sections:
+    bottom += dataset[section]
+
+for section in sections:
+    sns.barplot(y=dataset.index, x=bottom, ax=ax, label=section, formatter=format_hash, orient="h")
+    bottom -= dataset[section]
+
+ax.set_xlabel("Compilation Time (ms)")
+ax.set_ylabel("Class Hash")
+ax.set_title("Native Compilation Time")
+ax.legend()
+
+plt.show()