You are viewing an old version of this page. View the current version.

Compare with Current View Page History

Version 1 Next »


Why we need notifications?

  • To ensure whether the value is set properly and updated in the database

Module and component

  • Logging mechanism - RDKB Logger
  • RDKB logger is linked to RDK-B modules to enable component wise logging
  • Component responsible for enabling/disabling notifications : LogAgent
  • Supported modules : TR069, PAM, Notify_comp, PSM, MTA,CM, WiFi, CR, EthAgent, Harvester,PowerMgr, FSC, Mesh

During Boot-up 

  • When Rpi boots-up , each RDK-B component will be initialized which in turn will initialize logger and start logging into the corresponding log file depending on the log level set for the component

Options to log notifications

  • LoggerEnable - to enable/disable logs for particular component. If it is TRUE logs are enabled otherwise logs are disabled.
  • LogLevels - To set different log levels for each component. By default all modules log level is 4 (RDK_LOG_INFO).

How enable/disable notifications works?

  • The notifications are disabled by default
  • To enable notifications for particular module , set LogAgent.X_RDKCENTRAL-COM_LoggerEnable to TRUE
  • This in turn sends signals to all the available modules
  • Now we set Logger for the required module , i.e, Device.LogAgent.X_RDKCENTRAL-COM_<Module>_ LoggerEnable to TRUE
  • Here only for that particular module Logger will be set to true and provides the logs in log folder. For others it will be in FALSE state.
  • Flow : LogAgent_SetParamBoolValue() -> SendSignal (to all modules) -> check the module to which Logger is enabled -> SendSignal(<MODULE>_PROC_NAME) -> TRUE
  • This loads the module and set to TRUE

Notification levels 

  • Files :
    1. ./etc/debug.ini
    2. rdkb_log4crc configuration files
  • Level for all components can be controlled using “X_RDKCENTRAL-COM_LogLevel”
  • It is by default set to level 4 which is RDK_LOG_INFO.
  • Log levels can be controlled independently for each module
  • Example:RDK.<component name> = ALL, FATAL, ERROR WARNING, NOTICE, INFO, DEBUG
  • For the modules not having entries in configuration file, log level is set to default log levels. (Currently this is set to LOG.RDK.DEFAULT = ERROR in debug.ini)

Examples

Changing SSID name

  • Default SSID

root@RaspberryPi-Gateway:~#  dmcli eRT getv Device.WiFi.SSID.1.SSID
CR component name is: eRT.com.cisco.spvtg.ccsp.CR
subsystem_prefix eRT.
getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.1.SSID
Execution succeed.
Parameter    1 name: Device.WiFi.SSID.1.SSID
               type:     string,    value: RPI_RDKB-AP0

  • Module : Onewifi . By default the logs are enabled with below configuration
  • /etc/debug.ini

LOG.RDK.WIFI = FATAL ERROR WARNING NOTICE INFO

  • Logs 

r

240809-13:51:27.591054 [mod=WIFI, lvl=WARN] [tid=1953]
Subsystem is eRT.
240809-13:51:27.591768 [mod=WIFI, lvl=INFO] [tid=1953] Connect to bus daemon...
240809-13:51:27.591959 [mod=WIFI, lvl=WARN] [tid=1953] RBus is enabled
240809-13:51:27.592057 [mod=WIFI, lvl=INFO] [tid=1953] rbuscore.c:2326 RBus Enabled

240809-13:51:27.592180 [mod=WIFI, lvl=INFO] [tid=1953] connection opened for eRT.com.cisco.spvtg.ccsp.wifi
240809-13:51:27.592388 [mod=WIFI, lvl=INFO] [tid=1953] rbuscore.c:926 Registering method table for object eRT.com.cisco.spvtg.ccsp.wifi

240809-13:51:27.592546 [mod=WIFI, lvl=INFO] [tid=1953] eRT.com.cisco.spvtg.ccsp.wifi start to check eRT.com.cisco.spvtg.ccsp.psm status
240809-13:51:27.596322 [mod=WIFI, lvl=INFO] [tid=1953] eRT.com.cisco.spvtg.ccsp.psm is ready, eRT.com.cisco.spvtg.ccsp.wifi continue
240809-13:51:27.596434 [mod=WIFI, lvl=INFO] [tid=1953] !!! Connected to message bus... bus_handle: 0x0x7f8c018de0 !!!
240809-13:51:28.602883 [mod=WIFI, lvl=INFO] [tid=1953] CcspBaseIf_Register_Event_rbus : rbus_registerEvent called for event: currentSessionIDSignal
240809-13:51:28.620576 [mod=WIFI, lvl=INFO] [tid=1953] rbuscore.c:742 Subscription for _rbus_session_mgr::currentSessionIDSignal is now active.

240809-13:51:28.621396 [mod=WIFI, lvl=WARN] [tid=1953] Register empty object : com.
240809-13:51:28.621487 [mod=WIFI, lvl=WARN] [tid=1953] Register empty object : com.cisco.
240809-13:51:28.621543 [mod=WIFI, lvl=WARN] [tid=1953] Register empty object : com.cisco.spvtg.
240809-13:51:28.621601 [mod=WIFI, lvl=WARN] [tid=1953] Register empty object : com.cisco.spvtg.ccsp.
240809-13:51:28.628362 [mod=WIFI, lvl=WARN] [tid=1953] Data model XML file 1 = TR181-WiFi-USGv2.XML
240809-13:51:28.628910 [mod=WIFI, lvl=WARN] [tid=1953] DM Library module name = CCSP Base Data Model
240809-13:51:28.638364 [mod=WIFI, lvl=WARN] [tid=1953] DM Library module name = COSA_TR181_WiFi_USGv2
240809-13:51:28.638518 [mod=WIFI, lvl=WARN] [tid=1953] Loading DM library libwifi.so...
240809-13:51:28.651047 [mod=WIFI, lvl=WARN] [tid=1953]  RDKB_SYSTEM_BOOT_UP_LOG : CosaWifiInitialize - WiFi initialize.
240809-13:51:29.296945 [mod=WIFI, lvl=INFO] [tid=1953] rbus.c:2771 rbus open for component: WebconfigDML

240809-13:51:29.297285 [mod=WIFI, lvl=INFO] [tid=1953] rbus.c:2847  rbus open (WebconfigDML) success

240809-13:51:29.298751 [mod=WIFI, lvl=INFO] [tid=1621] rbus.c:1018 Consumer=rbus.OneWifi.INBOX.1555 SUBSCRIBED to event=Device.WiFi.WebConfig.Data.Subdoc.North

240809-13:51:29.300330 [mod=WIFI, lvl=INFO] [tid=1953] rbuscore.c:742 Subscription for Device.WiFi.WebConfig.Data.Subdoc.North::Device.WiFi.WebConfig.Data.Subdoc.North is now active.

240809-13:51:29.300482 [mod=WIFI, lvl=INFO] [tid=1953] rbus.c:4786 Device.WiFi.WebConfig.Data.Subdoc.North subscribe retries succeeded

240809-13:51:29.301349 [mod=WIFI, lvl=INFO] [tid=1621] rbus.c:1018 Consumer=rbus.OneWifi.INBOX.1555 SUBSCRIBED to event=Device.WiFi.WebConfig.Data.Init_dml

240809-13:51:29.302305 [mod=WIFI, lvl=INFO] [tid=1953] rbuscore.c:742 Subscription for Device.WiFi.WebConfig.Data.Init_dml::Device.WiFi.WebConfig.Data.Init_dml is now active.

240809-13:51:29.302440 [mod=WIFI, lvl=INFO] [tid=1953] rbus.c:4786 Device.WiFi.WebConfig.Data.Init_dml subscribe retries succeeded

240809-13:51:29.493276 [mod=WIFI, lvl=WARN] [tid=1953]  RDKB_SYSTEM_BOOT_UP_LOG : CosaWifiInitialize - WiFi initialization complete.
240809-13:51:29.493495 [mod=WIFI, lvl=INFO] [tid=1953] rbuscore.c:2326 RBus Enabled

240809-13:51:29.493567 [mod=WIFI, lvl=INFO] [tid=1953] rbus.c:2771 rbus open for component: t2_lib_ccsp-wifi-agent

240809-13:51:29.493853 [mod=WIFI, lvl=INFO] [tid=1953] rbus.c:2847  rbus open (t2_lib_ccsp-wifi-agent) success

240809-13:51:29.496362 [mod=WIFI, lvl=ERROR] [tid=1953] rbus.c:3317 get by t2_lib_ccsp-wifi-agent failed; Received error 17 from RBUS Daemon for the object Telemetry.ReportProfiles.ccsp-wifi-agent.EventMarkerList

  • Changing the SSID

root@RaspberryPi-Gateway:~# dmcli eRT setv Device.WiFi.SSID.1.SSID string RPI_RdkB

CR component name is: eRT.com.cisco.spvtg.ccsp.CR

subsystem_prefix eRT.

setv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.1.SSID

Execution succeed.

  • Logs:

240809-13:51:38.446402 [mod=WIFI, lvl=INFO] [tid=1555] rbus.c:4786 Device.DeviceInfo.X_RDKCENTRAL-COM_xOpsDeviceMgmt.Mesh.Enable subscribe retries succeeded

240809-13:51:46.478663 [mod=WIFI, lvl=INFO] [tid=1709] subscribeSubdocForceReset: [Device.X_RDK_WebConfig.webcfgSubdocForceReset] Component found
240809-13:51:46.478765 [mod=WIFI, lvl=INFO] [tid=1709] subscribeSubdocForceReset: subscribing to event Device.X_RDK_WebConfig.webcfgSubdocForceReset
240809-13:51:46.480941 [mod=WIFI, lvl=INFO] [tid=1709] rbuscore.c:742 Subscription for Device.X_RDK_WebConfig.webcfgSubdocForceReset::Device.X_RDK_WebConfig.webcfgSubdocForceReset is now active.

240809-13:51:46.481080 [mod=WIFI, lvl=INFO] [tid=1709] rbus.c:4786 Device.X_RDK_WebConfig.webcfgSubdocForceReset subscribe retries succeeded

240809-13:51:46.481150 [mod=WIFI, lvl=INFO] [tid=1709] subscribeSubdocForceReset: subscribed to event Device.X_RDK_WebConfig.webcfgSubdocForceReset
240809-13:51:46.481230 [mod=WIFI, lvl=INFO] [tid=1709] subscribeSubdocForceReset: job done
240809-13:55:00.879242 [mod=WIFI, lvl=WARN] [tid=1621] << DslhWmpdoMpaSetParameterValues sending Notification str Device.WiFi.SSID.1.SSID,16,RPI_RdkB,RPI_RDKB-AP0,2 >>
240809-13:55:00.879371 [mod=WIFI, lvl=WARN] [tid=1621] << DslhWmpdoMpaSetParameterValues sending Notification Device.WiFi.SSID.1.SSID,16,RPI_RdkB,RPI_RDKB-AP0,2 >>
240809-13:55:00.879419 [mod=WIFI, lvl=WARN] [tid=1621] << DslhWmpdoMpaSetParameterValues sending Notification ulArraySize 1 >>
240809-13:55:00.879476 [mod=WIFI, lvl=WARN] [tid=1621] DslhObjcoValidate: SSID, bsUpdate = 3

240809-13:55:00.879575 [mod=WIFI, lvl=WARN] [tid=1621] Send all pending notifications 1
240809-13:55:00.879791 [mod=WIFI, lvl=WARN] [tid=1621] Before committing:Device.WiFi.SSID.1.
240809-13:55:00.879819 [mod=WIFI, lvl=WARN] [tid=9545]  Send_Notification_Thread_Func paramCount 1
240809-13:55:00.879846 [mod=WIFI, lvl=WARN] [tid=1621] After committing:Device.WiFi.SSID.1.:0
240809-13:55:00.879896 [mod=WIFI, lvl=WARN] [tid=9545] << Send_Notification_Thread_Func i 0 >>
240809-13:55:00.879985 [mod=WIFI, lvl=WARN] [tid=9545] << str[i] Device.WiFi.SSID.1.SSID,16,RPI_RdkB,RPI_RDKB-AP0,2 >>
240809-13:55:00.883654 [mod=WIFI, lvl=WARN] [tid=9545] << Send_Notification_Thread_Func, now g_isBusy  is not anymore busy, we have notify>>

  • Flow :
    DslhObjcoCommit() -> SSID_Commit() -> CosaDmlWiFiSsidSetCfg() -> wifi_setSSIDName() -> wifi_hostapdWrite() -> cfgChange = TRUE

Change the log level during runtime

root@RaspberryPi-Gateway:~# rdklogctrl OneWifi LOG.RDK.WIFI TRACE1-TRACE9
Sent message to update log level of LOG.RDK.WIFI for OneWifi process


 Changing lan mode (PAM)

  • Enabling Logger and Log level

LOG.RDK.PAM = FATAL ERROR WARNING NOTICE INFO

  • Checking the current Lan mode

dmcli eRT getv Device.X_CISCO_COM_DeviceControl.LanManagementEntry.1.LanMode

CR component name is: eRT.com.cisco.spvtg.ccsp.CR
subsystem_prefix eRT.
getv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.X_CISCO_COM_DeviceControl.LanManagementEntry.1.LanMode
Execution succeed.
Parameter    1 name: Device.X_CISCO_COM_DeviceControl.LanManagementEntry.1.LanMode
               type:     string,    value: router

  • Changing the lan mode to bridge-static

root@RaspberryPi-Gateway:~# dmcli eRT setv Device.X_CISCO_COM_DeviceControl.LanManagementEntry.1.LanMode string bridge-static

CR component name is: eRT.com.cisco.spvtg.ccsp.CR

subsystem_prefix eRT.

setv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.X_CISCO_COM_DeviceControl.LanManagementEntry.1.LanMode

Execution succeed.

  • Logs:

241009-06:53:25.578466 [mod=PAM, lvl=WARN] [tid=964] << DslhWmpdoMpaSetParameterValues sending Notification str Device.X_CISCO_COM_DeviceControl.LanManagementEntry.1.LanMode,16,bridge-static,router,2 >>
241009-06:53:25.578587 [mod=PAM, lvl=WARN] [tid=964] << DslhWmpdoMpaSetParameterValues sending Notification Device.X_CISCO_COM_DeviceControl.LanManagementEntry.1.LanMode,16,bridge-static,router,2 >>
241009-06:53:25.578636 [mod=PAM, lvl=WARN] [tid=964] << DslhWmpdoMpaSetParameterValues sending Notification ulArraySize 1 >>
241009-06:53:25.578717 [mod=PAM, lvl=WARN] [tid=964] DslhObjcoValidate: LanMode, bsUpdate = 3

241009-06:53:25.578896 [mod=PAM, lvl=WARN] [tid=964] RDKB_LAN_CONFIG_CHANGED: Setting new LanMode value (bridge-dhcp(1),bridge-static(2),router(3),full-bridge-static(4)) as (2)...
241009-06:53:25.579518 [mod=PAM, lvl=WARN] [tid=964] Send all pending notifications 1
241009-06:53:25.579762 [mod=PAM, lvl=WARN] [tid=964] Before committing:Device.X_CISCO_COM_DeviceControl.LanManagementEntry.1.
241009-06:53:25.579784 [mod=PAM, lvl=WARN] [tid=31227]  Send_Notification_Thread_Func paramCount 1
241009-06:53:25.579889 [mod=PAM, lvl=WARN] [tid=31227] << Send_Notification_Thread_Func i 0 >>
241009-06:53:25.579967 [mod=PAM, lvl=WARN] [tid=31227] << str[i] Device.X_CISCO_COM_DeviceControl.LanManagementEntry.1.LanMode,16,bridge-static,router,2 >>
241009-06:53:25.580847 [mod=PAM, lvl=INFO] [tid=964] LanMode:Adv_Bridge_Mode_selected
241009-06:53:25.582140 [mod=PAM, lvl=WARN] [tid=31227] << Send_Notification_Thread_Func, now g_isBusy  is not anymore busy, we have notify>>
241009-06:53:25.590738 [mod=PAM, lvl=WARN] [tid=964] --------- LanMngm_Commit CosaDmlDcResetBr0 1.0.0.254,0.255.255.255>>
241009-06:53:25.594950 [mod=PAM, lvl=WARN] [tid=964] --------- LanMngm_Commit CosaDmlDcResetBr0 <<
241009-06:53:25.595116 [mod=PAM, lvl=WARN] [tid=964] After committing:Device.X_CISCO_COM_DeviceControl.LanManagementEntry.1.:0
241009-06:53:25.656529 [mod=PAM, lvl=WARN] [tid=964] -----DeviceControl_GetParamBoolValue,Trying to get parameter 'ErouterEnable'
241009-06:53:25.656698 [mod=PAM, lvl=WARN] [tid=964] DslhObjcoValidate: ErouterEnable, bsUpdate = 3

241009-06:53:25.658429 [mod=PAM, lvl=WARN] [tid=964] DslhObjcoValidate: Enable, bsUpdate = 3

241009-06:53:25.659793 [mod=PAM, lvl=WARN] [tid=964] Before committing:Device.Bridging.Bridge.1.Port.9.
241009-06:53:25.659920 [mod=PAM, lvl=NOTICE] [tid=964] <HL>SWBrConfirmStructureUpdate port remove member Inx=dmsb.l2net.1.Members.Eth, Val=lbr0
241009-06:53:25.659970 [mod=PAM, lvl=NOTICE] [tid=964] <HL> _COSA_RemoveBPortMember path=dmsb.l2net.1.Members.Eth name=lbr0
241009-06:53:25.660059 [mod=PAM, lvl=NOTICE] [tid=964] <HL> _Psm_GetBPortMemberList path=dmsb.l2net.1.Members.Eth value=NULL
241009-06:53:25.661407 [mod=PAM, lvl=NOTICE] [tid=964] _Psm_GetBPortMemberList: retPsmGet == CCSP_SUCCESS reading dmsb.l2net.1.Members.Eth=
241009-06:53:25.661509 [mod=PAM, lvl=NOTICE] [tid=964] <HL> _COSA_DelToken str= token=lbr0
241009-06:53:25.661554 [mod=PAM, lvl=NOTICE] [tid=964] <HL> _COSA_DelToken Not Found token in Buffer=
241009-06:53:25.661622 [mod=PAM, lvl=NOTICE] [tid=964] <HL>SWBrConfirmStructureUpdate port add member Inx=dmsb.l2net.1.Members.Eth, Val=lbr0
241009-06:53:25.661670 [mod=PAM, lvl=NOTICE] [tid=964] <HL> _COSA_AddBPortMember path=dmsb.l2net.1.Members.Eth name=lbr0
241009-06:53:25.661713 [mod=PAM, lvl=NOTICE] [tid=964] <HL> _Psm_GetBPortMemberList path=dmsb.l2net.1.Members.Eth value=NULL
241009-06:53:25.663032 [mod=PAM, lvl=NOTICE] [tid=964] _Psm_GetBPortMemberList: retPsmGet == CCSP_SUCCESS reading dmsb.l2net.1.Members.Eth=
241009-06:53:25.663137 [mod=PAM, lvl=NOTICE] [tid=964] <HL> _COSA_AddToken new Str=lbr0 after add:lbr0
241009-06:53:25.663181 [mod=PAM, lvl=NOTICE] [tid=964] <HL> _Psm_SetBPortMemberList path=dmsb.l2net.1.Members.Eth value=lbr0
241009-06:53:25.664380 [mod=PAM, lvl=NOTICE] [tid=964] _Psm_SetBPortMemberList: retPsmSet == CCSP_SUCCESS writing dmsb.l2net.1.Members.Eth=lbr0
241009-06:53:25.664465 [mod=PAM, lvl=NOTICE] [tid=964] <HL> _COSA_AddBPortMember new path=dmsb.l2net.1.Members.Eth name=lbr0
241009-06:53:25.664527 [mod=PAM, lvl=NOTICE] [tid=964] <HL> _Psm_AddLinkMembers param_name=dmsb.l2net.1.Members.Link
241009-06:53:25.665632 [mod=PAM, lvl=NOTICE] [tid=964] _Psm_AddLinkMembers: retPsmGet == CCSP_SUCCESS reading dmsb.l2net.1.Members.Link
241009-06:53:25.701156 [mod=PAM, lvl=NOTICE] [tid=964] lanBrPCtlSetEnabled: ioctl(SIOCGIFFLAGS) failed (errno: 19): No such device
241009-06:53:25.713424 [mod=PAM, lvl=NOTICE] [tid=964] <HL> _COSA_GetInterfaceTypeStr
241009-06:53:25.713585 [mod=PAM, lvl=NOTICE] [tid=964] _Psm_SetBPort linkType=Ethernet port->linkType=1
241009-06:53:25.721470 [mod=PAM, lvl=WARN] [tid=964] After committing:Device.Bridging.Bridge.1.Port.9.:0
241009-06:53:25.721574 [mod=PAM, lvl=NOTICE] [tid=964] The notification = 0
241009-06:53:25.722793 [mod=PAM, lvl=WARN] [tid=964] Before committing:Device.X_CISCO_COM_DeviceControl.
241009-06:53:25.722809 [mod=PAM, lvl=INFO] [tid=31281] bridge_mode_wifi_notifier_thread - Mode:2 Radio:true SSID:false
241009-06:53:25.722917 [mod=PAM, lvl=WARN] [tid=964] After committing:Device.X_CISCO_COM_DeviceControl.:0

  • No labels

DISCLAIMER: Please note that the use of the RDK Wiki is subject to its Privacy Policy & Terms of Use. In addition, this Wiki may be accessed by all RDK licensees and their contractors.