Skip to content

RDKB-64112: Account ID check removal from IDM#10

Open
snayak002c wants to merge 33 commits into
developfrom
idm_full_logging
Open

RDKB-64112: Account ID check removal from IDM#10
snayak002c wants to merge 33 commits into
developfrom
idm_full_logging

Conversation

@snayak002c
Copy link
Copy Markdown

@snayak002c snayak002c commented May 15, 2026

Reason for change: Remove all accountId-based pairing restrictions so devices pair irrespective of accountId
Test Procedure:
Risks: Low
Coverage:

Signed-off-by:[email protected]

veeraputhiran-thangavel and others added 30 commits March 25, 2026 14:59
Remove all accountId-based pairing restrictions so devices pair
irrespective of accountId value when both run new code, and work
correctly with valid accountId in mixed scenarios.

Changes:
- Remove while(1) blocking loop in start_discovery that waited for
  RFC accountId to become non-Unknown (XLE could never start discovery
  when RFC was not yet provisioned)
- Remove digit-only validation that rejected accountIds containing
  non-digit characters (rejected 'Unknown')
- Remove accountId match check that required peer accountId to equal
  own accountId (prevented XLE from being added when it returned Unknown)
- Remove now-unused static accountId[] global declaration

idm_server.c is unchanged.

Coverage:
  XLE new + XB new : works for valid and Unknown accountId
  XLE new + XB old : works when XLE RFC accountId is valid
  XLE old + XB new : works when XLE RFC accountId is valid
Device list insertion and callback now happen regardless of whether
GetAccountId succeeds, so devices that don't implement the action or
return an error are still associated.

When GetAccountId succeeds the accountId is logged as metadata.
When it fails a diagnostic message is logged and pairing continues.

This fully removes accountId-based pairing restrictions from the
client side.
- New idm_log.h / idm_log.c: shared logging module for idm_client and
  idm_server. Writes timestamped lines to
  /rdklogs/logs/InterDeviceManager.txt.0 with RDK log format:
    YYMMDD-HH:MM:SS.uuuuuu [mod=INTERDEVICEMANAGER, lvl=<LEVEL>] [tid=NNN] func line - message
- Persistent file descriptor with inode-check reopen on rdklogger rotation
- Thread-safe via pthread_mutex_t; _GNU_SOURCE guard for localtime_r/syscall
- IDM_LOG_INFO(fmt, ...) macro for INFO-level logging
- IDM_LOG_ERR(fmt, ...)  macro for ERROR-level logging
- Format attribute __attribute__((format(printf, 4, 5))) for compile-time
  format-string validation
- T2 telemetry: t2_event_s("IDM_DISCOVERY_STARTED_split", ...)
  and t2_event_s("IDM_DEVICE_ASSOCIATED_split", ...) at key events
- Makefile.am: idm_log.c added to libupnpidm_la_SOURCES
Change IDM_LOG_FILE from /rdklogs/logs/InterDeviceManager.txt.0
to /rdklogs/logs/Consolelog.txt.0 so IDM log output is consolidated
into the standard console log file.
Co-authored-by: Copilot <[email protected]>
Add IDM_LOG_ERR() alongside every existing g_message/g_critical error
print so errors appear in both the GLib log (g_message) and the RDK
console log (Consolelog.txt.0 via idm_log.c).

Errors covered (30 call sites):
- SE cert passcode retrieval failure (rdkconfig_get)
- g_tls_certificate_new_from_file_with_password failure
- HW cert fallback path: NULL certFile/keyFile, file not found,
  g_tls_certificate_new_from_files failure
- Normal cert path: same three cases
- GUPnP service proxy action error (processStringRequest)
- gssdp_resource_browser_rescan failures (cp and cp_bgw variants)
- xupnp stuck >5 minutes — all four code paths (IDM_DEBUG and
  production, inactive and null-count variants)
- NULL cp/dproxy received in available callbacks (broadband + gateway)
- Gateway receiver id NULL, UDN NULL
- Memory allocation failure for GwyDeviceData
- sproxy NULL on device available
- Device receiver id NULL, device UDN NULL (non-broadband path)
- Missing mandatory start_discovery parameters
- p12 cert file creation failure
- SE HW certificate not accessible
- idm_server_start failure
- pthread_create failure for EventHandler thread
- Mandatory TLS cert files absent
- GUPnP context creation failure

g_message/g_critical calls are preserved unchanged.
Remove the 6 IDM_LOG_ERR calls inside the verify_devices() polling
loop that fire every ~30s when gssdp is broken:
- gssdp_resource_browser_rescan failed (cp and cp_bgw)
- xupnp stuck >5min cp/cp_bgw inactive count threshold
- xupnp stuck >5min cp/cp_bgw null count threshold

These will be re-added with rate-limiting in a follow-up commit.
The existing g_message calls in the same paths are left untouched.
The remaining 24 IDM_LOG_ERR calls (startup / event-driven paths)
carry no flooding risk and are retained.
- idm_log.c: when fopen(IDM_LOG_FILE) fails, emit a rate-limited
  diagnostic via stderr (once per 60 s) with errno string instead of
  silently dropping the message.  Add <errno.h> and <string.h> includes.
- idm_client.c: remove trailing \n from all 24 IDM_LOG_ERR/INFO fmt
  strings; idm_consolelog already appends a newline via fputc, so the
  extra \n was producing blank lines between log entries.

Addresses Copilot review comments #1-#4 on idm_log.c/idm_log.h.
The three IDM_LOG_INFO prints:
  - start_discovery called for serial %s        (line 927)
  - device associated sno=%s  (BGW path, line 732)
  - device associated sno=%s  (XB path, line 839)

are redundant with CcspTraceInfo prints in rdk-interdevicemanager:
  - discovery start: CcspTraceInfo line 770 logs base MAC + start
  - pairing: CcspTraceInfo line 378 in discovery_cb logs IPv4/IPv6/MAC/
    discovery_status/authentication_status for every callback() invocation

Removing avoids duplicate entries in Consolelog.txt.0 and eliminates
the noisy self-association entries seen in field logs (MWN2983C0544
appearing as 'device associated' alongside the real XB serial).
1. Restore IDM_LOG_FILE to /rdklogs/logs/InterDeviceManager.txt.0
   (reverts commit f4755b1 which changed it to Consolelog.txt.0).
   UPNP/IDM log output now lands in the same file used by the
   rdk-interdevicemanager component — InterDeviceManager.txt.0 —
   consistent with the log4crc appender for LOG.RDK.INTERDEVICEMANAGER.
   All rotation/permissions behaviour is unchanged (rdklogger still owns
   the file; idm_log_reopen() detects inode change on rotation).

2. Sanitize sensitive file-path logging in idm_client.c (5 call sites
   introduced by veeraputhiran commit b94fc4a):
   - 'certFile or keyFile not found certFile=%s keyFile=%s'  (×2)
   - 'g_tls_certificate_new_from_files failed certFile=%s keyFile=%s' (×2)
   - 'cannot create p12 cert file from %s'
   Each now logs only the high-level failure without the actual path.

3. Remove absolute-path exposure in idm_log.c stderr fallback
   (introduced by commit 3971804): the rate-limited fopen-failure
   message no longer emits IDM_LOG_FILE in the format string.

No new log files created. No functional behaviour changed.
Extends the dual-logging introduced in b94fc4a (IDM_LOG_ERR for all
error paths) to info-level events so that the full IDM lifecycle is
visible in InterDeviceManager.txt.0 — not just errors.

15 IDM_LOG_INFO call sites added alongside existing g_message calls:

Discovery lifecycle:
  - discovery started: interface + port (start_discovery)
  - stop discovery triggered / complete (verify_devices loop)

Device lifecycle:
  - broadband device discovered (sno) — bgw available cb
  - device associated (sno) — bgw path
  - device discovered (sno) — non-bgw available cb
  - device associated (sno) — non-bgw path
  - device went down (sno) — bgw unavailable cb
  - device deleted from list — bgw unavailable cb
  - device removed from list — delete_gwyitem

TLS / cert setup:
  - p12 cert file created successfully
  - TLS context: using SE HW certificate
  - TLS context: using extracted cert files
  - UPnP running in secure mode
  - TLS CA file configured   [path redacted — no filename in log]

Omitted (intentionally):
  - TELEMETRY_ g_messages — those go to T2 split markers, not log
  - Internal loop/state debug: 'goto start', sysevent fd, EventListen
    counters, main loop NULL checks — high-frequency / low signal
  - g_message calls already beside an IDM_LOG_ERR — error wins

Base branch (remove_xle_accountid_check_v3) is untouched.
Adds 27 more IDM_LOG_INFO/ERR call sites to reach full coverage of
all meaningful events in idm_client.c. Every g_message that carries
operational signal now has a companion IDM_LOG call writing to
InterDeviceManager.txt.0.

New IDM_LOG_INFO call sites (22):
  WAN / EventHandler:
    - wan-status started / stopped
  SE cert init:
    - SE cert passcode decoded
    - using SE certificate with passcode
    - SE certificate loaded successfully
  Connect-point / device lifecycle:
    - broadband device available cb triggered (bgw)
    - device already in list skipping (bgw + non-bgw paths)
    - new device available cb triggered (non-bgw)
    - device not found in list for removal
    - quitting main loop / main loop not running / main loop NULL
    - gssdp rescan failed (cp) / gssdp rescan failed (cp_bgw)
    - verify_devices thread started
    - TLS context: SE HW cert (non-GUPNP_1_2 path)
    - TLS context: extracted cert files (non-GUPNP_1_2 path)
    - tls interaction object created
    - X1BroadbandGateway control point active
    - UPnP running in non-secure mode
    - UPnP threads started
    - IDM UPnP init complete
    - main loop exited
    - freeing server memory / removing device list entries

New IDM_LOG_ERR call site (1):
    - failed to delete device from list (delete_gwyitem failure)

Intentionally excluded (no IDM_LOG added):
  - TELEMETRY_ g_messages (T2 split markers)
  - xupnp stuck >5min paths (removed by veeraputhiran/5a31a2b, flooding risk)
  - Sensitive device data: IP, MAC, IPv6, receiverid values
  - Sysevent per-iteration noise: EventListen, wan-status polling loop
  - Function-entry/exit trace markers (__FUNCTION__/__LINE__ only)
  - Error sub-detail messages already inside an IDM_LOG_ERR block
Add #include "idm_log.h" and companion IDM_LOG_INFO/ERR calls alongside
every meaningful g_message/g_printerr in idm_server.c so that server-side
events appear in InterDeviceManager.txt.0.

IDM_LOG_INFO (15 call sites):
  - GetAccountId action invoked         (value redacted, event only)
  - free_server_memory called
  - recv_id generated from MAC          (UUID value redacted)
  - IDM server start interface=<iface>
  - IDM server TLS cert files present   (paths redacted)
  - server TLS context: SE HW cert / extracted cert files (×4 paths)
  - server UPnP context created
  - server TLS CA cert configured       (path redacted)
  - X1Identity UPnP service ready
  - server UUID assigned
  - IDM.XML device file updated
  - IDM server init complete

IDM_LOG_ERR (15 call sites):
  - XML: target node not found
  - failed to read device XML file
  - failed to set UDN in device XML
  - failed to set serial number in device XML
  - failed to open device XML for writing
  - failed to write device XML file
  - getUidfromRecvId: MAC tokenize failed
  - getUUID: NULL output buffer / empty recvId / failed
  - server TLS context creation failed (with error message)
  - failed to get X1Identity UPnP service
  - mandatory TLS files absent
  - server context creation failed (with error message)
  - failed to get DiscoverFriendlies UPnP service

Intentionally excluded:
  - free_server_memory internal clear markers (__FUNCTION__ traces)
  - Commented-out g_printerr for open_document failure (already commented)
Remove the hand-rolled idm_log.c (file open, inode check, mutex, fprintf)
and rewrite idm_log.h to delegate directly to RDK_LOG() via rdk_debug.h.

Changes:
- idm_log.h: #include rdk_debug.h; IDM_LOG_INFO -> RDK_LOG(RDK_LOG_INFO, ...)
             IDM_LOG_ERR  -> RDK_LOG(RDK_LOG_ERROR, ...)
             Module string: LOG.RDK.INTERDEVICEMANAGER — same category used
             by the interdevicemanager binary, routes to InterDeviceManager.txt
             Format prefix: (%s:%d) matching CcspTraceInfo convention
- idm_log.c: deleted — no longer needed; rdklogger owns timestamps, rotation
             and level filtering via log4c/debug.ini
- src/Makefile.am: remove idm_log.c from libupnpidm_la_SOURCES;
                   add libupnpidm_la_LIBADD = -lrdkloggers

No changes to idm_client.c or idm_server.c — all call sites continue to
use IDM_LOG_INFO() / IDM_LOG_ERR() macros unchanged.
Update idm_log.h to use ccsp_trace.h directly, matching the exact
logging API used by the interdevicemanager binary that links libupnpidm.la.

Changes:
- idm_log.h: include ccsp_trace.h (replaces rdk_debug.h)
  IDM_LOG_INFO(fmt,...) -> CcspTraceInfo(  ("(%s:%d) " fmt "\n", __func__, __LINE__, ...))
  IDM_LOG_ERR(fmt, ...) -> CcspTraceError( ("(%s:%d) " fmt "\n", __func__, __LINE__, ...))
  pComponentName is the extern provided by interdevicemanager main();
  CcspTraceGetRdkLogModule() maps it to LOG.RDK.INTERDEVICEMANAGER.
- src/Makefile.am: libupnpidm_la_LIBADD adds -lccsp_common alongside
  -lrdkloggers; CcspTraceGetRdkLogModule() lives in libccsp_common.

No changes to idm_client.c or idm_server.c — all IDM_LOG_INFO/IDM_LOG_ERR
call sites are unchanged.
Replace all IDM_LOG_INFO/IDM_LOG_ERR macro call sites with the CcspTrace
API directly used by the interdevicemanager binary, so that idm_client.c
and idm_server.c use the exact same logging pattern as the rest of the
interdevicemanager component.

Changes:
- idm_client.c: #include "ccsp_trace.h" (replaces idm_log.h)
  all 66 IDM_LOG_INFO -> CcspTraceInfo((...))
  all IDM_LOG_ERR    -> CcspTraceError((...))
- idm_server.c: same; 30 calls converted
- idm_log.h: deleted — no longer referenced by any source file

pComponentName extern is provided by interdevicemanager main(); the library
links against -lrdkloggers -lccsp_common (libupnpidm_la_LIBADD).
Every g_message/g_critical/fprintf(stderr) that had a CcspTraceInfo or
CcspTraceError call directly adjacent was a duplicate — the same event
logged to both GLib (stdout/journald) and InterDeviceManager.txt.

Remove the 72 redundant lines from idm_client.c and 25 from idm_server.c.
The 42+6 standalone g_message calls with no adjacent CcspTrace counterpart
are preserved unchanged.

CcspTrace call counts are unchanged: 66 in idm_client.c, 30 in idm_server.c.
Replace every g_message, g_critical, g_printerr, and fprintf(stderr)
in idm_client.c and idm_server.c with the appropriate CcspTrace call:

  g_critical / g_printerr / fprintf(stderr)   -> CcspTraceError
  g_message with error/fail/cannot keywords   -> CcspTraceError
  g_message informational                     -> CcspTraceInfo

TELEMETRY_* g_message markers are preserved unchanged — they are
consumed by the telemetry pipeline, not a logging mechanism.

Result: idm_client.c has 107 CcspTrace calls, idm_server.c has 44.
No GLib or stdio logging calls remain in either file.
TELEMETRY_XUPNP_PARTIAL_DISCOVERY -> CcspTraceError (error path)
TELEMETRY_IDM_DISCOVERY_STARTED   -> CcspTraceInfo  (info path)

t2_event_s() calls are unchanged.
idm_client.c and idm_server.c now have zero g_message/g_critical/
g_printerr/fprintf(stderr) calls.
…ding

Split CcspTraceInfo calls into INFO (lifecycle) vs DEBUG (trace/internal):

CcspTraceDebug — per-callback, polling-loop, function-entry/exit, internals:
  idm_client.c: 37 calls demoted
    - EventListen poll results, wan-status thread internals
    - per-device fields: clientIP, BcastMacAddress, GatewayIPv6, receiverId
    - function entry/exit: %s:%d Entered/Called/completed/Completed
    - TLS internals: Getting passcode, Freeing pass phrase
    - callback=%p, Device Addition in loop, discovery_interval config
  idm_server.c: 12 calls demoted
    - GetAccountId action invoked (fires per UPnP action)
    - free_server_memory cleanup sub-steps
    - recv_id generated from MAC
    - server TLS context sub-steps (SE/extracted ×2, CA cert)

CcspTraceInfo — kept for lifecycle/state-change events only:
  idm_client.c: 43 calls  |  idm_server.c: 7 calls
  Examples: wan-status started/stopped, device discovered/went down,
  device associated, IDM UPnP init complete, discovery started,
  UPnP running in secure/non-secure mode, stop discovery, xupnp stuck,
  IDM server start/init complete, server UUID assigned, IDM.XML updated

Runtime level control via /etc/debug.ini:
  LOG.RDK.INTERDEVICEMANAGER=INFO  -> lifecycle only (production)
  LOG.RDK.INTERDEVICEMANAGER=DEBUG -> full trace (field diagnostics)
CcspTrace appends its own newline; a \n at the end of the format
string produced a blank line after every log entry (double-line traces).
Removed the trailing \n from all 16 affected CcspTrace calls across
idm_client.c (8) and idm_server.c (8). Message text is otherwise unchanged.
Two fprintf(stderr,...) conversions had their message text altered:
  'failed to open device XML file' (lowercase, shortened)
instead of the original:
  'Failed to open the device xml file /etc/xupnp/IDM*.xml'

Restore exact original wording. Only the logging method changes,
never the message content.
The redundant-removal step deleted 95 g_message/g_critical/g_printerr
calls that were adjacent to IDM_LOG_ calls. While some were truly
duplicate (same text), many had different messages (e.g. actual values
like accountId=%s vs the IDM_LOG_ summary phrase).

Restore all deleted original messages as CcspTraceInfo/CcspTraceError
calls. Each original g_message now sits before its adjacent IDM_LOG_
derived CcspTrace call, preserving all log information.
Previous approach of restoring deleted g_messages had a bug: when
the same message appeared in multiple #ifdef branches, the script
matched on substring anchors and inserted both copies into the first
matching location instead of each into its own branch. This caused
adjacent duplicates like:

  CcspTraceInfo(("Certificate creation failed from cert and key files"));
  CcspTraceInfo(("Certificate creation failed from cert and key files")); // dup

Fix: reset both files to 4c12ca9 and re-do conversion in a single
correct pass. Each log call is converted in-place (no lines moved):
  g_message(...)       -> CcspTraceInfo((...))\n  g_critical/g_printerr -> CcspTraceError((...))
  fprintf(stderr,...)  -> CcspTraceError((...))
  IDM_LOG_INFO(...)    -> CcspTraceInfo((...))\n  IDM_LOG_ERR(...)     -> CcspTraceError((...))\n  #include "idm_log.h" -> #include "ccsp_trace.h"

Trailing \n stripped from format strings. DEBUG/INFO split preserved
from original demotion set (49 calls demoted to CcspTraceDebug).
From diff 5cb526e..HEAD, every IDM_LOG_INFO/ERR addition we made
between commits 818254d--4c12ca9 produced a CcspTrace call that sat
adjacent to the original g_message-derived CcspTrace call, logging
the same event twice with different wording.

Remove all 66 redundant IDM_LOG_-derived CcspTrace calls wherever
they are adjacent to an original g_message-derived CcspTrace call.
Standalone IDM_LOG_-derived calls with no adjacent original are kept.

Remaining adjacent pairs (5) are all from original g_message code:
- Sequential events in stop_discovery()
- IDM association + TELEMETRY_ marker
- Error summary + parameter dump
- g_message + g_critical pair with different context fields
35 messages with error/failure/null/warning content were logged at
Info or Debug level. Promote all to CcspTraceError:

idm_server.c (5):
  getUUID: NULL input, UUID fetch failure,
  Device Protection context creation error,
  Cannot get X1Identity service,
  Broadcast context creation error

idm_client.c (30):
  Passcode fetch failure, TLS cert creation failures,
  cert file NULL / not found / creation failed paths,
  gupnp proxy action failure,
  forced rescan failures, xupnp stuck / restart trigger,
  main loop NULL, unable to delete from list,
  WARNING null pointer (broadband/gateway),
  receiver ID / UDN NULL conditions,
  mandatory values missing, p12 creation failure,
  SE HW cert inaccessible, idm_server_start failure,
  event handler thread creation error,
  GUPnP context creation error

Left at Info: 'SE HW cert not available' (informational fallback),
  TELEMETRY_ marker. Left at Debug: error->message detail line.
Two build errors on TECHNICOLORXB7:

1. idm_server.c: 'else without a previous if' (line 265)
   CcspTrace macros on some platforms expand to an 'if(...)' statement
   internally. A bare if/else around such a macro creates a dangling
   else. Add braces around the if/else in getUidfromRecvId().

2. idm_client.c: duplicate 'unsigned' / BOOLEAN typedef conflict
   platform_hal.h (#define BOOLEAN unsigned char) is included before
   ccsp_trace.h, which pulls in user_base.h with:
     typedef unsigned char BOOLEAN, *PBOOLEAN;
   The macro expansion makes this 'unsigned unsigned char'.
   Fix: move #include "ccsp_trace.h" to before the #ifndef BROADBAND
   block so user_base.h's typedef runs before platform_hal.h's macro
   definition on all build targets.
Copilot AI review requested due to automatic review settings May 15, 2026 18:22
@snayak002c snayak002c requested review from a team as code owners May 15, 2026 18:22
Copy link
Copy Markdown

Copilot AI left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

This PR updates IDM client/server/library logging to use RDK/CCSP trace logging and adds IDM discovery/association telemetry hooks.

Changes:

  • Adds RDK logger build flags and libraries for libupnpidm.
  • Replaces many GLib/stdout/stderr logs with CcspTrace* calls.
  • Adds Telemetry 2.0 IDM discovery/association events and changes IDM_DP device association flow.

Reviewed changes

Copilot reviewed 4 out of 4 changed files in this pull request and generated 1 comment.

File Description
src/Makefile.am Adds RDK logging compile/link settings for IDM library.
src/idm_server.c Converts IDM server logs to CCSP trace logging.
src/idm_library.c Converts IDM library logs to CCSP trace logging.
src/idm_client.c Converts IDM client logs, adds telemetry events, and updates discovery association behavior.

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

Comment thread src/idm_client.c
Comment on lines +716 to +724
g_mutex_lock(mutex);
xdevlist = g_list_insert_sorted_with_data(xdevlist, gwydata,(GCompareDataFunc)g_list_compare_sno, NULL);
g_mutex_unlock(mutex);
CcspTraceInfo(("Associating device %s\n", sno));
CcspTraceInfo(("TELEMETRY_IDM_DEVICE_ASSOCIATED:%s\n", sno));
#if defined(ENABLE_FEATURE_TELEMETRY2_0)
t2_event_s("IDM_DEVICE_ASSOCIATED_split", sno);
#endif
callback(&di,1,1);
@veeraputhiran-thangavel veeraputhiran-thangavel changed the title Idm full logging RDKB-64112: Account ID check removal from IDM May 16, 2026
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.

4 participants