[21:58:24.890,883] [NWK_MGR/LSTN] PKT_HEX: [                           NWK_MGR>>>>>>>>>>>>>>>>>>>>CON009] [ucst] 12:00:72:0B:08:0B:10:01:18:0D:20:E8:66:29:34:57:49:01:00:4B:12:00
[21:58:24.890,933] [NWK_MGR/LSTN] PKTTYPE: [                           NWK_MGR>>>>>>>>>>>>>>>>>>>>CON009] NwkZigbeeNwkInfoCnf
[21:58:24.890,981] [NWK_MGR/LSTN] PKTBODY:                                                          cmdId = NWK_ZIGBEE_NWK_INFO_CNF
[21:58:24.891,021] [NWK_MGR/LSTN] PKTBODY:                                                          status = NWK_UP
[21:58:24.891,057] [NWK_MGR/LSTN] PKTBODY:                                                          nwkChannel = 0x0000000D (13)
[21:58:24.891,092] [NWK_MGR/LSTN] PKTBODY:                                                          panId = 0x00003368 (13160)
[21:58:24.891,129] [NWK_MGR/LSTN] PKTBODY:                                                          extPanId = 00:12:4B:00:01:49:57:34
[21:58:24.891,319] [NWK_MGR/LSTN] INFO   : ...sent 22 bytes to Client
[21:58:24.891,378] [NWK_MGR/LSTN] INFO   : !Done
[21:58:24.894,906] [Z_STACK/LSTN] INFO   : ...sent 52 bytes to Client
[21:58:24.898,749] [Z_STACK/LSTN] INFO   : !Done
[22:00:10.136,806] [Z_STACK/LSTN] INFO   : Receive message...
[22:00:10.136,952] [Z_STACK/LSTN] INFO   : zstackpb zspbHandlePbCb: subsystemID:31, cmdId:43
[22:00:10.137,014] [Z_STACK/LSTN] INFO   : preparing to send 0 bytes, subSys 0x05, cmdId 0x50, pData:
[22:00:10.137,049] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[22:00:10.137,099] [Z_STACK/LSTN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 00:25:50
[22:00:10.137,149] [Z_STACK/LSTN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 00:25:50
[22:00:10.137,346] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...
[22:00:10.137,397] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[22:00:10.137,426] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[22:00:10.144,543] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 00:25:50
[22:00:10.135,452] [NWK_MGR/LSTN] INFO   : Receive message...
[22:00:10.135,876] [NWK_MGR/LSTN] PKT_HEX: [                           NWK_MGR<<<<<<<<<<<<<<<<<<<<CON009] [read] 07:00:12:0C:08:0C:10:02:18:B4:01
[22:00:10.135,953] [NWK_MGR/LSTN] PKTTYPE: [                           NWK_MGR<<<<<<<<<<<<<<<<<<<<CON009] NwkSetPermitJoinReq
[22:00:10.136,007] [NWK_MGR/LSTN] PKTBODY:                                                          cmdId = NWK_SET_PERMIT_JOIN_REQ
[22:00:10.136,048] [NWK_MGR/LSTN] PKTBODY:                                                          permitJoin = PERMIT_ALL
[22:00:10.136,084] [NWK_MGR/LSTN] PKTBODY:                                                          permitJoinTime = 0x000000B4 (180)
[22:00:10.136,126] [NWK_MGR/LSTN] MISC1  : Processing Set Permit Join Request.
[22:00:10.136,155] [NWK_MGR/LSTN] MISC1  : NwkMgr sendZdoMgmtPermitJoinReq: nwkaddr FFFC
[22:00:10.136,194] [NWK_MGR/LSTN] INFO   : preparing to send 11 bytes, subSys 0x11, cmdId 0x43, pData:
[22:00:10.136,225] [NWK_MGR/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[22:00:10.136,293] [NWK_MGR/LSTN] PKT_HEX: [                  Z_STACK<<NWK_MGR                  ] [SREQ] 0B:00:31:43:08:43:10:FC:FF:03:18:B4:01:20:01
[22:00:10.136,336] [NWK_MGR/LSTN] PKTTYPE: [                  Z_STACK<<NWK_MGR                  ] zdoMgmtPermitJoinReq
[22:00:10.136,382] [NWK_MGR/LSTN] PKTBODY:                                                          cmdID = ZDO_MGMT_PERMIT_JOIN_REQ
[22:00:10.136,423] [NWK_MGR/LSTN] PKTBODY:                                                          nwkAddr = 0x0000FFFC (65532)
[22:00:10.136,458] [NWK_MGR/LSTN] PKTBODY:                                                          duration = 0x000000B4 (180)
[22:00:10.136,491] [NWK_MGR/LSTN] PKTBODY:                                                          tcSignificance = 1
[22:00:10.149,543] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 18:65:50:00:00:09:68:33:00:00:34:57:49:01:00:4B:12:00:00:00:00:00:00:00:00:00:0D
[22:00:10.152,936] [Z_STACK/READ] INFO   : Received 24 bytes, subSys 0x65, cmdId 0x50
[22:00:10.153,076] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
[22:00:10.153,112] [Z_STACK/READ] INFO   : Client Read: (len 27):
[22:00:10.152,242] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 18:65:50:00:00:09:68:33:00:00:34:57:49:01:00:4B:12:00:00:00:00:00:00:00:00:00:0D
[22:00:10.157,808] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[22:00:10.157,960] [Z_STACK/LSTN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:5, cmdID:36, len::5
[22:00:10.158,012] [Z_STACK/LSTN] INFO   : preparing to send 5 bytes, subSys 0x05, cmdId 0x36, pData:
[22:00:10.158,045] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[22:00:10.158,110] [Z_STACK/LSTN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 05:25:36:02:00:00:B4:01
[22:00:10.158,170] [Z_STACK/LSTN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 05:25:36:02:00:00:B4:01
[22:00:10.158,379] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...
[22:00:10.158,431] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[22:00:10.158,459] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[22:00:10.159,977] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 05:25:36:02:00:00:B4:01
[22:00:10.163,015] [NWK_MGR/LSTN] INFO   : Waiting for synchronous response...
[22:00:10.163,165] [NWK_MGR/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[22:00:10.163,201] [NWK_MGR/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[22:00:10.166,456] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 01:65:36:00
[22:00:10.168,319] [Z_STACK/READ] INFO   : Received 1 bytes, subSys 0x65, cmdId 0x36
[22:00:10.168,445] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
[22:00:10.168,480] [Z_STACK/READ] INFO   : Client Read: (len 4):
[22:00:10.167,865] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 01:65:36:00
[22:00:10.172,704] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[22:00:10.172,868] [Z_STACK/LSTN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:5, cmdID:36, len::5
[22:00:10.172,915] [Z_STACK/LSTN] INFO   : preparing to send 5 bytes, subSys 0x05, cmdId 0x36, pData:
[22:00:10.172,947] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[22:00:10.173,012] [Z_STACK/LSTN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 05:25:36:02:FC:FF:B4:01
[22:00:10.173,073] [Z_STACK/LSTN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 05:25:36:02:FC:FF:B4:01
[22:00:10.173,281] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...
[22:00:10.173,333] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[22:00:10.173,362] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[22:00:10.177,324] [Z_STACK/READ] INFO   : Received 3 bytes, subSys 0x45, cmdId 0xB6
[22:00:10.177,448] [Z_STACK/READ] INFO   : RPC_CMD_AREQ cmdId: 0xB6
[22:00:10.177,483] [Z_STACK/READ] INFO   : [DBG] Allocated      @ 0xB6B004C8 (received  4 messages)...
[22:00:10.177,513] [Z_STACK/READ] INFO   : Filling new message (@ 0xB6B004C8)...
[22:00:10.177,581] [Z_STACK/HNDL] INFO   : [MUTEX] Mutex for AREQ unlocked
[22:00:10.177,624] [Z_STACK/HNDL] INFO   : [DBG] Processing     @ 0xB6B004C8
[22:00:10.177,652] [Z_STACK/HNDL] INFO   : [MUTEX] AREQ Calling asynchMsgCback (Handle)...
[22:00:10.177,678] [Z_STACK/HNDL] INFO   : [DBG] asyncCB: subSys:0x00000005, cmdId:0x000000B6, len:0x00000003, pData:0xB6B004D0
[22:00:10.177,710] [Z_STACK/HNDL] DEBUG  : znp_misc handleAsyncMsgs: Unrecognized cmdID:b6
[22:00:10.177,738] [Z_STACK/HNDL] INFO   : [MUTEX] AREQ (Handle) (message @ 0xB6B004C8)...
[22:00:10.177,765] [Z_STACK/HNDL] INFO   : [DBG] Clearing               @ 0xB6B004C8 (processed 4 messages)...
[22:00:10.177,793] [Z_STACK/HNDL] INFO   : [MUTEX] Wait for AREQ semaphore
[22:00:10.176,736] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 03:45:B6:00:00:00
[22:00:10.176,951] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 03:45:B6:00:00:00
[22:00:10.184,279] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 05:25:36:02:FC:FF:B4:01
[22:00:10.196,423] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 01:65:36:00
[22:00:10.196,843] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 01:65:36:00
[22:00:10.205,704] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 03:45:B6:00:00:00
[22:00:10.205,917] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 03:45:B6:00:00:00
[22:00:10.220,644] [Z_STACK/READ] INFO   : Received 1 bytes, subSys 0x65, cmdId 0x36
[22:00:10.220,803] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
[22:00:10.220,840] [Z_STACK/READ] INFO   : Client Read: (len 4):
[22:00:10.220,917] [Z_STACK/READ] INFO   : Received 3 bytes, subSys 0x45, cmdId 0xB6
[22:00:10.220,957] [Z_STACK/READ] INFO   : RPC_CMD_AREQ cmdId: 0xB6
[22:00:10.220,986] [Z_STACK/READ] INFO   : [DBG] Allocated      @ 0xB6B004D8 (received  5 messages)...
[22:00:10.221,013] [Z_STACK/READ] INFO   : Filling new message (@ 0xB6B004D8)...
[22:00:10.221,084] [Z_STACK/HNDL] INFO   : [MUTEX] Mutex for AREQ unlocked
[22:00:10.221,129] [Z_STACK/HNDL] INFO   : [DBG] Processing     @ 0xB6B004D8
[22:00:10.221,158] [Z_STACK/HNDL] INFO   : [MUTEX] AREQ Calling asynchMsgCback (Handle)...
[22:00:10.221,185] [Z_STACK/HNDL] INFO   : [DBG] asyncCB: subSys:0x00000005, cmdId:0x000000B6, len:0x00000003, pData:0xB6B004E0
[22:00:10.221,216] [Z_STACK/HNDL] DEBUG  : znp_misc handleAsyncMsgs: Unrecognized cmdID:b6
[22:00:10.221,244] [Z_STACK/HNDL] INFO   : [MUTEX] AREQ (Handle) (message @ 0xB6B004D8)...
[22:00:10.221,271] [Z_STACK/HNDL] INFO   : [DBG] Clearing               @ 0xB6B004D8 (processed 5 messages)...
[22:00:10.221,300] [Z_STACK/HNDL] INFO   : [MUTEX] Wait for AREQ semaphore
[22:00:10.223,403] [NWK_MGR/READ] INFO   : Received 4 bytes, subSys 0x71, cmdId 0xFA
[22:00:10.223,524] [NWK_MGR/READ] INFO   : [MUTEX] SRSP Cond signal set
[22:00:10.224,652] [NWK_MGR/READ] INFO   : Client Read: (len 8):
[22:00:10.225,546] [NWK_MGR/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[22:00:10.225,678] [NWK_MGR/LSTN] MISC1  : Sending ZigBee Generic Confirmation
[22:00:10.225,767] [NWK_MGR/LSTN] PKT_HEX: [                           NWK_MGR>>>>>>>>>>>>>>>>>>>>CON009] [ucst] 04:00:72:00:08:00:10:00
[22:00:10.225,817] [NWK_MGR/LSTN] PKTTYPE: [                           NWK_MGR>>>>>>>>>>>>>>>>>>>>CON009] NwkZigbeeGenericCnf
[22:00:10.225,863] [NWK_MGR/LSTN] PKTBODY:                                                          cmdId = ZIGBEE_GENERIC_CNF
[22:00:10.225,901] [NWK_MGR/LSTN] PKTBODY:                                                          status = STATUS_SUCCESS
[22:00:10.226,207] [NWK_MGR/LSTN] INFO   : ...sent 8 bytes to Client
[22:00:10.226,276] [NWK_MGR/LSTN] INFO   : !Done
[22:00:10.222,671] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[22:00:10.222,865] [Z_STACK/LSTN] PKT_HEX: [                  Z_STACK>>NWK_MGR                  ] [ucst] 04:00:71:FA:08:43:10:00
[22:00:10.222,937] [Z_STACK/LSTN] PKTTYPE: [                  Z_STACK>>NWK_MGR                  ] zstackDefaultRsp
[22:00:10.222,994] [Z_STACK/LSTN] PKTBODY:                                                          cmdID = ZDO_MGMT_PERMIT_JOIN_REQ
[22:00:10.223,034] [Z_STACK/LSTN] PKTBODY:                                                          status = ZSuccess
[22:00:10.230,755] [Z_STACK/LSTN] INFO   : ...sent 8 bytes to Client
[22:00:10.232,161] [Z_STACK/LSTN] INFO   : !Done
[22:00:12.247,890] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 0C:45:CA:A9:ED:E7:C9:27:21:00:4B:12:00:00:00
[22:00:12.256,701] [NWK_MGR/READ] INFO   : Received 18 bytes, subSys 0x51, cmdId 0x95
[22:00:12.256,823] [NWK_MGR/READ] INFO   : RPC_CMD_AREQ cmdId: 0x95
[22:00:12.256,858] [NWK_MGR/READ] INFO   : [DBG] Allocated      @ 0xB6B004F8 (received  3 messages)...
[22:00:12.256,888] [NWK_MGR/READ] INFO   : Filling new message (@ 0xB6B004F8)...
[22:00:12.250,717] [Z_STACK/READ] INFO   : Received 12 bytes, subSys 0x45, cmdId 0xCA
[22:00:12.250,853] [Z_STACK/READ] INFO   : RPC_CMD_AREQ cmdId: 0xCA
[22:00:12.250,891] [Z_STACK/READ] INFO   : [DBG] Allocated      @ 0xB6B01270 (received  6 messages)...
[22:00:12.250,920] [Z_STACK/READ] INFO   : Filling new message (@ 0xB6B01270)...
[22:00:12.255,287] [Z_STACK/HNDL] INFO   : [MUTEX] Mutex for AREQ unlocked
[22:00:12.255,393] [Z_STACK/HNDL] INFO   : [DBG] Processing     @ 0xB6B01270
[22:00:12.255,426] [Z_STACK/HNDL] INFO   : [MUTEX] AREQ Calling asynchMsgCback (Handle)...
[22:00:12.255,454] [Z_STACK/HNDL] INFO   : [DBG] asyncCB: subSys:0x00000005, cmdId:0x000000CA, len:0x0000000C, pData:0xB6B01278
[22:00:12.255,489] [Z_STACK/HNDL] INFO   : zstackpb Sending TC Device Ind: nwkAddr:0xEDA9, extAddr:0x00124B002127C9E7, parentAddr:0x0000
[22:00:12.255,735] [Z_STACK/HNDL] PKT_HEX: [                  Z_STACK>>NWK_MGR                  ] [ucst] 12:00:51:95:08:95:01:10:A9:DB:03:19:E7:C9:27:21:00:4B:12:00:20:00
[22:00:12.255,810] [Z_STACK/HNDL] PKTTYPE: [                  Z_STACK>>NWK_MGR                  ] zdoTcDeviceInd
[22:00:12.255,867] [Z_STACK/HNDL] PKTBODY:                                                          cmdID = <NOT_FOUND>
[22:00:12.255,909] [Z_STACK/HNDL] PKTBODY:                                                          nwkAddr = 0x0000EDA9 (60841)
[22:00:12.255,947] [Z_STACK/HNDL] PKTBODY:                                                          extendedAddr = 00:12:4B:00:21:27:C9:E7
[22:00:12.255,981] [Z_STACK/HNDL] PKTBODY:                                                          parentAddr = 0x00000000 (0)
[22:00:12.256,302] [Z_STACK/HNDL] INFO   : ...sent 22 bytes to Client
[22:00:12.256,373] [Z_STACK/HNDL] INFO   : [MUTEX] AREQ (Handle) (message @ 0xB6B01270)...
[22:00:12.256,405] [Z_STACK/HNDL] INFO   : [DBG] Clearing               @ 0xB6B01270 (processed 6 messages)...
[22:00:12.256,435] [Z_STACK/HNDL] INFO   : [MUTEX] Wait for AREQ semaphore
[22:00:12.259,510] [NWK_MGR/HNDL] INFO   : [MUTEX] Mutex for AREQ unlocked
[22:00:12.263,763] [NWK_MGR/HNDL] INFO   : [DBG] Processing     @ 0xB6B004F8
[22:00:12.263,834] [NWK_MGR/HNDL] INFO   : [MUTEX] AREQ Calling asynchMsgCback (Handle)...
[22:00:12.263,864] [NWK_MGR/HNDL] INFO   : [DBG] asyncCB: subSys:0x00000011, cmdId:0x00000095, len:0x00000012, pData:0xB6B00500
[22:00:12.263,916] [NWK_MGR/HNDL] MISC1  : Processing ZDO TC Device Ind: 00124B002127C9E7
[22:00:12.263,949] [NWK_MGR/HNDL] INFO   :
NwkMgr AddDevice State Machine Started on 0x00124b002127c9e7
[22:00:12.263,978] [NWK_MGR/HNDL] INFO   :   nwkAddr EDA9, parent 0000
[22:00:12.264,008] [NWK_MGR/HNDL] INFO   :
AddDevice: No state machines, extending list to 16
[22:00:12.264,038] [NWK_MGR/HNDL] INFO   :
AddDevice: Initiated new state machine
[22:00:12.264,072] [NWK_MGR/HNDL] INFO   : [MUTEX] AREQ (Handle) (message @ 0xB6B004F8)...
[22:00:12.264,100] [NWK_MGR/HNDL] INFO   : [DBG] Clearing               @ 0xB6B004F8 (processed 3 messages)...
[22:00:12.264,128] [NWK_MGR/HNDL] INFO   : [MUTEX] Wait for AREQ semaphore
[22:00:12.250,123] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 0C:45:CA:A9:ED:E7:C9:27:21:00:4B:12:00:00:00
[22:00:12.646,644] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 0D:45:C1:A9:ED:A9:ED:E7:C9:27:21:00:4B:12:00:8E
[22:00:12.646,887] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 0D:45:C1:A9:ED:A9:ED:E7:C9:27:21:00:4B:12:00:8E
[22:00:12.647,406] [Z_STACK/READ] INFO   : Received 13 bytes, subSys 0x45, cmdId 0xC1
[22:00:12.647,517] [Z_STACK/READ] INFO   : RPC_CMD_AREQ cmdId: 0xC1
[22:00:12.647,550] [Z_STACK/READ] INFO   : [DBG] Allocated      @ 0xB6B01288 (received  7 messages)...
[22:00:12.647,674] [Z_STACK/READ] INFO   : Filling new message (@ 0xB6B01288)...
[22:00:12.650,796] [NWK_MGR/READ] INFO   : Received 31 bytes, subSys 0x51, cmdId 0x48
[22:00:12.650,919] [NWK_MGR/READ] INFO   : RPC_CMD_AREQ cmdId: 0x48
[22:00:12.650,953] [NWK_MGR/READ] INFO   : [DBG] Allocated      @ 0xB6B00518 (received  4 messages)...
[22:00:12.650,981] [NWK_MGR/READ] INFO   : Filling new message (@ 0xB6B00518)...
[22:00:12.656,940] [NWK_MGR/HNDL] INFO   : [MUTEX] Mutex for AREQ unlocked
[22:00:12.657,092] [NWK_MGR/HNDL] INFO   : [DBG] Processing     @ 0xB6B00518
[22:00:12.657,130] [NWK_MGR/HNDL] INFO   : [MUTEX] AREQ Calling asynchMsgCback (Handle)...
[22:00:12.657,158] [NWK_MGR/HNDL] INFO   : [DBG] asyncCB: subSys:0x00000011, cmdId:0x00000048, len:0x0000001F, pData:0xB6B00520
[22:00:12.657,215] [NWK_MGR/HNDL] MISC1  : NwkMgr processZdoDeviceAnnounce: ieeeaddr 00124B002127C9E7, nwkaddr EDA9, capInfo 0E
[22:00:12.657,254] [NWK_MGR/HNDL] INFO   :
AddDevice: Retrying state 1, remaining tries: 4
[22:00:12.657,287] [NWK_MGR/HNDL] MISC1  : NwkMgr sendZdoIeeeAddrReq: ieeeaddr 0000
[22:00:12.657,328] [NWK_MGR/HNDL] INFO   : preparing to send 8 bytes, subSys 0x11, cmdId 0x31, pData:
[22:00:12.657,359] [NWK_MGR/HNDL] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[22:00:12.657,431] [NWK_MGR/HNDL] PKT_HEX: [                  Z_STACK<<NWK_MGR                  ] [SREQ] 08:00:31:31:08:31:10:00:18:00:20:00
[22:00:12.657,480] [NWK_MGR/HNDL] PKTTYPE: [                  Z_STACK<<NWK_MGR                  ] zdoIeeeAddrReq
[22:00:12.657,528] [NWK_MGR/HNDL] PKTBODY:                                                          cmdID = ZDO_IEEE_ADDR_REQ
[22:00:12.657,567] [NWK_MGR/HNDL] PKTBODY:                                                          nwkAddr = 0x00000000 (0)
[22:00:12.657,601] [NWK_MGR/HNDL] PKTBODY:                                                          type = SINGLE_DEVICE
[22:00:12.657,635] [NWK_MGR/HNDL] PKTBODY:                                                          startIndex = 0x00000000 (0)
[22:00:12.657,859] [NWK_MGR/HNDL] INFO   : Waiting for synchronous response...
[22:00:12.657,912] [NWK_MGR/HNDL] INFO   : [MUTEX] Lock SRSP Mutex
[22:00:12.657,940] [NWK_MGR/HNDL] INFO   : [MUTEX] Wait for SRSP Cond signal...
[22:00:12.649,549] [Z_STACK/HNDL] INFO   : [MUTEX] Mutex for AREQ unlocked
[22:00:12.649,672] [Z_STACK/HNDL] INFO   : [DBG] Processing     @ 0xB6B01288
[22:00:12.649,709] [Z_STACK/HNDL] INFO   : [MUTEX] AREQ Calling asynchMsgCback (Handle)...
[22:00:12.649,738] [Z_STACK/HNDL] INFO   : [DBG] asyncCB: subSys:0x00000005, cmdId:0x000000C1, len:0x0000000D, pData:0xB6B01290
[22:00:12.649,773] [Z_STACK/HNDL] INFO   : zstackpb Sending Device Announce Ind
[22:00:12.649,918] [Z_STACK/HNDL] PKT_HEX: [                  Z_STACK>>NWK_MGR                  ] [ucst] 1F:00:51:48:08:48:10:A9:DB:03:18:A9:DB:03:21:E7:C9:27:21:00:4B:12:00:2A:0A:08:00:10:01:18:01:20:01:28:00
[22:00:12.649,976] [Z_STACK/HNDL] PKTTYPE: [                  Z_STACK>>NWK_MGR                  ] zdoDeviceAnnounceInd
[22:00:12.650,034] [Z_STACK/HNDL] PKTBODY:                                                          cmdID = ZDO_DEVICE_ANNOUNCE
[22:00:12.650,075] [Z_STACK/HNDL] PKTBODY:                                                          srcAddr = 0x0000EDA9 (60841)
[22:00:12.650,111] [Z_STACK/HNDL] PKTBODY:                                                          devAddr = 0x0000EDA9 (60841)
[22:00:12.650,148] [Z_STACK/HNDL] PKTBODY:                                                          devExtAddr = 00:12:4B:00:21:27:C9:E7
[22:00:12.650,182] [Z_STACK/HNDL] PKTBODY:                                                          capInfo :
[22:00:12.650,213] [Z_STACK/HNDL] PKTBODY:                                                            panCoord = 0
[22:00:12.650,300] [Z_STACK/HNDL] PKTBODY:                                                            ffd = 1
[22:00:12.650,335] [Z_STACK/HNDL] PKTBODY:                                                            mainsPower = 1
[22:00:12.650,370] [Z_STACK/HNDL] PKTBODY:                                                            rxOnWhenIdle = 1
[22:00:12.650,403] [Z_STACK/HNDL] PKTBODY:                                                            security = 0
[22:00:12.660,942] [Z_STACK/LSTN] INFO   : Receive message...
[22:00:12.665,817] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 04:25:01:00:00:00:00
[22:00:12.664,946] [Z_STACK/LSTN] INFO   : zstackpb zspbHandlePbCb: subsystemID:31, cmdId:31
[22:00:12.665,088] [Z_STACK/LSTN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:5, cmdID:1, len::4
[22:00:12.665,134] [Z_STACK/LSTN] INFO   : preparing to send 4 bytes, subSys 0x05, cmdId 0x01, pData:
[22:00:12.665,166] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[22:00:12.665,228] [Z_STACK/LSTN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 04:25:01:00:00:00:00
[22:00:12.665,285] [Z_STACK/LSTN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 04:25:01:00:00:00:00
[22:00:12.665,537] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...
[22:00:12.665,592] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[22:00:12.665,621] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[22:00:12.668,232] [Z_STACK/HNDL] INFO   : ...sent 35 bytes to Client
[22:00:12.668,384] [Z_STACK/HNDL] INFO   : [MUTEX] AREQ (Handle) (message @ 0xB6B01288)...
[22:00:12.668,427] [Z_STACK/HNDL] INFO   : [DBG] Clearing               @ 0xB6B01288 (processed 7 messages)...
[22:00:12.668,457] [Z_STACK/HNDL] INFO   : [MUTEX] Wait for AREQ semaphore
[22:00:12.674,183] [NWK_MGR/READ] INFO   : Received 4 bytes, subSys 0x71, cmdId 0xFA
[22:00:12.674,291] [NWK_MGR/READ] INFO   : [MUTEX] SRSP Cond signal set
[22:00:12.674,324] [NWK_MGR/READ] INFO   : Client Read: (len 8):
[22:00:12.672,559] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 01:65:01:00
[22:00:12.672,773] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 01:65:01:00
[22:00:12.678,733] [NWK_MGR/HNDL] INFO   : [MUTEX] Unlock SRSP Mutex
[22:00:12.678,914] [NWK_MGR/HNDL] INFO   : [MUTEX] AREQ (Handle) (message @ 0xB6B00518)...
[22:00:12.678,961] [NWK_MGR/HNDL] INFO   : [DBG] Clearing               @ 0xB6B00518 (processed 4 messages)...
[22:00:12.678,991] [NWK_MGR/HNDL] INFO   : [MUTEX] Wait for AREQ semaphore
[22:00:12.683,493] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 0D:45:81:00:34:57:49:01:00:4B:12:00:00:00:00:00
[22:00:12.683,862] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 0D:45:81:00:34:57:49:01:00:4B:12:00:00:00:00:00
[22:00:12.673,241] [Z_STACK/READ] INFO   : Received 1 bytes, subSys 0x65, cmdId 0x01
[22:00:12.673,376] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
[22:00:12.673,412] [Z_STACK/READ] INFO   : Client Read: (len 4):
[22:00:12.673,509] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[22:00:12.673,611] [Z_STACK/LSTN] PKT_HEX: [                  Z_STACK>>NWK_MGR                  ] [ucst] 04:00:71:FA:08:31:10:00
[22:00:12.673,674] [Z_STACK/LSTN] PKTTYPE: [                  Z_STACK>>NWK_MGR                  ] zstackDefaultRsp
[22:00:12.673,729] [Z_STACK/LSTN] PKTBODY:                                                          cmdID = ZDO_IEEE_ADDR_REQ
[22:00:12.673,771] [Z_STACK/LSTN] PKTBODY:                                                          status = ZSuccess
[22:00:12.673,979] [Z_STACK/LSTN] INFO   : ...sent 8 bytes to Client
[22:00:12.674,038] [Z_STACK/LSTN] INFO   : !Done
[22:00:12.716,890] [Z_STACK/READ] INFO   : Received 13 bytes, subSys 0x45, cmdId 0x81
[22:00:12.717,051] [Z_STACK/READ] INFO   : RPC_CMD_AREQ cmdId: 0x81
[22:00:12.717,089] [Z_STACK/READ] INFO   : [DBG] Allocated      @ 0xB6B01288 (received  8 messages)...
[22:00:12.717,118] [Z_STACK/READ] INFO   : Filling new message (@ 0xB6B01288)...
[22:00:12.717,418] [Z_STACK/HNDL] INFO   : [MUTEX] Mutex for AREQ unlocked
[22:00:12.717,497] [Z_STACK/HNDL] INFO   : [DBG] Processing     @ 0xB6B01288
[22:00:12.717,530] [Z_STACK/HNDL] INFO   : [MUTEX] AREQ Calling asynchMsgCback (Handle)...
[22:00:12.717,559] [Z_STACK/HNDL] INFO   : [DBG] asyncCB: subSys:0x00000005, cmdId:0x00000081, len:0x0000000D, pData:0xB6B01290
[22:00:12.717,591] [Z_STACK/HNDL] DEBUG  : znp_misc handleAsyncMsgs: Unrecognized cmdID:81
[22:00:12.717,619] [Z_STACK/HNDL] INFO   : [MUTEX] AREQ (Handle) (message @ 0xB6B01288)...
[22:00:12.717,646] [Z_STACK/HNDL] INFO   : [DBG] Clearing               @ 0xB6B01288 (processed 8 messages)...
[22:00:12.717,675] [Z_STACK/HNDL] INFO   : [MUTEX] Wait for AREQ semaphore
[22:00:21.608,769] [Z_STACK/LSTN] INFO   : Receive message...
[22:00:21.608,952] [Z_STACK/LSTN] INFO   : zstackpb zspbHandlePbCb: subsystemID:31, cmdId:15
[22:00:21.609,011] [Z_STACK/LSTN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:5, cmdID:45, len::4
[22:00:21.609,048] [Z_STACK/LSTN] INFO   : preparing to send 4 bytes, subSys 0x05, cmdId 0x45, pData:
[22:00:21.609,079] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[22:00:21.609,140] [Z_STACK/LSTN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 04:25:45:00:00:00:05
[22:00:21.609,197] [Z_STACK/LSTN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 04:25:45:00:00:00:05
[22:00:21.609,516] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...
[22:00:21.609,575] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[22:00:21.609,604] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[22:00:21.612,573] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 04:25:45:00:00:00:05
[22:00:21.616,215] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 01:65:45:00
[22:00:21.602,473] [NWK_MGR/MAIN] INFO   :
AddDevice: Retrying state 2, remaining tries: 3
[22:00:21.602,659] [NWK_MGR/MAIN] MISC1  : NwkMgr MOT sendNwkRouteReq
[22:00:21.602,710] [NWK_MGR/MAIN] INFO   : preparing to send 6 bytes, subSys 0x11, cmdId 0x15, pData:
[22:00:21.602,743] [NWK_MGR/MAIN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[22:00:21.602,815] [NWK_MGR/MAIN] PKT_HEX: [                  Z_STACK<<NWK_MGR                  ] [SREQ] 06:00:31:15:08:15:10:00:30:05
[22:00:21.602,864] [NWK_MGR/MAIN] PKTTYPE: [                  Z_STACK<<NWK_MGR                  ] devNwkRouteReq
[22:00:21.602,916] [NWK_MGR/MAIN] PKTBODY:                                                          cmdID = DEV_NWK_ROUTE_REQ
[22:00:21.602,955] [NWK_MGR/MAIN] PKTBODY:                                                          dstAddr = 0x00000000 (0)
[22:00:21.602,996] [NWK_MGR/MAIN] PKTBODY:                                                          radius = 0x00000005 (5)
[22:00:21.603,336] [NWK_MGR/MAIN] INFO   : Waiting for synchronous response...
[22:00:21.603,378] [NWK_MGR/MAIN] INFO   : [MUTEX] Lock SRSP Mutex
[22:00:21.603,406] [NWK_MGR/MAIN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[22:00:21.620,454] [Z_STACK/READ] INFO   : Received 1 bytes, subSys 0x65, cmdId 0x45
[22:00:21.620,589] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
[22:00:21.620,625] [Z_STACK/READ] INFO   : Client Read: (len 4):
[22:00:21.619,869] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 01:65:45:00
[22:00:21.623,984] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[22:00:21.624,190] [Z_STACK/LSTN] PKT_HEX: [                  Z_STACK>>NWK_MGR                  ] [ucst] 04:00:71:FA:08:15:10:00
[22:00:21.624,262] [Z_STACK/LSTN] PKTTYPE: [                  Z_STACK>>NWK_MGR                  ] zstackDefaultRsp
[22:00:21.624,317] [Z_STACK/LSTN] PKTBODY:                                                          cmdID = DEV_NWK_ROUTE_REQ
[22:00:21.624,358] [Z_STACK/LSTN] PKTBODY:                                                          status = ZSuccess
[22:00:21.624,799] [NWK_MGR/READ] INFO   : Received 4 bytes, subSys 0x71, cmdId 0xFA
[22:00:21.624,929] [NWK_MGR/READ] INFO   : [MUTEX] SRSP Cond signal set
[22:00:21.624,963] [NWK_MGR/READ] INFO   : Client Read: (len 8):
[22:00:21.630,334] [NWK_MGR/MAIN] INFO   : [MUTEX] Unlock SRSP Mutex
[22:00:21.630,502] [NWK_MGR/MAIN] MISC1  : NwkMgr sendZdoIeeeAddrReq: ieeeaddr 0000
[22:00:21.630,559] [NWK_MGR/MAIN] INFO   : preparing to send 8 bytes, subSys 0x11, cmdId 0x31, pData:
[22:00:21.630,594] [NWK_MGR/MAIN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[22:00:21.630,666] [NWK_MGR/MAIN] PKT_HEX: [                  Z_STACK<<NWK_MGR                  ] [SREQ] 08:00:31:31:08:31:10:00:18:00:20:00
[22:00:21.630,717] [NWK_MGR/MAIN] PKTTYPE: [                  Z_STACK<<NWK_MGR                  ] zdoIeeeAddrReq
[22:00:21.630,767] [NWK_MGR/MAIN] PKTBODY:                                                          cmdID = ZDO_IEEE_ADDR_REQ
[22:00:21.630,806] [NWK_MGR/MAIN] PKTBODY:                                                          nwkAddr = 0x00000000 (0)
[22:00:21.630,843] [NWK_MGR/MAIN] PKTBODY:                                                          type = SINGLE_DEVICE
[22:00:21.630,878] [NWK_MGR/MAIN] PKTBODY:                                                          startIndex = 0x00000000 (0)
[22:00:21.631,099] [NWK_MGR/MAIN] INFO   : Waiting for synchronous response...
[22:00:21.631,150] [NWK_MGR/MAIN] INFO   : [MUTEX] Lock SRSP Mutex
[22:00:21.631,179] [NWK_MGR/MAIN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[22:00:21.635,460] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 04:25:01:00:00:00:00
[22:00:21.634,519] [Z_STACK/LSTN] INFO   : ...sent 8 bytes to Client
[22:00:21.634,666] [Z_STACK/LSTN] INFO   : !Done
[22:00:21.634,740] [Z_STACK/LSTN] INFO   : Receive message...
[22:00:21.634,817] [Z_STACK/LSTN] INFO   : zstackpb zspbHandlePbCb: subsystemID:31, cmdId:31
[22:00:21.634,865] [Z_STACK/LSTN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:5, cmdID:1, len::4
[22:00:21.634,899] [Z_STACK/LSTN] INFO   : preparing to send 4 bytes, subSys 0x05, cmdId 0x01, pData:
[22:00:21.634,930] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[22:00:21.634,990] [Z_STACK/LSTN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 04:25:01:00:00:00:00
[22:00:21.635,047] [Z_STACK/LSTN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 04:25:01:00:00:00:00
[22:00:21.641,205] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...
[22:00:21.642,444] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 01:65:01:00
[22:00:21.645,641] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 01:65:01:00
[22:00:21.649,628] [Z_STACK/READ] INFO   : Received 1 bytes, subSys 0x65, cmdId 0x01
[22:00:21.649,961] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
[22:00:21.650,010] [Z_STACK/READ] INFO   : Client Read: (len 4):
[22:00:21.651,286] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 0D:45:81:00:34:57:49:01:00:4B:12:00:00:00:00:00
[22:00:21.651,518] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 0D:45:81:00:34:57:49:01:00:4B:12:00:00:00:00:00
[22:00:21.652,802] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[22:00:21.655,740] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[22:00:21.656,802] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[22:00:21.657,711] [Z_STACK/LSTN] PKT_HEX: [                  Z_STACK>>NWK_MGR                  ] [ucst] 04:00:71:FA:08:31:10:00
[22:00:21.660,748] [Z_STACK/LSTN] PKTTYPE: [                  Z_STACK>>NWK_MGR                  ] zstackDefaultRsp
[22:00:21.662,095] [Z_STACK/LSTN] PKTBODY:                                                          cmdID = ZDO_IEEE_ADDR_REQ
[22:00:21.663,942] [Z_STACK/LSTN] PKTBODY:                                                          status = ZSuccess
[22:00:21.665,261] [NWK_MGR/READ] INFO   : Received 4 bytes, subSys 0x71, cmdId 0xFA
[22:00:21.665,401] [NWK_MGR/READ] INFO   : [MUTEX] SRSP Cond signal set
[22:00:21.665,437] [NWK_MGR/READ] INFO   : Client Read: (len 8):
[22:00:21.668,300] [NWK_MGR/MAIN] INFO   : [MUTEX] Unlock SRSP Mutex
[22:00:21.671,384] [Z_STACK/LSTN] INFO   : ...sent 8 bytes to Client
[22:00:21.672,595] [Z_STACK/LSTN] INFO   : !Done
[22:00:21.688,367] [Z_STACK/READ] INFO   : Received 13 bytes, subSys 0x45, cmdId 0x81
[22:00:21.688,539] [Z_STACK/READ] INFO   : RPC_CMD_AREQ cmdId: 0x81
[22:00:21.688,578] [Z_STACK/READ] INFO   : [DBG] Allocated      @ 0xB6B01288 (received  9 messages)...
[22:00:21.688,608] [Z_STACK/READ] INFO   : Filling new message (@ 0xB6B01288)...
[22:00:21.688,701] [Z_STACK/HNDL] INFO   : [MUTEX] Mutex for AREQ unlocked
[22:00:21.688,749] [Z_STACK/HNDL] INFO   : [DBG] Processing     @ 0xB6B01288
[22:00:21.688,778] [Z_STACK/HNDL] INFO   : [MUTEX] AREQ Calling asynchMsgCback (Handle)...
[22:00:21.688,806] [Z_STACK/HNDL] INFO   : [DBG] asyncCB: subSys:0x00000005, cmdId:0x00000081, len:0x0000000D, pData:0xB6B01290
[22:00:21.688,838] [Z_STACK/HNDL] DEBUG  : znp_misc handleAsyncMsgs: Unrecognized cmdID:81
[22:00:21.688,866] [Z_STACK/HNDL] INFO   : [MUTEX] AREQ (Handle) (message @ 0xB6B01288)...
[22:00:21.688,893] [Z_STACK/HNDL] INFO   : [DBG] Clearing               @ 0xB6B01288 (processed 9 messages)...
[22:00:21.688,923] [Z_STACK/HNDL] INFO   : [MUTEX] Wait for AREQ semaphore
[22:00:30.680,773] [Z_STACK/LSTN] INFO   : Receive message...
[22:00:30.680,905] [Z_STACK/LSTN] INFO   : zstackpb zspbHandlePbCb: subsystemID:31, cmdId:15
[22:00:30.680,961] [Z_STACK/LSTN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:5, cmdID:45, len::4
[22:00:30.680,996] [Z_STACK/LSTN] INFO   : preparing to send 4 bytes, subSys 0x05, cmdId 0x45, pData:
[22:00:30.681,026] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[22:00:30.681,085] [Z_STACK/LSTN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 04:25:45:00:00:00:05
[22:00:30.681,140] [Z_STACK/LSTN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 04:25:45:00:00:00:05
[22:00:30.681,301] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...
[22:00:30.681,344] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[22:00:30.681,372] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[22:00:30.687,895] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 04:25:45:00:00:00:05
[22:00:30.679,844] [NWK_MGR/MAIN] INFO   :
AddDevice: Retrying state 2, remaining tries: 2
[22:00:30.680,028] [NWK_MGR/MAIN] MISC1  : NwkMgr MOT sendNwkRouteReq
[22:00:30.680,079] [NWK_MGR/MAIN] INFO   : preparing to send 6 bytes, subSys 0x11, cmdId 0x15, pData:
[22:00:30.680,111] [NWK_MGR/MAIN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[22:00:30.680,183] [NWK_MGR/MAIN] PKT_HEX: [                  Z_STACK<<NWK_MGR                  ] [SREQ] 06:00:31:15:08:15:10:00:30:05
[22:00:30.680,232] [NWK_MGR/MAIN] PKTTYPE: [                  Z_STACK<<NWK_MGR                  ] devNwkRouteReq
[22:00:30.680,282] [NWK_MGR/MAIN] PKTBODY:                                                          cmdID = DEV_NWK_ROUTE_REQ
[22:00:30.680,321] [NWK_MGR/MAIN] PKTBODY:                                                          dstAddr = 0x00000000 (0)
[22:00:30.680,362] [NWK_MGR/MAIN] PKTBODY:                                                          radius = 0x00000005 (5)
[22:00:30.692,263] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 01:65:45:00
[22:00:30.696,199] [Z_STACK/READ] INFO   : Received 1 bytes, subSys 0x65, cmdId 0x45
[22:00:30.696,325] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
[22:00:30.696,360] [Z_STACK/READ] INFO   : Client Read: (len 4):
[22:00:30.695,664] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 01:65:45:00
[22:00:30.700,175] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[22:00:30.700,382] [Z_STACK/LSTN] PKT_HEX: [                  Z_STACK>>NWK_MGR                  ] [ucst] 04:00:71:FA:08:15:10:00
[22:00:30.700,456] [Z_STACK/LSTN] PKTTYPE: [                  Z_STACK>>NWK_MGR                  ] zstackDefaultRsp
[22:00:30.700,512] [Z_STACK/LSTN] PKTBODY:                                                          cmdID = DEV_NWK_ROUTE_REQ
[22:00:30.700,554] [Z_STACK/LSTN] PKTBODY:                                                          status = ZSuccess
[22:00:30.700,769] [Z_STACK/LSTN] INFO   : ...sent 8 bytes to Client
[22:00:30.700,831] [Z_STACK/LSTN] INFO   : !Done
[22:00:30.704,364] [NWK_MGR/READ] INFO   : Received 4 bytes, subSys 0x71, cmdId 0xFA
[22:00:30.704,524] [NWK_MGR/READ] INFO   : [MUTEX] SRSP Cond signal set
[22:00:30.704,558] [NWK_MGR/READ] INFO   : Client Read: (len 8):
[22:00:30.707,252] [NWK_MGR/MAIN] INFO   : Waiting for synchronous response...
[22:00:30.708,799] [NWK_MGR/MAIN] INFO   : [MUTEX] Lock SRSP Mutex
[22:00:30.711,393] [NWK_MGR/MAIN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[22:00:30.713,636] [Z_STACK/LSTN] INFO   : Receive message...
[22:00:30.713,790] [Z_STACK/LSTN] INFO   : zstackpb zspbHandlePbCb: subsystemID:31, cmdId:31
[22:00:30.713,846] [Z_STACK/LSTN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:5, cmdID:1, len::4
[22:00:30.713,882] [Z_STACK/LSTN] INFO   : preparing to send 4 bytes, subSys 0x05, cmdId 0x01, pData:
[22:00:30.713,913] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[22:00:30.714,136] [Z_STACK/LSTN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 04:25:01:00:00:00:00
[22:00:30.714,205] [Z_STACK/LSTN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 04:25:01:00:00:00:00
[22:00:30.714,389] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...
[22:00:30.714,435] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[22:00:30.714,464] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[22:00:30.712,818] [NWK_MGR/MAIN] INFO   : [MUTEX] Unlock SRSP Mutex
[22:00:30.712,965] [NWK_MGR/MAIN] MISC1  : NwkMgr sendZdoIeeeAddrReq: ieeeaddr 0000
[22:00:30.713,019] [NWK_MGR/MAIN] INFO   : preparing to send 8 bytes, subSys 0x11, cmdId 0x31, pData:
[22:00:30.713,053] [NWK_MGR/MAIN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[22:00:30.713,125] [NWK_MGR/MAIN] PKT_HEX: [                  Z_STACK<<NWK_MGR                  ] [SREQ] 08:00:31:31:08:31:10:00:18:00:20:00
[22:00:30.713,177] [NWK_MGR/MAIN] PKTTYPE: [                  Z_STACK<<NWK_MGR                  ] zdoIeeeAddrReq
[22:00:30.713,225] [NWK_MGR/MAIN] PKTBODY:                                                          cmdID = ZDO_IEEE_ADDR_REQ
[22:00:30.713,266] [NWK_MGR/MAIN] PKTBODY:                                                          nwkAddr = 0x00000000 (0)
[22:00:30.713,302] [NWK_MGR/MAIN] PKTBODY:                                                          type = SINGLE_DEVICE
[22:00:30.713,336] [NWK_MGR/MAIN] PKTBODY:                                                          startIndex = 0x00000000 (0)
[22:00:30.720,808] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 04:25:01:00:00:00:00
[22:00:30.723,943] [NWK_MGR/MAIN] INFO   : Waiting for synchronous response...
[22:00:30.725,030] [NWK_MGR/MAIN] INFO   : [MUTEX] Lock SRSP Mutex
[22:00:30.726,049] [NWK_MGR/MAIN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[22:00:30.728,169] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 01:65:01:00
[22:00:30.729,356] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 01:65:01:00
[22:00:30.732,168] [Z_STACK/READ] INFO   : Received 1 bytes, subSys 0x65, cmdId 0x01
[22:00:30.732,316] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
[22:00:30.732,354] [Z_STACK/READ] INFO   : Client Read: (len 4):
[22:00:30.735,439] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[22:00:30.739,082] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 0D:45:81:00:34:57:49:01:00:4B:12:00:00:00:1E:00
[22:00:30.739,323] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 0D:45:81:00:34:57:49:01:00:4B:12:00:00:00:1E:00
[22:00:30.741,062] [Z_STACK/LSTN] PKT_HEX: [                  Z_STACK>>NWK_MGR                  ] [ucst] 04:00:71:FA:08:31:10:00
[22:00:30.743,983] [Z_STACK/LSTN] PKTTYPE: [                  Z_STACK>>NWK_MGR                  ] zstackDefaultRsp
[22:00:30.745,078] [Z_STACK/LSTN] PKTBODY:                                                          cmdID = ZDO_IEEE_ADDR_REQ
[22:00:30.748,080] [Z_STACK/LSTN] PKTBODY:                                                          status = ZSuccess
[22:00:30.749,452] [NWK_MGR/READ] INFO   : Received 4 bytes, subSys 0x71, cmdId 0xFA
[22:00:30.749,585] [NWK_MGR/READ] INFO   : [MUTEX] SRSP Cond signal set
[22:00:30.749,789] [NWK_MGR/READ] INFO   : Client Read: (len 8):
[22:00:30.752,999] [NWK_MGR/MAIN] INFO   : [MUTEX] Unlock SRSP Mutex
[22:00:30.754,255] [Z_STACK/LSTN] INFO   : ...sent 8 bytes to Client
[22:00:30.755,987] [Z_STACK/LSTN] INFO   : !Done
[22:00:30.776,392] [Z_STACK/READ] INFO   : Received 13 bytes, subSys 0x45, cmdId 0x81
[22:00:30.776,551] [Z_STACK/READ] INFO   : RPC_CMD_AREQ cmdId: 0x81
[22:00:30.776,588] [Z_STACK/READ] INFO   : [DBG] Allocated      @ 0xB6B01288 (received  10 messages)...
[22:00:30.776,617] [Z_STACK/READ] INFO   : Filling new message (@ 0xB6B01288)...
[22:00:30.776,711] [Z_STACK/HNDL] INFO   : [MUTEX] Mutex for AREQ unlocked
[22:00:30.776,756] [Z_STACK/HNDL] INFO   : [DBG] Processing     @ 0xB6B01288
[22:00:30.776,784] [Z_STACK/HNDL] INFO   : [MUTEX] AREQ Calling asynchMsgCback (Handle)...
[22:00:30.776,811] [Z_STACK/HNDL] INFO   : [DBG] asyncCB: subSys:0x00000005, cmdId:0x00000081, len:0x0000000D, pData:0xB6B01290
[22:00:30.776,843] [Z_STACK/HNDL] DEBUG  : znp_misc handleAsyncMsgs: Unrecognized cmdID:81
[22:00:30.776,871] [Z_STACK/HNDL] INFO   : [MUTEX] AREQ (Handle) (message @ 0xB6B01288)...
[22:00:30.776,898] [Z_STACK/HNDL] INFO   : [DBG] Clearing               @ 0xB6B01288 (processed 10 messages)...
[22:00:30.776,926] [Z_STACK/HNDL] INFO   : [MUTEX] Wait for AREQ semaphore
[22:00:39.765,354] [Z_STACK/LSTN] INFO   : Receive message...
[22:00:39.765,488] [Z_STACK/LSTN] INFO   : zstackpb zspbHandlePbCb: subsystemID:31, cmdId:15
[22:00:39.765,544] [Z_STACK/LSTN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:5, cmdID:45, len::4
[22:00:39.765,578] [Z_STACK/LSTN] INFO   : preparing to send 4 bytes, subSys 0x05, cmdId 0x45, pData:
[22:00:39.765,608] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[22:00:39.765,666] [Z_STACK/LSTN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 04:25:45:00:00:00:05
[22:00:39.765,721] [Z_STACK/LSTN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 04:25:45:00:00:00:05
[22:00:39.765,892] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...
[22:00:39.765,937] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[22:00:39.765,967] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[22:00:39.772,682] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 04:25:45:00:00:00:05
[22:00:39.764,434] [NWK_MGR/MAIN] INFO   :
AddDevice: Retrying state 2, remaining tries: 1
[22:00:39.764,620] [NWK_MGR/MAIN] MISC1  : NwkMgr MOT sendNwkRouteReq
[22:00:39.764,670] [NWK_MGR/MAIN] INFO   : preparing to send 6 bytes, subSys 0x11, cmdId 0x15, pData:
[22:00:39.764,703] [NWK_MGR/MAIN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[22:00:39.764,774] [NWK_MGR/MAIN] PKT_HEX: [                  Z_STACK<<NWK_MGR                  ] [SREQ] 06:00:31:15:08:15:10:00:30:05
[22:00:39.764,823] [NWK_MGR/MAIN] PKTTYPE: [                  Z_STACK<<NWK_MGR                  ] devNwkRouteReq
[22:00:39.764,873] [NWK_MGR/MAIN] PKTBODY:                                                          cmdID = DEV_NWK_ROUTE_REQ
[22:00:39.764,912] [NWK_MGR/MAIN] PKTBODY:                                                          dstAddr = 0x00000000 (0)
[22:00:39.764,953] [NWK_MGR/MAIN] PKTBODY:                                                          radius = 0x00000005 (5)
[22:00:39.777,130] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 01:65:45:00
[22:00:39.780,709] [Z_STACK/READ] INFO   : Received 1 bytes, subSys 0x65, cmdId 0x45
[22:00:39.780,954] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
[22:00:39.781,003] [Z_STACK/READ] INFO   : Client Read: (len 4):
[22:00:39.779,982] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 01:65:45:00
[22:00:39.784,832] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[22:00:39.785,041] [Z_STACK/LSTN] PKT_HEX: [                  Z_STACK>>NWK_MGR                  ] [ucst] 04:00:71:FA:08:15:10:00
[22:00:39.785,113] [Z_STACK/LSTN] PKTTYPE: [                  Z_STACK>>NWK_MGR                  ] zstackDefaultRsp
[22:00:39.785,168] [Z_STACK/LSTN] PKTBODY:                                                          cmdID = DEV_NWK_ROUTE_REQ
[22:00:39.785,209] [Z_STACK/LSTN] PKTBODY:                                                          status = ZSuccess
[22:00:39.785,416] [Z_STACK/LSTN] INFO   : ...sent 8 bytes to Client
[22:00:39.785,481] [Z_STACK/LSTN] INFO   : !Done
[22:00:39.789,635] [NWK_MGR/READ] INFO   : Received 4 bytes, subSys 0x71, cmdId 0xFA
[22:00:39.789,785] [NWK_MGR/READ] INFO   : [MUTEX] SRSP Cond signal set
[22:00:39.789,821] [NWK_MGR/READ] INFO   : Client Read: (len 8):
[22:00:39.792,010] [NWK_MGR/MAIN] INFO   : Waiting for synchronous response...
[22:00:39.794,461] [NWK_MGR/MAIN] INFO   : [MUTEX] Lock SRSP Mutex
[22:00:39.795,458] [NWK_MGR/MAIN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[22:00:39.799,095] [Z_STACK/LSTN] INFO   : Receive message...
[22:00:39.799,249] [Z_STACK/LSTN] INFO   : zstackpb zspbHandlePbCb: subsystemID:31, cmdId:31
[22:00:39.799,307] [Z_STACK/LSTN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:5, cmdID:1, len::4
[22:00:39.799,343] [Z_STACK/LSTN] INFO   : preparing to send 4 bytes, subSys 0x05, cmdId 0x01, pData:
[22:00:39.799,375] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[22:00:39.798,233] [NWK_MGR/MAIN] INFO   : [MUTEX] Unlock SRSP Mutex
[22:00:39.798,361] [NWK_MGR/MAIN] MISC1  : NwkMgr sendZdoIeeeAddrReq: ieeeaddr 0000
[22:00:39.798,415] [NWK_MGR/MAIN] INFO   : preparing to send 8 bytes, subSys 0x11, cmdId 0x31, pData:
[22:00:39.798,448] [NWK_MGR/MAIN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[22:00:39.798,521] [NWK_MGR/MAIN] PKT_HEX: [                  Z_STACK<<NWK_MGR                  ] [SREQ] 08:00:31:31:08:31:10:00:18:00:20:00
[22:00:39.798,571] [NWK_MGR/MAIN] PKTTYPE: [                  Z_STACK<<NWK_MGR                  ] zdoIeeeAddrReq
[22:00:39.798,620] [NWK_MGR/MAIN] PKTBODY:                                                          cmdID = ZDO_IEEE_ADDR_REQ
[22:00:39.798,660] [NWK_MGR/MAIN] PKTBODY:                                                          nwkAddr = 0x00000000 (0)
[22:00:39.798,696] [NWK_MGR/MAIN] PKTBODY:                                                          type = SINGLE_DEVICE
[22:00:39.798,731] [NWK_MGR/MAIN] PKTBODY:                                                          startIndex = 0x00000000 (0)
[22:00:39.803,700] [Z_STACK/LSTN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 04:25:01:00:00:00:00
[22:00:39.806,310] [Z_STACK/LSTN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 04:25:01:00:00:00:00
[22:00:39.808,043] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 04:25:01:00:00:00:00
[22:00:39.811,098] [NWK_MGR/MAIN] INFO   : Waiting for synchronous response...
[22:00:39.813,359] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...
[22:00:39.816,002] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 01:65:01:00
[22:00:39.819,329] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 01:65:01:00
[22:00:39.823,139] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 0D:45:81:00:34:57:49:01:00:4B:12:00:00:00:1E:00
[22:00:39.823,377] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 0D:45:81:00:34:57:49:01:00:4B:12:00:00:00:1E:00
[22:00:39.826,409] [NWK_MGR/MAIN] INFO   : [MUTEX] Lock SRSP Mutex
[22:00:39.827,958] [Z_STACK/READ] INFO   : Received 1 bytes, subSys 0x65, cmdId 0x01
[22:00:39.828,111] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
[22:00:39.828,146] [Z_STACK/READ] INFO   : Client Read: (len 4):
[22:00:39.829,192] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[22:00:39.832,077] [NWK_MGR/MAIN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[22:00:39.833,176] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[22:00:39.834,060] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[22:00:39.835,992] [Z_STACK/LSTN] PKT_HEX: [                  Z_STACK>>NWK_MGR                  ] [ucst] 04:00:71:FA:08:31:10:00
[22:00:39.837,244] [Z_STACK/LSTN] PKTTYPE: [                  Z_STACK>>NWK_MGR                  ] zstackDefaultRsp
[22:00:39.840,108] [NWK_MGR/READ] INFO   : Received 4 bytes, subSys 0x71, cmdId 0xFA
[22:00:39.840,245] [NWK_MGR/READ] INFO   : [MUTEX] SRSP Cond signal set
[22:00:39.840,280] [NWK_MGR/READ] INFO   : Client Read: (len 8):
[22:00:39.839,295] [Z_STACK/LSTN] PKTBODY:                                                          cmdID = ZDO_IEEE_ADDR_REQ
[22:00:39.839,402] [Z_STACK/LSTN] PKTBODY:                                                          status = ZSuccess
[22:00:39.844,223] [NWK_MGR/MAIN] INFO   : [MUTEX] Unlock SRSP Mutex
[22:00:39.847,386] [Z_STACK/LSTN] INFO   : ...sent 8 bytes to Client
[22:00:39.848,625] [Z_STACK/LSTN] INFO   : !Done
[22:00:39.864,845] [Z_STACK/READ] INFO   : Received 13 bytes, subSys 0x45, cmdId 0x81
[22:00:39.865,001] [Z_STACK/READ] INFO   : RPC_CMD_AREQ cmdId: 0x81
[22:00:39.865,040] [Z_STACK/READ] INFO   : [DBG] Allocated      @ 0xB6B01288 (received  11 messages)...
[22:00:39.865,069] [Z_STACK/READ] INFO   : Filling new message (@ 0xB6B01288)...
[22:00:39.865,166] [Z_STACK/HNDL] INFO   : [MUTEX] Mutex for AREQ unlocked
[22:00:39.865,213] [Z_STACK/HNDL] INFO   : [DBG] Processing     @ 0xB6B01288
[22:00:39.865,243] [Z_STACK/HNDL] INFO   : [MUTEX] AREQ Calling asynchMsgCback (Handle)...
[22:00:39.865,272] [Z_STACK/HNDL] INFO   : [DBG] asyncCB: subSys:0x00000005, cmdId:0x00000081, len:0x0000000D, pData:0xB6B01290
[22:00:39.865,303] [Z_STACK/HNDL] DEBUG  : znp_misc handleAsyncMsgs: Unrecognized cmdID:81
[22:00:39.865,331] [Z_STACK/HNDL] INFO   : [MUTEX] AREQ (Handle) (message @ 0xB6B01288)...
[22:00:39.865,358] [Z_STACK/HNDL] INFO   : [DBG] Clearing               @ 0xB6B01288 (processed 11 messages)...
[22:00:39.865,388] [Z_STACK/HNDL] INFO   : [MUTEX] Wait for AREQ semaphore
[22:00:48.855,279] [NWK_MGR/MAIN] INFO   :
AddDevice: Retrying state 2, remaining tries: 0
[22:00:48.855,461] [NWK_MGR/MAIN] INFO   :
AddDevice: Failed to get response from target node, state 2
[22:00:48.855,496] [NWK_MGR/MAIN] INFO   :  device 00124B002127C9E7
[22:00:48.855,529] [NWK_MGR/MAIN] INFO   :
[22:00:48.855,622] [NWK_MGR/MAIN] DEBUG  : - AddDevice Failed 1 on 00124B002127C9E7
[22:00:48.855,656] [NWK_MGR/MAIN] INFO   : zNwkSrv_AD_FreeStateMachine: Entered pState=0xb6d00588
[22:00:48.855,685] [NWK_MGR/MAIN] INFO   : zNwkSrv_AD_FreeStateMachine: State machine freed
[22:00:48.855,712] [NWK_MGR/MAIN] INFO   : nwkMgrDb_FreeDeviceInfo: Entered pDeviceInfo=0xb6d00510
[22:00:48.855,739] [NWK_MGR/MAIN] INFO   : nwkMgrDb_FreeDeviceInfoSubstructures: Entered pDeviceInfo=0xb6d00510
[22:00:48.855,766] [NWK_MGR/MAIN] INFO   : nwkMgrDb_FreeDeviceInfoSubstructures: Exit
[22:00:48.855,796] [NWK_MGR/MAIN] INFO   : zNwkSrv_AD_FreeStateMachine: Exit