RDK-62042: Improve performance of GetAvailableInterfaces and GetInterfaceState - #337
Conversation
There was a problem hiding this comment.
Pull request overview
This PR addresses the high latency of GetAvailableInterfaces / GetInterfaceState on the GNOME (libnm) backend by removing the per-call NMClient creation and serving reads from an event-maintained cache, with additional timing logs to validate the improvement.
Changes:
- Added microsecond timing logs around the COM-RPC calls and iterator serialization in the JSON-RPC layer.
- Reworked GNOME backend
GetAvailableInterfaces/GetInterfaceStateto read from a shared interface-state “mirror” instead of creating anNMClientper request. - Introduced a mutex-protected interface-state mirror (state + MAC) maintained by NetworkManager event callbacks.
Reviewed changes
Copilot reviewed 4 out of 4 changed files in this pull request and generated 3 comments.
| File | Description |
|---|---|
| plugin/NetworkManagerJsonRpc.cpp | Adds [PERF] timing logs for GetAvailableInterfaces and GetInterfaceState JSON-RPC handlers. |
| plugin/gnome/NetworkManagerGnomeProxy.cpp | Switches interface read APIs to use the event-maintained mirror (no per-call NMClient), adds impl-level perf logs. |
| plugin/gnome/NetworkManagerGnomeEvents.h | Declares mirror data structure and helper APIs for reads/writes and enabled/connected mapping. |
| plugin/gnome/NetworkManagerGnomeEvents.cpp | Implements the mirror (map + mutex) and updates it from device state change / add / remove events. |
💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.
c679f0e to
a1542d1
Compare
There was a problem hiding this comment.
Pull request overview
Copilot reviewed 6 out of 6 changed files in this pull request and generated 1 comment.
Suppressed comments (3)
plugin/gnome/NetworkManagerGnomeEvents.cpp:531
ifnameis created fromnm_device_get_iface(device)earlier in this function. Sincenm_device_get_iface()can benullptr, constructing astd::stringwithout checking can crash; the subsequent cache update added here makes that path more likely to be exercised. Consider guardingnm_device_get_iface()and returning early when it is null.
/* ip events added only for eth0 and wlan0 */
if(ifname == nmUtils::ethIface() || ifname == nmUtils::wlanIface())
{
GnomeNetworkManagerEvents::updateInterfaceStateCache(ifname, nm_device_get_state(device), nm_device_get_hw_address(device));
g_signal_connect(device, "notify::" NM_DEVICE_STATE, G_CALLBACK(GnomeNetworkManagerEvents::deviceStateChangeCb), nmEvents);
plugin/gnome/NetworkManagerGnomeEvents.cpp:593
ifnamecomes fromnm_device_get_iface(device)earlier in this function.nm_device_get_iface()can returnnullptr, and constructingstd::string ifname = nm_device_get_iface(device);is undefined behavior. Add a null check before building the string so the newly added cache removal can’t be reached with an invalidifname.
/* Device is gone: drop it from the cache so the reads omit it
(matches the original live-device-list behaviour). */
GnomeNetworkManagerEvents::removeInterfaceStateCache(ifname);
plugin/gnome/NetworkManagerGnomeEvents.cpp:695
- In this loop,
ifnameis constructed fromnm_device_get_iface(device)without a null check. The same file already treatsnm_device_get_iface()as nullable (e.g.,refreshIpFamilyCache), so this can crash during initial seeding before the cache update added here. Use aconst char*+ null check andcontinuewhen it’s missing.
if( ((device != NULL) && NM_IS_DEVICE(device)) )
{
std::string ifname = nm_device_get_iface(device);
if((ifname == nmUtils::ethIface()) || (ifname == nmUtils::wlanIface()))
{
NMDeviceState devState = nm_device_get_state(device);
GnomeNetworkManagerEvents::updateInterfaceStateCache(ifname, devState, nm_device_get_hw_address(device));
a1542d1 to
aab2157
Compare
There was a problem hiding this comment.
Pull request overview
Copilot reviewed 6 out of 6 changed files in this pull request and generated no new comments.
Suppressed comments (5)
plugin/NetworkManagerJsonRpc.cpp:207
- Same as above: because logPrint formats before it checks log level (plugin/NetworkManagerLogger.cpp:85-114), this debug perf log adds unconditional vsnprintf overhead on every request. Please gate this log behind a DEBUG-level check if you want it to be effectively free when DEBUG is off.
NMLOG_DEBUG("[PERF] GetAvailableInterfaces iterator drain+serialize took %lld us, total %lld us",
static_cast<long long>(std::chrono::duration_cast<std::chrono::microseconds>(tEnd - tAfterComRpc).count()),
static_cast<long long>(std::chrono::duration_cast<std::chrono::microseconds>(tEnd - tStart).count()));
plugin/NetworkManagerJsonRpc.cpp:278
- Because NetworkManagerLogger::logPrint() formats the message before checking the configured level (plugin/NetworkManagerLogger.cpp:85-114), this new NMLOG_DEBUG([PERF]...) statement adds unconditional formatting overhead in a hot path. Gate it so the formatting only happens when DEBUG is enabled.
NMLOG_DEBUG("[PERF] GetInterfaceState COM-RPC call took %lld us",
static_cast<long long>(std::chrono::duration_cast<std::chrono::microseconds>(std::chrono::steady_clock::now() - tStart).count()));
plugin/gnome/NetworkManagerGnomeProxy.cpp:625
- Same issue as the other new perf logs: NetworkManagerLogger::logPrint() formats before checking log level (plugin/NetworkManagerLogger.cpp:85-114), so this NMLOG_DEBUG call incurs formatting overhead even when DEBUG is disabled. Gate it behind a DEBUG-level check to keep GetInterfaceState as cheap as possible.
NMLOG_DEBUG("[PERF] GetInterfaceState (impl) total %lld us",
static_cast<long long>(std::chrono::duration_cast<std::chrono::microseconds>(std::chrono::steady_clock::now() - tEntry).count()));
plugin/NetworkManagerJsonRpc.cpp:178
- NMLOG_DEBUG ultimately calls NetworkManagerLogger::logPrint(), which currently does vsnprintf() before it checks the configured log level (see plugin/NetworkManagerLogger.cpp:85-114). These new [PERF] debug logs will therefore incur formatting cost on every call even when DEBUG is disabled, partially negating the performance win in this hot path. Consider guarding the debug log so it only executes when DEBUG is enabled.
This issue also appears in the following locations of the same file:
- line 205
- line 277
NMLOG_DEBUG("[PERF] GetAvailableInterfaces COM-RPC call took %lld us",
static_cast<long long>(std::chrono::duration_cast<std::chrono::microseconds>(tAfterComRpc - tStart).count()));
plugin/gnome/NetworkManagerGnomeProxy.cpp:381
- NMLOG_DEBUG calls NetworkManagerLogger::logPrint(), which currently does vsnprintf() before it checks log level (plugin/NetworkManagerLogger.cpp:85-114). This new [PERF] debug log will therefore add unconditional formatting overhead on every GetAvailableInterfaces call even when DEBUG is disabled. Consider gating this log behind a DEBUG-level check.
This issue also appears on line 624 of the same file.
NMLOG_DEBUG("[PERF] GetAvailableInterfaces (impl) total %lld us",
static_cast<long long>(std::chrono::duration_cast<std::chrono::microseconds>(std::chrono::steady_clock::now() - tEntry).count()));
aab2157 to
d7ce251
Compare
d7ce251 to
fd5c995
Compare
…faceState Serve interface-state reads from an event-maintained cache. GetAvailableInterfaces and GetInterfaceState on the Gnome backend created a throwaway NMClient per call (nm_client_new), which synchronously dumps NetworkManager's entire object model and cost ~300ms-1.4s, blowing the 100ms SLA for GetAvailableInterfaces. Serve both reads from a gnome-owned cache of raw NMDeviceState (plus MAC), maintained solely by the event monitor: - Record state on the startup device walk, device-added, and every notify::state transition; drop the entry on device-removed. - Capture the MAC and keep it in sync whenever NM reports a new HW address. - Derive enabled/connected at read time from a single canonical definition, removing the prior >= vs > drift between the two APIs. - Make the reads pure: drop their side-effect writes to the shared connected/enabled atomics (the event path is now the sole writer). - Treat an interface absent from the cache as omitted, and an empty interface list as a valid (successful) result rather than an error. The cache holds a libnm type, so it lives in the Gnome backend; the backend-agnostic NetworkManagerImplementation header stays libnm-free. Add microsecond-resolution [PERF] instrumentation for both reads across the JSON-RPC and impl layers. It is logged at DEBUG level so it stays silent in normal operation and can be enabled on demand for diagnostics. When either COM-RPC read takes one second or more, also emit a WARN so pathological latencies surface without enabling DEBUG. Gate the log level check ahead of message formatting in NetworkManagerLogger::logPrint. Previously vsnprintf ran unconditionally and the level was only checked afterward, so every disabled log still paid the formatting cost. This affects all logging: disabled logs (at any level) now short-circuit before formatting. The RDK-logger build gates on rdk_logger_is_logLevel_enabled and the native build on the configured level, so filtering stays authoritative for each variant. Rework the libnm L1 tests to drive GetAvailableInterfaces and GetInterfaceState through the event-state cache (the sole public writer) instead of mocking the per-call NMClient device enumeration, and reset the process-global cache in test setup for order-independent runs.
fd5c995 to
005d65e
Compare
There was a problem hiding this comment.
Pull request overview
Copilot reviewed 7 out of 7 changed files in this pull request and generated no new comments.
Suppressed comments (3)
plugin/NetworkManagerJsonRpc.cpp:180
- The warning threshold is set to 1s, but the PR description mentions a 100ms SLA for GetAvailableInterfaces. With the current condition, slow calls between 100ms and 1s will only show up at DEBUG and may be missed in production logs; consider warning at (or near) the SLA threshold.
NMLOG_DEBUG("[PERF] GetAvailableInterfaces COM-RPC call took %lld us", comRpcUs);
if (comRpcUs >= 1000000)
NMLOG_WARNING("[PERF] GetAvailableInterfaces COM-RPC call took %lld us (>= 1s)", comRpcUs);
plugin/NetworkManagerJsonRpc.cpp:282
- The warning threshold is set to 1s, but this PR is explicitly targeting sub-100ms performance for interface-state APIs. Lowering the warning threshold (e.g., to 100ms) will make regressions visible without requiring DEBUG logs.
const long long comRpcUs = static_cast<long long>(std::chrono::duration_cast<std::chrono::microseconds>(std::chrono::steady_clock::now() - tStart).count());
NMLOG_DEBUG("[PERF] GetInterfaceState COM-RPC call took %lld us", comRpcUs);
if (comRpcUs >= 1000000)
NMLOG_WARNING("[PERF] GetInterfaceState COM-RPC call took %lld us (>= 1s)", comRpcUs);
plugin/gnome/NetworkManagerGnomeEvents.cpp:52
- The interface-state cache is a process-global static, but it is never cleared on event-monitor stop/deinit. This can leave stale interface state visible after a plugin reload or event monitor restart within the same process (the L2 tests already need to manually clear entries for determinism). Consider clearing the cache when starting/stopping the event monitor (or in Deinitialize) so reads cannot return stale data across lifecycle transitions.
/* Gnome-owned interface-state cache (raw NMDeviceState + MAC per interface).
Written only by the event monitor; read by the proxy's pure readers. */
static std::map<std::string, GnomeNetworkManagerEvents::InterfaceStateInfo> _ifaceStateCache;
static std::mutex _ifaceStateCacheMutex;
Updated include Function Name
There was a problem hiding this comment.
Pull request overview
Copilot reviewed 7 out of 7 changed files in this pull request and generated no new comments.
Suppressed comments (5)
Previously missed (3) — in code that hasn't changed since the last review.
plugin/NetworkManagerJsonRpc.cpp:181
- The GetAvailableInterfaces perf instrumentation logs a "COM-RPC" duration even when
_networkManageris null (no COM-RPC happens), andtAfterComRpcisconstso it can’t be set conditionally. Consider only timing/logging the COM-RPC segment when the call is actually made, while still keeping a total timer for the full handler.
This issue also appears in the following locations of the same file:
- line 206
- line 259
const auto tStart = std::chrono::steady_clock::now();
if (_networkManager)
rc = _networkManager->GetAvailableInterfaces(_interfaces);
else
plugin/gnome/NetworkManagerGnomeProxy.cpp:610
- Spelling/wording in the log message: "not valied" is a typo, and the
interface.c_str()!=nullptrcheck is redundant (c_str()is never null). This makes the error message harder to read than necessary.
NMLOG_ERROR("interface: %s; not valied", interface.c_str()!=nullptr? interface.c_str():"empty");
plugin/gnome/NetworkManagerGnomeEvents.cpp:52
- The interface-state cache is a process-global static map. Since it’s not cleared on event-monitor stop/start, a plugin reload within the same process (or a NetworkManager restart without emitting device-removed signals) can leave stale entries that will be served by GetAvailableInterfaces/GetInterfaceState. Consider clearing the cache when starting/stopping the monitor (or in the events singleton constructor/destructor) to ensure reads don’t return stale state across lifetimes.
/* Gnome-owned interface-state cache (raw NMDeviceState + MAC per interface).
Written only by the event monitor; read by the proxy's pure readers. */
static std::map<std::string, GnomeNetworkManagerEvents::InterfaceStateInfo> _ifaceStateCache;
static std::mutex _ifaceStateCacheMutex;
plugin/NetworkManagerJsonRpc.cpp:263
- GetInterfaceState perf logging currently measures from the start of the handler (including parameter validation) and still logs a "COM-RPC call" duration on BAD_REQUEST / UNAVAILABLE paths where no COM-RPC occurs. This makes the numbers hard to compare to the 100ms/1s SLA. Consider timing/logging only around the
_networkManager->GetInterfaceState(...)call when it is actually invoked.
const auto tStart = std::chrono::steady_clock::now();
if (parameters.HasLabel("interface"))
{
const string interface = parameters["interface"].String();
plugin/NetworkManagerJsonRpc.cpp:209
- This "iterator drain+serialize" perf log runs even when
_networkManageris null (no COM-RPC and no iterator drain), so the label/durations become misleading on the UNAVAILABLE path. Consider gating the post-call breakdown on_networkManagerbeing present (or adjust the label to be a pure total).
const auto tEnd = std::chrono::steady_clock::now();
NMLOG_DEBUG("[PERF] GetAvailableInterfaces iterator drain+serialize took %lld us, total %lld us",
static_cast<long long>(std::chrono::duration_cast<std::chrono::microseconds>(tEnd - tAfterComRpc).count()),
static_cast<long long>(std::chrono::duration_cast<std::chrono::microseconds>(tEnd - tStart).count()));
GetAvailableInterfaces and GetInterfaceState on the Gnome backend created a throwaway NMClient per call (nm_client_new), which synchronously dumps NetworkManager's entire object model and cost ~300ms-1.4s, blowing the 100ms SLA for GetAvailableInterfaces.
To fix this, serve interface-state reads from an event-maintained cache.