Skip to content

perf(signatures): memoise the evented dispatch set, plus three correctness fixes - #3234

Open
doomedraven wants to merge 1 commit into
masterfrom
perf-plugins-dispatch
Open

doomedraven wants to merge 1 commit into
masterfrom
perf-plugins-dispatch

Conversation

@doomedraven

Copy link
Copy Markdown
Collaborator

Sixth of the performance series (#3229 network, #3230 behavior, #3231 machinery, #3232 elastic/jsondump, #3233 mongo). This one is lib/cuckoo/core/plugins.py.

1. The evented dispatch loop recomputed loop-invariant set algebra per API call

RunSignatures.run():

for idx, call in enumerate(calls):
    api = call.get("api")
    cat = call.get("category")
    call_sigs = sigs.intersection(self.call_for_api.get(api, set()).union(self.call_for_api.get("any", set())))
    call_sigs = call_sigs.intersection(self.call_for_cat.get(cat, set()).union(self.call_for_cat.get("any", set())))
    call_sigs.update(evented_set.intersection(self.call_always))

Four intermediate sets, two unions and three intersections, per API call. Three operands never change for the lifetime of the loop:

expression varies per call?
self.call_for_api.get("any", set()) no
self.call_for_cat.get("any", set()) no
evented_set.intersection(self.call_always) no
self.call_for_api.get(api, set()) only with api
self.call_for_cat.get(cat, set()) only with cat

The result depends solely on (api, category) — a few hundred API names by twenty-odd categories — while the loop runs once per API call, commonly 100k–5M times per analysis.

Note

The cache for exactly this is already in the code. self.api_sigs = {} is initialised in __init__ and described in the class docstring as "Cache of signatures to call per API name", but nothing in the repository ever read or wrote it. It was designed and never wired up. This PR wires it up.

self.api_sigs.clear() per process is required: sigs is process-dependent, so a cache carried across processes would dispatch the wrong signature set for the second process onward. There is a test for that specifically.

Measured

The benchmark drives the real RunSignatures.run() — not a reimplementation of the algebra — with 200,000 calls, 400 distinct API names, 20 categories and 200 evented signatures whose on_call is a no-op:

run 1 run 2 run 3
master 4.159 s 4.137 s 4.409 s
this PR 2.417 s 2.391 s 2.401 s

~1.73x, i.e. ~8.7 µs of dispatch overhead removed per call.

Important

This is dispatch overhead only. Real on_call bodies are unchanged, so the end-to-end gain on a live analysis is proportionally smaller — the more work the signatures themselves do, the smaller the share.

Risk: the filter buckets (call_for_api, call_for_cat, call_for_processname, call_always) are built once in __init__ from filter_apinames / filter_categories / filter_processnames, which are class attributes defaulting to set() in abstracts.py and never mutated in place anywhere in the repo. A memoised entry therefore cannot go stale. The cached value is a frozenset; the inner loop only iterates it.

2. Bug: every evented signature reported the same execution time

for key, value in stats.items():
    if value:
        self.results["statistics"]["signatures"].append({"name": key, "time": round(timediff, 3)})

value is the signature's accumulated time. It is computed, tested in the if, then discarded: the appended time is timediff, a variable leaking out of the preceding on_complete loop. Every evented signature was reported with whatever duration the last measured signature happened to take, which makes these numbers useless for finding slow signatures.

round(timediff, 3)round(value, 3).

Also dropped the if sig.name not in stats: stats[sig.name] = 0 re-check inside the hot loop — stats[sig.name] = 0 is already set for every evented signature immediately above the loop, and every signature reachable through call_sigs comes from evented_list.

3. O(n²) TTP de-duplication

[
    self.ttps.append({"ttp": ttp, "signature": sig.name})
    for ttp in sig.ttps
    if {"ttp": ttp, "signature": sig.name} not in self.ttps
]

Each membership test is a linear scan of a growing list of dicts, the dict literal is built twice per iteration, and a list comprehension is used purely for its side effect. Two identical copies of this, one in the evented branch and one in the non-evented branch.

Replaced with _add_ttps() backed by a set of (ttp, signature) pairs mirroring self.ttps. Insertion order of self.ttps is preserved (tested). Measured 8.50 ms → 0.27 ms at 300 matched signatures — small in absolute terms, worth doing while the file is open.

4. break where continue belongs

RunReporting.__init__:

for process in results["behavior"]["processes"]:
    if isinstance(process["calls"], list) and type(process["calls"]).__name__ != "ParseProcessLog":
        break
    process["calls"].begin_reporting()
    process["calls"] = list(process["calls"])

The condition identifies one process whose calls came from a JSON reprocess rather than a live ParseProcessLog. break abandons the whole loop on the first such process. Processes are populated uniformly in practice, so today this is equivalent to continue — but only by accident. If the list is ever mixed, the remaining ParseProcessLog instances never get begin_reporting() and reach the reporting modules unconverted.

5. Dead guard removed

RunProcessing.run() had if not hasattr(self.results, "debug"):. self.results is a plain dict, so that is always False and the append always ran.

Warning

The apparent fix — if "debug" not in self.results — would be a behaviour change: it would start dropping the "behavioral log too big" errors whenever anything else had already written to results["debug"], which is common. The condition is removed instead, keeping the setdefault chain and the current behaviour, with a comment recording why.

Tests

tests/test_plugins_dispatch.py, 7 tests. They monkeypatch list_plugins rather than calling register_plugin, so the fake signatures cannot leak into tests/test_signature.py's global registry.

  • Equivalence oracle: the pre-cache set algebra is kept in the test file and run against the same RunSignatures instance buckets; the dispatch recorded by each signature during a real run() must match it exactly. 3 processes x 60 calls x 8 signatures covering every filter combination (none, api, cat, proc, api+cat, api+proc, cat+proc, all three).
  • Cache is not reused across processes (process-filtered signature must only see its own pid).
  • Cache holds exactly one entry per distinct (api, category) pair.
  • statistics.signatures[].time reports each signature's own time — fails on master.
  • _add_ttps dedups, preserves order, and handles the empty and single cases.

Negative control: with lib/cuckoo/core/plugins.py reverted to master, 5 of the 7 fail.

The existing tests/test_signature.py (21 end-to-end cases over tests/test_data/*/reports/report.json) passes unchanged, which is the real equivalence check on the filter semantics.

ruff check and black --check clean.

TAG=agy

…tness fixes

RunSignatures.run() rebuilt the same set algebra on every API call: two
unions and three intersections, four intermediate sets, per call. Three of
the operands are loop-invariant and the result depends only on
(api, category) - a few hundred API names by twenty-odd categories - while
the loop runs once per API call, commonly 100k-5M times per analysis.

The cache for exactly this was already declared. self.api_sigs is
initialised in __init__ and documented as "Cache of signatures to call per
API name", but nothing ever read or wrote it. It is now wired up. The cache
is cleared per process because `sigs` is process-dependent.

Measured with the real RunSignatures.run(), 200k calls, 200 no-op evented
signatures (bench drives the actual dispatcher, not a reimplementation):

  original   4.14 s / 4.14 s / 4.41 s
  patched    2.42 s / 2.39 s / 2.40 s

That is dispatch overhead only. Real on_call bodies are unchanged, so the
end-to-end gain is proportionally smaller.

The filter buckets are built once in __init__ from class attributes that are
never mutated at runtime, so a memoised entry cannot go stale.

Also fixed, all in the same area:

- statistics.signatures[].time reported `round(timediff, 3)`, a variable
  leaking out of the preceding on_complete loop, instead of `value`, the
  signature's own accumulated time. Every evented signature was reported
  with whatever duration the last measured signature happened to take.

- TTP de-duplication tested `{"ttp": ..., "signature": ...} not in self.ttps`,
  a linear scan of a growing list of dicts, building the dict literal twice
  per iteration, inside a list comprehension used only for its side effect.
  Replaced with a set of (ttp, signature) pairs mirroring self.ttps.

- RunReporting.__init__ used `break` where `continue` belongs. The check is
  per-process, so the first process whose calls came from a JSON reprocess
  abandoned the whole loop and left any remaining ParseProcessLog instances
  without begin_reporting() and unconverted.

- Removed the dead `if not hasattr(self.results, "debug")` guard in
  RunProcessing.run(). self.results is a dict, so it was always False and the
  append always ran. Rewriting it as `"debug" not in self.results` would
  start dropping those errors once anything else had written to
  results["debug"], so the condition is dropped and behaviour is unchanged.

TAG=agy
CONV=803339f8-9160-458e-b33a-f8319cfdb51e
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant