jarshwah
commented
2 months ago Somewhat answering my own question, fixit can generate debug logs for how long each execution of each plugin hook takes. But the format of those logs isn't very useful with a large number of files (and, tbh, figuring out how to configure the logging framework to output those logs wasn't something I tried to do).
LintRunner.collect_violations provides a timings_hook that can be used to collect timings but it isn't exposed in the main CLI. Installing fixit as an editable package locally, patching it, and running can provide a lot more detail:
diff --git a/src/fixit/engine.py b/src/fixit/engine.py
index 2e56dda..7a5f5ef 100644
--- a/src/fixit/engine.py
+++ b/src/fixit/engine.py
@@ -48,6 +48,20 @@ def diff_violation(path: Path, module: Module, violation: LintViolation) -> str:
)
+def timing_hook(timings: Timings) -> None:
+ """
+ Log timings for each rule.
+ """
+ split_timings = {}
+ for name, duration in timings.items():
+ rule, hook = name.split(".")
+ split_timings.setdefault(rule, {})[hook] = duration
+ for rule, durations in split_timings.items():
+ for hook, duration in durations.items():
+ print(f'"{rule}","{hook}",{duration}\n', end="")
+
+
+
class LintRunner:
def __init__(self, path: Path, source: FileContent) -> None:
self.path = path
@@ -67,6 +81,8 @@ class LintRunner:
lint rules have finished running, passing in a dictionary of
``RuleName.visit_function_name`` -> ``duration in microseconds``.
"""
+ if timings_hook is None:
+ timings_hook = timing_hook
@contextmanager
def visit_hook(name: str) -> Iterator[None]:$ fixit lint src > ~/Documents/fixit-rule-timing.csvThen analyse with pandas:
import pandas as pd
data = pd.read_csv("~/Documents/fixit-rule-timing.csv", names=["plugin", "hook", "duration"])
# Convert duration to seconds
data["duration"] = data["duration"].div(1000000).round(2)
# Agg by plugin+hook
agg = data.groupby(["plugin", "hook"])["duration"].sum()
top_N = agg.nlargest(20)
print(top_N)
thatch
zsol
As per the title, we're seeing incredibly long run times when running fixit==2.1.0.
Our code base is approx 4M lines of python code. On a Circle CI Large instance (4 CPU / 8gb), it takes up to an hour to run across the entire code base. We've worked around this by only running on changed files, which takes approximately 1 minute, except when we edit the fixit config or any of our custom rules where we'll run the entire suite.
I'm keen to try and understand why the runs may be slow by profiling in some way. Is there any tooling or logging available within fixit itself that might help to track down where some of the problems may be? To be clear, I'm coming at this from the assumption that the way we've written our rules is mostly to blame, and would like to identify the worst offenders.
While I'm not really able to share our implementations, I can provide some details of our current usage (if that might prompt some thoughts of "oh, of course that would be slow!":
We make heavy use of QualifiedNameProvider and FilePathProvider. We have lots of helper functions that presumably construct lots of instances, like so:
Still, I'm more interested in being able to analyse performance and profiling data myself rather than guessing, so anything in this space would be incredibly helpful.