• 状态 Resolved
  • 已锁定 已锁定
  • 回复 8 回复
  • 订户 19 订户
  • 视图 2127 视图
  • 用户 0 会员在此处
选项
选项
相关

This thread has been locked.

If you have a related question, please click the "Ask a related question" button in the top right corner. The newly created question will be automatically linked to this question.

Zigbee_3_0_Linux_Gateway 与ZNP固件通信中断

user4447611
Prodigy 140 points
Other Parts Discussed in Thread: CC2652P

目前跑ZNP固件用的是cc2652p，通过串口与网关Zigbee_3_0_Linux_Gateway 进行通信，但是在应用运行一段时间后，就会出现应用下发入网指令（循环4分钟发一次）给ZNP时返回Status FAILURE，这个时候ZNP端连接的终端设备信息就无法上报到网关应用，请问这个问题一般会由什么原因引起的呢？（ZNP端Power Mode已经配置成Always On (Low Power Mode disabled)）

[2021-04-14 09:40:12|INFO|PID=21359<commissioning_engine.c:618>]comm_send_permit_join: Sending NWK_SET_PERMIT_JOIN_REQ with Join Time 0xf0
[09:40:12.331,911] [GW-APP/MAIN] MISC2 : sent to NWK_MGR: len=7, cmd_id=12, subsystem=18
[09:40:12.332,424] [GW-APP/MAIN] MISC2 : Raw=07:00:12:0C:08:0C:10:01:18:F0:01
[09:40:14.382,774] [GW-APP/MAIN] MISC2 : received from NWK_MGR: len=4, cmd_id=0, subsystem=114
[09:40:14.383,317] [GW-APP/MAIN] MISC2 : Raw=04:00:72:00:08:00:10:01
[09:40:14.383,784] [GW-APP/MAIN] INFO : Calling confirmation callback
[2021-04-14 09:40:14|INFO|PID=21359<commissioning_engine.c:275>]comm_process_permit_join: Received ZIGBEE_GENERIC_CNF
[2021-04-14 09:40:14|INFO|PID=21359<commissioning_engine.c:299>]comm_process_permit_join: Error: Status FAILURE.

  • 0
    TI__Guru* 82220 points
    SDK版本是多少,linux_gateway与ZNP通信看下这里的academy试一下dev.ti.com/.../node
  • 0 回复 Kevin Qiu
    Prodigy 140 points

    目前我使用的SDK版本是simplelink_cc13x2_26x2_sdk_4_30_00_54，最近我在测试过程中遇到Linux_Gateway与ZNP通信超时的问题，以下是最新的log信息，请问这问题该如何解决呢？

    [15:08:24.917,925] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 00:25:50

    [15:08:24.920,865] [NWK_MGR/LSTN] INFO   : Waiting for synchronous response...

    [15:08:24.921,523] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...

    [15:08:24.926,015] [NWK_MGR/LSTN] INFO   : [MUTEX] Lock SRSP Mutex

    [15:08:24.927,081] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex

    [15:08:24.929,602] [NWK_MGR/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...

    [15:08:24.930,813] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...

    [15:08:26.926,101] [NWK_MGR/LSTN] INFO   : [MUTEX] SRSP Cond Wait timed out!

    [15:08:26.926,612] [NWK_MGR/LSTN] ERROR  : SRSP Cond Wait timed out!

    [15:08:26.927,240] [Z_STACK/LSTN] INFO   : [MUTEX] SRSP Cond Wait timed out!

    [15:08:26.927,682] [Z_STACK/LSTN] ERROR  : SRSP Cond Wait timed out!

    [15:08:26.928,122] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex

    [15:08:26.928,575] [Z_STACK/LSTN] ERROR  : apicSendSynchData() failed getting response

    [15:08:26.929,018] [Z_STACK/LSTN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:5, cmdID:36, len::5

    [15:08:26.927,048] [NWK_MGR/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex

    [15:08:26.933,150] [NWK_MGR/LSTN] ERROR  : apicSendSynchData() failed getting response

    [15:08:26.935,361] [NWK_MGR/LSTN] MISC1  : Sending ZigBee Generic Confirmation

    [15:08:26.929,476] [Z_STACK/LSTN] INFO   : preparing to send 5 bytes, subSys 0x05, cmdId 0x36, pData:

    [15:08:26.938,755] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex

    [15:08:26.938,624] [NWK_MGR/LSTN] PKT_HEX: [                           NWK_MGR>>>>>>>>>>>GW-APP] [ucst] 04:00:72:00:08:00:10:01

    [15:08:26.942,096] [NWK_MGR/LSTN] PKTTYPE: [                           NWK_MGR>>>>>>>>>>>GW-APP] NwkZigbeeGenericCnf

    [15:08:26.943,339] [Z_STACK/LSTN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 05:25:36:02:00:00:F0:01

    [15:08:26.945,901] [NWK_MGR/LSTN] PKTBODY:                                                          cmdId = ZIGBEE_GENERIC_CNF

    [15:08:26.949,015] [Z_STACK/LSTN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 05:25:36:02:00:00:F0:01

    [15:08:26.950,293] [NWK_MGR/LSTN] PKTBODY:                                                          status = STATUS_FAILURE

    [15:08:26.953,644] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...

    [15:08:26.958,948] [NWK_MGR/LSTN] INFO   : ...sent 8 bytes to Client

    [15:08:26.959,764] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex

    [15:08:26.962,552] [NWK_MGR/LSTN] MISC1  : Processing System Reset Request Failed - Status:3

    [15:08:26.963,689] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...

    [15:08:26.966,345] [NWK_MGR/LSTN] INFO   : !Done

    [15:08:28.959,849] [Z_STACK/LSTN] INFO   : [MUTEX] SRSP Cond Wait timed out!

    [15:08:28.960,347] [Z_STACK/LSTN] ERROR  : SRSP Cond Wait timed out!

    [15:08:28.960,786] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex

    [15:08:28.961,221] [Z_STACK/LSTN] ERROR  : apicSendSynchData() failed getting response

    [15:08:28.961,665] [Z_STACK/LSTN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:5, cmdID:36, len::5

    [15:08:28.965,345] [Z_STACK/LSTN] INFO   : preparing to send 5 bytes, subSys 0x05, cmdId 0x36, pData:

    [15:08:28.968,014] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex

    [15:08:28.973,562] [Z_STACK/LSTN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 05:25:36:02:FC:FF:F0:01

    [15:08:28.978,293] [Z_STACK/LSTN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 05:25:36:02:FC:FF:F0:01

    [15:08:28.980,365] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...

    [15:08:28.984,364] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex

    [15:08:28.988,311] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...

    [UART] Send synch data timed out

    [ERR] SRSP: npi_ipc_errno 0x02040100

    !Done

    Synchronous Request Timeout...

    Receive message...

    NPI SREQ:  (len 8) 0x05 0x25 0x36 0x02 0x00 0x00 0xF0 0x01

    [15:08:30.928,820] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 05:25:36:02:00:00:F0:01

    [15:08:30.984,424] [Z_STACK/LSTN] INFO   : [MUTEX] SRSP Cond Wait timed out!

    [15:08:30.984,928] [Z_STACK/LSTN] ERROR  : SRSP Cond Wait timed out!

    [15:08:30.985,372] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex

    [15:08:30.986,632] [Z_STACK/LSTN] ERROR  : apicSendSynchData() failed getting response

    [15:08:30.989,291] [Z_STACK/LSTN] PKT_HEX: [                  Z_STACK>>NWK_MGR                  ] [ucst] 04:00:71:FA:08:43:10:00

    [15:08:30.991,451] [Z_STACK/LSTN] PKTTYPE: [                  Z_STACK>>NWK_MGR                  ] zstackDefaultRsp

    [15:08:30.993,982] [Z_STACK/LSTN] PKTBODY:                                                          cmdID = ZDO_MGMT_PERMIT_JOIN_REQ

    [15:08:30.996,578] [Z_STACK/LSTN] PKTBODY:                                                          status = ZSuccess

    [15:08:30.999,392] [NWK_MGR/READ] INFO   : Received 4 bytes, subSys 0x71, cmdId 0xFA

    [15:08:30.999,916] [NWK_MGR/READ] INFO   : [MUTEX] SRSP Cond signal set

    [15:08:31.000,353] [NWK_MGR/READ] INFO   : Client Read: (len 8):

    [15:08:31.002,524] [Z_STACK/LSTN] INFO   : ...sent 8 bytes to Client

    [15:08:31.005,716] [Z_STACK/LSTN] INFO   : !Done

    [UART] Send synch data timed out

    [ERR] SRSP: npi_ipc_errno 0x02040100

    !Done

    Synchronous Request Timeout...

    Receive message...

    NPI SREQ:  (len 8) 0x05 0x25 0x36 0x02 0xFC 0xFF 0xF0 0x01

    [15:08:36.942,176] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 05:25:36:02:FC:FF:F0:01

    [UART] Send synch data timed out

    [ERR] SRSP: npi_ipc_errno 0x02040100

    !Done

    Synchronous Request Timeout...

  • +1 回复 user4447611
    Guru 109510 points
    參考一下 e2e.ti.com/.../cc2652p-sdk-4-30-znp-uart-no-response-after-running-a-while 、 simplelink_cc13x2_26x2_sdk_4_30_00_54的ZNP有問題，你要升級到4.40之後的SDK的ZNP
  • 0 回复 user4447611
    TI__Guru* 82220 points
    SDK4.40以后解决了这个问题，建议你升级到SDK5.10版本
  • 0 回复 Kevin Qiu
    Prodigy 140 points

    全屏 NwkSetPermitJoinReq.log 下载 
    [14:39:50.269,479] [NWK_MGR/LSTN] INFO   : Receive message...
[14:39:50.270,160] [NWK_MGR/LSTN] PKT_HEX: [                           NWK_MGR<<<<<<<<<<<GW-APP] [read] 07:00:12:0C:08:0C:10:01:18:F0:01
[14:39:50.270,678] [NWK_MGR/LSTN] PKTTYPE: [                           NWK_MGR<<<<<<<<<<<GW-APP] NwkSetPermitJoinReq
[14:39:50.271,179] [NWK_MGR/LSTN] PKTBODY:                                                          cmdId = NWK_SET_PERMIT_JOIN_REQ
[14:39:50.271,661] [NWK_MGR/LSTN] PKTBODY:                                                          permitJoin = PERMIT_NETWORK
[14:39:50.272,140] [NWK_MGR/LSTN] PKTBODY:                                                          permitJoinTime = 0x000000F0 (240)
[14:39:50.272,635] [NWK_MGR/LSTN] MISC1  : Processing Set Permit Join Request.
[14:39:50.279,736] [NWK_MGR/LSTN] MISC1  : NwkMgr sendZdoMgmtPermitJoinReq: nwkaddr FFFC
[14:39:50.285,508] [NWK_MGR/LSTN] INFO   : preparing to send 11 bytes, subSys 0x11, cmdId 0x43, pData:
[14:39:50.293,916] [NWK_MGR/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[14:39:50.298,502] [NWK_MGR/LSTN] PKT_HEX: [                  Z_STACK<<NWK_MGR                  ] [SREQ] 0B:00:31:43:08:43:10:FC:FF:03:18:F0:01:20:01
[14:39:50.302,217] [NWK_MGR/LSTN] PKTTYPE: [                  Z_STACK<<NWK_MGR                  ] zdoMgmtPermitJoinReq
[14:39:50.305,894] [NWK_MGR/LSTN] PKTBODY:                                                          cmdID = ZDO_MGMT_PERMIT_JOIN_REQ
[14:39:50.312,275] [NWK_MGR/LSTN] PKTBODY:                                                          nwkAddr = 0x0000FFFC (65532)
[14:39:50.319,185] [NWK_MGR/LSTN] PKTBODY:                                                          duration = 0x000000F0 (240)
[14:39:50.324,608] [NWK_MGR/LSTN] PKTBODY:                                                          tcSignificance = 1
[14:39:50.338,828] [Z_STACK/LSTN] INFO   : Receive message...
[14:39:50.339,430] [Z_STACK/LSTN] INFO   : zstackpb zspbHandlePbCb: subsystemID:31, cmdId:43
[14:39:50.339,911] [Z_STACK/LSTN] INFO   : preparing to send 0 bytes, subSys 0x05, cmdId 0x50, pData:
[14:39:50.340,361] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[14:39:50.340,873] [Z_STACK/LSTN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 00:25:50
[14:39:50.342,438] [Z_STACK/LSTN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 00:25:50
Receive message...
NPI SREQ:  (len 3) 0x00 0x25 0x50
[14:39:50.344,426] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 00:25:50
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x65, Cmd ID: 0x50, length: 24
[14:39:50.349,539] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 18:65:50:00:00:09:C9:47:00:00:9D:B0:5B:21:00:4B:12:00:00:00:00:00:00:00:00:00:0C
[UART] npi_procframe signal synch response received (invoked by read loop)
NPI SRSP: (len 27) 0x18 0x65 0x50 0x00 0x00 0x09 0xC9 0x47 0x00 0x00 0x9D 0xB0 0x5B 0x21 0x00 0x4B 0x12 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x0C
[14:39:50.350,660] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 18:65:50:00:00:09:C9:47:00:00:9D:B0:5B:21:00:4B:12:00:00:00:00:00:00:00:00:00:0C
...sent 27 bytes to Client #5
!Done
[14:39:50.347,877] [NWK_MGR/LSTN] INFO   : Waiting for synchronous response...
[14:39:50.353,549] [NWK_MGR/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[14:39:50.357,228] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...
[14:39:50.357,895] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[14:39:50.358,768] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[14:39:50.354,385] [NWK_MGR/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x44, Cmd ID: 0x81, length: 32
[14:39:50.978,752] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 20:44:81:00:00:19:00:03:78:08:0E:00:63:00:6B:E4:8A:00:00:0C:01:17:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
[UART] npi_procframe signal areq callback thread (invoked by read loop)
[-->] 32 bytes, subSys 0x44, cmdId 0x81, pData: 0x00 0x00 0x19 0x00 0x03 0x78 0x08 0x0E 0x00 0x63 0x00 0x6B 0xE4 0x8A 0x00 0x00 0x0C 0x01 0x17 0x01 0x00 0xBE 0xBE 0x52 0x26 0x07 0x00 0x00 0x00 0x03 0x78 0x1D
Dispatch AREQ to all active connections: #5.
[14:39:50.980,912] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 20:44:81:00:00:19:00:03:78:08:0E:00:63:00:6B:E4:8A:00:00:0C:01:17:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
...sent 35 bytes to Client #5
[14:39:52.353,640] [NWK_MGR/LSTN] INFO   : [MUTEX] SRSP Cond Wait timed out!
[14:39:52.354,161] [NWK_MGR/LSTN] ERROR  : SRSP Cond Wait timed out!
[14:39:52.354,600] [NWK_MGR/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[14:39:52.355,038] [NWK_MGR/LSTN] ERROR  : apicSendSynchData() failed getting response
[14:39:52.355,488] [NWK_MGR/LSTN] MISC1  : Sending ZigBee Generic Confirmation
[14:39:52.356,076] [NWK_MGR/LSTN] PKT_HEX: [                           NWK_MGR>>>>>>>>>>>GW-APP] [ucst] 04:00:72:00:08:00:10:01
[14:39:52.356,588] [NWK_MGR/LSTN] PKTTYPE: [                           NWK_MGR>>>>>>>>>>>GW-APP] NwkZigbeeGenericCnf
[14:39:52.358,497] [Z_STACK/LSTN] INFO   : [MUTEX] SRSP Cond Wait timed out!
[14:39:52.358,988] [Z_STACK/LSTN] ERROR  : SRSP Cond Wait timed out!
[14:39:52.359,426] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[14:39:52.359,862] [Z_STACK/LSTN] ERROR  : apicSendSynchData() failed getting response
[14:39:52.360,301] [Z_STACK/LSTN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:5, cmdID:36, len::5
[14:39:52.360,763] [Z_STACK/LSTN] INFO   : preparing to send 5 bytes, subSys 0x05, cmdId 0x36, pData:
[14:39:52.364,061] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[14:39:52.366,710] [NWK_MGR/LSTN] PKTBODY:                                                          cmdId = ZIGBEE_GENERIC_CNF
[14:39:52.368,838] [Z_STACK/LSTN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 05:25:36:02:00:00:F0:01
[14:39:52.371,179] [NWK_MGR/LSTN] PKTBODY:                                                          status = STATUS_FAILURE
[14:39:52.373,913] [Z_STACK/LSTN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 05:25:36:02:00:00:F0:01
Receive message...
NPI SREQ:  (len 8) 0x05 0x25 0x36 0x02 0x00 0x00 0xF0 0x01
[14:39:52.384,921] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 05:25:36:02:00:00:F0:01
[14:39:52.383,306] [NWK_MGR/LSTN] INFO   : ...sent 8 bytes to Client
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x65, Cmd ID: 0x36, length: 1
[14:39:52.388,632] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 01:65:36:00
[UART] npi_procframe signal synch response received (invoked by read loop)
NPI SRSP: (len 4) 0x01 0x65 0x36 0x00
[14:39:52.389,488] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 01:65:36:00
...sent 4 bytes to Client #5
!Done
[14:39:52.386,841] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...
[14:39:52.388,048] [NWK_MGR/LSTN] MISC1  : Processing System Reset Request Failed - Status:3
[14:39:52.392,793] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[14:39:52.392,945] [NWK_MGR/LSTN] INFO   : !Done
[14:39:52.395,729] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[14:39:54.392,875] [Z_STACK/LSTN] INFO   : [MUTEX] SRSP Cond Wait timed out!
[14:39:54.393,474] [Z_STACK/LSTN] ERROR  : SRSP Cond Wait timed out!
[14:39:54.393,915] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[14:39:54.394,351] [Z_STACK/LSTN] ERROR  : apicSendSynchData() failed getting response
[14:39:54.394,792] [Z_STACK/LSTN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:5, cmdID:36, len::5
[14:39:54.396,311] [Z_STACK/LSTN] INFO   : preparing to send 5 bytes, subSys 0x05, cmdId 0x36, pData:
[14:39:54.398,870] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[14:39:54.402,904] [Z_STACK/LSTN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 05:25:36:02:FC:FF:F0:01
[14:39:54.406,343] [Z_STACK/LSTN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 05:25:36:02:FC:FF:F0:01
Receive message...
NPI SREQ:  (len 8) 0x05 0x25 0x36 0x02 0xFC 0xFF 0xF0 0x01
[14:39:54.409,353] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 05:25:36:02:FC:FF:F0:01
[14:39:54.411,400] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x65, Cmd ID: 0x36, length: 1
[14:39:54.415,462] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 01:65:36:00
[UART] npi_procframe signal synch response received (invoked by read loop)
NPI SRSP: (len 4) 0x01 0x65 0x36 0x00
[14:39:54.416,337] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 01:65:36:00
...sent 4 bytes to Client #5
!Done
[14:39:54.419,162] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[14:39:54.421,820] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[14:39:56.419,278] [Z_STACK/LSTN] INFO   : [MUTEX] SRSP Cond Wait timed out!
[14:39:56.419,751] [Z_STACK/LSTN] ERROR  : SRSP Cond Wait timed out!
[14:39:56.420,190] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[14:39:56.420,622] [Z_STACK/LSTN] ERROR  : apicSendSynchData() failed getting response
[14:39:56.423,115] [Z_STACK/LSTN] PKT_HEX: [                  Z_STACK>>NWK_MGR                  ] [ucst] 04:00:71:FA:08:43:10:00
[14:39:56.424,795] [Z_STACK/LSTN] PKTTYPE: [                  Z_STACK>>NWK_MGR                  ] zstackDefaultRsp
[14:39:56.429,836] [Z_STACK/LSTN] PKTBODY:                                                          cmdID = ZDO_MGMT_PERMIT_JOIN_REQ
[14:39:56.433,403] [Z_STACK/LSTN] PKTBODY:                                                          status = ZSuccess
[14:39:56.438,542] [NWK_MGR/READ] INFO   : Received 4 bytes, subSys 0x71, cmdId 0xFA
[14:39:56.439,089] [NWK_MGR/READ] INFO   : [MUTEX] SRSP Cond signal set
[14:39:56.439,529] [NWK_MGR/READ] INFO   : Client Read: (len 8):
[14:39:56.441,765] [Z_STACK/LSTN] INFO   : ...sent 8 bytes to Client
[14:39:56.445,362] [Z_STACK/LSTN] INFO   : !Done
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x44, Cmd ID: 0x81, length: 27
[14:40:00.909,163] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 1B:44:81:00:00:01:00:4B:3E:08:04:00:51:00:0F:5D:94:00:00:07:18:0B:0A:21:00:20:32:4B:3E:1D
[UART] npi_procframe signal areq callback thread (invoked by read loop)
[-->] 27 bytes, subSys 0x44, cmdId 0x81, pData: 0x00 0x00 0x01 0x00 0x4B 0x3E 0x08 0x04 0x00 0x51 0x00 0x0F 0x5D 0x94 0x00 0x00 0x07 0x18 0x0B 0x0A 0x21 0x00 0x20 0x32 0x4B 0x3E 0x1D
Dispatch AREQ to all active connections: #5.
[14:40:00.911,250] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 1B:44:81:00:00:01:00:4B:3E:08:04:00:51:00:0F:5D:94:00:00:07:18:0B:0A:21:00:20:32:4B:3E:1D
...sent 30 bytes to Client #5
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x44, Cmd ID: 0x81, length: 27
[14:40:05.901,510] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 1B:44:81:00:00:01:00:7E:84:08:04:00:51:00:E3:1F:99:00:00:07:18:49:0A:21:00:20:32:7E:84:1D
[UART] npi_procframe signal areq callback thread (invoked by read loop)
[-->] 27 bytes, subSys 0x44, cmdId 0x81, pData: 0x00 0x00 0x01 0x00 0x7E 0x84 0x08 0x04 0x00 0x51 0x00 0xE3 0x1F 0x99 0x00 0x00 0x07 0x18 0x49 0x0A 0x21 0x00 0x20 0x32 0x7E 0x84 0x1D
Dispatch AREQ to all active connections: #5.
[14:40:05.903,587] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 1B:44:81:00:00:01:00:7E:84:08:04:00:51:00:E3:1F:99:00:00:07:18:49:0A:21:00:20:32:7E:84:1D
...sent 30 bytes to Client #5
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x44, Cmd ID: 0x81, length: 32
[14:40:20.981,345] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 20:44:81:00:00:19:00:03:78:08:0E:00:57:00:32:81:A7:00:00:0C:01:18:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
[UART] npi_procframe signal areq callback thread (invoked by read loop)
[-->] 32 bytes, subSys 0x44, cmdId 0x81, pData: 0x00 0x00 0x19 0x00 0x03 0x78 0x08 0x0E 0x00 0x57 0x00 0x32 0x81 0xA7 0x00 0x00 0x0C 0x01 0x18 0x01 0x00 0xBE 0xBE 0x52 0x26 0x07 0x00 0x00 0x00 0x03 0x78 0x1D
Dispatch AREQ to all active connections: #5.
[14:40:20.983,501] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 20:44:81:00:00:19:00:03:78:08:0E:00:57:00:32:81:A7:00:00:0C:01:18:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
...sent 35 bytes to Client #5
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x44, Cmd ID: 0x81, length: 32
[14:40:50.973,701] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 20:44:81:00:00:19:00:03:78:08:0E:00:5A:00:7E:1B:C4:00:00:0C:01:19:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
[UART] npi_procframe signal areq callback thread (invoked by read loop)
[-->] 32 bytes, subSys 0x44, cmdId 0x81, pData: 0x00 0x00 0x19 0x00 0x03 0x78 0x08 0x0E 0x00 0x5A 0x00 0x7E 0x1B 0xC4 0x00 0x00 0x0C 0x01 0x19 0x01 0x00 0xBE 0xBE 0x52 0x26 0x07 0x00 0x00 0x00 0x03 0x78 0x1D
Dispatch AREQ to all active connections: #5.
[14:40:50.975,854] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 20:44:81:00:00:19:00:03:78:08:0E:00:5A:00:7E:1B:C4:00:00:0C:01:19:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
...sent 35 bytes to Client #5
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x44, Cmd ID: 0x81, length: 32
[14:41:20.975,682] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 20:44:81:00:00:19:00:03:78:08:0E:00:63:00:23:B8:E0:00:00:0C:01:1A:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
[UART] npi_procframe signal areq callback thread (invoked by read loop)
[-->] 32 bytes, subSys 0x44, cmdId 0x81, pData: 0x00 0x00 0x19 0x00 0x03 0x78 0x08 0x0E 0x00 0x63 0x00 0x23 0xB8 0xE0 0x00 0x00 0x0C 0x01 0x1A 0x01 0x00 0xBE 0xBE 0x52 0x26 0x07 0x00 0x00 0x00 0x03 0x78 0x1D
Dispatch AREQ to all active connections: #5.
[14:41:20.977,912] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 20:44:81:00:00:19:00:03:78:08:0E:00:63:00:23:B8:E0:00:00:0C:01:1A:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
...sent 35 bytes to Client #5
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x44, Cmd ID: 0x81, length: 32
[14:41:50.970,490] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 20:44:81:00:00:19:00:03:78:08:0E:00:63:00:02:53:0D:00:00:0C:01:1B:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
[UART] npi_procframe signal areq callback thread (invoked by read loop)
[-->] 32 bytes, subSys 0x44, cmdId 0x81, pData: 0x00 0x00 0x19 0x00 0x03 0x78 0x08 0x0E 0x00 0x63 0x00 0x02 0x53 0x0D 0x00 0x00 0x0C 0x01 0x1B 0x01 0x00 0xBE 0xBE 0x52 0x26 0x07 0x00 0x00 0x00 0x03 0x78 0x1D
Dispatch AREQ to all active connections: #5.
[14:41:50.972,650] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 20:44:81:00:00:19:00:03:78:08:0E:00:63:00:02:53:0D:00:00:0C:01:1B:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
...sent 35 bytes to Client #5
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x44, Cmd ID: 0x81, length: 32
[14:42:20.968,290] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 20:44:81:00:00:19:00:03:78:08:0E:00:57:00:A1:EE:29:00:00:0C:01:1C:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
[UART] npi_procframe signal areq callback thread (invoked by read loop)
[-->] 32 bytes, subSys 0x44, cmdId 0x81, pData: 0x00 0x00 0x19 0x00 0x03 0x78 0x08 0x0E 0x00 0x57 0x00 0xA1 0xEE 0x29 0x00 0x00 0x0C 0x01 0x1C 0x01 0x00 0xBE 0xBE 0x52 0x26 0x07 0x00 0x00 0x00 0x03 0x78 0x1D
Dispatch AREQ to all active connections: #5.
[14:42:20.970,500] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 20:44:81:00:00:19:00:03:78:08:0E:00:57:00:A1:EE:29:00:00:0C:01:1C:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
...sent 35 bytes to Client #5
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x44, Cmd ID: 0x81, length: 32
[14:42:50.977,476] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 20:44:81:00:00:19:00:03:78:08:0E:00:54:00:03:8D:46:00:00:0C:01:1D:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
[UART] npi_procframe signal areq callback thread (invoked by read loop)
[-->] 32 bytes, subSys 0x44, cmdId 0x81, pData: 0x00 0x00 0x19 0x00 0x03 0x78 0x08 0x0E 0x00 0x54 0x00 0x03 0x8D 0x46 0x00 0x00 0x0C 0x01 0x1D 0x01 0x00 0xBE 0xBE 0x52 0x26 0x07 0x00 0x00 0x00 0x03 0x78 0x1D
Dispatch AREQ to all active connections: #5.
[14:42:50.979,638] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 20:44:81:00:00:19:00:03:78:08:0E:00:54:00:03:8D:46:00:00:0C:01:1D:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
...sent 35 bytes to Client #5
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x44, Cmd ID: 0x81, length: 32
[14:43:20.963,388] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 20:44:81:00:00:19:00:03:78:08:0E:00:5A:00:BF:25:63:00:00:0C:01:1E:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
[UART] npi_procframe signal areq callback thread (invoked by read loop)
[-->] 32 bytes, subSys 0x44, cmdId 0x81, pData: 0x00 0x00 0x19 0x00 0x03 0x78 0x08 0x0E 0x00 0x5A 0x00 0xBF 0x25 0x63 0x00 0x00 0x0C 0x01 0x1E 0x01 0x00 0xBE 0xBE 0x52 0x26 0x07 0x00 0x00 0x00 0x03 0x78 0x1D
Dispatch AREQ to all active connections: #5.
[14:43:20.965,598] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 20:44:81:00:00:19:00:03:78:08:0E:00:5A:00:BF:25:63:00:00:0C:01:1E:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
...sent 35 bytes to Client #5
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x44, Cmd ID: 0x81, length: 27
[14:43:24.760,226] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 1B:44:81:00:00:01:00:03:78:08:04:00:5D:00:F3:C4:66:00:00:07:18:DD:0A:21:00:20:4E:03:78:1D
[UART] npi_procframe signal areq callback thread (invoked by read loop)
[-->] 27 bytes, subSys 0x44, cmdId 0x81, pData: 0x00 0x00 0x01 0x00 0x03 0x78 0x08 0x04 0x00 0x5D 0x00 0xF3 0xC4 0x66 0x00 0x00 0x07 0x18 0xDD 0x0A 0x21 0x00 0x20 0x4E 0x03 0x78 0x1D
Dispatch AREQ to all active connections: #5.
[14:43:24.761,414] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 1B:44:81:00:00:01:00:03:78:08:04:00:5D:00:F3:C4:66:00:00:07:18:DD:0A:21:00:20:4E:03:78:1D
...sent 30 bytes to Client #5
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x44, Cmd ID: 0x81, length: 32
[14:43:50.961,297] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 20:44:81:00:00:19:00:03:78:08:0E:00:63:00:61:C1:7F:00:00:0C:01:1F:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
[UART] npi_procframe signal areq callback thread (invoked by read loop)
[-->] 32 bytes, subSys 0x44, cmdId 0x81, pData: 0x00 0x00 0x19 0x00 0x03 0x78 0x08 0x0E 0x00 0x63 0x00 0x61 0xC1 0x7F 0x00 0x00 0x0C 0x01 0x1F 0x01 0x00 0xBE 0xBE 0x52 0x26 0x07 0x00 0x00 0x00 0x03 0x78 0x1D
Dispatch AREQ to all active connections: #5.
[14:43:50.963,515] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 20:44:81:00:00:19:00:03:78:08:0E:00:63:00:61:C1:7F:00:00:0C:01:1F:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
...sent 35 bytes to Client #5
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x44, Cmd ID: 0x81, length: 32
[14:44:20.959,091] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 20:44:81:00:00:19:00:03:78:08:0E:00:5D:00:02:5D:9C:00:00:0C:01:20:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
[UART] npi_procframe signal areq callback thread (invoked by read loop)
[-->] 32 bytes, subSys 0x44, cmdId 0x81, pData: 0x00 0x00 0x19 0x00 0x03 0x78 0x08 0x0E 0x00 0x5D 0x00 0x02 0x5D 0x9C 0x00 0x00 0x0C 0x01 0x20 0x01 0x00 0xBE 0xBE 0x52 0x26 0x07 0x00 0x00 0x00 0x03 0x78 0x1D
Dispatch AREQ to all active connections: #5.
[14:44:20.961,303] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 20:44:81:00:00:19:00:03:78:08:0E:00:5D:00:02:5D:9C:00:00:0C:01:20:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
...sent 35 bytes to Client #5
[14:44:50.485,249] [NWK_MGR/LSTN] INFO   : Receive message...
[14:44:50.485,919] [NWK_MGR/LSTN] PKT_HEX: [                           NWK_MGR<<<<<<<<<<<GW-APP] [read] 07:00:12:0C:08:0C:10:01:18:F0:01
[14:44:50.486,437] [NWK_MGR/LSTN] PKTTYPE: [                           NWK_MGR<<<<<<<<<<<GW-APP] NwkSetPermitJoinReq
[14:44:50.486,937] [NWK_MGR/LSTN] PKTBODY:                                                          cmdId = NWK_SET_PERMIT_JOIN_REQ
[14:44:50.487,414] [NWK_MGR/LSTN] PKTBODY:                                                          permitJoin = PERMIT_NETWORK
[14:44:50.487,891] [NWK_MGR/LSTN] PKTBODY:                                                          permitJoinTime = 0x000000F0 (240)
[14:44:50.488,382] [NWK_MGR/LSTN] MISC1  : Processing Set Permit Join Request.
[14:44:50.488,828] [NWK_MGR/LSTN] MISC1  : NwkMgr sendZdoMgmtPermitJoinReq: nwkaddr FFFC
[14:44:50.499,333] [NWK_MGR/LSTN] INFO   : preparing to send 11 bytes, subSys 0x11, cmdId 0x43, pData:
[14:44:50.503,326] [NWK_MGR/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[14:44:50.507,922] [NWK_MGR/LSTN] PKT_HEX: [                  Z_STACK<<NWK_MGR                  ] [SREQ] 0B:00:31:43:08:43:10:FC:FF:03:18:F0:01:20:01
[14:44:50.511,663] [NWK_MGR/LSTN] PKTTYPE: [                  Z_STACK<<NWK_MGR                  ] zdoMgmtPermitJoinReq
[14:44:50.514,926] [NWK_MGR/LSTN] PKTBODY:                                                          cmdID = ZDO_MGMT_PERMIT_JOIN_REQ
[14:44:50.518,146] [NWK_MGR/LSTN] PKTBODY:                                                          nwkAddr = 0x0000FFFC (65532)
[14:44:50.523,118] [NWK_MGR/LSTN] PKTBODY:                                                          duration = 0x000000F0 (240)
[14:44:50.526,329] [NWK_MGR/LSTN] PKTBODY:                                                          tcSignificance = 1
[14:44:50.530,226] [Z_STACK/LSTN] INFO   : Receive message...
[14:44:50.530,821] [Z_STACK/LSTN] INFO   : zstackpb zspbHandlePbCb: subsystemID:31, cmdId:43
[14:44:50.531,303] [Z_STACK/LSTN] INFO   : preparing to send 0 bytes, subSys 0x05, cmdId 0x50, pData:
[14:44:50.531,752] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[14:44:50.532,266] [Z_STACK/LSTN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 00:25:50
[14:44:50.532,787] [Z_STACK/LSTN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 00:25:50
Receive message...
NPI SREQ:  (len 3) 0x00 0x25 0x50
[14:44:50.536,779] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 00:25:50
[14:44:50.535,967] [NWK_MGR/LSTN] INFO   : Waiting for synchronous response...
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x65, Cmd ID: 0x50, length: 24
[14:44:50.542,506] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 18:65:50:00:00:09:C9:47:00:00:9D:B0:5B:21:00:4B:12:00:00:00:00:00:00:00:00:00:0C
[UART] npi_procframe signal synch response received (invoked by read loop)
NPI SRSP: (len 27) 0x18 0x65 0x50 0x00 0x00 0x09 0xC9 0x47 0x00 0x00 0x9D 0xB0 0x5B 0x21 0x00 0x4B 0x12 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x0C
[14:44:50.543,610] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 18:65:50:00:00:09:C9:47:00:00:9D:B0:5B:21:00:4B:12:00:00:00:00:00:00:00:00:00:0C
...sent 27 bytes to Client #5
!Done
[14:44:50.539,083] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...
[14:44:50.545,124] [NWK_MGR/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[14:44:50.548,527] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[14:44:50.550,227] [NWK_MGR/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[14:44:50.551,622] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[14:44:50.553,458] [NWK_MGR/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[14:44:50.556,453] [NWK_MGR/LSTN] MISC1  : Sending ZigBee Generic Confirmation
[14:44:50.560,849] [NWK_MGR/LSTN] PKT_HEX: [                           NWK_MGR>>>>>>>>>>>GW-APP] [ucst] 04:00:72:00:08:00:10:00
[14:44:50.563,598] [NWK_MGR/LSTN] PKTTYPE: [                           NWK_MGR>>>>>>>>>>>GW-APP] NwkZigbeeGenericCnf
[14:44:50.566,495] [NWK_MGR/LSTN] PKTBODY:                                                          cmdId = ZIGBEE_GENERIC_CNF
[14:44:50.569,395] [NWK_MGR/LSTN] PKTBODY:                                                          status = STATUS_SUCCESS
[14:44:50.576,472] [NWK_MGR/LSTN] INFO   : ...sent 8 bytes to Client
[14:44:50.579,769] [NWK_MGR/LSTN] INFO   : !Done
[14:44:52.548,614] [Z_STACK/LSTN] INFO   : [MUTEX] SRSP Cond Wait timed out!
[14:44:52.549,219] [Z_STACK/LSTN] ERROR  : SRSP Cond Wait timed out!
[14:44:52.549,665] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[14:44:52.550,101] [Z_STACK/LSTN] ERROR  : apicSendSynchData() failed getting response
[14:44:52.550,542] [Z_STACK/LSTN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:5, cmdID:36, len::5
[14:44:52.551,004] [Z_STACK/LSTN] INFO   : preparing to send 5 bytes, subSys 0x05, cmdId 0x36, pData:
[14:44:52.551,453] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[14:44:52.552,004] [Z_STACK/LSTN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 05:25:36:02:00:00:F0:01
[14:44:52.552,556] [Z_STACK/LSTN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 05:25:36:02:00:00:F0:01
Receive message...
NPI SREQ:  (len 8) 0x05 0x25 0x36 0x02 0x00 0x00 0xF0 0x01
[14:44:52.553,776] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 05:25:36:02:00:00:F0:01
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x65, Cmd ID: 0x36, length: 1
[14:44:52.557,406] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 01:65:36:00
[UART] npi_procframe signal synch response received (invoked by read loop)
NPI SRSP: (len 4) 0x01 0x65 0x36 0x00
[14:44:52.558,295] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 01:65:36:00
...sent 4 bytes to Client #5
!Done
[14:44:52.562,065] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...
[14:44:52.564,994] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[14:44:52.568,133] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[14:44:54.565,102] [Z_STACK/LSTN] INFO   : [MUTEX] SRSP Cond Wait timed out!
[14:44:54.565,623] [Z_STACK/LSTN] ERROR  : SRSP Cond Wait timed out!
[14:44:54.566,060] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[14:44:54.566,494] [Z_STACK/LSTN] ERROR  : apicSendSynchData() failed getting response
[14:44:54.566,934] [Z_STACK/LSTN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:5, cmdID:36, len::5
[14:44:54.567,395] [Z_STACK/LSTN] INFO   : preparing to send 5 bytes, subSys 0x05, cmdId 0x36, pData:
[14:44:54.567,846] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[14:44:54.568,394] [Z_STACK/LSTN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 05:25:36:02:FC:FF:F0:01
[14:44:54.568,948] [Z_STACK/LSTN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 05:25:36:02:FC:FF:F0:01
Receive message...
NPI SREQ:  (len 8) 0x05 0x25 0x36 0x02 0xFC 0xFF 0xF0 0x01
[14:44:54.574,111] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 05:25:36:02:FC:FF:F0:01
[14:44:54.575,863] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x65, Cmd ID: 0x36, length: 1
[14:44:54.579,826] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 01:65:36:00
[UART] npi_procframe signal synch response received (invoked by read loop)
NPI SRSP: (len 4) 0x01 0x65 0x36 0x00
[14:44:54.580,684] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 01:65:36:00
...sent 4 bytes to Client #5
!Done
[14:44:54.578,977] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[14:44:54.585,760] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[14:44:56.579,032] [Z_STACK/LSTN] INFO   : [MUTEX] SRSP Cond Wait timed out!
[14:44:56.579,549] [Z_STACK/LSTN] ERROR  : SRSP Cond Wait timed out!
[14:44:56.579,984] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[14:44:56.580,420] [Z_STACK/LSTN] ERROR  : apicSendSynchData() failed getting response
[14:44:56.581,001] [Z_STACK/LSTN] PKT_HEX: [                  Z_STACK>>NWK_MGR                  ] [ucst] 04:00:71:FA:08:43:10:00
[14:44:56.583,640] [Z_STACK/LSTN] PKTTYPE: [                  Z_STACK>>NWK_MGR                  ] zstackDefaultRsp
[14:44:56.585,997] [Z_STACK/LSTN] PKTBODY:                                                          cmdID = ZDO_MGMT_PERMIT_JOIN_REQ
[14:44:56.588,653] [Z_STACK/LSTN] PKTBODY:                                                          status = ZSuccess
[14:44:56.591,431] [NWK_MGR/READ] INFO   : Received 4 bytes, subSys 0x71, cmdId 0xFA
[14:44:56.591,957] [NWK_MGR/READ] INFO   : [MUTEX] SRSP Cond signal set
[14:44:56.592,396] [NWK_MGR/READ] INFO   : Client Read: (len 8):
[14:44:56.594,379] [Z_STACK/LSTN] INFO   : ...sent 8 bytes to Client
[14:44:56.597,773] [Z_STACK/LSTN] INFO   : !Done
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x44, Cmd ID: 0x81, length: 27
[14:45:00.889,937] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 1B:44:81:00:00:01:00:4B:3E:08:04:00:51:00:D9:71:C2:00:00:07:18:0C:0A:21:00:20:32:4B:3E:1D
[UART] npi_procframe signal areq callback thread (invoked by read loop)
[-->] 27 bytes, subSys 0x44, cmdId 0x81, pData: 0x00 0x00 0x01 0x00 0x4B 0x3E 0x08 0x04 0x00 0x51 0x00 0xD9 0x71 0xC2 0x00 0x00 0x07 0x18 0x0C 0x0A 0x21 0x00 0x20 0x32 0x4B 0x3E 0x1D
Dispatch AREQ to all active connections: #5.
[14:45:00.891,045] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 1B:44:81:00:00:01:00:4B:3E:08:04:00:51:00:D9:71:C2:00:00:07:18:0C:0A:21:00:20:32:4B:3E:1D
...sent 30 bytes to Client #5
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x44, Cmd ID: 0x81, length: 27
[14:45:05.885,380] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 1B:44:81:00:00:01:00:7E:84:08:04:00:3F:00:6F:35:C7:00:00:07:18:4A:0A:21:00:20:32:7E:84:1D
[UART] npi_procframe signal areq callback thread (invoked by read loop)
[-->] 27 bytes, subSys 0x44, cmdId 0x81, pData: 0x00 0x00 0x01 0x00 0x7E 0x84 0x08 0x04 0x00 0x3F 0x00 0x6F 0x35 0xC7 0x00 0x00 0x07 0x18 0x4A 0x0A 0x21 0x00 0x20 0x32 0x7E 0x84 0x1D
Dispatch AREQ to all active connections: #5.
[14:45:05.886,503] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 1B:44:81:00:00:01:00:7E:84:08:04:00:3F:00:6F:35:C7:00:00:07:18:4A:0A:21:00:20:32:7E:84:1D
...sent 30 bytes to Client #5
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x44, Cmd ID: 0x81, length: 32
[14:45:20.969,648] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 20:44:81:00:00:19:00:03:78:08:0E:00:63:00:E4:97:D5:00:00:0C:01:22:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
[UART] npi_procframe signal areq callback thread (invoked by read loop)
[-->] 32 bytes, subSys 0x44, cmdId 0x81, pData: 0x00 0x00 0x19 0x00 0x03 0x78 0x08 0x0E 0x00 0x63 0x00 0xE4 0x97 0xD5 0x00 0x00 0x0C 0x01 0x22 0x01 0x00 0xBE 0xBE 0x52 0x26 0x07 0x00 0x00 0x00 0x03 0x78 0x1D
Dispatch AREQ to all active connections: #5.
[14:45:20.971,804] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 20:44:81:00:00:19:00:03:78:08:0E:00:63:00:E4:97:D5:00:00:0C:01:22:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
...sent 35 bytes to Client #5
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x44, Cmd ID: 0x81, length: 32
[14:45:50.965,773] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 20:44:81:00:00:19:00:03:78:08:0E:00:60:00:19:33:02:00:00:0C:01:23:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
[UART] npi_procframe signal areq callback thread (invoked by read loop)
[-->] 32 bytes, subSys 0x44, cmdId 0x81, pData: 0x00 0x00 0x19 0x00 0x03 0x78 0x08 0x0E 0x00 0x60 0x00 0x19 0x33 0x02 0x00 0x00 0x0C 0x01 0x23 0x01 0x00 0xBE 0xBE 0x52 0x26 0x07 0x00 0x00 0x00 0x03 0x78 0x1D
Dispatch AREQ to all active connections: #5.
[14:45:50.967,910] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 20:44:81:00:00:19:00:03:78:08:0E:00:60:00:19:33:02:00:00:0C:01:23:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
...sent 35 bytes to Client #5
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x44, Cmd ID: 0x81, length: 32
[14:46:20.954,613] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 20:44:81:00:00:19:00:03:78:08:0E:00:6C:00:86:CC:1E:00:00:0C:01:24:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
[UART] npi_procframe signal areq callback thread (invoked by read loop)
[-->] 32 bytes, subSys 0x44, cmdId 0x81, pData: 0x00 0x00 0x19 0x00 0x03 0x78 0x08 0x0E 0x00 0x6C 0x00 0x86 0xCC 0x1E 0x00 0x00 0x0C 0x01 0x24 0x01 0x00 0xBE 0xBE 0x52 0x26 0x07 0x00 0x00 0x00 0x03 0x78 0x1D
Dispatch AREQ to all active connections: #5.
[14:46:20.956,776] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 20:44:81:00:00:19:00:03:78:08:0E:00:6C:00:86:CC:1E:00:00:0C:01:24:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
...sent 35 bytes to Client #5
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x44, Cmd ID: 0x81, length: 32
[14:46:50.959,942] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 20:44:81:00:00:19:00:03:78:08:0E:00:6C:00:FB:69:3B:00:00:0C:01:25:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
[UART] npi_procframe signal areq callback thread (invoked by read loop)
[-->] 32 bytes, subSys 0x44, cmdId 0x81, pData: 0x00 0x00 0x19 0x00 0x03 0x78 0x08 0x0E 0x00 0x6C 0x00 0xFB 0x69 0x3B 0x00 0x00 0x0C 0x01 0x25 0x01 0x00 0xBE 0xBE 0x52 0x26 0x07 0x00 0x00 0x00 0x03 0x78 0x1D
Dispatch AREQ to all active connections: #5.
[14:46:50.962,165] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 20:44:81:00:00:19:00:03:78:08:0E:00:6C:00:FB:69:3B:00:00:0C:01:25:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
...sent 35 bytes to Client #5
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x44, Cmd ID: 0x81, length: 32
[14:47:20.957,347] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 20:44:81:00:00:19:00:03:78:08:0E:00:6C:00:7E:05:58:00:00:0C:01:26:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
[UART] npi_procframe signal areq callback thread (invoked by read loop)
[-->] 32 bytes, subSys 0x44, cmdId 0x81, pData: 0x00 0x00 0x19 0x00 0x03 0x78 0x08 0x0E 0x00 0x6C 0x00 0x7E 0x05 0x58 0x00 0x00 0x0C 0x01 0x26 0x01 0x00 0xBE 0xBE 0x52 0x26 0x07 0x00 0x00 0x00 0x03 0x78 0x1D
Dispatch AREQ to all active connections: #5.
[14:47:20.959,488] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 20:44:81:00:00:19:00:03:78:08:0E:00:6C:00:7E:05:58:00:00:0C:01:26:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
...sent 35 bytes to Client #5
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x44, Cmd ID: 0x81, length: 32
[14:48:20.950,046] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 20:44:81:00:00:19:00:03:78:08:0E:00:6C:00:05:3C:91:00:00:0C:01:28:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
[UART] npi_procframe signal areq callback thread (invoked by read loop)
[-->] 32 bytes, subSys 0x44, cmdId 0x81, pData: 0x00 0x00 0x19 0x00 0x03 0x78 0x08 0x0E 0x00 0x6C 0x00 0x05 0x3C 0x91 0x00 0x00 0x0C 0x01 0x28 0x01 0x00 0xBE 0xBE 0x52 0x26 0x07 0x00 0x00 0x00 0x03 0x78 0x1D
Dispatch AREQ to all active connections: #5.
[14:48:20.951,216] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 20:44:81:00:00:19:00:03:78:08:0E:00:6C:00:05:3C:91:00:00:0C:01:28:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
...sent 35 bytes to Client #5
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x44, Cmd ID: 0x81, length: 32
[14:48:50.939,635] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 20:44:81:00:00:19:00:03:78:08:0E:00:72:00:A5:D5:AD:00:00:0C:01:29:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
[UART] npi_procframe signal areq callback thread (invoked by read loop)
[-->] 32 bytes, subSys 0x44, cmdId 0x81, pData: 0x00 0x00 0x19 0x00 0x03 0x78 0x08 0x0E 0x00 0x72 0x00 0xA5 0xD5 0xAD 0x00 0x00 0x0C 0x01 0x29 0x01 0x00 0xBE 0xBE 0x52 0x26 0x07 0x00 0x00 0x00 0x03 0x78 0x1D
Dispatch AREQ to all active connections: #5.
[14:48:50.941,849] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 20:44:81:00:00:19:00:03:78:08:0E:00:72:00:A5:D5:AD:00:00:0C:01:29:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
...sent 35 bytes to Client #5
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x44, Cmd ID: 0x81, length: 32
[14:49:20.939,403] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 20:44:81:00:00:19:00:03:78:08:0E:00:75:00:C0:71:CA:00:00:0C:01:2A:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
[UART] npi_procframe signal areq callback thread (invoked by read loop)
[-->] 32 bytes, subSys 0x44, cmdId 0x81, pData: 0x00 0x00 0x19 0x00 0x03 0x78 0x08 0x0E 0x00 0x75 0x00 0xC0 0x71 0xCA 0x00 0x00 0x0C 0x01 0x2A 0x01 0x00 0xBE 0xBE 0x52 0x26 0x07 0x00 0x00 0x00 0x03 0x78 0x1D
Dispatch AREQ to all active connections: #5.
[14:49:20.941,654] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 20:44:81:00:00:19:00:03:78:08:0E:00:75:00:C0:71:CA:00:00:0C:01:2A:01:00:BE:BE:52:26:07:00:00:00:03:78:1D
...sent 35 bytes to Client #5

    你好，我目前已经升级到SDK5.10版本，但是我在假期运行过程中还是会出现以下问题

    [14:39:52.358,497] [Z_STACK/LSTN] INFO : [MUTEX] SRSP Cond Wait timed out!
    [14:39:52.358,988] [Z_STACK/LSTN] ERROR : SRSP Cond Wait timed out!
    [14:39:52.359,426] [Z_STACK/LSTN] INFO : [MUTEX] Unlock SRSP Mutex
    [14:39:52.359,862] [Z_STACK/LSTN] ERROR : apicSendSynchData() failed getting response

    附件是我抓取的log，目前还没解决

  • 0 回复 user4447611
    Guru 109510 points
    發生問題的時候如果只重起Linux GW可以重新運行的起來嗎？
  • 0 回复 YiKai Chen
    Prodigy 140 points
    重启Linux GW是可以重新運行起来，但是一段时间后就又会出现
  • 0 回复 user4447611
    Guru 109510 points
    這樣感覺上是Linux GW UART的問題而不是ZNP的問題，你應該要查你的Linux GW UART