CC2530: Linux Gateway - NWK_GET_LOCAL_DEVICE_INFO_CNF returning "00:00:00:00:00:00:00:00" as IeeeAddress

Mario DW

Part Number: CC2530

I am working on identifying why the Linux Gateway architecture is not working properly "from time to time", and one of the reasons is that the NWK_GET_LOCAL_DEVICE_INFO_REQ can return a "NULL" address which is then filled in the gateway_self_addr variable that is used across the application.

Any suggestion regarding this? Should the extendedpanid be used instead of the ieeeaddr?

This is a gateway log extract when the address is fine:

[2020-09-11 08:35:09] [08:35:06.358,099] [NWK_MGR/LSTN] PKT_HEX: [                           NWK_MGR<<<<<<<<<<<<<<<<<<<<CON007] [read] 02:00:12:07:08:07
[2020-09-11 08:35:09] [08:35:06.358,450] [NWK_MGR/LSTN] PKTTYPE: [                           NWK_MGR<<<<<<<<<<<<<<<<<<<<CON007] NwkGetLocalDeviceInfoReq
[2020-09-11 08:35:09] [08:35:06.358,505] [NWK_MGR/LSTN] PKTBODY:                                                          cmdId = NWK_GET_LOCAL_DEVICE_INFO_REQ
[2020-09-11 08:35:09] [08:35:06.358,550] [NWK_MGR/LSTN] MISC1  : NWK_GET_LOCAL_DEVICE_INFO_REQ:
[2020-09-11 08:35:09] [08:35:06.358,842] [NWK_MGR/LSTN] PKT_HEX: [                           NWK_MGR>>>>>>>>>>>>>>>>>>>>CON007] [ucst] 44:00:72:08:08:08:12:40:08:00:11:77:82:22
[2020-09-11 08:35:09] [08:35:06.358,889] [NWK_MGR/LSTN] PKTTYPE: [                           NWK_MGR>>>>>>>>>>>>>>>>>>>>CON007] NwkGetLocalDeviceInfoCnf
[2020-09-11 08:35:10] [08:35:06.358,957] [NWK_MGR/LSTN] PKTBODY:                                                          cmdId = NWK_GET_LOCAL_DEVICE_INFO_CNF
[2020-09-11 08:35:10] [08:35:06.358,999] [NWK_MGR/LSTN] PKTBODY:                                                          deviceInfoList :
[2020-09-11 08:35:10] [08:35:06.359,033] [NWK_MGR/LSTN] PKTBODY:                                                            networkAddress = 0x00000000 (0)
[2020-09-11 08:35:10] [08:35:06.359,312] [NWK_MGR/LSTN] PKTBODY:                                                            ieeeAddress = 00:12:4B:00:10:22:82:77
[2020-09-11 08:35:10] [08:35:06.359,355] [NWK_MGR/LSTN] PKTBODY:                                                            manufacturerId = 0x00000007 (7)
[2020-09-11 08:35:10] [08:35:06.359,388] [NWK_MGR/LSTN] PKTBODY:                                                            simpleDescList :
[2020-09-11 08:35:10] [08:35:06.359,418] [NWK_MGR/LSTN] PKTBODY:                                                              [000] :
[2020-09-11 08:35:10] [08:35:06.359,449] [NWK_MGR/LSTN] PKTBODY:                                                                endpointId = 0x00000001 (1)
[2020-09-11 08:35:10] [08:35:06.359,485] [NWK_MGR/LSTN] PKTBODY:                                                                profileId = 0x00000104 (260)
[2020-09-11 08:35:10] [08:35:06.359,518] [NWK_MGR/LSTN] PKTBODY:                                                                deviceId = 0x00000007 (7)
[2020-09-11 08:35:10] [08:35:06.359,552] [NWK_MGR/LSTN] PKTBODY:                                                                deviceVer = 0x00000000 (0)
[2020-09-11 08:35:10] [08:35:06.359,584] [NWK_MGR/LSTN] PKTBODY:                                                                inputClusters :
[2020-09-11 08:35:10] [08:35:06.359,615] [NWK_MGR/LSTN] PKTBODY:                                                                  [000] = 0x00000000 (0)
[2020-09-11 08:35:10] [08:35:06.359,647] [NWK_MGR/LSTN] PKTBODY:                                                                  [001] = 0x00000003 (3)
[2020-09-11 08:35:10] [08:35:06.359,678] [NWK_MGR/LSTN] PKTBODY:                                                                  [002] = 0x00000501 (1281)
[2020-09-11 08:35:10] [08:35:06.359,710] [NWK_MGR/LSTN] PKTBODY:                                                                outputClusters :
[2020-09-11 08:35:10] [08:35:06.359,741] [NWK_MGR/LSTN] PKTBODY:                                                                  [000] = 0x00000006 (6)
[2020-09-11 08:35:10] [08:35:06.359,772] [NWK_MGR/LSTN] PKTBODY:                                                                  [001] = 0x00000004 (4)
[2020-09-11 08:35:10] [08:35:06.359,803] [NWK_MGR/LSTN] PKTBODY:                                                                  [002] = 0x00000005 (5)
[2020-09-11 08:35:10] [08:35:06.359,834] [NWK_MGR/LSTN] PKTBODY:                                                                  [003] = 0x00000500 (1280)
[2020-09-11 08:35:10] [08:35:06.359,865] [NWK_MGR/LSTN] PKTBODY:                                                                  [004] = 0x00000009 (9)
[2020-09-11 08:35:10] [08:35:06.359,896] [NWK_MGR/LSTN] PKTBODY:                                                                  [005] = 0x00000101 (257)
[2020-09-11 08:35:10] [08:35:06.359,927] [NWK_MGR/LSTN] PKTBODY:                                                                  [006] = 0x00000020 (32)
[2020-09-11 08:35:10] [08:35:06.359,959] [NWK_MGR/LSTN] PKTBODY:                                                              [001] :
[2020-09-11 08:35:10] [08:35:06.359,990] [NWK_MGR/LSTN] PKTBODY:                                                                endpointId = 0x000000F2 (242)
[2020-09-11 08:35:10] [08:35:06.360,024] [NWK_MGR/LSTN] PKTBODY:                                                                profileId = 0x0000A1E0 (41440)
[2020-09-11 08:35:10] [08:35:06.360,061] [NWK_MGR/LSTN] PKTBODY:                                                                deviceId = 0x00000061 (97)
[2020-09-11 08:35:10] [08:35:06.360,094] [NWK_MGR/LSTN] PKTBODY:                                                                deviceVer = 0x00000000 (0)
[2020-09-11 08:35:10] [08:35:06.360,128] [NWK_MGR/LSTN] PKTBODY:                                                                outputClusters :
[2020-09-11 08:35:10] [08:35:06.360,159] [NWK_MGR/LSTN] PKTBODY:                                                                  [000] = 0x00000021 (33)
[2020-09-11 08:35:10] [08:35:06.360,195] [NWK_MGR/LSTN] PKTBODY:                                                            deviceStatus = DEVICE_ON_LINE

This is an extract when the result is bad:

[2020-10-08 23:14:56] [23:14:55.577,978] [NWK_MGR/LSTN] MISC1  : NWK_GET_LOCAL_DEVICE_INFO_REQ:
[2020-10-08 23:14:56] [23:14:55.578,256] [NWK_MGR/LSTN] PKT_HEX: [                           NWK_MGR>>>>>>>>>>>>>>>>>>>>CON007] [ucst] 44:00:72:08:08:08:12:40:08:00:11:00:00:00:00:00:00:00:00:20:
[2020-10-08 23:14:56] [23:14:55.578,300] [NWK_MGR/LSTN] PKTTYPE: [                           NWK_MGR>>>>>>>>>>>>>>>>>>>>CON007] NwkGetLocalDeviceInfoCnf
[2020-10-08 23:14:56] [23:14:55.578,355] [NWK_MGR/LSTN] PKTBODY:                                                          cmdId = NWK_GET_LOCAL_DEVICE_INFO_CNF
[2020-10-08 23:14:56] [23:14:55.578,393] [NWK_MGR/LSTN] PKTBODY:                                                          deviceInfoList :
[2020-10-08 23:14:56] [23:14:55.578,426] [NWK_MGR/LSTN] PKTBODY:                                                            networkAddress = 0x00000000 (0)
[2020-10-08 23:14:56] [23:14:55.578,465] [NWK_MGR/LSTN] PKTBODY:                                                            ieeeAddress = 00:00:00:00:00:00:00:00
[2020-10-08 23:14:56] [23:14:55.578,500] [NWK_MGR/LSTN] PKTBODY:                                                            manufacturerId = 0x00000007 (7)
[2020-10-08 23:14:56] [23:14:55.578,533] [NWK_MGR/LSTN] PKTBODY:                                                            simpleDescList :
[2020-10-08 23:14:56] [23:14:55.578,563] [NWK_MGR/LSTN] PKTBODY:                                                              [000] :
[2020-10-08 23:14:56] [23:14:55.578,596] [NWK_MGR/LSTN] PKTBODY:                                                                endpointId = 0x00000001 (1)
[2020-10-08 23:14:56] [23:14:55.578,631] [NWK_MGR/LSTN] PKTBODY:                                                                profileId = 0x00000104 (260)
[2020-10-08 23:14:56] [23:14:55.578,664] [NWK_MGR/LSTN] PKTBODY:                                                                deviceId = 0x00000007 (7)
[2020-10-08 23:14:56] [23:14:55.578,703] [NWK_MGR/LSTN] PKTBODY:                                                                deviceVer = 0x00000000 (0)
[2020-10-08 23:14:56] [23:14:55.578,736] [NWK_MGR/LSTN] PKTBODY:                                                                inputClusters :
[2020-10-08 23:14:56] [23:14:55.578,768] [NWK_MGR/LSTN] PKTBODY:                                                                  [000] = 0x00000000 (0)
[2020-10-08 23:14:56] [23:14:55.578,800] [NWK_MGR/LSTN] PKTBODY:                                                                  [001] = 0x00000003 (3)
[2020-10-08 23:14:56] [23:14:55.578,832] [NWK_MGR/LSTN] PKTBODY:                                                                  [002] = 0x00000501 (1281)
[2020-10-08 23:14:56] [23:14:55.578,864] [NWK_MGR/LSTN] PKTBODY:                                                                outputClusters :
[2020-10-08 23:14:56] [23:14:55.578,894] [NWK_MGR/LSTN] PKTBODY:                                                                  [000] = 0x00000006 (6)
[2020-10-08 23:14:56] [23:14:55.578,925] [NWK_MGR/LSTN] PKTBODY:                                                                  [001] = 0x00000004 (4)
[2020-10-08 23:14:56] [23:14:55.578,956] [NWK_MGR/LSTN] PKTBODY:                                                                  [002] = 0x00000005 (5)
[2020-10-08 23:14:56] [23:14:55.578,988] [NWK_MGR/LSTN] PKTBODY:                                                                  [003] = 0x00000500 (1280)
[2020-10-08 23:14:56] [23:14:55.579,019] [NWK_MGR/LSTN] PKTBODY:                                                                  [004] = 0x00000009 (9)
[2020-10-08 23:14:56] [23:14:55.579,050] [NWK_MGR/LSTN] PKTBODY:                                                                  [005] = 0x00000101 (257)
[2020-10-08 23:14:56] [23:14:55.579,082] [NWK_MGR/LSTN] PKTBODY:                                                                  [006] = 0x00000020 (32)
[2020-10-08 23:14:56] [23:14:55.579,141] [NWK_MGR/LSTN] PKTBODY:                                                              [001] :
[2020-10-08 23:14:56] [23:14:55.579,176] [NWK_MGR/LSTN] PKTBODY:                                                                endpointId = 0x000000F2 (242)
[2020-10-08 23:14:56] [23:14:55.579,211] [NWK_MGR/LSTN] PKTBODY:                                                                profileId = 0x0000A1E0 (41440)
[2020-10-08 23:14:56] [23:14:55.579,244] [NWK_MGR/LSTN] PKTBODY:                                                                deviceId = 0x00000061 (97)
[2020-10-08 23:14:56] [23:14:55.579,278] [NWK_MGR/LSTN] PKTBODY:                                                                deviceVer = 0x00000000 (0)
[2020-10-08 23:14:56] [23:14:55.579,409] [NWK_MGR/LSTN] PKTBODY:                                                                outputClusters :
[2020-10-08 23:14:56] [23:14:55.579,443] [NWK_MGR/LSTN] PKTBODY:                                                                  [000] = 0x00000021 (33)
[2020-10-08 23:14:56] [23:14:55.579,480] [NWK_MGR/LSTN] PKTBODY:                                                            deviceStatus = DEVICE_ON_LINE
[2020-10-08 23:14:56] [23:14:55.579,644] [NWK_MGR/LSTN] INFO   : ...sent 72 bytes to Client
[2020-10-08 23:14:56] [23:14:55.579,694] [NWK_MGR/LSTN] INFO   : !Done

In the "functionnal log", I can find:

[2020-10-06 23:46:59] [23:46:58.991,341] [NWK_MGR/LSTN] MISC1  : NWK_ZIGBEE_NWK_INFO_REQ
[2020-10-06 23:46:59] [23:46:58.991,367] [NWK_MGR/LSTN] MISC1  : NwkMgr sendSysNwkInfoReadReqAndSetTxPower:
[2020-10-06 23:46:59] [23:46:58.991,433] [NWK_MGR/LSTN] INFO   : preparing to send 2 bytes, subSys 0x11, cmdId 0x08, pData:
[2020-10-06 23:46:59] [23:46:58.991,469] [NWK_MGR/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[2020-10-06 23:46:59] [23:46:58.991,522] [NWK_MGR/LSTN] PKT_HEX: [                  Z_STACK<<NWK_MGR                  ] [SREQ] 02:00:31:08:08:08
[2020-10-06 23:46:59] [23:46:58.991,563] [NWK_MGR/LSTN] PKTTYPE: [                  Z_STACK<<NWK_MGR                  ] sysNwkInfoReadReq
[2020-10-06 23:46:59] [23:46:58.991,601] [NWK_MGR/LSTN] PKTBODY:                                                          cmdID = SYS_NWK_INFO_READ_REQ
[2020-10-06 23:46:59] [23:46:58.991,745] [NWK_MGR/LSTN] INFO   : Waiting for synchronous response...
[2020-10-06 23:46:59] [23:46:58.991,780] [NWK_MGR/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[2020-10-06 23:46:59] [23:46:58.991,806] [NWK_MGR/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[2020-10-06 23:46:59] [23:46:58.993,325] [Z_STACK/LSTN] INFO   : Receive message...
[2020-10-06 23:46:59] [23:46:58.993,466] [Z_STACK/LSTN] INFO   : zstackpb zspbHandlePbCb: subsystemID:31, cmdId:8
[2020-10-06 23:46:59] [23:46:58.993,509] [Z_STACK/LSTN] INFO   : preparing to send 0 bytes, subSys 0x05, cmdId 0x50, pData:
[2020-10-06 23:46:59] [23:46:58.993,541] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[2020-10-06 23:46:59] [23:46:58.993,712] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...
[2020-10-06 23:46:59] [23:46:58.993,758] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[2020-10-06 23:46:59] [23:46:58.993,784] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[2020-10-06 23:46:59] [23:46:59.004,169] [Z_STACK/READ] INFO   : Received 24 bytes, subSys 0x65, cmdId 0x50
[2020-10-06 23:46:59] [23:46:59.004,299] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
[2020-10-06 23:46:59] [23:46:59.004,329] [Z_STACK/READ] INFO   : Client Read: (len 27):
[2020-10-06 23:46:59] [23:46:59.004,412] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[2020-10-06 23:46:59] [23:46:59.004,465] [Z_STACK/LSTN] INFO   : zstackpb Sending Network Info Response
[2020-10-06 23:46:59] [23:46:59.004,649] [Z_STACK/LSTN] INFO   : ...sent 53 bytes to Client
[2020-10-06 23:46:59] [23:46:59.004,710] [Z_STACK/LSTN] INFO   : !Done
[2020-10-06 23:46:59] [23:46:59.004,881] [NWK_MGR/READ] INFO   : Received 49 bytes, subSys 0x71, cmdId 0x0E
[2020-10-06 23:46:59] [23:46:59.004,962] [NWK_MGR/READ] INFO   : [MUTEX] SRSP Cond signal set
[2020-10-06 23:46:59] [23:46:59.004,988] [NWK_MGR/READ] INFO   : Client Read: (len 53):
[2020-10-06 23:46:59] [23:46:59.005,057] [NWK_MGR/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[2020-10-06 23:46:59] [23:46:59.005,144] [NWK_MGR/LSTN] MISC1  : NwkInfoReadRsp:
[2020-10-06 23:46:59] [23:46:59.005,184] [NWK_MGR/LSTN] MISC1  : - nwkaddr:0000
[2020-10-06 23:46:59] [23:46:59.005,211] [NWK_MGR/LSTN] MISC1  : - ieeeaddr:00124B0010228277
[2020-10-06 23:46:59] [23:46:59.005,239] [NWK_MGR/LSTN] MISC1  : - devstate:9
[2020-10-06 23:46:59] [23:46:59.005,264] [NWK_MGR/LSTN] MISC1  : - panid:DF0D
[2020-10-06 23:46:59] [23:46:59.005,289] [NWK_MGR/LSTN] MISC1  : - extendedpanid:00124B0010228277
[2020-10-06 23:46:59] [23:46:59.005,314] [NWK_MGR/LSTN] MISC1  : - coordaddr:0000
[2020-10-06 23:46:59] [23:46:59.005,339] [NWK_MGR/LSTN] MISC1  : - coordextaddr:0000000000000000
[2020-10-06 23:46:59] [23:46:59.005,363] [NWK_MGR/LSTN] MISC1  : - devtypes: Coordinator: 1
[2020-10-06 23:46:59] [23:46:59.005,388] [NWK_MGR/LSTN] MISC1  : - devtypes: Router: 0
[2020-10-06 23:46:59] [23:46:59.005,412] [NWK_MGR/LSTN] MISC1  : - logicalchannel:11

In the dysfunctional log, I find this:

[2020-10-08 23:07:41] [23:07:41.556,011] [NWK_MGR/LSTN] MISC1  : NWK_ZIGBEE_NWK_INFO_REQ
[2020-10-08 23:07:41] [23:07:41.556,041] [NWK_MGR/LSTN] MISC1  : NwkMgr sendSysNwkInfoReadReqAndSetTxPower:
[2020-10-08 23:07:41] [23:07:41.556,081] [NWK_MGR/LSTN] INFO   : preparing to send 2 bytes, subSys 0x11, cmdId 0x08, pData:
[2020-10-08 23:07:41] [23:07:41.556,113] [NWK_MGR/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[2020-10-08 23:07:41] [23:07:41.556,171] [NWK_MGR/LSTN] PKT_HEX: [                  Z_STACK<<NWK_MGR                  ] [SREQ] 02:00:31:08:08:08
[2020-10-08 23:07:41] [23:07:41.556,216] [NWK_MGR/LSTN] PKTTYPE: [                  Z_STACK<<NWK_MGR                  ] sysNwkInfoReadReq
[2020-10-08 23:07:41] [23:07:41.556,448] [NWK_MGR/LSTN] PKTBODY:                                                          cmdID = SYS_NWK_INFO_READ_REQ
[2020-10-08 23:07:41] [23:07:41.556,655] [Z_STACK/LSTN] INFO   : Receive message...
[2020-10-08 23:07:41] [23:07:41.556,756] [Z_STACK/LSTN] INFO   : zstackpb zspbHandlePbCb: subsystemID:31, cmdId:8
[2020-10-08 23:07:41] [23:07:41.556,798] [Z_STACK/LSTN] INFO   : preparing to send 0 bytes, subSys 0x05, cmdId 0x50, pData:
[2020-10-08 23:07:41] [23:07:41.556,833] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[2020-10-08 23:07:41] [23:07:41.556,946] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...
[2020-10-08 23:07:41] [23:07:41.556,988] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[2020-10-08 23:07:41] [23:07:41.557,016] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[2020-10-08 23:07:41] [23:07:41.557,045] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[2020-10-08 23:07:41] [23:07:41.557,074] [Z_STACK/LSTN] INFO   : zstackpb Sending Network Info Response
[2020-10-08 23:07:41] [23:07:41.557,167] [Z_STACK/LSTN] INFO   : ...sent 51 bytes to Client
[2020-10-08 23:07:41] [23:07:41.557,209] [Z_STACK/LSTN] INFO   : !Done
[2020-10-08 23:07:41] [23:07:41.559,259] [NWK_MGR/READ] INFO   : Received 47 bytes, subSys 0x71, cmdId 0x0E
[2020-10-08 23:07:41] [23:07:41.559,473] [NWK_MGR/READ] INFO   : [MUTEX] SRSP Cond signal set
[2020-10-08 23:07:41] [23:07:41.559,508] [NWK_MGR/READ] INFO   : Client Read: (len 51):
[2020-10-08 23:07:41] [23:07:41.559,572] [NWK_MGR/LSTN] INFO   : Waiting for synchronous response...
[2020-10-08 23:07:41] [23:07:41.559,615] [NWK_MGR/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[2020-10-08 23:07:41] [23:07:41.559,643] [NWK_MGR/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[2020-10-08 23:07:41] [23:07:41.559,671] [NWK_MGR/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[2020-10-08 23:07:41] [23:07:41.559,734] [NWK_MGR/LSTN] MISC1  : NwkInfoReadRsp:
[2020-10-08 23:07:41] [23:07:41.559,766] [NWK_MGR/LSTN] MISC1  : - nwkaddr:0000
[2020-10-08 23:07:41] [23:07:41.559,796] [NWK_MGR/LSTN] MISC1  : - ieeeaddr:0000000000000000
[2020-10-08 23:07:41] [23:07:41.559,827] [NWK_MGR/LSTN] MISC1  : - devstate:0
[2020-10-08 23:07:41] [23:07:41.559,855] [NWK_MGR/LSTN] MISC1  : - panid:0000
[2020-10-08 23:07:41] [23:07:41.559,882] [NWK_MGR/LSTN] MISC1  : - extendedpanid:0000000000000000
[2020-10-08 23:07:41] [23:07:41.559,910] [NWK_MGR/LSTN] MISC1  : - coordaddr:0000
[2020-10-08 23:07:41] [23:07:41.559,937] [NWK_MGR/LSTN] MISC1  : - coordextaddr:0000000000000000
[2020-10-08 23:07:41] [23:07:41.559,965] [NWK_MGR/LSTN] MISC1  : - devtypes: Coordinator: 1
[2020-10-08 23:07:41] [23:07:41.559,992] [NWK_MGR/LSTN] MISC1  : - devtypes: Router: 0
[2020-10-08 23:07:41] [23:07:41.560,019] [NWK_MGR/LSTN] MISC1  : - logicalchannel:0

and

[2020-10-08 23:11:16] [23:11:15.981,005] [NWK_MGR/LSTN] MISC1  : NWK_ZIGBEE_NWK_INFO_REQ
[2020-10-08 23:11:16] [23:11:15.981,032] [NWK_MGR/LSTN] MISC1  : NwkMgr sendSysNwkInfoReadReqAndSetTxPower:
[2020-10-08 23:11:16] [23:11:15.981,077] [NWK_MGR/LSTN] INFO   : preparing to send 2 bytes, subSys 0x11, cmdId 0x08, pData:
[2020-10-08 23:11:16] [23:11:15.981,106] [NWK_MGR/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[2020-10-08 23:11:16] [23:11:15.981,158] [NWK_MGR/LSTN] PKT_HEX: [                  Z_STACK<<NWK_MGR                  ] [SREQ] 02:00:31:08:08:08
[2020-10-08 23:11:16] [23:11:15.981,199] [NWK_MGR/LSTN] PKTTYPE: [                  Z_STACK<<NWK_MGR                  ] sysNwkInfoReadReq
[2020-10-08 23:11:16] [23:11:15.981,237] [NWK_MGR/LSTN] PKTBODY:                                                          cmdID = SYS_NWK_INFO_READ_REQ
[2020-10-08 23:11:16] [23:11:15.981,380] [NWK_MGR/LSTN] INFO   : Waiting for synchronous response...
[2020-10-08 23:11:16] [23:11:15.981,416] [NWK_MGR/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[2020-10-08 23:11:16] [23:11:15.981,442] [NWK_MGR/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[2020-10-08 23:11:16] [23:11:15.981,538] [Z_STACK/LSTN] INFO   : Receive message...
[2020-10-08 23:11:16] [23:11:15.981,626] [Z_STACK/LSTN] INFO   : zstackpb zspbHandlePbCb: subsystemID:31, cmdId:8
[2020-10-08 23:11:16] [23:11:15.981,665] [Z_STACK/LSTN] INFO   : preparing to send 0 bytes, subSys 0x05, cmdId 0x50, pData:
[2020-10-08 23:11:16] [23:11:15.981,697] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[2020-10-08 23:11:16] [23:11:15.981,795] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...
[2020-10-08 23:11:16] [23:11:15.981,831] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[2020-10-08 23:11:16] [23:11:15.981,857] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[2020-10-08 23:11:16] [23:11:15.981,882] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[2020-10-08 23:11:16] [23:11:15.981,909] [Z_STACK/LSTN] INFO   : zstackpb Sending Network Info Response
[2020-10-08 23:11:16] [23:11:15.982,002] [Z_STACK/LSTN] INFO   : ...sent 53 bytes to Client
[2020-10-08 23:11:16] [23:11:15.982,043] [Z_STACK/LSTN] INFO   : !Done
[2020-10-08 23:11:16] [23:11:15.982,456] [NWK_MGR/READ] INFO   : Received 49 bytes, subSys 0x71, cmdId 0x0E
[2020-10-08 23:11:16] [23:11:15.982,529] [NWK_MGR/READ] INFO   : [MUTEX] SRSP Cond signal set
[2020-10-08 23:11:16] [23:11:15.982,554] [NWK_MGR/READ] INFO   : Client Read: (len 53):
[2020-10-08 23:11:16] [23:11:15.984,168] [NWK_MGR/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[2020-10-08 23:11:16] [23:11:15.984,297] [NWK_MGR/LSTN] MISC1  : NwkInfoReadRsp:
[2020-10-08 23:11:16] [23:11:15.984,330] [NWK_MGR/LSTN] MISC1  : - nwkaddr:0000
[2020-10-08 23:11:16] [23:11:15.984,359] [NWK_MGR/LSTN] MISC1  : - ieeeaddr:0000000000000000
[2020-10-08 23:11:16] [23:11:15.984,388] [NWK_MGR/LSTN] MISC1  : - devstate:9
[2020-10-08 23:11:16] [23:11:15.984,413] [NWK_MGR/LSTN] MISC1  : - panid:DF0D
[2020-10-08 23:11:16] [23:11:15.984,438] [NWK_MGR/LSTN] MISC1  : - extendedpanid:00124B0010228277
[2020-10-08 23:11:16] [23:11:15.984,463] [NWK_MGR/LSTN] MISC1  : - coordaddr:0000
[2020-10-08 23:11:16] [23:11:15.984,488] [NWK_MGR/LSTN] MISC1  : - coordextaddr:0000000000000000
[2020-10-08 23:11:16] [23:11:15.984,512] [NWK_MGR/LSTN] MISC1  : - devtypes: Coordinator: 1
[2020-10-08 23:11:16] [23:11:15.984,537] [NWK_MGR/LSTN] MISC1  : - devtypes: Router: 0
[2020-10-08 23:11:16] [23:11:15.984,561] [NWK_MGR/LSTN] MISC1  : - logicalchannel:11
[2020-10-08 23:11:16]

over 3 years ago

0 Ryan Brown1 over 3 years ago

TI__Guru**** 202236 points

Hi le_top,

The IEEE address is set inside zmain_ext_addr, which attempts to read an entry from the NV memory. If this fails then it takes the IEEE 802.15.4 address stored in the Info Page of the CC2530. In a few images the NV memory appears to not be initialized or corrupted since the devstate, logicalchannel, and panid are also all zeros. The last image is the most curious since everything appears correct except for the ieeeaddr. This would indicate that a faulty IEEE address was allowed from NV when forming the network, however the extended PAN ID correctly used the address stored in the device's Info Page. Are you able to easily replicate the issue and how does it respond to a device or factory reset? I also recommend further debugging zmain_ext_addr. https://e2e.ti.com/support/wireless-connectivity/zigbee-and-thread/f/158/t/902631

Regards,
Ryan

0 Mario DW over 3 years ago in reply to Ryan Brown1

Genius 3145 points

The issue happens often enough, but I do not know exactly how to reproduce it for certain.

We have not set the IEEE Address in NV memory and we expect to read the IEEE address that has been set in the factory.

Usually when I pwoer cycle the Linux Gateway, the problem goes away, but it does not always go away (this is an impression).

I only recently checked why the gateway address was incorrect from time to time.

Normally the startup of the ZigbeeGw is supposed to HW reset the CC2530. I am not sure this still works in this setup (something I'll have to check again).

Based the analysis given, is there any way to resolve this through the GW software?
Should we write the factory IEEE Address to the secondary address - can we do this using one of the gateway commands?

I have modified the gateway application (not the gateway) to restart the connection procedure when the IEEE Adress returns 0, but in that case this just goes on forever.

I didn't expect that using the gateway implied that I was going to have to debug the ZNP in cooperation with the gateway, and I fear about what is going to happen when this is going to be deployed in people's homes.

0 Ryan Brown1 over 3 years ago in reply to Mario DW

TI__Guru**** 202236 points

When you detect that the IEEE address is incorrect with your gateway application then you could send a software reset type SYS_RESET_REQ to the ZNP to see if this resolves the issue. Or if you know what the proper IEEE address should be then you could use SYS_OSAL_NV_WRITE to write the ZCD_NV_EXTADDR and ZCD_NV_EXTENDED_PAN_ID, this is described in SWRA671 for cloning ZC devices. However this would also require a ZNP reset. What do you mean by the restart connection procedure going on forever?

Regards,
Ryan

0 Mario DW over 3 years ago in reply to Ryan Brown1

Genius 3145 points

This is the the modified si_init_state function.

With "going on forever", I mean that in state 4, the gateway_self_addr is 0 and restart the intialisation process. This is repeated "forever" (unless it works at startup).

I also added the "system_send_reset_request" if the procedure is started 3 times.

void si_init_state_machine(const bool timed_out, void * const arg _UNUSED)
{
	static int state = 0;
    static bool lost=TRUE;
    static int failureCount=0;

	if (!network_manager_server.connected)
	{
        state = 5;
	}
	else if ((!timed_out) || (state == 0))
	{
		state++;
        if(state==5) {
            lost=FALSE;
        }
	}
	
	UI_PRINT_LOG("Init state %d", state);
	
	switch (state)
	{
        case 4:
            if(gateway_self_addr.ieee_addr==0) {
                if(++failureCount>3) {
                    system_send_reset_request(true);
                }
                state=1;
                /** fall through */
            } else {
                //state++;
                device_send_list_request();
                break;
            }
		case 1:
			si_register_idle_callback(si_init_state_machine, NULL);
			
			if(!waiting_for_confirmation)
			{
				nwk_send_info_request();
			}
			else
			{
				state = 0;
			}
			break;
		case 2:
			device_send_local_info_request();
			break;
		case 3:
            device_send_list_maintenance_request();
            break;
        case 5:
			si_unregister_idle_callback();
			state = 0;
			break;
		default:
			break;
	}
}

0 Ryan Brown1 over 3 years ago in reply to Mario DW

TI__Guru**** 202236 points

I apologize for the confusion, but is your issue resolved or improved with the function provided?

Regards,
Ryan

0 Mario DW over 3 years ago in reply to Ryan Brown1

Genius 3145 points

Hello

Thank you for your concern.

The function that I provided did not resolve the issue;

I shared it to show that:

- It includes a call to reset the gatewy (system_send_reset_request );

- It repeats the starup procedure untill the gateway address is correct (which does not happen when it is failing).

Kind regards

Mario

0 Ryan Brown1 over 3 years ago in reply to Mario DW

TI__Guru**** 202236 points

Hi Mario,

It fails consistently because it continues to read an incorrect IEEE address stored in NV memory during startup, you must write the correct address back to the NV memory or perform a factory reset (SYS_OSAL_NV_WRITE a value of 0x03 to ZCD_NV_STARTUP_OPTION followed by soft/hard reset).

Regards,
Ryan

0 Mario DW over 3 years ago in reply to Ryan Brown1

Genius 3145 points

1) I am using the Linux Gateway solution here, which is connected to the ZNP implementation on the device.

The network interface does not provide a method to perform operations on NV memory according to my search (looking for "nv" in the protofiles did not reveal a method).

Can I write the IEEE through the GW & check if it written already on subsequent starts?

2) It may be better to update the ZNP/ZSTACK to return the hardwired IEEE address in case the NV address can not be read? That could be an option at compile time.

3) Doing a factory reset on a device installed at a consumer's home is not the ideal operation to do. We do not clearly know why this is happening, so it might easily happen in the field. The best solution would be "2" in this case.

0 Ryan Brown1 over 3 years ago in reply to Mario DW

TI__Guru**** 202236 points

1) The Linux Gateway solution employs the MT interface so it is possible to add SYS_OSAL_NV_WRITE and other commands to the gateway application, also see znp_misc.c

2) You could modify zmain_ext_addr from ZMain.c of the ZNP

3) I agree that a factory reset is not the best option

Regards,
Ryan

0 Mario DW over 3 years ago in reply to Ryan Brown1

Genius 3145 points

1) 'znp_misc.c' is inside the znp_server so that means that I would have to evolve the gateway app to also connect to the ZNP server, and extend the protobuf interface to get access to these commands. Furthermore, it seems that the ZNP is accepting only one connection, so to go this way there is another level of understanding and developing the gateway ahead. Not quite foreseen in my workload.

2) I have opened another forum entry regarding debugging the ZNP. Mandatory to understand what is going on in ZMain.

Zigbee & Thread

Zigbee & Thread forum

CC2530: Linux Gateway - NWK_GET_LOCAL_DEVICE_INFO_CNF returning "00:00:00:00:00:00:00:00" as IeeeAddress