Conversation
|
Thanks for following up on the profiling suggestion from #551 — this is exactly the right place to have looked, and the diff is small and readable. Two findings, though, and the first is a blocker. The cache can serve a stale class
An instance built from the cache-served class then fails This matters here more than it might elsewhere: retained class-level dispatch state was fixed twice in this release already (#425/#428 at the protocol layer, #560 at the schema layer), and The ~40% looks like a cumulative-time artifact
What does holdPart 1 of your mechanism is accurate: on a registry miss the default Where that leaves itI'd rather not take the staleness risk for a saving that small, so I'm inclined to decline this one — but the miss-path observation is a genuine find and worth keeping. If you'd like to pursue it, memoising the default descriptor into the registry on a miss the way a hit is already written back would capture the same benefit without a second never-invalidated cache, and A full wall-clock A/B is still running; I'll add it if it changes anything, though given the magnitudes I expect it to be inside the noise. |
|
Follow-up on the wall-clock A/B I said was still running. It doesn't change the conclusion, but two results are worth adding, and one is in your favour. On the path you targeted, the fix does what you said it does. Measured in isolation on the uncached default-factory branch, per-call cost drops by roughly 38–40%, reproducibly across repeated runs. And the steady-state registered-hit path is unaffected either way — your cache check sits behind At whole- One thing I should have mentioned in my first comment: the diff adds no tests, so nothing guards the cache against the staleness above. That leaves it where it was — the stale-dispatch risk is the deciding factor, not the performance. If you want to take this further, the productive version is profiling by self-time rather than cumulative time, which is what makes |
…port_module (#574) (#586) Proposed by @Ts-Boom in #563. A next layer code nobody registered resolves to the fallback ModuleDescriptor the registry's default factory produces, and _lookup_next_layer deliberately does not write that back -- recording a miss in a class-level defaultdict is the defect #425/#428 fixed at this layer and #560 fixed at the schema layer. So every unrecognised frame resolved the same descriptor again: 48 of the 52 ModuleDescriptor.klass resolutions an extraction of many_interfaces.pcapng performs, each re-entering importlib.import_module for a module sys.modules already held. - ModuleDescriptor.klass now reads sys.modules first, and enters import_module only when the module is not loaded yet -- or when the loaded module does not have the attribute, which is a body still executing (a circular import, or another thread part way through importing it) and is what import_module's per-module lock exists to wait for. Measured on CPython 3.14.7: klass 436 -> 117 ns, the whole miss path 883 -> 526 ns, and import_module calls during extract() 48 -> 0 on many_interfaces.pcapng and 4 -> 0 on ipv4.pcap. The hit path is untouched (124 -> 127 ns, inside noise), since it is already memoised by the registry write-back. - Nothing memoises the resolved class, which is the deliberate part. The class is re-read with getattr on every access, so sys.modules stays the only module cache in play and its invalidation is the interpreter's: importlib.reload rebinds the class inside the same module object, and sys.modules.pop() replaces the object outright. #563's class-level _MODULE_CACHE followed neither, and an instance built from the class it kept fails isinstance against the live one. - Records in _lookup_next_layer's docstring why no memo lives there, so the next reader does not add one. Honest about the scale: this is not measurable in extract() wall clock. 48 avoided calls is ~17 us against a ~37 ms extraction, two orders of magnitude inside this host's single-digit-millisecond run-to-run variance, and repeated A/B pairs flipped sign. #563's "~40% of cumulative time" does not reproduce: _import_next_layer's self time is 0.58% against its 90.2% cumulative, because it is a recursive-descent dispatcher that has the whole nested parse beneath it. aenum.extend_enum at 16.7% self time is where the real time is (#575). Also found, not fixed here: the function-level `from ... import NoPayload` statements on the protocol layer, one of which is _import_next_layer's length == 0 fast path, run 890 times on http.pcap at ~162 ns against ~58 ns for the sys.modules equivalent -- ~92 us on a ~540 ms extraction, so left alone rather than paid for with a second resolution path. Adds tests/protocols/test_dispatch_default_resolution_unit.py, and four cases to tests/corekit/test_module.py. The two that assert the saving fail on the pre-fix code (5 import_module calls for 5 lookups); the three guards fail against the designs this one rejects -- the reload guard against #563's cache, and all three against writing the resolved fallback back under the missed code. Closes #574.
…port_module (#574) (#586) Proposed by @Ts-Boom in #563. A next layer code nobody registered resolves to the fallback ModuleDescriptor the registry's default factory produces, and _lookup_next_layer deliberately does not write that back -- recording a miss in a class-level defaultdict is the defect #425/#428 fixed at this layer and #560 fixed at the schema layer. So every unrecognised frame resolved the same descriptor again: 48 of the 52 ModuleDescriptor.klass resolutions an extraction of many_interfaces.pcapng performs, each re-entering importlib.import_module for a module sys.modules already held. - ModuleDescriptor.klass now reads sys.modules first, and enters import_module only when the module is not loaded yet -- or when the loaded module does not have the attribute, which is a body still executing (a circular import, or another thread part way through importing it) and is what import_module's per-module lock exists to wait for. Measured on CPython 3.14.7: klass 436 -> 117 ns, the whole miss path 883 -> 526 ns, and import_module calls during extract() 48 -> 0 on many_interfaces.pcapng and 4 -> 0 on ipv4.pcap. The hit path is untouched (124 -> 127 ns, inside noise), since it is already memoised by the registry write-back. - Nothing memoises the resolved class, which is the deliberate part. The class is re-read with getattr on every access, so sys.modules stays the only module cache in play and its invalidation is the interpreter's: importlib.reload rebinds the class inside the same module object, and sys.modules.pop() replaces the object outright. #563's class-level _MODULE_CACHE followed neither, and an instance built from the class it kept fails isinstance against the live one. - Records in _lookup_next_layer's docstring why no memo lives there, so the next reader does not add one. Honest about the scale: this is not measurable in extract() wall clock. 48 avoided calls is ~17 us against a ~37 ms extraction, two orders of magnitude inside this host's single-digit-millisecond run-to-run variance, and repeated A/B pairs flipped sign. #563's "~40% of cumulative time" does not reproduce: _import_next_layer's self time is 0.58% against its 90.2% cumulative, because it is a recursive-descent dispatcher that has the whole nested parse beneath it. aenum.extend_enum at 16.7% self time is where the real time is (#575). Also found, not fixed here: the function-level `from ... import NoPayload` statements on the protocol layer, one of which is _import_next_layer's length == 0 fast path, run 890 times on http.pcap at ~162 ns against ~58 ns for the sys.modules equivalent -- ~92 us on a ~540 ms extraction, so left alone rather than paid for with a second resolution path. Adds tests/protocols/test_dispatch_default_resolution_unit.py, and four cases to tests/corekit/test_module.py. The two that assert the saving fail on the pre-fix code (5 import_module calls for 5 lookups); the three guards fail against the designs this one rejects -- the reload guard against #563's cache, and all three against writing the resolved fallback back under the missed code. Closes #574.
…port_module (#574) (#586) Proposed by @Ts-Boom in #563. A next layer code nobody registered resolves to the fallback ModuleDescriptor the registry's default factory produces, and _lookup_next_layer deliberately does not write that back -- recording a miss in a class-level defaultdict is the defect #425/#428 fixed at this layer and #560 fixed at the schema layer. So every unrecognised frame resolved the same descriptor again: 48 of the 52 ModuleDescriptor.klass resolutions an extraction of many_interfaces.pcapng performs, each re-entering importlib.import_module for a module sys.modules already held. - ModuleDescriptor.klass now reads sys.modules first, and enters import_module only when the module is not loaded yet -- or when the loaded module does not have the attribute, which is a body still executing (a circular import, or another thread part way through importing it) and is what import_module's per-module lock exists to wait for. Measured on CPython 3.14.7: klass 436 -> 117 ns, the whole miss path 883 -> 526 ns, and import_module calls during extract() 48 -> 0 on many_interfaces.pcapng and 4 -> 0 on ipv4.pcap. The hit path is untouched (124 -> 127 ns, inside noise), since it is already memoised by the registry write-back. - Nothing memoises the resolved class, which is the deliberate part. The class is re-read with getattr on every access, so sys.modules stays the only module cache in play and its invalidation is the interpreter's: importlib.reload rebinds the class inside the same module object, and sys.modules.pop() replaces the object outright. #563's class-level _MODULE_CACHE followed neither, and an instance built from the class it kept fails isinstance against the live one. - Records in _lookup_next_layer's docstring why no memo lives there, so the next reader does not add one. Honest about the scale: this is not measurable in extract() wall clock. 48 avoided calls is ~17 us against a ~37 ms extraction, two orders of magnitude inside this host's single-digit-millisecond run-to-run variance, and repeated A/B pairs flipped sign. #563's "~40% of cumulative time" does not reproduce: _import_next_layer's self time is 0.58% against its 90.2% cumulative, because it is a recursive-descent dispatcher that has the whole nested parse beneath it. aenum.extend_enum at 16.7% self time is where the real time is (#575). Also found, not fixed here: the function-level `from ... import NoPayload` statements on the protocol layer, one of which is _import_next_layer's length == 0 fast path, run 890 times on http.pcap at ~162 ns against ~58 ns for the sys.modules equivalent -- ~92 us on a ~540 ms extraction, so left alone rather than paid for with a second resolution path. Adds tests/protocols/test_dispatch_default_resolution_unit.py, and four cases to tests/corekit/test_module.py. The two that assert the saving fail on the pre-fix code (5 import_module calls for 5 lookups); the three guards fail against the designs this one rejects -- the reload guard against #563's cache, and all three against writing the resolved fallback back under the missed code. Closes #574.
|
Following up now that our own version has landed: your proposal shipped, with credit.
Two things worth telling you about how it ended up, because both are departures from what this PR did. It caches nothing. Rather than memoising the resolved class, — which is why the requirement "no stale class survives a reload" and "memoise the class" cannot both be satisfied. The wall clock shows nothing, and we are not claiming otherwise. The call-count and per-call wins are real: That last point connects to something your PR prompted us to check properly, now #575: profiled by self time rather than cumulative, So this PR can be closed as superseded rather than rejected. Thank you for it — the direction was right and the credit is in the history. |
This PR resolves a significant performance bottleneck identified during profiling of
pcapkit.extract()by eliminating redundant dynamic imports (importlib.import_moduleand in-functionimportoverheads) executed over thousands of packets.🔍 The Problem
Profiling the extraction script revealed that
ProtocolBase._import_next_layer()and its associated lookups accounted for approximately ~40% of the cumulative total execution time. The underlying issue originates in the fallback mechanism and on-the-fly imports:ProtocolBase._lookup_registry()falls back to a defaultModuleDescriptorthat maps to theRawprotocol. Because this descriptor isn't inherently cached into the main registry on a miss,ModuleDescriptor.klass(which usesimportlib.import_moduleunder the hood) was re-evaluating the dynamic import for every single unrecognized packet frame._import_next_layer()repeatedly triggered slow in-functionimportstatements per extraction.💡 The Solution
Introduced
ProtocolBase._MODULE_CACHE—a static, class-level dictionary—to guarantee that each unique protocol descriptor is evaluated and dynamically imported exactly once._lookup_next_layer(), if a returnedModuleDescriptoris requested, the resulting.klassimport is securely cached and returned for all future packet checks matching that module and name pair._import_next_layer(), fallback assignments likeNoPayloadandRawclasses check the cache dictionary before invoking local imports.🚀 Impact
This minor caching abstraction drastically slashes the overhead associated with redundant standard module locks and repeated
importlibresolutions on large packet captures, improving parse timings uniformly across parsing flows.