RDK Resources
[*RDK Preferred*]
Code Management Facility
RDK Forums
[RDK Conferences]
RDK Support
Archives
Papers & Presentations Archive
Papers & Presentations Archive
The scope of this work is to explain webconfig feature validation procedure through RDKM Webconfig UI(http://webconfig.rdkcentral.com:9008/) for BPI Reference Platform .
Module | TR-181 DM Parameter | Purpose / Inputs |
---|---|---|
WebConfig |
dmcli eRT getv Device.X_RDK_WebConfig.RfcEnable | enable/disable webconfig |
dmcli eRT getv Device.X_RDK_WebConfig.URL |
By default this DM is empty. It Should have webconfig server url with CPE MAC Address |
|
dmcli eRT setv Device.X_RDK_WebConfig.URL string http://webconfig.rdkcentral.com:9007/api/v1/device/<CPE MAC>/config |
replace CPE MAC and set URL for ex: http://webconfig.rdkcentral.com:9007/api/v1/device/aabbccddeeff/config |
|
dmcli eRT getv Device.X_RDK_WebConfig.URL | verify URL set or not | |
dmcli eRT getv Device.X_RDK_WebConfig.ForceSync |
Value "root" for ForceSync DM - to sync all the values from webconfig server to CPE devices. Value "telemetry" for ForceSync DM - to sync telemetryprofile data's |
|
dmcli eRT getv Device.X_RDK_WebConfig.SupplementaryServiceUrls.Telemetry |
By default this DM is empty. It Should have webconfig server url with CPE MAC Address |
|
dmcli eRT setv Device.X_RDK_WebConfig.SupplementaryServiceUrls.Telemetry string http://webconfig.rdkcentral.com:9007/api/v1/device/<CPE MAC>/config |
replace CPE MAC and set URL .This is used for telemetry feature. for ex: http://webconfig.rdkcentral.com:9007/api/v1/device/aabbccddeeff/config |
|
dmcli eRT setv Device.X_RDK_WebConfig.SupplementaryServiceUrls.Telemetry string NULL |
Disabling WebConfig telemetry Supplementary Services |
root@Filogic-GW:~# dmcli eRT getv Device.X_RDK_WebConfig. CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. Parameter 1 name: Device.X_RDK_WebConfig.RfcEnable type: bool, value: true Parameter 2 name: Device.X_RDK_WebConfig.Data type: string, value: gap3ZWJjZmdibG9ikYWkbmFtZaRyb290p3ZlcnNpb24ApnN0YXR1c6dzdWNjZXNzrWVycm9yX2RldGFpbHOkbm9uZaplcnJvcl9jb2RlAA== Parameter 3 name: Device.X_RDK_WebConfig.SupportedDocs type: string, value: 16777247,33554435,50331649,67108865,83886081,100663297,117440513,134217729,201326594,218103809 Parameter 4 name: Device.X_RDK_WebConfig.SupportedSchemaVersion type: string, value: Parameter 5 name: Device.X_RDK_WebConfig.webcfgSubdocForceReset type: string, value: Parameter 6 name: Device.X_RDK_WebConfig.URL type: string, value: http://webconfig.rdkcentral.com:9007/api/v1/device/8A976BAF3F90/config Parameter 7 name: Device.X_RDK_WebConfig.ForceSync type: string, value: Parameter 8 name: Device.X_RDK_WebConfig.SupplementaryServiceUrls.Telemetry type: string, value: http://webconfig.rdkcentral.com:9007/api/v1/device/8A976BAF3F90/config
subdoc_name : privatessid
subdoc_data :
{ "private_ssid_2g":{ "SSID":"Test_webconfig_2g", "Enable":true, "SSIDAdvertisementEnabled":true }, "private_security_2g":{ "EncryptionMethod":"AES", "ModeEnabled":"WPA2-Personal", "Passphrase":"webconfig_2g" } }
TR-181 DM : Device.WiFi.Private
MAC : CPE_MAC (Ex : d83add3c5cc3)
2. In CPE , trigger the below command,
root@Filogic-GW:/rdklogs/logs# dmcli eRT setv Device.X_RDK_WebConfig.ForceSync string root CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. setv from/to component(webconfig): Device.X_RDK_WebConfig.ForceSync Execution succeed. |
3. Using dmcli to check the wifi DM parameters
root@Filogic-GW:/# 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: Test_webconfig_2g root@Filogic-GW:/# dmcli eRT getv Device.WiFi.AccessPoint.1.Security.KeyPassphrase 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.AccessPoint.1.Security.KeyPassphrase Execution succeed. Parameter 1 name: Device.WiFi.AccessPoint.1.Security.KeyPassphrase type: string, value: webconfig_2g root@Filogic-GW:/# iw wifi0 info Interface wifi0 ifindex 16 wdev 0x1 addr d8:3a:dd:3c:5c:c5 ssid Test_webconfig_2g type AP wiphy 0 channel 1 (2412 MHz), width: 20 MHz, center1: 2412 MHz txpower 31.00 dBm
4. Success Logs
240425-08:17:40.189970 [mod=WEBCONFIG, lvl=INFO] [tid=4376] WEBCONFIG: doc privatessid is updated to version 289218514 status pending error_details none error_code 0 trans_id 0 temp->retry_count 0 240425-08:17:40.190537 [mod=WEBCONFIG, lvl=INFO] [tid=4376] WEBCONFIG: subdoc_name: privatessid, version: 289218514, transaction_id: 25012 240425-08:17:40.190669 [mod=WEBCONFIG, lvl=INFO] [tid=4376] WEBCONFIG: doc privatessid is updated to version 289218514 status pending error_details none error_code 0 trans_id 25012 temp->retry_count 0 240425-08:17:40.190736 [mod=WEBCONFIG, lvl=INFO] [tid=4376] WEBCONFIG: Request:> param[0].name = Device.WiFi.Private, type = 5 240425-08:17:40.195397 [mod=WEBCONFIG, lvl=INFO] [tid=2909] WEBCONFIG: Received msg privatessid,25012,289218514,ACK,90 from topic webconfigSignal 240425-08:17:40.195501 [mod=WEBCONFIG, lvl=INFO] [tid=2909] WEBCONFIG: Received webconfig event signal Info privatessid,25012,289218514,ACK,90 240425-08:17:40.195649 [mod=WEBCONFIG, lvl=INFO] [tid=4381] WEBCONFIG: TIMEOUT EVENT: privatessid,25012,289218514,ACK,90 (doc apply need time) 240425-08:17:40.195731 [mod=WEBCONFIG, lvl=INFO] [tid=4381] WEBCONFIG: doc apply need time, start timer. 240425-08:17:40.195799 [mod=WEBCONFIG, lvl=INFO] [tid=4381] WEBCONFIG: Timer list is empty 240425-08:17:40.195921 [mod=WEBCONFIG, lvl=INFO] [tid=4381] WEBCONFIG: new_node->subdoc_name privatessid new_node->txid 25012 new_node->timeout 90 status 1 added to list 240425-08:17:40.195984 [mod=WEBCONFIG, lvl=INFO] [tid=4381] WEBCONFIG: startWebcfgTimer success 240425-08:17:40.196150 [mod=WEBCONFIG, lvl=INFO] [tid=4377] WEBCONFIG: dest is event:subdoc-report/privatessid/mac:d83add3c5cc3/ack 240425-08:17:40.196231 [mod=WEBCONFIG, lvl=INFO] [tid=4377] WEBCONFIG: stringifiedNotifyPayload is {"device_id":"mac:d83add3c5cc3","namespace":"privatessid","application_status":"pending","timeout":90,"transaction_uuid":"c64bb03a-d4d0-4f30-9cfc-53bc18fd367b","version":"289218514"} 240425-08:17:40.196421 [mod=WEBCONFIG, lvl=INFO] [tid=4377] WEBCONFIG: Notification successfully sent to Webconfig.Upstream 240425-08:17:40.197419 [mod=WEBCONFIG, lvl=INFO] [tid=4376] WEBCONFIG: The ret status for rbus_setMulti is 0 240425-08:17:40.197505 [mod=WEBCONFIG, lvl=INFO] [tid=4376] WEBCONFIG: ccspRetStatus is 100 240425-08:17:40.227876 [mod=WEBCONFIG, lvl=INFO] [tid=4376] WEBCONFIG: Request:> param[0].name = Device.WiFi.Private, type = 5 240425-08:17:40.228193 [mod=WEBCONFIG, lvl=INFO] [tid=2909] WEBCONFIG: Received msg privatessid,25012,289218514,ACK,0 from topic webconfigSignal 240425-08:17:40.228284 [mod=WEBCONFIG, lvl=INFO] [tid=2909] WEBCONFIG: Received webconfig event signal Info privatessid,25012,289218514,ACK,0 240425-08:17:40.228459 [mod=WEBCONFIG, lvl=INFO] [tid=4381] WEBCONFIG: ACK EVENT: privatessid,25012,289218514,ACK,0 (doc apply success) 240425-08:17:40.228526 [mod=WEBCONFIG, lvl=INFO] [tid=4381] WEBCONFIG: doc apply success, proceed to add to DB
subdoc_name : lan
subdoc_data :
{ "DhcpServerEnable": "True", "LanIPAddress": "10.0.0.1", "LanSubnetMask": "255.255.255.0", "DhcpStartIPAddress": "10.0.0.8", "DhcpEndIPAddress": "10.0.0.240", "LeaseTime": 7200 }
TR-181 DM : Device.DHCPv4.Server.Lan
MAC : CPE_MAC (Ex : d83add3c5cc3)
2. In CPE , trigger the ForceSync as "root"
3. Using dmcli to check the DM
root@Filogic-GW:/# dmcli eRT getv Device.DHCPv4.Server.Pool.1.MinAddress CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.DHCPv4.Server.Pool.1.MinAddress Execution succeed. Parameter 1 name: Device.DHCPv4.Server.Pool.1.MinAddress type: string, value: 10.0.0.8 root@RaspberryPi-Gateway:/# dmcli eRT getv Device.DHCPv4.Server.Pool.1.LeaseTime CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.DHCPv4.Server.Pool.1.LeaseTime Execution succeed. Parameter 1 name: Device.DHCPv4.Server.Pool.1.LeaseTime type: int, value: 7200 root@RaspberryPi-Gateway:/# dmcli eRT getv Device.DHCPv4.Server.Pool.1.MaxAddress CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.DHCPv4.Server.Pool.1.MaxAddress Execution succeed. Parameter 1 name: Device.DHCPv4.Server.Pool.1.MaxAddress type: string, value: 10.0.0.240
4. Success Logs
240423-06:06:16.534327 [mod=WEBCONFIG, lvl=INFO] [tid=3692] WEBCONFIG: doc lan is updated to version 627376240 status pending error_details none error_code 0 trans_id 0 temp->retry_count 0 240423-06:06:16.534921 [mod=WEBCONFIG, lvl=INFO] [tid=3692] WEBCONFIG: subdoc_name: lan, version: 627376240, transaction_id: 8517 240423-06:06:16.535035 [mod=WEBCONFIG, lvl=INFO] [tid=3692] WEBCONFIG: doc lan is updated to version 627376240 status pending error_details none error_code 0 trans_id 8517 temp->retry_count 0 240423-06:06:16.535104 [mod=WEBCONFIG, lvl=INFO] [tid=3692] WEBCONFIG: Request:> param[0].name = Device.DHCPv4.Server.Lan, type = 5 240423-06:06:16.538867 [mod=WEBCONFIG, lvl=INFO] [tid=2793] WEBCONFIG: Received msg lan,8517,627376240,ACK,13 from topic webconfigSignal 240423-06:06:16.538964 [mod=WEBCONFIG, lvl=INFO] [tid=2793] WEBCONFIG: Received webconfig event signal Info lan,8517,627376240,ACK,13 240423-06:06:16.539538 [mod=WEBCONFIG, lvl=INFO] [tid=3699] WEBCONFIG: TIMEOUT EVENT: lan,8517,627376240,ACK,13 (doc apply need time) 240423-06:06:16.539607 [mod=WEBCONFIG, lvl=INFO] [tid=3699] WEBCONFIG: doc apply need time, start timer. 240423-06:06:16.539665 [mod=WEBCONFIG, lvl=INFO] [tid=3699] WEBCONFIG: Timer list is empty 240423-06:06:16.539725 [mod=WEBCONFIG, lvl=INFO] [tid=3699] WEBCONFIG: new_node->subdoc_name lan new_node->txid 8517 new_node->timeout 13 status 1 added to list 240423-06:06:16.539780 [mod=WEBCONFIG, lvl=INFO] [tid=3699] WEBCONFIG: startWebcfgTimer success 240423-06:06:16.540403 [mod=WEBCONFIG, lvl=INFO] [tid=3693] WEBCONFIG: dest is event:subdoc-report/lan/mac:d83add3c5cc3/ack 240423-06:06:16.540489 [mod=WEBCONFIG, lvl=INFO] [tid=3693] WEBCONFIG: stringifiedNotifyPayload is {"device_id":"mac:d83add3c5cc3","namespace":"lan","application_status":"pending","timeout":13,"transaction_uuid":"bc673958-91ea-4b7b-b068-1c7d9252417f","version":"627376240"} 240423-06:06:16.540695 [mod=WEBCONFIG, lvl=INFO] [tid=3693] WEBCONFIG: Notification successfully sent to Webconfig.Upstream 240423-06:06:16.540700 [mod=WEBCONFIG, lvl=INFO] [tid=3692] WEBCONFIG: The ret status for rbus_setMulti is 0 240423-06:06:16.541295 [mod=WEBCONFIG, lvl=INFO] [tid=3692] WEBCONFIG: ccspRetStatus is 100 240423-06:06:16.541364 [mod=WEBCONFIG, lvl=INFO] [tid=3692] WEBCONFIG: setValues success. ccspStatus : 100
240423-06:06:16.537008 [mod=PAM, lvl=WARN] [tid=1463] base64 decoded data contains 194 bytes 240423-06:06:16.537072 [mod=PAM, lvl=WARN] [tid=1463] Base64 decode Elapsed time : 0 ms 240423-06:06:16.537135 [mod=PAM, lvl=WARN] [tid=1463] MSGPACK_UNPACK_SUCCESS :2 240423-06:06:16.537222 [mod=PAM, lvl=WARN] [tid=1463] pLanInfo->entries_count is 1 240423-06:06:16.537279 [mod=PAM, lvl=WARN] [tid=1463] pLanInfo->subdoc_name is lan 240423-06:06:16.537335 [mod=PAM, lvl=WARN] [tid=1463] pLanInfo->version is 627376240 240423-06:06:16.537391 [mod=PAM, lvl=WARN] [tid=1463] pLanInfo->transaction_id is 8517 240423-06:06:16.537446 [mod=PAM, lvl=WARN] [tid=1463] Lan configuration received 240423-06:06:16.537508 [mod=PAM, lvl=INFO] [tid=1463] PushBlobRequest : subdoc_name lan , txid 8517, version 627376240 , entries 1 240423-06:06:16.537581 [mod=PAM, lvl=INFO] [tid=1463] Inside FUNC checkNewVersionUpdateRequired LINE 1244 240423-06:06:16.537645 [mod=PAM, lvl=INFO] [tid=1463] checkIfVersionExecInQueue : Queue Empty 240423-06:06:16.537707 [mod=PAM, lvl=INFO] [tid=1463] New version available , prcessing new Blob request 240423-06:06:16.537785 [mod=PAM, lvl=INFO] [tid=1463] calculateTimeout is NULL , using default timeout routine 240423-06:06:16.537843 [mod=PAM, lvl=INFO] [tid=1463] PushBlobRequest timeout received from calcTimeout is 13 240423-06:06:16.537902 [mod=PAM, lvl=INFO] [tid=1463] getPendingQueueTimeout : Queue Empty 240423-06:06:16.537962 [mod=PAM, lvl=INFO] [tid=1463] PushBlobRequest : Send received request ACK , timeout is 13 240423-06:06:16.538023 [mod=PAM, lvl=INFO] [tid=1463] send_ACK : doc name lan , doc version 627376240, txid is 8517 timeout is 13 240423-06:06:16.538083 [mod=PAM, lvl=INFO] [tid=1463] isWebCfgRbusEnabled: rbus enabled is 1 240423-06:06:16.538139 [mod=PAM, lvl=INFO] [tid=1463] sendWebConfigSignal : rbus_set :: event_name : webconfigSignal :: 240423-06:06:16.539767 [mod=PAM, lvl=WARN] [tid=1463] PushBlobRequest complete 240423-06:06:16.539854 [mod=PAM, lvl=WARN] [tid=1463] Before committing:Device.DHCPv4.Server. 240423-06:06:16.539979 [mod=PAM, lvl=WARN] [tid=1463] After committing:Device.DHCPv4.Server.:0 240423-06:06:16.540003 [mod=PAM, lvl=INFO] [tid=1716] Received event 240423-06:06:16.540284 [mod=PAM, lvl=INFO] [tid=24223] Inside FUNC execute_request LINE 854 240423-06:06:16.544687 [mod=PAM, lvl=WARN] [tid=24223] Dhcpv4_Reset_Cache done 240423-06:06:16.544767 [mod=PAM, lvl=WARN] [tid=24223] CheckIpIsValid:IpAddressReceivedIs:10.0.0.1 240423-06:06:16.544829 [mod=PAM, lvl=WARN] [tid=24223] CheckIpIsValid:IpAddressReceivedIs:10.0.0.8 240423-06:06:16.544887 [mod=PAM, lvl=WARN] [tid=24223] CheckIpIsValid:IpAddressReceivedIs:10.0.0.240 240423-06:06:16.544952 [mod=PAM, lvl=WARN] [tid=24223] Dhcpv4_Lan_Ip_IsInPrivate_Blocked_AddrRange:addr:a000001 240423-06:06:16.545015 [mod=PAM, lvl=WARN] [tid=24223] Entering Dhcpv4_Lan_BackupFromDb 240423-06:06:16.551077 [mod=PAM, lvl=WARN] [tid=24223] Dhcpv4_Cache_ApplyAllToDb line.no 328 numOfParam 6 240423-06:06:16.556649 [mod=PAM, lvl=WARN] [tid=24223] Dhcpv4_Cache_ApplyAllToDb line.no 344 Success 240423-06:06:16.557618 [mod=PAM, lvl=NOTICE] [tid=24223] CosaDmlDhcpsGetPool: ulIndex = 0 240423-06:06:16.559081 [mod=PAM, lvl=WARN] [tid=24223] Process_Lan_WebConfigRequest: setting lan-restart 240423-06:06:16.573772 [mod=PAM, lvl=WARN] [tid=1463] CosaNTPInitJournal : Partner = RDKM 240423-06:06:16.577499 [mod=PAM, lvl=WARN] [tid=1463] CosaNTPInitJournal : Partner = RDKM 240423-06:06:16.635650 [mod=PAM, lvl=INFO] [tid=1716] messageQueueProcessing : Execution success , sending completed ACK 240423-06:06:16.640807 [mod=PAM, lvl=INFO] [tid=1716] send_ACK : doc name lan , doc version 627376240, txid is 8517 timeout is 0 240423-06:06:16.640906 [mod=PAM, lvl=INFO] [tid=1716] isWebCfgRbusEnabled: rbus enabled is 1 240423-06:06:16.640956 [mod=PAM, lvl=INFO] [tid=1716] sendWebConfigSignal : rbus_set :: event_name : webconfigSignal :: 240423-06:06:16.646741 [mod=PAM, lvl=WARN] [tid=1716] Entering FreeResources_Lan
subdoc_name: wan
subdoc_data :
{ "Enable" : true, "InternalIP" : "10.0.0.17" }
TR-181 DM : Device.NAT.X_CISCO_COM_DMZ.Data
MAC : CPE_MAC (Ex : d83add3c5cc3)
2. In CPE , trigger root as ForceSync
3. Using dmcli to check the DM,
root@Filogic-GW:/usr/www2# dmcli eRT getv Device.NAT.X_CISCO_COM_DMZ.Enable CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.NAT.X_CISCO_COM_DMZ.Enable Execution succeed. Parameter 1 name: Device.NAT.X_CISCO_COM_DMZ.Enable type: bool, value: true root@RaspberryPi-Gateway:/usr/www2# dmcli eRT getv Device.NAT.X_CISCO_COM_DMZ.InternalIP CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.NAT.X_CISCO_COM_DMZ.InternalIP Execution succeed. Parameter 1 name: Device.NAT.X_CISCO_COM_DMZ.InternalIP type: string, value: 10.0.0.17
4. Success Logs
240423-06:14:24.589883 [mod=WEBCONFIG, lvl=INFO] [tid=3692] WEBCONFIG: doc wan is updated to version 3808881139 status pending error_details none error_code 0 trans_id 0 temp->retry_count 0 240423-06:14:24.590358 [mod=WEBCONFIG, lvl=INFO] [tid=3692] WEBCONFIG: subdoc_name: wan, version: 3808881139, transaction_id: 5016 240423-06:14:24.590448 [mod=WEBCONFIG, lvl=INFO] [tid=3692] WEBCONFIG: doc wan is updated to version 3808881139 status pending error_details none error_code 0 trans_id 5016 temp->retry_count 0 240423-06:14:24.590494 [mod=WEBCONFIG, lvl=INFO] [tid=3692] WEBCONFIG: Request:> param[0].name = Device.NAT.X_CISCO_COM_DMZ.Data, type = 5 240423-06:14:24.593472 [mod=WEBCONFIG, lvl=INFO] [tid=2793] WEBCONFIG: Received msg wan,5016,3808881139,ACK,10 from topic webconfigSignal 240423-06:14:24.593540 [mod=WEBCONFIG, lvl=INFO] [tid=2793] WEBCONFIG: Received webconfig event signal Info wan,5016,3808881139,ACK,10 240423-06:14:24.593638 [mod=WEBCONFIG, lvl=INFO] [tid=3699] WEBCONFIG: TIMEOUT EVENT: wan,5016,3808881139,ACK,10 (doc apply need time) 240423-06:14:24.593688 [mod=WEBCONFIG, lvl=INFO] [tid=3699] WEBCONFIG: doc apply need time, start timer. 240423-06:14:24.593749 [mod=WEBCONFIG, lvl=INFO] [tid=3699] WEBCONFIG: Timer list is empty 240423-06:14:24.593796 [mod=WEBCONFIG, lvl=INFO] [tid=3699] WEBCONFIG: new_node->subdoc_name wan new_node->txid 5016 new_node->timeout 10 status 1 added to list 240423-06:14:24.593834 [mod=WEBCONFIG, lvl=INFO] [tid=3699] WEBCONFIG: startWebcfgTimer success 240423-06:14:24.593973 [mod=WEBCONFIG, lvl=INFO] [tid=3693] WEBCONFIG: dest is event:subdoc-report/wan/mac:d83add3c5cc3/ack 240423-06:14:24.594023 [mod=WEBCONFIG, lvl=INFO] [tid=3693] WEBCONFIG: stringifiedNotifyPayload is {"device_id":"mac:d83add3c5cc3","namespace":"wan","application_status":"pending","timeout":10,"transaction_uuid":"ae7952f3-1886-47aa-9427-dfca584a1f2d","version":"3808881139"} 240423-06:14:24.594147 [mod=WEBCONFIG, lvl=INFO] [tid=3693] WEBCONFIG: Notification successfully sent to Webconfig.Upstream 240423-06:14:24.595800 [mod=WEBCONFIG, lvl=INFO] [tid=3692] WEBCONFIG: The ret status for rbus_setMulti is 0 240423-06:14:24.595864 [mod=WEBCONFIG, lvl=INFO] [tid=3692] WEBCONFIG: ccspRetStatus is 100 240423-06:14:24.595912 [mod=WEBCONFIG, lvl=INFO] [tid=3692] WEBCONFIG: setValues success. ccspStatus : 100
240423-06:14:24.592125 [mod=PAM, lvl=WARN] [tid=1463] base64 decoded data contains 82 bytes 240423-06:14:24.592168 [mod=PAM, lvl=WARN] [tid=1463] Base64 decode Elapsed time : 0 ms 240423-06:14:24.592212 [mod=PAM, lvl=WARN] [tid=1463] MSGPACK_UNPACK_SUCCESS :2 240423-06:14:24.592259 [mod=PAM, lvl=WARN] [tid=1463] rpm->subdoc_name is wan 240423-06:14:24.592300 [mod=PAM, lvl=WARN] [tid=1463] rpm->version is 3808881139 240423-06:14:24.592339 [mod=PAM, lvl=WARN] [tid=1463] rpm->transaction_id is 5016 240423-06:14:24.592377 [mod=PAM, lvl=WARN] [tid=1463] DMZ/wan configuration received 240423-06:14:24.592421 [mod=PAM, lvl=INFO] [tid=1463] PushBlobRequest : subdoc_name wan , txid 5016, version 3808881139 , entries 0 240423-06:14:24.592462 [mod=PAM, lvl=INFO] [tid=1463] Inside FUNC checkNewVersionUpdateRequired LINE 1244 240423-06:14:24.592519 [mod=PAM, lvl=INFO] [tid=1463] checkIfVersionExecInQueue : Queue Empty 240423-06:14:24.592559 [mod=PAM, lvl=INFO] [tid=1463] New version available , prcessing new Blob request 240423-06:14:24.592616 [mod=PAM, lvl=INFO] [tid=1463] calculateTimeout is NULL , using default timeout routine 240423-06:14:24.592657 [mod=PAM, lvl=INFO] [tid=1463] PushBlobRequest timeout received from calcTimeout is 10 240423-06:14:24.592696 [mod=PAM, lvl=INFO] [tid=1463] getPendingQueueTimeout : Queue Empty 240423-06:14:24.592738 [mod=PAM, lvl=INFO] [tid=1463] PushBlobRequest : Send received request ACK , timeout is 10 240423-06:14:24.592780 [mod=PAM, lvl=INFO] [tid=1463] send_ACK : doc name wan , doc version 3808881139, txid is 5016 timeout is 10 240423-06:14:24.592825 [mod=PAM, lvl=INFO] [tid=1463] isWebCfgRbusEnabled: rbus enabled is 1 240423-06:14:24.592867 [mod=PAM, lvl=INFO] [tid=1463] sendWebConfigSignal : rbus_set :: event_name : webconfigSignal :: 240423-06:14:24.594806 [mod=PAM, lvl=WARN] [tid=1463] PushBlobRequest complete 240423-06:14:24.594940 [mod=PAM, lvl=WARN] [tid=1463] Before committing:Device.NAT.X_CISCO_COM_DMZ. 240423-06:14:24.595028 [mod=PAM, lvl=WARN] [tid=1463] !!!!!! in X_CISCO_COM_DMZ_Commit pDmz->InternalIP: 0.0.0.0 !!!!!! 240423-06:14:24.595118 [mod=PAM, lvl=INFO] [tid=1716] Received event 240423-06:14:24.595157 [mod=PAM, lvl=WARN] [tid=1463] After committing:Device.NAT.X_CISCO_COM_DMZ.:0 240423-06:14:24.595385 [mod=PAM, lvl=INFO] [tid=32256] Inside FUNC execute_request LINE 854 240423-06:14:24.595454 [mod=PAM, lvl=WARN] [tid=32256] DMZ configurartion recieved!!!!!! 240423-06:14:24.595508 [mod=PAM, lvl=WARN] [tid=32256] dmz_cache backup [0].cmd - dmz_enabled 240423-06:14:24.595551 [mod=PAM, lvl=WARN] [tid=32256] dmz_cache backup [0].val - 240423-06:14:24.595604 [mod=PAM, lvl=WARN] [tid=32256] dmz_cache backup [1].cmd - dmz_dst_ip_addr 240423-06:14:24.595646 [mod=PAM, lvl=WARN] [tid=32256] dmz_cache backup [1].val - 240423-06:14:24.607573 [mod=PAM, lvl=INFO] [tid=32256] CheckIfIpIsValid:IpAddressReceivedIs:10.0.0.17 240423-06:14:24.608313 [mod=PAM, lvl=WARN] [tid=32256] dmz_cache apply to DB [0].cmd - dmz_enabled 240423-06:14:24.608395 [mod=PAM, lvl=WARN] [tid=32256] dmz_cache apply to DB [0].val - 1 240423-06:14:24.608448 [mod=PAM, lvl=WARN] [tid=32256] dmz_cache apply to DB [1].cmd - dmz_dst_ip_addr 240423-06:14:24.608490 [mod=PAM, lvl=WARN] [tid=32256] dmz_cache apply to DB [1].val - 10.0.0.17 240423-06:14:24.613281 [mod=PAM, lvl=WARN] [tid=32256] DMZ configurartion applied!!!!!!!! 240423-06:14:24.613371 [mod=PAM, lvl=NOTICE] [tid=32256] DMZ_split:Feature Switch DMZ 1 240423-06:14:24.618447 [mod=PAM, lvl=WARN] [tid=1463] CosaNTPInitJournal : Partner = RDKM 240423-06:14:24.628410 [mod=PAM, lvl=WARN] [tid=1463] CosaNTPInitJournal : Partner = RDKM 240423-06:14:24.649677 [mod=PAM, lvl=WARN] [tid=32256] DMZ configurartion applied to DML layer!!!!!!!! 240423-06:14:24.649780 [mod=PAM, lvl=WARN] [tid=32256] rpm->param[0].Enable true 240423-06:14:24.649826 [mod=PAM, lvl=WARN] [tid=32256] rpm->entries[0].internal_ip 10.0.0.17 240423-06:14:24.650282 [mod=PAM, lvl=INFO] [tid=1716] messageQueueProcessing : Execution success , sending completed ACK 240423-06:14:24.655732 [mod=PAM, lvl=INFO] [tid=1716] send_ACK : doc name wan , doc version 3808881139, txid is 5016 timeout is 0 240423-06:14:24.655818 [mod=PAM, lvl=INFO] [tid=1716] isWebCfgRbusEnabled: rbus enabled is 1 240423-06:14:24.655866 [mod=PAM, lvl=INFO] [tid=1716] sendWebConfigSignal : rbus_set :: event_name : webconfigSignal :: 240423-06:14:24.667342 [mod=PAM, lvl=INFO] [tid=1716] Entering freeResources_dmz
subdoc_name : portforwarding
subdoc_data :
[ { "InternalClient": "10.0.0.111", "ExternalPortEndRange": "23", "Enable": "true", "Protocol": "TCP/UDP", "Description": "telnet", "ExternalPort": "23" }, { "InternalClient": "10.0.0.112", "ExternalPortEndRange": "25", "Enable": "true", "Protocol": "TCP/UDP", "Description": "mail", "ExternalPort": "25" }, { "InternalClient": "10.0.0.102", "ExternalPortEndRange": "443", "Enable": "true", "Protocol": "TCP/UDP", "Description": "https", "ExternalPort": "443" } ]
TR-181 DM : Device.NAT.X_RDK_PortMapping.Data
MAC : CPE_MAC (Ex : d83add3c5cc3)
2. In CPE, trigger ForceSync as root
3. Using dmcli to check the DM
root@Filogic-GW:~# dmcli eRT getv Device.NAT. CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.NAT. Execution succeed. Parameter 1 name: Device.NAT.X_CISCO_COM_TCPTimeout type: uint, value: 0 Parameter 2 name: Device.NAT.X_CISCO_COM_UDPTimeout type: uint, value: 0 Parameter 3 name: Device.NAT.X_CISCO_COM_ICMPTimeout type: uint, value: 0 Parameter 4 name: Device.NAT.X_Comcast_com_EnablePortMapping type: bool, value: true Parameter 5 name: Device.NAT.X_Comcast_com_EnableHSPortMapping type: bool, value: true Parameter 6 name: Device.NAT.X_Comcast_com_EnableNATMapping type: bool, value: false Parameter 7 name: Device.NAT.PortMappingNumberOfEntries type: uint, value: 3 Parameter 8 name: Device.NAT.X_CISCO_COM_DMZ.Enable type: bool, value: false Parameter 9 name: Device.NAT.X_CISCO_COM_DMZ.RemoteIPStart type: string, value: Parameter 10 name: Device.NAT.X_CISCO_COM_DMZ.RemoteIPEnd type: string, value: Parameter 11 name: Device.NAT.X_CISCO_COM_DMZ.InternalIP type: string, value: 0.0.0.0 Parameter 12 name: Device.NAT.X_CISCO_COM_DMZ.InternalMAC type: string, value: Parameter 13 name: Device.NAT.X_CISCO_COM_DMZ.IPv6Host type: string, value: Parameter 14 name: Device.NAT.X_CISCO_COM_DMZ.Data type: string, value: Parameter 15 name: Device.NAT.PortMapping.1.Enable type: bool, value: true Parameter 16 name: Device.NAT.PortMapping.1.Status type: string, value: Enabled Parameter 17 name: Device.NAT.PortMapping.1.Alias type: string, value: Parameter 18 name: Device.NAT.PortMapping.1.AllInterfaces type: bool, value: true Parameter 19 name: Device.NAT.PortMapping.1.LeaseDuration type: uint, value: 0 Parameter 20 name: Device.NAT.PortMapping.1.ExternalPort type: uint, value: 23 Parameter 21 name: Device.NAT.PortMapping.1.ExternalPortEndRange type: uint, value: 23 Parameter 22 name: Device.NAT.PortMapping.1.InternalPort type: uint, value: 0 Parameter 23 name: Device.NAT.PortMapping.1.Protocol type: string, value: BOTH Parameter 24 name: Device.NAT.PortMapping.1.InternalClient type: string, value: 10.0.0.111 Parameter 25 name: Device.NAT.PortMapping.1.RemoteHost type: string, value: 0.0.0.0 Parameter 26 name: Device.NAT.PortMapping.1.X_Comcast_com_PublicIP type: string, value: 0.0.0.0 Parameter 27 name: Device.NAT.PortMapping.1.Description type: string, value: telnet Parameter 28 name: Device.NAT.PortMapping.1.Interface type: string, value: Parameter 29 name: Device.NAT.PortMapping.1.X_CISCO_COM_InternalClientV6 type: string, value: x Parameter 30 name: Device.NAT.PortMapping.2.Enable type: bool, value: true Parameter 31 name: Device.NAT.PortMapping.2.Status type: string, value: Enabled Parameter 32 name: Device.NAT.PortMapping.2.Alias type: string, value: Parameter 33 name: Device.NAT.PortMapping.2.AllInterfaces type: bool, value: true Parameter 34 name: Device.NAT.PortMapping.2.LeaseDuration type: uint, value: 0 Parameter 35 name: Device.NAT.PortMapping.2.ExternalPort type: uint, value: 25 Parameter 36 name: Device.NAT.PortMapping.2.ExternalPortEndRange type: uint, value: 25 Parameter 37 name: Device.NAT.PortMapping.2.InternalPort type: uint, value: 0 Parameter 38 name: Device.NAT.PortMapping.2.Protocol type: string, value: BOTH Parameter 39 name: Device.NAT.PortMapping.2.InternalClient type: string, value: 10.0.0.112 Parameter 40 name: Device.NAT.PortMapping.2.RemoteHost type: string, value: 0.0.0.0 Parameter 41 name: Device.NAT.PortMapping.2.X_Comcast_com_PublicIP type: string, value: 0.0.0.0 Parameter 42 name: Device.NAT.PortMapping.2.Description type: string, value: mail Parameter 43 name: Device.NAT.PortMapping.2.Interface type: string, value: Parameter 44 name: Device.NAT.PortMapping.2.X_CISCO_COM_InternalClientV6 type: string, value: x Parameter 45 name: Device.NAT.PortMapping.3.Enable type: bool, value: true Parameter 46 name: Device.NAT.PortMapping.3.Status type: string, value: Enabled Parameter 47 name: Device.NAT.PortMapping.3.Alias type: string, value: Parameter 48 name: Device.NAT.PortMapping.3.AllInterfaces type: bool, value: true Parameter 49 name: Device.NAT.PortMapping.3.LeaseDuration type: uint, value: 0 Parameter 50 name: Device.NAT.PortMapping.3.ExternalPort type: uint, value: 443 Parameter 51 name: Device.NAT.PortMapping.3.ExternalPortEndRange type: uint, value: 443 Parameter 52 name: Device.NAT.PortMapping.3.InternalPort type: uint, value: 0 Parameter 53 name: Device.NAT.PortMapping.3.Protocol type: string, value: BOTH Parameter 54 name: Device.NAT.PortMapping.3.InternalClient type: string, value: 10.0.0.102 Parameter 55 name: Device.NAT.PortMapping.3.RemoteHost type: string, value: 0.0.0.0 Parameter 56 name: Device.NAT.PortMapping.3.X_Comcast_com_PublicIP type: string, value: 0.0.0.0 Parameter 57 name: Device.NAT.PortMapping.3.Description type: string, value: https Parameter 58 name: Device.NAT.PortMapping.3.Interface type: string, value: Parameter 59 name: Device.NAT.PortMapping.3.X_CISCO_COM_InternalClientV6 type: string, value: x Parameter 60 name: Device.NAT.X_RDK_PortMapping.Data type: string, value: Parameter 61 name: Device.NAT.X_CISCO_COM_PortTriggers.Enable type: bool, value: false Parameter 62 name: Device.NAT.X_CISCO_COM_PortTriggers.TriggerNumberOfEntries type: uint, value: 0
4. Success Logs
240423-06:29:55.135135 [mod=WEBCONFIG, lvl=INFO] [tid=3692] WEBCONFIG: doc portforwarding is updated to version 3329431262 status pending error_details none error_code 0 trans_id 0 temp->retry_count 0 240423-06:29:55.135651 [mod=WEBCONFIG, lvl=INFO] [tid=3692] WEBCONFIG: subdoc_name: portforwarding, version: 3329431262, transaction_id: 63776 240423-06:29:55.135754 [mod=WEBCONFIG, lvl=INFO] [tid=3692] WEBCONFIG: doc portforwarding is updated to version 3329431262 status pending error_details none error_code 0 trans_id 63776 temp->retry_count 0 240423-06:29:55.135811 [mod=WEBCONFIG, lvl=INFO] [tid=3692] WEBCONFIG: Request:> param[0].name = Device.NAT.X_RDK_PortMapping.Data, type = 5 240423-06:29:55.139435 [mod=WEBCONFIG, lvl=INFO] [tid=2793] WEBCONFIG: Received msg portforwarding,63776,3329431262,ACK,19 from topic webconfigSignal 240423-06:29:55.139522 [mod=WEBCONFIG, lvl=INFO] [tid=2793] WEBCONFIG: Received webconfig event signal Info portforwarding,63776,3329431262,ACK,19 240423-06:29:55.139694 [mod=WEBCONFIG, lvl=INFO] [tid=3699] WEBCONFIG: TIMEOUT EVENT: portforwarding,63776,3329431262,ACK,19 (doc apply need time) 240423-06:29:55.139765 [mod=WEBCONFIG, lvl=INFO] [tid=3699] WEBCONFIG: doc apply need time, start timer. 240423-06:29:55.139840 [mod=WEBCONFIG, lvl=INFO] [tid=3699] WEBCONFIG: Timer list is empty 240423-06:29:55.139912 [mod=WEBCONFIG, lvl=INFO] [tid=3699] WEBCONFIG: new_node->subdoc_name portforwarding new_node->txid 63776 new_node->timeout 19 status 1 added to list 240423-06:29:55.139967 [mod=WEBCONFIG, lvl=INFO] [tid=3699] WEBCONFIG: startWebcfgTimer success 240423-06:29:55.140139 [mod=WEBCONFIG, lvl=INFO] [tid=3693] WEBCONFIG: dest is event:subdoc-report/portforwarding/mac:d83add3c5cc3/ack 240423-06:29:55.140202 [mod=WEBCONFIG, lvl=INFO] [tid=3693] WEBCONFIG: stringifiedNotifyPayload is {"device_id":"mac:d83add3c5cc3","namespace":"portforwarding","application_status":"pending","timeout":19,"transaction_uuid":"6acc5f86-542d-46fd-bcbe-f63b67fbce45","version":"3329431262"} 240423-06:29:55.140383 [mod=WEBCONFIG, lvl=INFO] [tid=3693] WEBCONFIG: Notification successfully sent to Webconfig.Upstream 240423-06:29:55.142148 [mod=WEBCONFIG, lvl=INFO] [tid=3692] WEBCONFIG: The ret status for rbus_setMulti is 0 240423-06:29:55.142234 [mod=WEBCONFIG, lvl=INFO] [tid=3692] WEBCONFIG: ccspRetStatus is 100
240423-06:29:55.137534 [mod=PAM, lvl=WARN] [tid=1463] base64 decoded data contains 419 bytes 240423-06:29:55.137628 [mod=PAM, lvl=WARN] [tid=1463] Base64 decode Elapsed time : 0 ms 240423-06:29:55.137694 [mod=PAM, lvl=WARN] [tid=1463] MSGPACK_UNPACK_SUCCESS :2 240423-06:29:55.137794 [mod=PAM, lvl=WARN] [tid=1463] rpm->entries_count is 3 240423-06:29:55.137853 [mod=PAM, lvl=WARN] [tid=1463] rpm->subdoc_name is portforwarding 240423-06:29:55.137910 [mod=PAM, lvl=WARN] [tid=1463] rpm->version is 3329431262 240423-06:29:55.137966 [mod=PAM, lvl=WARN] [tid=1463] rpm->transaction_id is 63776 240423-06:29:55.138021 [mod=PAM, lvl=WARN] [tid=1463] Portmap configuration received 240423-06:29:55.138083 [mod=PAM, lvl=INFO] [tid=1463] PushBlobRequest : subdoc_name portforwarding , txid 63776, version 3329431262 , entries 3 240423-06:29:55.138142 [mod=PAM, lvl=INFO] [tid=1463] Inside FUNC checkNewVersionUpdateRequired LINE 1244 240423-06:29:55.138253 [mod=PAM, lvl=INFO] [tid=1463] checkIfVersionExecInQueue : Queue Empty 240423-06:29:55.138311 [mod=PAM, lvl=INFO] [tid=1463] New version available , prcessing new Blob request 240423-06:29:55.138399 [mod=PAM, lvl=INFO] [tid=1463] calculateTimeout is NULL , using default timeout routine 240423-06:29:55.138459 [mod=PAM, lvl=INFO] [tid=1463] PushBlobRequest timeout received from calcTimeout is 19 240423-06:29:55.138516 [mod=PAM, lvl=INFO] [tid=1463] getPendingQueueTimeout : Queue Empty 240423-06:29:55.138574 [mod=PAM, lvl=INFO] [tid=1463] PushBlobRequest : Send received request ACK , timeout is 19 240423-06:29:55.138633 [mod=PAM, lvl=INFO] [tid=1463] send_ACK : doc name portforwarding , doc version 3329431262, txid is 63776 timeout is 19 240423-06:29:55.138692 [mod=PAM, lvl=INFO] [tid=1463] isWebCfgRbusEnabled: rbus enabled is 1 240423-06:29:55.138749 [mod=PAM, lvl=INFO] [tid=1463] sendWebConfigSignal : rbus_set :: event_name : webconfigSignal :: 240423-06:29:55.140790 [mod=PAM, lvl=WARN] [tid=1463] PushBlobRequest complete 240423-06:29:55.140874 [mod=PAM, lvl=INFO] [tid=1716] Received event 240423-06:29:55.141283 [mod=PAM, lvl=INFO] [tid=15686] Inside FUNC execute_request LINE 854 240423-06:29:55.141378 [mod=PAM, lvl=WARN] [tid=15686] rpm->entries_count is 3 240423-06:29:55.141438 [mod=PAM, lvl=WARN] [tid=15686] Portmap configurartion recieved 240423-06:29:55.165710 [mod=PAM, lvl=WARN] [tid=1463] CosaNTPInitJournal : Partner = RDKM 240423-06:29:55.170084 [mod=PAM, lvl=WARN] [tid=1463] CosaNTPInitJournal : Partner = RDKM 240423-06:29:55.180459 [mod=PAM, lvl=INFO] [tid=15686] CheckIfIpIsValid:IpAddressReceivedIs:10.0.0.111 240423-06:29:55.180571 [mod=PAM, lvl=INFO] [tid=15686] CheckIfPortsAreValid:ExternalPortEndRangeReceivedIs:23 240423-06:29:55.180627 [mod=PAM, lvl=INFO] [tid=15686] CheckIfPortsAreValid:ExternalPortEndRangeReceivedIs:23 240423-06:29:55.180699 [mod=PAM, lvl=INFO] [tid=15686] CheckIfIpIsValid:IpAddressReceivedIs:10.0.0.112 240423-06:29:55.180748 [mod=PAM, lvl=INFO] [tid=15686] CheckIfPortsAreValid:ExternalPortEndRangeReceivedIs:25 240423-06:29:55.180793 [mod=PAM, lvl=INFO] [tid=15686] CheckIfPortsAreValid:ExternalPortEndRangeReceivedIs:25 240423-06:29:55.180875 [mod=PAM, lvl=INFO] [tid=15686] CheckIfIpIsValid:IpAddressReceivedIs:10.0.0.102 240423-06:29:55.180922 [mod=PAM, lvl=INFO] [tid=15686] CheckIfPortsAreValid:ExternalPortEndRangeReceivedIs:443 240423-06:29:55.180967 [mod=PAM, lvl=INFO] [tid=15686] CheckIfPortsAreValid:ExternalPortEndRangeReceivedIs:443 240423-06:29:55.219712 [mod=PAM, lvl=WARN] [tid=15686] Portmap configurartion applied 240423-06:29:55.219820 [mod=PAM, lvl=WARN] [tid=15686] rpm->entries[0].InternalClient 10.0.0.111 240423-06:29:55.219873 [mod=PAM, lvl=WARN] [tid=15686] rpm->entries[0].ExternalPortEndRange 23 240423-06:29:55.219922 [mod=PAM, lvl=WARN] [tid=15686] rpm->entries[0].Enable true 240423-06:29:55.219973 [mod=PAM, lvl=WARN] [tid=15686] rpm->entries[0].Protocol TCP/UDP 240423-06:29:55.220024 [mod=PAM, lvl=WARN] [tid=15686] rpm->entries[0].Description telnet 240423-06:29:55.220075 [mod=PAM, lvl=WARN] [tid=15686] rpm->entries[0].external_port 23 240423-06:29:55.220162 [mod=PAM, lvl=WARN] [tid=15686] rpm->entries[1].InternalClient 10.0.0.112 240423-06:29:55.220218 [mod=PAM, lvl=WARN] [tid=15686] rpm->entries[1].ExternalPortEndRange 25 240423-06:29:55.220265 [mod=PAM, lvl=WARN] [tid=15686] rpm->entries[1].Enable true 240423-06:29:55.220311 [mod=PAM, lvl=WARN] [tid=15686] rpm->entries[1].Protocol TCP/UDP 240423-06:29:55.220356 [mod=PAM, lvl=WARN] [tid=15686] rpm->entries[1].Description mail 240423-06:29:55.220401 [mod=PAM, lvl=WARN] [tid=15686] rpm->entries[1].external_port 25 240423-06:29:55.220443 [mod=PAM, lvl=WARN] [tid=15686] rpm->entries[2].InternalClient 10.0.0.102 240423-06:29:55.220492 [mod=PAM, lvl=WARN] [tid=15686] rpm->entries[2].ExternalPortEndRange 443 240423-06:29:55.220532 [mod=PAM, lvl=WARN] [tid=15686] rpm->entries[2].Enable true 240423-06:29:55.220572 [mod=PAM, lvl=WARN] [tid=15686] rpm->entries[2].Protocol TCP/UDP 240423-06:29:55.220611 [mod=PAM, lvl=WARN] [tid=15686] rpm->entries[2].Description https 240423-06:29:55.220650 [mod=PAM, lvl=WARN] [tid=15686] rpm->entries[2].external_port 443 240423-06:29:55.220749 [mod=PAM, lvl=INFO] [tid=1716] messageQueueProcessing : Execution success , sending completed ACK 240423-06:29:55.225331 [mod=PAM, lvl=INFO] [tid=1716] send_ACK : doc name portforwarding , doc version 3329431262, txid is 63776 timeout is 0 240423-06:29:55.225405 [mod=PAM, lvl=INFO] [tid=1716] isWebCfgRbusEnabled: rbus enabled is 1 240423-06:29:55.225449 [mod=PAM, lvl=INFO] [tid=1716] sendWebConfigSignal : rbus_set :: event_name : webconfigSignal :: 240423-06:29:55.227354 [mod=PAM, lvl=INFO] [tid=1716] Entering freeResources_PortForwarding
root@Filogic-GW:~# dmcli eRT getv Device.X_RDK_WebConfig.SupplementaryServiceUrls.Telemetry |
4. Trigger the below command in CPE
dmcli eRT setv Device.X_RDK_WebConfig.ForceSync string telemetry |
5. When T2 profiles are received via WebConfig, they are persisted in msgPack format in /nvram/
.t2reportprofiles
/profiles
.msgpack
root@Filogic-GW:/nvram/.t2reportprofiles# ls profiles.msgpack |
6. To check that the device received the profiles on the device, you can get a human-readable version of the profiles.msgpack file by doing the following on the device
webcfg_decoder -m profiles.msgpack
Sample data:
root@Filogic-GW:/nvram/.t2reportprofiles# webcfg_decoder -m profiles.msgpack rbus_open for component webcfg_decoder rbus_init is success. ret is 0 msgpack decoded data is: {"profiles":[{"name":"DM_DEVICEINFO_PROFILE", "versionHash":"cf3d1060", "value":{"Protocol":"HTTP", "EncodingType":"JSON", "ReportingInterval":600.000000, "ActivationTimeOut":1800.000000, "Parameter":[{"reference":"Device.DeviceInfo.X_COMCAST-COM_CM_MAC", "type":"dataModel", "name":"CmMacT1"}, {"type":"dataModel", "name":"ClearResetCount", "reference":"Device.DeviceInfo.ClearResetCount"}, {"type":"dataModel", "name":"Desc", "reference":"Device.DeviceInfo.Description"}, {"reference":"Device.DeviceInfo.FactoryResetCount", "type":"dataModel"}, {"type":"dataModel", "name":"MemFree", "reference":"Device.DeviceInfo.Hardware_MemFree"}, {"type":"dataModel", "name":"MemUsed", "reference":"Device.DeviceInfo.Hardware_MemUsed"}, {"type":"dataModel", "name":"HwVer", "reference":"Device.DeviceInfo.HardwareVersion"}, {"type":"dataModel", "name":"MemStatFree", "reference":"Device.DeviceInfo.MemoryStatus.Free"}, {"type":"dataModel", "name":"MemStatTotal", "reference":"Device.DeviceInfo.MemoryStatus.Total"}, {"type":"dataModel", "name":"MemStatUsed", "reference":"Device.DeviceInfo.MemoryStatus.Used"}, {"type":"dataModel", "name":"FrMemThrshld", "reference":"Device.DeviceInfo.MemoryStatus.X_RDKCENTRAL-COM_FreeMemThreshold"}, {"type":"dataModel", "name":"CpuUsage", "reference":"Device.DeviceInfo.ProcessStatus.CPUUsage"}, {"name":"Uptime", "reference":"Device.DeviceInfo.UpTime", "type":"dataModel"}], "Version":"1", "TimeReference":"0001-01-01T00:00:00Z", "HTTP":{"Compression":"None", "Method":"POST", "RequestURIParameter":[{"Name":"deviceId", "Reference":"Device.DeviceInfo.X_COMCAST-COM_CM_MAC"}, {"Name":"profileName", "Reference":"Profile.Name"}], "URL":"https://xconf.rdkcentral.com/xconf/telemetry_upload.php"}, "JSONEncoding":{"ReportFormat":"NameValuePair", "ReportTimestamp":"None"}}}, {"name":"RDKB-RPI-SELFHEALPROFILE", "versionHash":"de899a23", "value":{"Protocol":"HTTP", "EncodingType":"JSON", "ReportingInterval":600.000000, "HTTP":{"URL":"https://xconf.rdkcentral.com/xconf/telemetry_upload.php", "Compression":"None", "Method":"POST", "RequestURIParameter":[{"Name":"deviceId", "Reference":"Device.DeviceInfo.X_COMCAST-COM_CM_MAC"}, {"Name":"profileName", "Reference":"Profile.Name"}]}, "Description":"Report to check SelfHeal Parameters", "TimeReference":"0001-01-01T00:00:00Z", "ActivationTimeOut":1800.000000, "Parameter":[{"type":"dataModel", "name":"Profile", "reference":"Device.DeviceInfo.X_RDK.RDKProfileName"}, {"type":"dataModel", "name":"Time", "reference":"Device.Time.CurrentLocalTime"}, {"reference":"Device.DeviceInfo.X_COMCAST-COM_WAN_MAC", "type":"dataModel", "name":"mac"}, {"type":"dataModel", "name":"erouterIpv4", "reference":"Device.DeviceInfo.X_COMCAST-COM_WAN_IP"}, {"type":"dataModel", "name":"erouterIpv6", "reference":"Device.DeviceInfo.X_COMCAST-COM_WAN_IPv6"}, {"type":"dataModel", "name":"PartnerId", "reference":"Device.DeviceInfo.X_RDKCENTRAL-COM_Syndication.PartnerId"}, {"name":"Version", "reference":"Device.DeviceInfo.SoftwareVersion", "type":"dataModel"}, {"type":"dataModel", "name":"AccountId", "reference":"Device.DeviceInfo.X_RDKCENTRAL-COM_RFC.Feature.AccountInfo.AccountID"}, {"type":"dataModel", "name":"MAC", "reference":"Device.DeviceInfo.X_COMCAST-COM_CM_MAC"}, {"type":"dataModel", "reference":"Profile.Name"}, {"type":"dataModel", "reference":"Profile.Version"}, {"reference":"Device.DeviceInfo.UpTime", "use":"absolute", "type":"dataModel", "name":"UpTime"}, {"type":"event", "eventName":"SYS_ERROR_AdvSecurity_NotRunning", "component":"test_and_diagnostics", "use":"absolute"}, {"type":"event", "eventName":"SYS_SH_lighttpdCrash", "component":"test_and_diagnostics", "use":"count", "reportEmpty":false}, {"reportEmpty":false, "type":"event", "name":"FirmwareStart_Time", "eventName":"Firmware upgrade start time :", "component":"test_and_diagnostics", "use":"count"}, {"name":"WAN_SSH_STATUS", "reference":"Device.DeviceInfo.X_RDKCENTRAL-COM_Syndication.WANsideSSH.Enable", "use":"absolute", "type":"dataModel"}], "JSONEncoding":{"ReportFormat":"NameValuePair", "ReportTimestamp":"None"}, "Version":"1"}}, {"versionHash":"3f7b4f1b", "value":{"ReportingInterval":600.000000, "Parameter":[{"type":"dataModel", "name":"Profile", "reference":"Device.DeviceInfo.X_RDK.RDKProfileName"}, {"logFile":"BootTime.log", "use":"absolute", "type":"grep", "marker":"bootuptime_Ethernet_split", "search":"boot_to_ETH_uptime"}, {"marker":"bootuptime_wifi_split", "search":"boot_to_WIFI_uptime", "logFile":"BootTime.log", "use":"absolute", "type":"grep"}, {"marker":"bootuptime_tr069_split", "search":"boot_to_tr069_uptime", "logFile":"BootTime.log", "use":"absolute", "type":"grep"}, {"search":"Waninit_complete", "logFile":"BootTime.log", "use":"absolute", "type":"grep", "marker":"waninit_split"}, {"search":"boot_to_WEBPA_READY_uptime", "logFile":"BootTime.log", "use":"absolute", "type":"grep", "marker":"bootuptime_webpa_split"}, {"type":"grep", "marker":"bootuptime_meshagent_split", "search":"boot_to_meshagent_uptime", "logFile":"BootTime.log", "use":"absolute"}, {"type":"dataModel", "name":"MAC", "reference":"Device.DeviceInfo.X_COMCAST-COM_CM_MAC"}, {"type":"dataModel", "reference":"Profile.Name"}, {"reference":"Profile.Version", "type":"dataModel"}, {"name":"UpTime", "reference":"Device.DeviceInfo.UpTime", "use":"absolute", "type":"dataModel"}, {"component":"test_and_diagnostics", "use":"absolute", "type":"event", "eventName":"SYS_ERROR_AdvSecurity_NotRunning"}, {"component":"test_and_diagnostics", "use":"count", "reportEmpty":false, "type":"event", "eventName":"SYS_SH_lighttpdCrash"}, {"type":"event", "name":"FirmwareStart_Time", "eventName":"Firmware upgrade start time :", "component":"test_and_diagnostics", "use":"count", "reportEmpty":false}], "HTTP":{"URL":"https://xconf.rdkcentral.com/xconf/telemetry_upload.php", "Compression":"None", "Method":"POST", "RequestURIParameter":[{"Name":"deviceId", "Reference":"Device.DeviceInfo.X_COMCAST-COM_CM_MAC"}, {"Name":"profileName", "Reference":"Profile.Name"}]}, "Description":"Report to check BootTime Parameters", "Version":"1", "TimeReference":"0001-01-01T00:00:00Z", "ActivationTimeOut":1800.000000, "JSONEncoding":{"ReportFormat":"NameValuePair", "ReportTimestamp":"None"}, "Protocol":"HTTP", "EncodingType":"JSON"}, "name":"RDKB-RPI-BootTime-Logs"}], "subdoc_name":"telemetry", "version":3672340881, "transaction_id":30695} root@RaspberryPi-Gateway:/nvram/.t2reportprofiles#
7. Check the telemetry logs to confirm whether JSON report is generated properly or not (here, created 3 profiles in xconf server i,e
DM_DEVICEINFO_PROFILE , RDKB-RPI-BootTime-Logs,RDKB-RPI-SELFHEALPROFILE)
40411-13:22:47.374561 [mod=T2, lvl=INFO] [tid=3697] Successfully enabled profile : DM_DEVICEINFO_PROFILE 240411-13:22:47.374647 [mod=T2, lvl=INFO] [tid=3697] T2ER isn't initialized or dispatch thread is already running 240411-13:22:47.376483 [mod=T2, lvl=INFO] [tid=3697] Starting TimeoutThread for profile : RDKB-RPI-SELFHEALPROFILE 240411-13:22:47.376784 [mod=T2, lvl=INFO] [tid=3697] T2ER isn't initialized or dispatch thread is already running 240411-13:22:47.376841 [mod=T2, lvl=INFO] [tid=3697] Successfully enabled profile : RDKB-RPI-SELFHEALPROFILE 240411-13:22:47.376894 [mod=T2, lvl=INFO] [tid=3697] T2ER isn't initialized or dispatch thread is already running 240411-13:22:47.377527 [mod=T2, lvl=INFO] [tid=3700] Waiting for 600 sec for next TIMEOUT for profile as reporting interval is taken - RDKB-RPI-SELFHEALPROFILE 240411-13:22:47.377646 [mod=T2, lvl=INFO] [tid=3700] Waiting for timeref or reporting interval for the profile - RDKB-RPI-SELFHEALPROFILE is started 240411-13:22:47.378491 [mod=T2, lvl=INFO] [tid=3697] Starting TimeoutThread for profile : RDKB-RPI-BootTime-Logs 240411-13:22:47.378733 [mod=T2, lvl=INFO] [tid=3697] T2ER isn't initialized or dispatch thread is already running 240411-13:22:47.378789 [mod=T2, lvl=INFO] [tid=3697] Successfully enabled profile : RDKB-RPI-BootTime-Logs 240411-13:22:47.378849 [mod=T2, lvl=INFO] [tid=3697] T2ER isn't initialized or dispatch thread is already running 240411-13:22:47.379017 [mod=T2, lvl=INFO] [tid=3701] Waiting for 600 sec for next TIMEOUT for profile as reporting interval is taken - RDKB-RPI-BootTime-Logs 240411-13:22:47.379153 [mod=T2, lvl=INFO] [tid=3701] Waiting for timeref or reporting interval for the profile - RDKB-RPI-BootTime-Logs is started 240411-13:22:47.379195 [mod=T2, lvl=INFO] [tid=3698] Waiting for 600 sec for next TIMEOUT for profile as reporting interval is taken - DM_DEVICEINFO_PROFILE 240411-13:22:47.379274 [mod=T2, lvl=INFO] [tid=3698] Waiting for timeref or reporting interval for the profile - DM_DEVICEINFO_PROFILE is started 240411-13:22:47.395270 [mod=T2, lvl=INFO] [tid=3697] rbuscore.c:2326 RBus Enabled 240411-13:22:50.562716 [mod=T2, lvl=INFO] [tid=2464] rbus.c:1014 Consumer=rbus.meshAgent.INBOX.3316 SUBSCRIBED to event=Telemetry.ReportProfiles.ProfilesUpdated 240411-13:22:50.562857 [mod=T2, lvl=INFO] [tid=2464] eventSubHandler called: action=subscribe eventName=Telemetry.ReportProfiles.ProfilesUpdated 240424-07:52:36.000206 [mod=T2, lvl=INFO] [tid=18653] TIMEOUT for profile - RDKB-RPI-SELFHEALPROFILE 240424-07:52:36.000381 [mod=T2, lvl=INFO] [tid=18653] ReportProfiles_TimeoutCb ++in 240424-07:52:36.000411 [mod=T2, lvl=INFO] [tid=18654] TIMEOUT for profile - RDKB-RPI-BootTime-Logs 240424-07:52:36.000506 [mod=T2, lvl=INFO] [tid=18653] NotifyTimeout: profile RDKB-RPI-SELFHEALPROFILE is in Enabled state 240424-07:52:36.000523 [mod=T2, lvl=INFO] [tid=18654] ReportProfiles_TimeoutCb ++in 240424-07:52:36.000706 [mod=T2, lvl=INFO] [tid=18654] NotifyTimeout: profile RDKB-RPI-BootTime-Logs is in Enabled state 240424-07:52:36.000796 [mod=T2, lvl=INFO] [tid=28829] CollectAndReport ++in profileName : RDKB-RPI-SELFHEALPROFILE 240424-07:52:36.000737 [mod=T2, lvl=INFO] [tid=18653] ReportProfiles_TimeoutCb --out 240424-07:52:36.000989 [mod=T2, lvl=INFO] [tid=18653] Waiting for 600 sec for next TIMEOUT for profile as reporting interval is taken - RDKB-RPI-SELFHEALPROFILE 240424-07:52:36.001022 [mod=T2, lvl=INFO] [tid=18654] ReportProfiles_TimeoutCb --out 240424-07:52:36.001073 [mod=T2, lvl=INFO] [tid=28830] CollectAndReport ++in profileName : RDKB-RPI-BootTime-Logs 240424-07:52:36.001092 [mod=T2, lvl=INFO] [tid=18653] Waiting for timeref or reporting interval for the profile - RDKB-RPI-SELFHEALPROFILE is started 240424-07:52:36.001121 [mod=T2, lvl=INFO] [tid=18654] Waiting for 600 sec for next TIMEOUT for profile as reporting interval is taken - RDKB-RPI-BootTime-Logs 240424-07:52:36.001393 [mod=T2, lvl=INFO] [tid=18654] Waiting for timeref or reporting interval for the profile - RDKB-RPI-BootTime-Logs is started 240424-07:52:36.002013 [mod=T2, lvl=ERROR] [tid=28829] rbus.c:3660 Discover component names failed with error 6 and counts 1/0 240424-07:52:36.002104 [mod=T2, lvl=ERROR] [tid=28829] Failed to retrieve param : Device.DeviceInfo.X_RDK.RDKProfileName 240424-07:52:36.002504 [mod=T2, lvl=ERROR] [tid=28830] rbus.c:3660 Discover component names failed with error 6 and counts 1/0 240424-07:52:36.002607 [mod=T2, lvl=ERROR] [tid=28830] Failed to retrieve param : Device.DeviceInfo.X_RDK.RDKProfileName 240424-08:14:34.637693 [mod=T2, lvl=INFO] [tid=8850] cJSON Report = {"Report":[{"Profile.Name":"RDKB-RPI-BootTime-Logs"},{"Profile.Version":"1"},{"MAC":"D8:3A:DD:3C:5C:C3"},{"UpTime":"304"},{"bootuptime_Ethernet_split":"=20"},{"bootuptime_wifi_split":"=31"},{"bootuptime_tr069_split":"=31"},{"waninit_split":"=28"},{"bootuptime_webpa_split":"=35"},{"bootuptime_meshagent_split":"=37"}]} 240424-08:14:34.637829 [mod=T2, lvl=INFO] [tid=8850] Report Size = 318 240424-08:14:34.689539 [mod=T2, lvl=ERROR] [tid=8850] getParameterValue partner id failed 240424-08:14:34.803536 [mod=T2, lvl=INFO] [tid=8851] cJSON Report = {"Report":[{"Profile.Name":"RDKB-RPI-SELFHEALPROFILE"},{"Profile.Version":"1"},{"Time":"2024-04-24T08:14:33Z"},{"mac":"d8:3a:dd:3c:5c:c3"},{"erouterIpv4":"192.168.2.150"},{"PartnerId":"RDKM"},{"Version":"rdkb-generic-broadband-image_rdk-next_20240411132237"},{"MAC":"D8:3A:DD:3C:5C:C3"},{"UpTime":"304"},{"WAN_SSH_STATUS":"false"}]} 240424-08:14:34.803688 [mod=T2, lvl=INFO] [tid=8851] Report Size = 332 240424-08:14:35.173337 [mod=T2, lvl=INFO] [tid=8976] FILE:../../../../../../../../../rdk/components/generic/telemetry/source/bulkdata/reportprofiles.c FUNCTION:Process_Telemetry_WebConfigRequest LINE:863 240424-08:14:35.173513 [mod=T2, lvl=INFO] [tid=8976] FILE:../../../../../../../../../rdk/components/generic/telemetry/source/bulkdata/reportprofiles.c FUNCTION:Process_Telemetry_WebConfigRequest LINE:867 Execution in Handler, excuted 240424-08:14:35.173707 [mod=T2, lvl=INFO] [tid=8976] Number of report profiles in current configuration is 3 240424-08:14:35.173827 [mod=T2, lvl=INFO] [tid=8976] rbuscore.c:2326 RBus Enabled 240424-08:14:35.173945 [mod=T2, lvl=INFO] [tid=8976] DM_DEVICEINFO_PROFILE is found 240424-08:14:35.173996 [mod=T2, lvl=INFO] [tid=8976] RDKB-RPI-SELFHEALPROFILE is found 240424-08:14:35.174067 [mod=T2, lvl=INFO] [tid=8976] RDKB-RPI-BootTime-Logs is found 240424-08:14:35.174124 [mod=T2, lvl=INFO] [tid=8976] rbuscore.c:2326 RBus Enabled 240424-08:14:35.174388 [mod=T2, lvl=INFO] [tid=8976] Profile DM_DEVICEINFO_PROFILE with cf3d1060 hash already exist 240424-08:14:35.174463 [mod=T2, lvl=INFO] [tid=8976] Profile RDKB-RPI-SELFHEALPROFILE with de899a23 hash already exist 240424-08:14:35.174528 [mod=T2, lvl=INFO] [tid=8976] Profile RDKB-RPI-BootTime-Logs with 3f7b4f1b hash already exist 240424-08:14:35.174675 [mod=T2, lvl=INFO] [tid=8976] rbuscore.c:2326 RBus Enabled 240424-08:14:35.655881 [mod=T2, lvl=INFO] [tid=8850] The return status from the child with pid 8911 is CurlStatus : 1 240424-08:14:35.655998 [mod=T2, lvl=INFO] [tid=8850] The return status from the child with pid 8911 SetopCode: No error; ResponseCode : No error; HTTP_CODE : 200; Line Number : 335 240424-08:14:35.656040 [mod=T2, lvl=INFO] [tid=8850] Report Sent Successfully over HTTP : 200 240424-08:14:35.656103 [mod=T2, lvl=INFO] [tid=8850] Elapsed Time for : RDKB-RPI-BootTime-Logs = 1.142592536 (Sec.NanoSec) 240424-08:14:35.656157 [mod=T2, lvl=INFO] [tid=8850] CollectAndReport --out 240424-08:14:35.825062 [mod=T2, lvl=ERROR] [tid=8851] getParameterValue partner id failed 240424-08:14:35.833962 [mod=T2, lvl=INFO] [tid=8849] cJSON Report = {"Report":[{"CmMacT1":"D8:3A:DD:3C:5C:C3"},{"ClearResetCount":"false"},{"Desc":"Raspberry Pi 3 device"},{"Device.DeviceInfo.FactoryResetCount":"1"},{"MemFree":"133"},{"MemUsed":"272"},{"MemStatFree":"3277"},{"MemStatTotal":"3513"},{"MemStatUsed":"148"},{"FrMemThrshld":"0"},{"CpuUsage":"6"},{"Uptime":"305"}]} 240424-08:14:35.834136 [mod=T2, lvl=INFO] [tid=8849] Report Size = 309 240424-08:14:35.860502 [mod=T2, lvl=ERROR] [tid=8849] getParameterValue partner id failed 240424-08:14:36.807264 [mod=T2, lvl=INFO] [tid=8849] The return status from the child with pid 9024 is CurlStatus : 1 240424-08:14:36.807380 [mod=T2, lvl=INFO] [tid=8849] The return status from the child with pid 9024 SetopCode: No error; ResponseCode : No error; HTTP_CODE : 200; Line Number : 335 240424-08:14:36.807423 [mod=T2, lvl=INFO] [tid=8849] Report Sent Successfully over HTTP : 200 240424-08:14:36.807477 [mod=T2, lvl=INFO] [tid=8849] Elapsed Time for : DM_DEVICEINFO_PROFILE = 2.295589017 (Sec.NanoSec) 240424-08:14:36.807530 [mod=T2, lvl=INFO] [tid=8849] CollectAndReport --out 240424-08:14:36.830727 [mod=T2, lvl=INFO] [tid=8851] The return status from the child with pid 9015 is CurlStatus : 1 240424-08:14:36.830838 [mod=T2, lvl=INFO] [tid=8851] The return status from the child with pid 9015 SetopCode: No error; ResponseCode : No error; HTTP_CODE : 200; Line Number : 335 240424-08:14:36.830885 [mod=T2, lvl=INFO] [tid=8851] Report Sent Successfully over HTTP : 200 240424-08:14:36.830943 [mod=T2, lvl=INFO] [tid=8851] Elapsed Time for : RDKB-RPI-SELFHEALPROFILE = 2.315808869 (Sec.NanoSec)
RDKBACCL-291 - Getting issue details... STATUS
Webconfig Integration in RDKB RPI
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.
Powered by a free Atlassian Confluence Open Source Project License granted to RDKCentral. Evaluate Confluence today.
3 Comments
Satish Kaluvalapalli
Hi Keerthana Pandurangan , Is there any existing way to handle subdoc dependencies? For example, the
privatessid
subdoc depends on theradio
enable config subdoc. If both configurations are sent by the server, how can we ensure that theradio
subdoc is applied first, and only upon success, theprivatessid
subdoc is processed?sipra samantray
Hi Satish Kaluvalapalli ,
Could you share the radio subdoc schema that you are using and the corresponding Rbus param, so that will check and get back.
Satish Kaluvalapalli
Hi sipra samantray ,
Here is the basic radio subdoc (TR181 Parameter - Device.WiFi.X_RDK_RadioData), might extend the same subdoc in future if required.
Basically, my point is that in this case first radio subdoc should be executed and upon success of radio subdoc, privatessid subdoc needs to be applied. Otherwise privatessid config applied but not taken into consideration if radio are disabled while applying the privatessid. Dependency applied only if server sends both radio and privatessid subdocs otherwise not needed. This is one example might have few other subdocs which have dependency on other subdocs.