root@arm:/home/ubuntu# cd /home/Precompiled/servers/
root@arm:/home/Precompiled/servers# ls
config.ini          GATEWAY_SRVR_arm    NWKMGR_SRVR_arm     zigbeeHAgw
DbDeviceInfo.csv    NPI_Gateway.cfg     OTA_SRVR_arm        ZLSZNP_arm
DbEndpoints.csv     NPI_lnx_arm_server  sample_app_ota.cfg
gateway_config.ini  NpiLnxLog.txt       start_application
gateway_config.tlg  nwkmgr_config.ini   track_servers
root@arm:/home/Precompiled/servers# ./zigbeeHAgw 
Platform type selected automatically as bbb.
To override this selection, please stop this script, and then run it again,
specifying the desired platform type at the command line:
  ./zigbeeHAgw [help | bbb | x86 ]

running ./zigbeeHAgw on an ARM
done processing arguments, board type bbb, target arm
NPI                 is 'NPI_lnx_arm_server'
Zstack linux server is 'ZLSZNP_arm'
gateway server      is 'GATEWAY_SRVR_arm'
network manager     is 'NWKMGR_SRVR_arm'
OTA server        is 'OTA_SRVR_arm'
Starting the ZigBee gateway subsystem
making sure there are no lingering servers...
there are 0 NPI servers
there are 0 ZLS servers
there are 0 GATEWAY servers
there are 0 NWKMGR servers
there are 0 OTA servers
(total 0)
done
===================================================
starting NPI, cmd ' ./NPI_lnx_arm_server NPI_Gateway.cfg -v 0xFFFFFFFF debugAll ' on Mon 24 May 2021 02:41:17 PM UTC
[14:41:17.499,259] [NPISRVR/MAIN] UNMSKBL: 
[14:41:17.499,473] [NPISRVR/MAIN] UNMSKBL:  ************************************************
[14:41:17.499,486] [NPISRVR/MAIN] UNMSKBL:  *  NPI Server v1.0.2d                          *
[14:41:17.499,496] [NPISRVR/MAIN] UNMSKBL:  ************************************************
[14:41:17.499,508] [NPISRVR/MAIN] UNMSKBL: 
gpioCfg                                 0x42b460
gpioCfg[0]                              0x24741630
gpioCfg[0].gpio                         0x24741650
gpioCfg[0].levelshifter                 0x247417d1
gpioCfg[1]                              0x24741638
gpioCfg[1].gpio                         0x24741960
gpioCfg[1].levelshifter                 0x24741ae1
gpioCfg[2]                              0x24741640
gpioCfg[2].gpio                         0x24741c70
gpioCfg[2].levelshifter                 0x24741df1
------------------------------------------------------
Serial Config Parsing:
-       Section:        TRACE
-       Key:            TRACE_LAYER_NAME_CHAR_COUNT
Found section [PORT]es
Found section [DEVICE]
Found section [GPIO_SRDY.GPIO]
Found section [GPIO_SRDY.LEVEL_SHIFTER]
Found section [GPIO_MRDY.GPIO]
Found section [GPIO_MRDY.LEVEL_SHIFTER]
Found section [GPIO_RESET.GPIO]
Found section [GPIO_RESET.LEVEL_SHIFTER]
Found section [UART]es
Startup phase 1 completed successfully, server started (NPI_PID=6529) on Mon 24 May 2021 02:41:17 PM UTC
Found section [SPI]tes
Found section [LOG]tes
------------------------------------------------------
Serial Config Parsing:
-       Section:        TRACE
-       Key:            TRACE_ARROW_CHAR_COUNT
Found section [PORT]es
Found section [DEVICE]
Found section [GPIO_SRDY.GPIO]
Found section [GPIO_SRDY.LEVEL_SHIFTER]
Found section [GPIO_MRDY.GPIO]
Found section [GPIO_MRDY.LEVEL_SHIFTER]
Found section [GPIO_RESET.GPIO]
Found section [GPIO_RESET.LEVEL_SHIFTER]
Found section [UART]es
Found section [SPI]tes
Found section [LOG]tes
------------------------------------------------------
Serial Config Parsing:
-       Section:        DEVICE
-       Key:            deviceKey
Found section [PORT]es
Found section [DEVICE]
Found wanted section!
Line to process deviceKey=0 ; UART (strlen=18)
Found key       'deviceKey' in  'deviceKey=0 ; UART'
Found value '0 '
Found value2 '0 '
[14:41:17.500,798] [NPISRVR/MAIN] INFO   : deviceKey = 0  (0 )
------------------------------------------------------
Serial Config Parsing:
-       Section:        DEVICE
-       Key:            devPath
Found section [PORT]es
Found section [DEVICE]
Found wanted section!
Line to process deviceKey=0 ; UART (strlen=18)
Line to process #deviceKey=1 ; SPI (strlen=18)
Li===================================================
ne to process #deviceKey=2 ; I2C (strlen=18)
Line to process  (strlen=0)
Line to process #devPath="/dev/ttyUSB2"; (strlen=24)
Line to process #devPath="/dev/ttyO4" ; UART/CDC (strlen=32)
Line to process devPath="/dev/ttymxc2" ; USART3 (strlen=31)
Found key       'devPath' in    'devPath="/dev/ttymxc2" ; USART3'
Found value '/dev/ttymxc2'
Found value2 '/dev/ttymxc2'
[14:41:17.500,991] [NPISRVR/MAIN] INFO   : 'devPath' specified in the config file is overriden by the soc_device_path command line argument
[14:41:17.501,000] [NPISRVR/MAIN] INFO   : devPath = '/dev/ttymxc2'
------------------------------------------------------
Serial Config Parsing:
-       Section:        LOG
-       Key:            log
Found section [PORT]es
Found section [DEVICE]
Found section [GPIO_SRDY.GPIO]
Found section [GPIO_SRDY.LEVEL_SHIFTER]
Found section [GPIO_MRDY.GPIO]
Found section [GPIO_MRDY.LEVEL_SHIFTER]
Found section [GPIO_RESET.GPIO]
Found section [GPIO_RESET.LEVEL_SHIFTER]
Found section [UART]es
Found section [SPI]tes
Found section [LOG]tes
Found wanted section!
Line to process log="./NpiLnxLog.txt" ; file to log all event/error (strlen=51)
Found key       'log' in        'log="./NpiLnxLog.txt" ; file to log all event/error'
Found value './NpiLnxLog.txt'
Found value2 './NpiLnxLog.txt'
[14:41:17.501,251] [NPISRVR/MAIN] INFO   : logPath = './NpiLnxLog.txt'
------------------------------------------------------
Serial Config Parsing:
-       Section:        UART
-       Key:            speed
Found section [PORT]es
Found section [DEVICE]
Found section [GPIO_SRDY.GPIO]
Found section [GPIO_SRDY.LEVEL_SHIFTER]
Found section [GPIO_MRDY.GPIO]
Found section [GPIO_MRDY.LEVEL_SHIFTER]
Found section [GPIO_RESET.GPIO]
Found section [GPIO_RESET.LEVEL_SHIFTER]
Found section [UART]es
Found wanted section!
Line to process speed=115200 ; speed (strlen=20)
Found key       'speed' in      'speed=115200 ; speed'
Found value '115200 '
Found value2 '115200 '
[UART] Opening device /dev/ttymxc2
[UART] Install IO signal handler 
[UART] Baud rate set to 115200 (0x001002)
[UART] c_cflag set to 0x0018B2
------------------------------------------------------
Serial Config Parsing:
-       Section:        UART
-       Key:            flowcontrol
Found line < 128 bstarting ZLSZNP, cmd ' ./ZLSZNP_arm 127.0.0.1:2533 config.ini -v 0xFFFFFFFF ' on Mon 24 May 2021 02:41:18 PM UTC
[UART] Wait for mutex in rx entry:
Found section [PORT]es
Found section [DEVICE]
Found section [GPIO_SRDY.GPIO]
Found section [GPIO_SRDY.LEVEL_SHIFTER]
Found section [GPIO_MRDY.GPIO]
Found section [GPIO_MRDY.LEVEL_SHIFTER]
Found section [GPIO_RESET.GPIO]
Found section [GPIO_RESET.LEVEL_SHIFTER]
Found section [UART]es
Found wanted section!
Line to process speed=115200 ; speed (strlen=20)
Line to process flowcontrol=0 ; 1=enabled 0=disable (strlen=35)
Found key       'flowcontrol' in        'flowcontrol=0 ; 1=enabled 0=disable'
Found value '0 '
Found value2 '0 '
------------------------------------------------------
Serial Config Parsing:
-       Section:        PORT
-       Key:            port
Found section [PORT]es
Found wanted section!
Line to process port=2533 (strlen=9)
Found key       'port' in       'port=2533'
Found value '2533'
Found value2 '2533'
... freeing memory (ret 0)
[14:41:17.502,433] [NPISRVR/MAIN] INFO   : Port: 2533
[14:41:17.502,786] [NPISRVR/MAIN] INFO   : Following IP addresses are available:
[14:41:17.502,983] [NPISRVR/MAIN] INFO   :  IPv4: interface: lo  IP Address 127.0.0.1
[14:41:17.502,996] [NPISRVR/MAIN] INFO   :  IPv6: interface: lo  IP Address ::1
[14:41:17.503,009] [NPISRVR/MAIN] INFO   : The socket will listen on the following IP addresses:
[14:41:17.503,019] [NPISRVR/MAIN] INFO   :   IPv4: 0.0.0.0
[14:41:17.503,030] [NPISRVR/MAIN] INFO   :   IPv6: ::
[14:41:17.503,040] [NPISRVR/MAIN] INFO   : 0.0.0.0 means it will listen to all available IP address
[14:41:17.503,110] [NPISRVR/MAIN] INFO   : waiting for first connection on #3...
[<-- 000:00:02.092293 (+1621867279. 92293)] Signal from UART, grabbing mutex
[<-- 000:00:02.092332 (+0.    39)] Signal read handle, owning mutex
[<-- 000:00:02.093189 (+0.   857)] Signal from UART, grabbing mutex
[<-- 000:00:02.093198 (+0.     9)] Signal read handle, owning mutex
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x41, Cmd ID: 0x80, length: 6
[14:41:19.093,269] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 06:41:80:00:02:00:02:07:01
[14:41:19.174,206] [Z_STACK/MAIN] MISC1  : Port: 2533

Startup phase 2 completed successfully, server started (ZLSZNP_PID=6536) on Mon 24 May 2021 02:41:19 PM UTC
[UART] npi_procframe signal areq callback thread (invoked by read loop) 
[14:41:19.174,794] [NPISRVR/MAIN] INFO   : Connected to #5.(127.0.0.1 / ::)
Receive message...
[14:41:19.175,377] [NPISRVR/MAIN] PKT_HEX: New incoming connection from client Z_STACK (connection # 5)
[<-- 000:00:00.175398 (+0. 82200)] 08 bytes, subSys 0x5F, cmdId 0x00, pData:    0x02 0x5A 0x5F 0x53 0x54 0x41 0x43 0x4B
!Done
Receive message...
[<-- 000:00:00.175466 (+0.    68)] 02 bytes, subSys 0x25, cmdId 0x3E, pData:    0xFF 0xFF
NPI SREQ:  (len 5) 0x02 0x25 0x3E 0xFF 0xFF
[<-- 000:00:00.175482 (+0.    16)] [UART] write 7 bytes to 4
[14:41:19.175,502] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 02:25:3E:FF:FF
[<-- 000:00:00.175556 (+0.    74)] [UART] result: 7
[<-- 000:00:00.175583 (+0.    27)] [UART] (synch data) Conditional wait 6 s
[<-- 000:00:00.178113 (+0.  2530)] Signal from UART, grabbing mutex
[<-- 000:00:00.178130 (+0.    17)] Signal read handle, owning mutex
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x65, Cmd ID: 0x3E, length: 1
[14:41:19.178,175] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 01:65:3E:00
[UART] npi_procframe signal synch response received (invoked by read loop) 
NPI SRSP: (len 4) 0x01 0x65 0x3E 0x00
[--> 000:00:00.178212 (+1621867279.178212)] 01 bytes, subSys 0x65, cmdId 0x3E, pData:    0x00
[14:41:19.178,232] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 01:65:3E:00
...sent 4 bytes to Client #5
!Done
Receive message...
[<-- 000:00:00.178601 (+0.   471)] 01 bytes, subSys 0x2F, cmdId 0x09, pData:    0x00
NPI SREQ:  (len 4) 0x01 0x2F 0x09 0x00
[<-- 000:00:00.178613 (+0.    12)] [UART] write 6 bytes to 4
[14:41:19.178,625] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 01:2F:09:00
[<-- 000:00:00.178657 (+0.    44)] [UART] result: 6
[<-- 000:00:00.178661 (+0.     4)] [UART] (synch data) Conditional wait 6 s
[<-- 000:00:00.181078 (+0.  2417)] Signal from UART, grabbing mutex
[<-- 000:00:00.181087 (+0.     9)] Signal read handle, owning mutex
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x6f, Cmd ID: 0x09, length: 1
[14:41:19.181,110] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 01:6F:09:00
[UART] npi_procframe signal synch response received (invoked by read loop) 
NPI SRSP: (len 4) 0x01 0x6F 0x09 0x00
[--> 000:00:00.181135 (+0.  2923)] 01 bytes, subSys 0x6F, cmdId 0x09, pData:    0x00
[14:41:19.181,149] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 01:6F:09:00
...sent 4 bytes to Client #5
!Done
Receive message...
[<-- 000:00:00.181363 (+0.   276)] 01 bytes, subSys 0x2F, cmdId 0x06, pData:    0x00
NPI SREQ:  (len 4) 0x01 0x2F 0x06 0x00
[<-- 000:00:00.181372 (+0.     9)] [UART] write 6 bytes to 4
[14:41:19.181,383] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 01:2F:06:00
[<-- 000:00:00.181411 (+0.    39)] [UART] result: 6
[<-- 000:00:00.181414 (+0.     3)] [UART] (synch data) Conditional wait 6 s
[<-- 000:00:00.183821 (+0.  2407)] Signal from UART, grabbing mutex
[<-- 000:00:00.183829 (+0.     8)] Signal read handle, owning mutex
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x6f, Cmd ID: 0x06, length: 1
[14:41:19.183,848] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 01:6F:06:00
[UART] npi_procframe signal synch response received (invoked by read loop) 
NPI SRSP: (len 4) 0x01 0x6F 0x06 0x00
[--> 000:00:00.183879 (+0.  2744)] 01 bytes, subSys 0x6F, cmdId 0x06, pData:    0x00
[14:41:19.183,892] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 01:6F:06:00
...sent 4 bytes to Client #5
!Done
Receive message...
[<-- 000:00:00.184089 (+0.   260)] 01 bytes, subSys 0x2F, cmdId 0x02, pData:    0x08
NPI SREQ:  (len 4) 0x01 0x2F 0x02 0x08
[<-- 000:00:00.184097 (+0.     8)] [UART] write 6 bytes to 4
[14:41:19.184,108] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 01:2F:02:08
[<-- 000:00:00.184133 (+0.    36)] [UART] result: 6
[<-- 000:00:00.184137 (+0.     4)] [UART] (synch data) Conditional wait 6 s
[<-- 000:00:00.187911 (+0.  3774)] Signal from UART, grabbing mutex
[<-- 000:00:00.187918 (+0.     7)] Signal read handle, owning mutex
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x6f, Cmd ID: 0x02, length: 1
[14:41:19.187,936] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 01:6F:02:00
[UART] npi_procframe signal synch response received (invoked by read loop) 
NPI SRSP: (len 4) 0x01 0x6F 0x02 0x00
[--> 000:00:00.187960 (+0.  4081)] 01 bytes, subSys 0x6F, cmdId 0x02, pData:    0x00
[14:41:19.187,974] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 01:6F:02:00
...sent 4 bytes to Client #5
!Done
Receive message...
[<-- 000:00:00.188377 (+0.   459)] 05 bytes, subSys 0x2F, cmdId 0x08, pData:    0x00 0x00 0x00 0x00 0x00
NPI SREQ:  (len 8) 0x05 0x2F 0x08 0x00 0x00 0x00 0x00 0x00
[<-- 000:00:00.188393 (+0.    16)] [UART] write 10 bytes to 4
[14:41:19.188,414] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 05:2F:08:00:00:00:00:00
[<-- 000:00:00.188447 (+0.    54)] [UART] result: 10
[<-- 000:00:00.188451 (+0.     4)] [UART] (synch data) Conditional wait 6 s
[<-- 000:00:00.191214 (+0.  2763)] Signal from UART, grabbing mutex
[<-- 000:00:00.191226 (+0.    12)] Signal read handle, owning mutex
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x6f, Cmd ID: 0x08, length: 1
[14:41:19.191,251] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 01:6F:08:00
[UART] npi_procframe signal synch response received (invoked by read loop) 
NPI SRSP: (len 4) 0x01 0x6F 0x08 0x00
[--> 000:00:00.191301 (+0.  3341)] 01 bytes, subSys 0x6F, cmdId 0x08, pData:    0x00
[14:41:19.191,319] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 01:6F:08:00
...sent 4 bytes to Client #5
!Done
Receive message...
[<-- 000:00:00.191595 (+0.   369)] 05 bytes, subSys 0x2F, cmdId 0x08, pData:    0x01 0x00 0x20 0x00 0x00
NPI SREQ:  (len 8) 0x05 0x2F 0x08 0x01 0x00 0x20 0x00 0x00
[<-- 000:00:00.191612 (+0.    17)] [UART] write 10 bytes to 4
[14:41:19.191,632] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 05:2F:08:01:00:20:00:00
[<-- 000:00:00.191668 (+0.    56)] [UART] result: 10
[<-- 000:00:00.191673 (+0.     5)] [UART] (synch data) Conditional wait 6 s
[<-- 000:00:00.194435 (+0.  2762)] Signal from UART, grabbing mutex
[<-- 000:00:00.194448 (+0.    13)] Signal read handle, owning mutex
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x6f, Cmd ID: 0x08, length: 1
[14:41:19.194,473] [NPISRVR/U_RX] PKT_HEX: 14:41:19.174,393] [Z_STACK/MAIN] MISC1  : IP addresses for 127.0.0.1:

[14:41:19.174,413] [Z_STACK/MAIN] MISC1  :   IPv4: 127.0.0.1
[14:41:19.174,425] [Z_STACK/MAIN] MISC1  : Trying to connect...
[14:41:19.174,739] [Z_STACK/MAIN] MISC1  : Connected.
[14:41:19.174,944] [Z_STACK/MAIN] UNMSKBL: 
[14:41:19.174,961] [Z_STACK/MAIN] UNMSKBL:  ************************************************
[14:41:19.174,972] [Z_STACK/MAIN] UNMSKBL:  *  ZStack Server for ZNP v1.0.2d               *
[14:41:19.174,983] [Z_STACK/MAIN] UNMSKBL:  ************************************************
[14:41:19.174,993] [Z_STACK/MAIN] UNMSKBL: 
[14:41:19.175,006] [Z_STACK/HNDL] INFO   : [MUTEX] Wait for AREQ semaphore
[14:41:19.175,042] [Z_STACK/MAIN] INFO   : trying to send 8 bytes, subSys 0x1F, cmdId 0x00
[14:41:19.175,086] [Z_STACK/MAIN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [AREQ] 08:5F:00:02:5A:5F:53:54:41:43:4B
[14:41:19.175,123] [Z_STACK/MAIN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [AREQ] 08:5F:00:02:5A:5F:53:54:41:43:4B
[14:41:19.175,331] [Z_STACK/MAIN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:5, cmdID:3e, len::2
[14:41:19.175,351] [Z_STACK/MAIN] INFO   : preparing to send 2 bytes, subSys 0x05, cmdId 0x3E, pData:
[14:41:19.175,364] [Z_STACK/MAIN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[14:41:19.175,388] [Z_STACK/MAIN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 02:25:3E:FF:FF
[14:41:19.175,411] [Z_STACK/MAIN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 02:25:3E:FF:FF
[14:41:19.175,468] [Z_STACK/MAIN] INFO   : Waiting for synchronous response...
[14:41:19.175,484] [Z_STACK/MAIN] INFO   : [MUTEX] Lock SRSP Mutex
[14:41:19.175,495] [Z_STACK/MAIN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[14:41:19.178,321] [Z_STACK/READ] INFO   : Received 1 bytes, subSys 0x65, cmdId 0x3E
[14:41:19.178,357] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
[14:41:19.178,370] [Z_STACK/READ] INFO   : Client Read: (len 4):
[14:41:19.178,399] [Z_STACK/MAIN] INFO   : [MUTEX] Unlock SRSP Mutex
[14:41:19.178,420] [Z_STACK/MAIN] INFO   : zstackpb config: defaultChannelList:2000, configPANID:ffff, deviceType:0
[14:41:19.178,435] [Z_STACK/MAIN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:f, cmdID:9, len::1
[14:41:19.178,451] [Z_STACK/MAIN] INFO   : preparing to send 1 bytes, subSys 0x0F, cmdId 0x09, pData:
[14:41:19.178,467] [Z_STACK/MAIN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[14:41:19.178,490] [Z_STACK/MAIN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 01:2F:09:00
[14:41:19.178,526] [Z_STACK/MAIN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 01:2F:09:00
[14:41:19.178,597] [Z_STACK/MAIN] INFO   : Waiting for synchronous response...
[14:41:19.178,607] [Z_STACK/MAIN] INFO   : [MUTEX] Lock SRSP Mutex
[14:41:19.178,615] [Z_STACK/MAIN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[14:41:19.181,205] [Z_STACK/READ] INFO   : Received 1 bytes, subSys 0x6F, cmdId 0x09
[14:41:19.181,220] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
[14:41:19.181,229] [Z_STACK/READ] INFO   : Client Read: (len 4):
[14:41:19.181,248] [Z_STACK/MAIN] INFO   : [MUTEX] Unlock SRSP Mutex
[14:41:19.181,260] [Z_STACK/MAIN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:f, cmdID:6, len::1
[14:41:19.181,277] [Z_STACK/MAIN] INFO   : preparing to send 1 bytes, subSys 0x0F, cmdId 0x06, pData:
[14:41:19.181,286] [Z_STACK/MAIN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[14:41:19.181,303] [Z_STACK/MAIN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 01:2F:06:00
[14:41:19.181,324] [Z_STACK/MAIN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 01:2F:06:00
[14:41:19.181,362] [Z_STACK/MAIN] INFO   : Waiting for synchronous response...
[14:41:19.181,372] [Z_STACK/MAIN] INFO   : [MUTEX] Lock SRSP Mutex
[14:41:19.181,380] [Z_STACK/MAIN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[14:41:19.183,933] [Z_STACK/READ] INFO   : Received 1 bytes, subSys 0x6F, cmdId 0x06
[14:41:19.183,949] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
[14:41:19.183,959] [Z_STACK/READ] INFO   : Client Read: (len 4):
[14:41:19.183,978] [Z_STACK/MAIN] INFO   : [MUTEX] Unlock SRSP Mutex
[14:41:19.183,989] [Z_STACK/MAIN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:f, cmdID:2, len::1
[14:41:19.184,000] [Z_STACK/MAIN] INFO   : preparing to send 1 bytes, subSys 0x0F, cmdId 0x02, pData:
[14:41:19.184,011] [Z_STACK/MAIN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[14:41:19.184,030] [Z_STACK/MAIN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 01:2F:02:08
[14:41:19.184,050] [Z_STACK/MAIN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 01:2F:02:08
[14:41:19.184,087] [Z_STACK/MAIN] INFO   : Waiting for synchronous response...
[14:41:19.184,097] [Z_STACK/MAIN] INFO   : [MUTEX] Lock SRSP Mutex
[14:41:19.184,105] [Z_STACK/MAIN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[14:41:19.188,017] [Z_STACK/READ] INFO   : Received 1 bytes, subSys 0x6F, cmdId 0x02
[14:41:19.188,032] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
[14:41:19.188,042] [Z_STACK/READ] INFO   : Client Read: (len 4):
[14:41:19.188,221] [Z_STACK/MAIN] INFO   : [MUTEX] Unlock SRSP Mutex
[14:41:19.188,239] [Z_STACK/MAIN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:f, cmdID:8, len::5
[14:41:19.188,253] [Z_STACK/MAIN] INFO   : preparing to send 5 bytes, subSys 0x0F, cmdId 0x08, pData:
[14:41:19.188,265] [Z_STACK/MAIN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[14:41:19.188,294] [Z_STACK/MAIN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 05:2F:08:00:00:00:00:00
[14:41:19.188,323] [Z_STACK/MAIN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 05:2F:08:00:00:00:00:00
[14:41:19.188,374] [Z_STACK/MAIN] INFO   : Waiting for synchronous response...
[14:41:19.188,388] [Z_STACK/MAIN] INFO   : [MUTEX] Lock SRSP Mutex
[14:41:19.188,399] [Z_STACK/MAIN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[14:41:19.191,374] [Z_STACK/READ] INFO   : Received 1 bytes, subSys 0x6F, cmdId 0x08
[14:41:19.191,394] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
[14:41:19.191,407] [Z_STACK/READ] INFO   : Client Read: (len 4):
[14:41:19.191,430] [Z_STACK/MAIN] INFO   : [MUTEX] Unlock SRSP Mutex
[14:41:19.191,445] [Z_STACK/MAIN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:f, cmdID:8, len::5
[14:41:19.191,458] [Z_STACK/MAIN] INFO   : preparing to send 5 bytes, subSys 0x0F, cmdId 0x08, pData:
[14:41:19.191,478] [Z_STACK/MAIN] INFO   : [M===================================================
m[SOCZIGB>>NPISRVR                                    ] [SRSP] 01:6F:08:00
[UART] npi_procframe signal synch response received (invoked by read loop) 
NPI SRSP: (len 4) 0x01 0x6F 0x08 0x00
[--> 000:00:00.194507 (+0.  3206)] 01 bytes, subSys 0x6F, cmdId 0x08, pData:    0x00
[14:41:19.194,525] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 01:6F:08:00
...sent 4 bytes to Client #5
!Done
Receive message...
[<-- 000:00:00.194784 (+0.   336)] 06 bytes, subSys 0x21, cmdId 0x09, pData:    0x83 0x00 0x00 0x02 0xFF 0xFF
NPI SREQ:  (len 9) 0x06 0x21 0x09 0x83 0x00 0x00 0x02 0xFF 0xFF
[<-- 000:00:00.194802 (+0.    18)] [UART] write 11 bytes to 4
[14:41:19.194,823] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 06:21:09:83:00:00:02:FF:FF
[<-- 000:00:00.194854 (+0.    52)] [UART] result: 11
[<-- 000:00:00.194860 (+0.     6)] [UART] (synch data) Conditional wait 6 s
[<-- 000:00:00.200313 (+0.  5453)] Signal from UART, grabbing mutex
[<-- 000:00:00.200324 (+0.    11)] Signal read handle, owning mutex
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x61, Cmd ID: 0x09, length: 1
[14:41:19.200,349] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 01:61:09:00
[UART] npi_procframe signal synch response received (invoked by read loop) 
NPI SRSP: (len 4) 0x01 0x61 0x09 0x00
[--> 000:00:00.200384 (+0.  5877)] 01 bytes, subSys 0x61, cmdId 0x09, pData:    0x00
[14:41:19.200,402] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 01:61:09:00
...sent 4 bytes to Client #5
!Done
Receive message...
[<-- 000:00:00.200673 (+0.   349)] 05 bytes, subSys 0x21, cmdId 0x09, pData:    0x87 0x00 0x00 0x01 0x00
NPI SREQ:  (len 8) 0x05 0x21 0x09 0x87 0x00 0x00 0x01 0x00
[<-- 000:00:00.200691 (+0.    18)] [UART] write 10 bytes to 4
[14:41:19.200,710] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 05:21:09:87:00:00:01:00
[<-- 000:00:00.200740 (+0.    49)] [UART] result: 10
[<-- 000:00:00.200744 (+0.     4)] [UART] (synch data) Conditional wait 6 s
[<-- 000:00:00.205956 (+0.  5212)] Signal from UART, grabbing mutex
[<-- 000:00:00.205966 (+0.    10)] Signal read handle, owning mutex
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x61, Cmd ID: 0x09, length: 1
[14:41:19.205,989] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 01:61:09:00
[UART] npi_procframe signal synch response received (invoked by read loop) 
NPI SRSP: (len 4) 0x01 0x61 0x09 0x00
[--> 000:00:00.206023 (+0.  5639)] 01 bytes, subSys 0x61, cmdId 0x09, pData:    0x00
[14:41:19.206,041] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 01:61:09:00
...sent 4 bytes to Client #5
!Done
Receive message...
[<-- 000:00:00.206329 (+0.   363)] 07 bytes, subSys 0x21, cmdId 0x15, pData:    0x96 0x00 0xC4 0x64 0x00 0x00 0x00
NPI SREQ:  (len 10) 0x07 0x21 0x15 0x96 0x00 0xC4 0x64 0x00 0x00 0x00
[<-- 000:00:00.206348 (+0.    19)] [UART] write 12 bytes to 4
[14:41:19.206,369] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 07:21:15:96:00:C4:64:00:00:00
[<-- 000:00:00.206400 (+0.    52)] [UART] result: 12
[<-- 000:00:00.206405 (+0.     5)] [UART] (synch data) Conditional wait 6 s
[<-- 000:00:00.209527 (+0.  3122)] Signal from UART, grabbing mutex
[<-- 000:00:00.209537 (+0.    10)] Signal read handle, owning mutex
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x60, Cmd ID: 0x00, length: 3
[14:41:19.209,565] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 03:60:00:02:21:15
[UART] npi_procframe signal synch response received (invoked by read loop) 
NPI SRSP: (len 4) 0x01 0x61 0x15 0xFF
[--> 000:00:00.209597 (+0.  3574)] 01 bytes, subSys 0x61, cmdId 0x15, pData:    0xFF
[14:41:19.209,615] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 01:61:15:FF
...sent 4 bytes to Client #5
!Done
Receive message...
[<-- 000:00:00.210930 (+0.  1393)] 01 bytes, subSys 0x2F, cmdId 0x05, pData:    0x04
NPI SREQ:  (len 4) 0x01 0x2F 0x05 0x04
[<-- 000:00:00.210948 (+0.    18)] [UART] write 6 bytes to 4
[14:41:19.210,968] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 01:2F:05:04
[<-- 000:00:00.211019 (+0.    71)] [UART] result: 6
[<-- 000:00:00.211025 (+0.     6)] [UART] (synch data) Conditional wait 6 s
[<-- 000:00:00.752484 (+0.541459)] Signal from UART, grabbing mutex
[<-- 000:00:00.752506 (+0.    22)] Signal read handle, owning mutex
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x6f, Cmd ID: 0x05, length: 1
[14:41:19.752,562] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 01:6F:05:00
[UART] npi_procframe signal synch response received (invoked by read loop) 
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x45, Cmd ID: 0xC0, length: 1
NPI SRSP: (len 4) 0x01 0x6F 0x05 0x00
[--> 000:00:00.752616 (+0.543019)] 01 bytes, subSys 0x6F, cmdId 0x05, pData:    0x00[14:41:19.752,616] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 01:45:C0:09

[UART] npi_procframe signal areq callback thread (invoked by read loop) 
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x4f, Cmd ID: 0x80, length: 3
[-->] 1 bytes, subSys 0x45, cmdId 0xC0, pData: 0x09[14:41:19.752,652] [NPISRVR/MAIN] PKT_HEX: 
[         NPISRVR>>Z_STACK                           ] [ucst] 01:6F:05:00
[--> 000:00:00.752661 (+0.    45)] 01 bytes, subSys 0x45, cmdId 0xC0, pData:    0x09
[14:41:19.752,690] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 03:4F:80:0D:00:04
[UART] npi_procframe signal areq callback thread (invoked by read loop) 
[14:41:19.752,707] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 01:45:C0:09
...sent 4 bytes to Client #5
!Done
...sent 4 bytes to Client #5
[-->] 3 bytes, subSys 0x4F, cmdId 0x80, pData: 0x0D 0x00 0x04
[--> 000:00:00.752811 (+0.   150)] 03 bytes, subSys 0x4F, cmdId 0x80, pData:    0x0D 0x00 0x04
[14:41:19.752,832] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 03:4F:80:0D:00:04
...sent 6 bytes to Client #5
[<-- 000:00:00.951015 (+0.198509)] Signal from UART, grabbing mutex
[<-- 000:00:00.951039 (+0.    24)] Signal read handle, owning mutex
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x4f, Cmd ID: 0x80, length: 3
[14:41:19.951,100] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 03:4F:80:08:02:00
[UART] npi_procframe signal areq callback thread (invoked UTEX] Lock SRSP Transaction Mutex
[14:41:19.191,508] [Z_STACK/MAIN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 05:2F:08:01:00:20:00:00
[14:41:19.191,537] [Z_STACK/MAIN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 05:2F:08:01:00:20:00:00
[14:41:19.191,593] [Z_STACK/MAIN] INFO   : Waiting for synchronous response...
[14:41:19.191,607] [Z_STACK/MAIN] INFO   : [MUTEX] Lock SRSP Mutex
[14:41:19.191,620] [Z_STACK/MAIN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[14:41:19.194,570] [Z_STACK/READ] INFO   : Received 1 bytes, subSys 0x6F, cmdId 0x08
[14:41:19.194,589] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
[14:41:19.194,602] [Z_STACK/READ] INFO   : Client Read: (len 4):
[14:41:19.194,625] [Z_STACK/MAIN] INFO   : [MUTEX] Unlock SRSP Mutex
[14:41:19.194,642] [Z_STACK/MAIN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:1, cmdID:9, len::6
[14:41:19.194,655] [Z_STACK/MAIN] INFO   : preparing to send 6 bytes, subSys 0x01, cmdId 0x09, pData:
[14:41:19.194,668] [Z_STACK/MAIN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[14:41:19.194,698] [Z_STACK/MAIN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 06:21:09:83:00:00:02:FF:FF
[14:41:19.194,728] [Z_STACK/MAIN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 06:21:09:83:00:00:02:FF:FF
[14:41:19.194,784] [Z_STACK/MAIN] INFO   : Waiting for synchronous response...
[14:41:19.194,799] [Z_STACK/MAIN] INFO   : [MUTEX] Lock SRSP Mutex
[14:41:19.194,811] [Z_STACK/MAIN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[14:41:19.200,450] [Z_STACK/READ] INFO   : Received 1 bytes, subSys 0x61, cmdId 0x09
[14:41:19.200,473] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
[14:41:19.200,486] [Z_STACK/READ] INFO   : Client Read: (len 4):
[14:41:19.200,510] [Z_STACK/MAIN] INFO   : [MUTEX] Unlock SRSP Mutex
[14:41:19.200,528] [Z_STACK/MAIN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:1, cmdID:9, len::5
[14:41:19.200,542] [Z_STACK/MAIN] INFO   : preparing to send 5 bytes, subSys 0x01, cmdId 0x09, pData:
[14:41:19.200,556] [Z_STACK/MAIN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[14:41:19.200,584] [Z_STACK/MAIN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 05:21:09:87:00:00:01:00
[14:41:19.200,613] [Z_STACK/MAIN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 05:21:09:87:00:00:01:00
[14:41:19.200,672] [Z_STACK/MAIN] INFO   : Waiting for synchronous response...
[14:41:19.200,686] [Z_STACK/MAIN] INFO   : [MUTEX] Lock SRSP Mutex
[14:41:19.200,699] [Z_STACK/MAIN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[14:41:19.206,093] [Z_STACK/READ] INFO   : Received 1 bytes, subSys 0x61, cmdId 0x09
[14:41:19.206,112] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
[14:41:19.206,123] [Z_STACK/READ] INFO   : Client Read: (len 4):
[14:41:19.206,149] [Z_STACK/MAIN] INFO   : [MUTEX] Unlock SRSP Mutex
[14:41:19.206,168] [Z_STACK/MAIN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:1, cmdID:15, len::7
[14:41:19.206,182] [Z_STACK/MAIN] INFO   : preparing to send 7 bytes, subSys 0x01, cmdId 0x15, pData:
[14:41:19.206,196] [Z_STACK/MAIN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[14:41:19.206,230] [Z_STACK/MAIN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 07:21:15:96:00:C4:64:00:00:00
[14:41:19.206,261] [Z_STACK/MAIN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 07:21:15:96:00:C4:64:00:00:00
[14:41:19.206,303] [Z_STACK/MAIN] INFO   : Waiting for synchronous response...
[14:41:19.206,317] [Z_STACK/MAIN] INFO   : [MUTEX] Lock SRSP Mutex
[14:41:19.206,327] [Z_STACK/MAIN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[14:41:19.209,664] [Z_STACK/READ] INFO   : Received 1 bytes, subSys 0x61, cmdId 0x15
[14:41:19.209,685] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
[14:41:19.209,698] [Z_STACK/READ] INFO   : Client Read: (len 4):
[14:41:19.209,726] [Z_STACK/MAIN] INFO   : [MUTEX] Unlock SRSP Mutex
[14:41:19.209,740] [Z_STACK/MAIN] DEBUG  : --> status failed: cmdID:15, status: 255
[14:41:19.209,756] [Z_STACK/MAIN] INFO   : Port: 2536
[14:41:19.210,144] [Z_STACK/MAIN] INFO   : Following IP addresses are available:

[14:41:19.210,360] [Z_STACK/MAIN] INFO   :  IPv4: interface: lo  IP Address 127.0.0.1
[14:41:19.210,378] [Z_STACK/MAIN] INFO   :  IPv6: interface: lo  IP Address ::1
[14:41:19.210,397] [Z_STACK/MAIN] INFO   : The socket will listen on the following IP addresses:

[14:41:19.210,411] [Z_STACK/MAIN] INFO   :   IPv4: 0.0.0.0
[14:41:19.210,425] [Z_STACK/MAIN] INFO   :   IPv6: ::
[14:41:19.210,438] [Z_STACK/MAIN] INFO   : 0.0.0.0 means it will listen to all available IP address

[14:41:19.210,498] [Z_STACK/MAIN] MISC1  : waiting for first connection on #4...
[14:41:19.210,701] [Z_STACK/MAIN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:f, cmdID:5, len::1
[14:41:19.210,720] [Z_STACK/MAIN] INFO   : preparing to send 1 bytes, subSys 0x0F, cmdId 0x05, pData:
[14:41:19.210,733] [Z_STACK/MAIN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[14:41:19.210,760] [Z_STACK/MAIN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 01:2F:05:04
[14:41:19.210,783] [Z_STACK/MAIN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 01:2F:05:04
[14:41:19.210,891] [Z_STACK/MAIN] INFO   : Waiting for synchronous response...
[14:41:19.210,905] [Z_STACK/MAIN] INFO   : [MUTEX] Lock SRSP Mutex
[14:41:19.210,917] [Z_STACK/MAIN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[14:41:19.752,805] [Z_STACK/READ] INFO   : Received 1 bytes, subSys 0x6F, cmdId 0x05
[14:41:19.752,836] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
[14:41:19.752,848] [Z_STACK/READ] INFO   : Client Read: (len 4):
[14:41:19.752,878] [Z_STACK/MAIN] INFO   : [MUTEX] Unlock SRSP Mutex
[14:41:19.795,381] [Z_STACK/READ] INFO   : Received 1 bytes, subSys 0x45, cmdId 0xC0
[14:41:19.795,400] [Z_STACK/READ] INFO   : RPC_CMD_AREQ cmdId: 0xC0
[14:41:19.795,412] [Z_STACK/READ] INFO   : [DBG] Allocated      @ 0x84000C60 (received  1 messages)...
[14:41:19.795,426] [Z_STACK/READ] INFO   : Filling new message (@ 0x84000C60)...
[14:41:19.795,458] [Z_STACK/READ] INFO   : Received 3 bytes, subSys 0x4F, cmdId 0x80
[14:41:19.795,479] [Z_STACK/READ] INFO   : RPC_CMD_AREQ cmdId: 0x80
[14:41:19.795,496] [Z_STACK/READ] INFO   : [DBG] Allocated      @ 0x84000C80 (received  2 messages)...
[14:41:19.795,511] [Z_STACK/READ] INFO   : Filling new message (@ 0x84000C80)...
[14:41:19.795,532] [Z_STACK/HNDL] INFO   : [MUTEX] Mutex for AREQ unlocked
[14:41:19.795,549] [Z_STACK/HNDL] INFO   : [DBG] Processing     @ 0x84000C60
[14:41:19.795,567] [Z_STACK/HNDL] INFO   : [MUTEX] AREQ Calling asynchMsgCback (Handle)...
[14:41:19.795,581] [Z_STACK/HNDLstarting NETWORK_MGR, cmd ' ./NWKMGR_SRVR_arm 127.0.0.1:2536 -v 0xFFFFFFFF ' on Mon 24 May 2021 02:41:21 PM UTC
by read loop) 
[-->] 3 bytes, subSys 0x4F, cmdId 0x80, pData: 0x08 0x02 0x00
[--> 000:00:00.951154 (+0.198343)] 03 bytes, subSys 0x4F, cmdId 0x80, pData:    0x08 0x02 0x00
[14:41:19.951,178] [NPISRVR/ACBK] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [bcst] 03:4F:80:08:02:00
] INFO   : [DBG] asyncCB: subSys:0x00000005, cmdId:0x000000C0, len:0x00000001, pData:0x84000C70
[14:41:19.795,596] [Z_STACK/HNDL] INFO   : [MUTEX] AREQ (Handle) (message @ 0x84000C60)...
[14:41:19.795,609] [Z_STACK/HNDL] INFO   : [DBG] Clearing               @ 0x84000C60 (processed 1 messages)...
[14:41:19.795,623] [Z_STACK/HNDL] INFO   : [MUTEX] Wait for AREQ semaphore
[14:41:19.795,636] [Z_STACK/HNDL] INFO   : [MUTEX] Mutex for AREQ unlocked
[14:41:19.795,648] [Z_STACK/HNDL] INFO   : [DBG] Processing     @ 0x84000C80
[14:41:19.795,659] [Z_STACK/HNDL] INFO   : [MUTEX] AREQ Calling asynchMsgCback (Handle)...
[14:41:19.795,671] [Z_STACK/HNDL] INFO   : [DBG] asyncCB: subSys:0x0000000F, cmdId:0x00000080, len:0x00000003, pData:0x84000C90
[14:41:19.795,909] [Z_STACK/HNDL] INFO   : [MUTEX] AREQ (Handle) (message @ 0x84000C80)...
[14:41:19.795,925] [Z_STACK/HNDL] INFO   : [DBG] Clearing               @ 0x84000C80 (processed 2 messages)...
[14:41:19.795,937] [Z_STACK/HNDL] INFO   : [MUTEX] Wait for AREQ semaphore
[14:41:19.795,959] [Z_STACK/MAIN] INFO   : zstackpb: AppCnfCommissioningNotification: state:13
[14:41:19.795,976] [Z_STACK/MAIN] INFO   : zstackpb: AppCnfCommissioningNotification: commMode:0
[14:41:19.795,990] [Z_STACK/MAIN] INFO   : zstackpb: AppCnfCommissioningNotification: remainingCommMode:4
[14:41:19.951,320] [Z_STACK/READ] INFO   : Received 3 bytes, subSys 0x4F, cmdId 0x80
[14:41:19.951,348] [Z_STACK/READ] INFO   : RPC_CMD_AREQ cmdId: 0x80
[14:41:19.951,360] [Z_STACK/READ] INFO   : [DBG] Allocated      @ 0x84000C40 (received  3 messages)...
[14:41:19.951,372] [Z_STACK/READ] INFO   : Filling new message (@ 0x84000C40)...
[14:41:19.951,402] [Z_STACK/HNDL] INFO   : [MUTEX] Mutex for AREQ unlocked
[14:41:19.951,417] [Z_STACK/HNDL] INFO   : [DBG] Processing     @ 0x84000C40
[14:41:19.951,432] [Z_STACK/HNDL] INFO   : [MUTEX] AREQ Calling asynchMsgCback (Handle)...
[14:41:19.951,444] [Z_STACK/HNDL] INFO   : [DBG] asyncCB: subSys:0x0000000F, cmdId:0x00000080, len:0x00000003, pData:0x84000C50
[14:41:19.951,485] [Z_STACK/HNDL] INFO   : [MUTEX] AREQ (Handle) (message @ 0x84000C40)...
[14:41:19.951,497] [Z_STACK/HNDL] INFO   : [DBG] Clearing               @ 0x84000C40 (processed 3 messages)...
[14:41:19.951,509] [Z_STACK/HNDL] INFO   : [MUTEX] Wait for AREQ semaphore
[14:41:19.951,528] [Z_STACK/MAIN] INFO   : zstackpb: AppCnfCommissioningNotification: state:8
[14:41:19.951,546] [Z_STACK/MAIN] INFO   : zstackpb: AppCnfCommissioningNotification: commMode:2
[14:41:19.951,560] [Z_STACK/MAIN] INFO   : zstackpb: AppCnfCommissioningNotification: remainingCommMode:0
[14:41:22.511,593] [NWK_MGR/MAIN] INFO   :  there are 2 args
...sent 6 bytes to Client #5
Receive message...
[<-- 000:00:03.515174 (+2.564135)] 00 bytes, subSys 0x25, cmdId 0x50, pData:   
NPI SREQ:  (len 3) 0x00 0x25 0x50
[<-- 000:00:03.515188 (+0.    14)] [UART] write 5 bytes to 4
[14:41:22.515,204] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 00:25:50
[14:41:22.512,240] [Z_STACK/LSTN] MISC1  : Connected to #5.(127.0.0.1 / ::)
[14:41:22.512,267] [Z_STACK/LSTN] INFO   : zstackpb zspbHandlePbCb - connected: 5
[14:41:22.512,280] [Z_STACK/LSTN] CONNECT: Connected to new client, connection # 5
[14:41:22.512,654] [Z_STACK/LSTN] INFO   : Receive message...
[14:41:22.512,683] [Z_STACK/LSTN] CONNECT: Client at connection # 5 identified itself as NWK_MGR
[14:41:22.512,702] [Z_STACK/LSTN] INFO   : zstackpb zspbHandlePbCb: subsystemID:5f, cmdId:0
[14:41:22.512,715] [Z_STACK/LSTN] INFO   : !Done
[14:41:22.514,605] [Z_STACK/LSTN] INFO   : Receive message...
[14:41:22.514,628] [Z_STACK/LSTN] INFO   : zstackpb zspbHandlePbCb: subsystemID:31, cmdId:14
[14:41:22.514,717] [Z_STACK/LSTN] PKT_HEX: [                  Z_STACK>>NWK_MGR                  ] [ucst] 04:00:71:FA:08:14:10:00
[14:41:22.514,739] [Z_STACK/LSTN] PKTTYPE: [                  Z_STACK>>NWK_MGR                  ] zstackDefaultRsp
[14:41:22.514,754] [Z_STACK/LSTN] PKTBODY:                                                          cmdID = DEV_ZDO_CBS_REQ
[14:41:22.514,767] [Z_STACK/LSTN] PKTBODY:                                                          status = ZSuccess
[14:41:22.514,825] [Z_STACK/LSTN] INFO   : ...sent 8 bytes to Client
[14:41:22.514,840] [Z_STACK/LSTN] INFO   : !Done
[14:41:22.515,036] [Z_STACK/LSTN] INFO   : Receive message...
[14:41:22.515,053] [Z_STACK/LSTN] INFO   : zstackpb zspbHandlePbCb: subsystemID:31, cmdId:8
[14:41:22.515,063] [Z_STACK/LSTN] INFO   : preparing to send 0 bytes, subSys 0x05, cmdId 0x50, pData:
[14:41:22.515,072] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[14:41:22.515,089] [Z_STACK/LSTN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 00:25:50
[14:41:22.515,107] [Z_STACK/LSTN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 00:25:50
[14:41:22.515,160] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...
[14:41:22.515,171] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[14:41:22.515,179] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[14:41:22.519,878] [Z_STACK/READ] INFO   : Received 24 bytes, subSys 0x65, cmdId 0x50
[14:41:22.519,897] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
[14:41:22.519,908] [Z_STACK/READ] INFO   : Client Read: (len 27):
[14:41:22.519,928] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[14:41:22.519,940] [Z_STACK/LSTN] INFO   : zstackpb Sending Network Info Response
[14:41:22.519,951] [Z_STACK/LSTN] INFO   : znp_misc osal_nv_read: id:1, len:8
[14:41:22.519,962] [Z_STACK/LSTN] INFO   : preparing to send 3 bytes, subSys 0x01, cmdId 0x08, pData:
[14:41:22.519,973] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[14:41:22.519,994] [Z_STACK/LSTN] PKT_HEX: [         NPISRVR<<Z_STACK                           ] [SREQ] 03:21:08:01:00:00
[14:41:22.520,016] [Z_STACK/LSTN] PKTTYPE: [         NPISRVR<<Z_STACK                           ] [SREQ] 03:21:08:01:00:00
[14:41:22.520,057] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...
[14:41:22.520,067] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
[14:41:22.520,075] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[14:41:22.528,865] [Z_STACK/READ] INFO   : Received 10 bytes, subSys 0x61, cmdId 0x08
[14:41:22.528,886] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
[14:41:22.528,910] [Z_STACK/READ] INFO   : Client Read: (len 13):
[14:41:22.528,934] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
[14:41:22.529,226] [Z_STACK/LSTN] PKT_HEX: [                  Z_STACK>>NWK_MGR                  ] [ucst] 31:00:71:0E:08:0E:10:00:19:FA:41:F6:14:00:4B:12:00:20:09:28:DE:AC:03:31:FA:41:F6:14:00:4B:12:00:3B
[14:41:22.529,253] [Z_STACK/LSTN] PKTTYPE: [                  Z_STACK>>NWK_MGR                  ] sysNwkInfoReadRsp
[14:41:22.529,279] [Z_STACK/LSTN] PKTBODY:                                                          cmdID = SYS_NWK_INFO_READ_RSP
[14:41:22.529,295] [Z_STACK/LSTN] PKTBODY:                                                          nwkAddr = 0x00000000 (0)
[14:41:22.529,313] [Z_STACK/LSTN] PKTBODY:                                                          ieeeAddr = 00:12:4B:00:14:F6:41:FA
[14:41:22.529,328] [Z_STACK/LSTN] PKTBODY:                                                          devState = DEV_ZB_COORD
[14:41:22.529,343] [Z_STACK/LSTN] PKTBODY:                                                          panId = 0x0000D65E (54878)
[14:41:22.529,359] [Z_STACK/LSTN] PKTBODY:                                                          extendedPanId = 00:12:4B:00:14:F6:41:FA
[14:41:22.529,374] [Z_STACK/LSTN] PKTBODY:                                                          coordAddr = 0x00000000 (0)
[14:41:22.529,391] [Z_STACK/LSTN] PKTBODY:                                                          coordExtAddr = 00:00:00:00:00:00:00:00
[14:41:22.529,406] [Z_STACK/LSTN] PKTBODY:                                                          devTypes :
[14:41:22.529,447] [Z_STACK/LSTN] ERROR  : ERROR: signal 11 was trigerred:
[14:41:22.529,465] [Z_STACK/LSTN] ERROR  :   Fault address: 0x84000ce8
[14:41:22.529,479] [Z_STACK/LSTN] ERROR  :   Fault reason: address not mapped to object
[14:41:22.530,091] [Z_STACK/LSTN] ERROR  : Stack trace unavailable
[14:41:22.530,108] [Z_STACK/LSTN] ERROR  : Executing original handler...
[<-- 000:00:03.515264 (+0.    76)] [UART] result: 5
[<-- 000:00:03.515270 (+0.     6)] [UART] (synch data) Conditional wait 6 s
[<-- 000:00:03.519640 (+0.  4370)] Signal from UART, grabbing mutex
[<-- 000:00:03.519653 (+0.    13)] Signal read handle, owning mutex
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x65, Cmd ID: 0x50, length: 24
[14:41:22.519,714] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 18:65:50:00:00:09:5E:D6:00:00:FA:41:F6:14:00:4B:12:00:00:00:00:00:00:00:00:00:0B
[UART] npi_procframe signal synch response received (invoked by read loop) 
NPI SRSP: (len 27) 0x18 0x65 0x50 0x00 0x00 0x09 0x5E 0xD6 0x00 0x00 0xFA 0x41 0xF6 0x14 0x00 0x4B 0x12 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x0B
[--> 000:00:03.519757 (+2.568603)] 24 bytes, subSys 0x65, cmdId 0x50, pData:    0x00 0x00 0x09 0x5E 0xD6 0x00 0x00 0xFA 0x41 0xF6 0x14 0x00 0x4B 0x12 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x0B
[14:41:22.519,805] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 18:65:50:00:00:09:5E:D6:00:00:FA:41:F6:14:00:4B:12:00:00:00:00:00:00:00:00:00:0B
...sent 27 bytes to Client #5
!Done
Receive message...
[<-- 000:00:03.520060 (+0.   407)] 03 bytes, subSys 0x21, cmdId 0x08, pData:    0x01 0x00 0x00
NPI SREQ:  (len 6) 0x03 0x21 0x08 0x01 0x00 0x00
[<-- 000:00:03.520071 (+0.    11)] [UART] write 8 bytes to 4
[14:41:22.520,085] [NPISRVR/MAIN] PKT_HEX: [SOCZIGB<<NPISRVR                                    ] [send] 03:21:08:01:00:00
[<-- 000:00:03.520117 (+0.    46)] [UART] result: 8
[<-- 000:00:03.520121 (+0.     4)] [UART] (synch data) Conditional wait 6 s
[<-- 000:00:03.528667 (+0.  8546)] Signal from UART, grabbing mutex
[<-- 000:00:03.528678 (+0.    11)] Signal read handle, owning mutex
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x61, Cmd ID: 0x08, length: 10
[14:41:22.528,721] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [SRSP] 0A:61:08:00:08:FA:41:F6:14:00:4B:12:00
[UART] npi_procframe signal synch response received (invoked by read loop) 
NPI SRSP: (len 13) 0x0A 0x61 0x08 0x00 0x08 0xFA 0x41 0xF6 0x14 0x00 0x4B 0x12 0x00
[--> 000:00:03.528763 (+0.  9006)] 10 bytes, subSys 0x61, cmdId 0x08, pData:    0x00 0x08 0xFA 0x41 0xF6 0x14 0x00 0x4B 0x12 0x00
[14:41:22.528,802] [NPISRVR/MAIN] PKT_HEX: [         NPISRVR>>Z_STACK                           ] [ucst] 0A:61:08:00:08:FA:41:F6:14:00:4B:12:00
[14:41:22.511,790] [NWK_MGR/MAIN] INFO   :  argv[0] = ./NWKMGR_SRVR_arm
[14:41:22.511,803] [NWK_MGR/MAIN] INFO   :  argv[1] = 127.0.0.1:2536
[14:41:22.511,853] [NWK_MGR/MAIN] MISC1  : Port: 2536

[14:41:22.511,885] [NWK_MGR/MAIN] MISC1  : IP addresses for 127.0.0.1:

[14:41:22.511,903] [NWK_MGR/MAIN] MISC1  :   IPv4: 127.0.0.1
[14:41:22.511,916] [NWK_MGR/MAIN] MISC1  : Trying to connect...
[14:41:22.512,170] [NWK_MGR/MAIN] MISC1  : Connected.
[14:41:22.512,391] [NWK_MGR/MAIN] UNMSKBL: 
[14:41:22.512,407] [NWK_MGR/MAIN] UNMSKBL:  ************************************************
[14:41:22.512,418] [NWK_MGR/MAIN] UNMSKBL:  *  Network Manager Server v1.0.2d              *
[14:41:22.512,428] [NWK_MGR/MAIN] UNMSKBL:  ************************************************
[14:41:22.512,440] [NWK_MGR/HNDL] INFO   : [MUTEX] Wait for AREQ semaphore
[14:41:22.512,473] [NWK_MGR/MAIN] UNMSKBL: 
[14:41:22.512,494] [NWK_MGR/MAIN] INFO   : trying to send 8 bytes, subSys 0x1F, cmdId 0x00
[14:41:22.512,537] [NWK_MGR/MAIN] PKT_HEX: [                  Z_STACK<<NWK_MGR                  ] [AREQ] 08:00:5F:00:03:4E:57:4B:5F:4D:47:52
[14:41:22.512,576] [NWK_MGR/MAIN] PKTTYPE: [                  Z_STACK<<NWK_MGR                  ] [AREQ] 08:00:5F:00:03:4E:57:4B:5F:4D:47:52
[14:41:22.512,841] [NWK_MGR/MAIN] MISC1  : NwkMgr: Sending Device ZDO CB Request
[14:41:22.513,496] [NWK_MGR/MAIN] INFO   : preparing to send 90 bytes, subSys 0x11, cmdId 0x14, pData:
[14:41:22.513,512] [NWK_MGR/MAIN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[14:41:22.513,662] [NWK_MGR/MAIN] PKT_HEX: [                  Z_STACK<<NWK_MGR                  ] [SREQ] 5A:00:31:14:08:14:10:01:18:01:20:01:28:01:30:01:38:01:40:01:48:01:50:01:58:01:60:01:68:01:70:01:71
[14:41:22.513,688] [NWK_MGR/MAIN] PKTTYPE: [                  Z_STACK<<NWK_MGR                  ] devZDOCBReq
[14:41:22.513,969] [NWK_MGR/MAIN] PKTBODY:                                                          cmdID = DEV_ZDO_CBS_REQ
[14:41:22.513,988] [NWK_MGR/MAIN] PKTBODY:                                                          srcRtgIndCB = 1
[14:41:22.514,003] [NWK_MGR/MAIN] PKTBODY:                                                          concentratorIndCb = 1
[14:41:22.514,018] [NWK_MGR/MAIN] PKTBODY:                                                          nwkDiscCnfCB = 1
[14:41:22.514,033] [NWK_MGR/MAIN] PKTBODY:                                                          beaconNotIndCB = 1
[14:41:22.514,047] [NWK_MGR/MAIN] PKTBODY:                                                          joinCnfCB = 1
[14:41:22.514,063] [NWK_MGR/MAIN] PKTBODY:                                                          leaveCnfCB = 1
[14:41:22.514,081] [NWK_MGR/MAIN] PKTBODY:                                                          leaveIndCB = 1
[14:41:22.514,097] [NWK_MGR/MAIN] PKTBODY:                                                          nwkAddrRsp = 1
[14:41:22.514,113] [NWK_MGR/MAIN] PKTBODY:                                                          ieeeAddrRsp = 1
[14:41:22.514,129] [NWK_MGR/MAIN] PKTBODY:                                                          nodeDescRsp = 1
[14:41:22.514,147] [NWK_MGR/MAIN] PKTBODY:                                                          powerDescRsp = 1
[14:41:22.514,166] [NWK_MGR/MAIN] PKTBODY:                                                          simpleDescRsp = 1
[14:41:22.514,183] [NWK_MGR/MAIN] PKTBODY:                                                          activeEndpointRsp = 1
[14:41:22.514,198] [NWK_MGR/MAIN] PKTBODY:                                                          matchDescRsp = 1
[14:41:22.514,213] [NWK_MGR/MAIN] PKTBODY:                                                          complexDescRsp = 1
[14:41:22.514,229] [NWK_MGR/MAIN] PKTBODY:                                                          userDescRsp = 1
[14:41:22.514,243] [NWK_MGR/MAIN] PKTBODY:                                                          discoveryCacheRsp = 1
[14:41:22.514,259] [NWK_MGR/MAIN] PKTBODY:                                                          userDescCnf = 1
[14:41:22.514,275] [NWK_MGR/MAIN] PKTBODY:                                                          serverDiscoveryRsp = 1
[14:41:22.514,291] [NWK_MGR/MAIN] PKTBODY:                                                          endDeviceTimeoutRsp = 1
[14:41:22.514,307] [NWK_MGR/MAIN] PKTBODY:                                                          bindRsp = 1
[14:41:22.514,321] [NWK_MGR/MAIN] PKTBODY:                                                          endDeviceBindRsp = 1
[14:41:22.514,337] [NWK_MGR/MAIN] PKTBODY:                                                          unbindRsp = 1
[14:41:22.514,353] [NWK_MGR/MAIN] PKTBODY:                                                          mgmtNwkDiscRsp = 1
[14:41:22.514,371] [NWK_MGR/MAIN] PKTBODY:                                                          mgmtLqiRsp = 1
[14:41:22.514,387] [NWK_MGR/MAIN] PKTBODY:                                                          mgmtRtgRsp = 1
[14:41:22.514,403] [NWK_MGR/MAIN] PKTBODY:                                                          mgmtBindRsp = 1
[14:41:22.514,419] [NWK_MGR/MAIN] PKTBODY:                                                          mgmtLeaveRsp = 1
[14:41:22.514,442] [NWK_MGR/MAIN] PKTBODY:                                                          mgmtDirectJoinRsp = 1
[14:41:22.514,465] [NWK_MGR/MAIN] PKTBODY:                                                          mgmtPermitJoinRsp = 1
[14:41:22.514,488] [NWK_MGR/MAIN] PKTBODY:                                                          mgmtNwkUpdateNotify = 1
[14:41:22.514,511] [NWK_MGR/MAIN] PKTBODY:                                                          deviceAnnounce = 1
[14:41:22.514,521] [NWK_MGR/MAIN] PKTBODY:                                                          devStateChange = 1
[14:41:22.514,535] [NWK_MGR/MAIN] PKTBODY:                                                          tcDeviceInd = 1
[14:41:22.514,615] [NWK_MGR/MAIN] INFO   : Waiting for synchronous response...
[14:41:22.514,626] [NWK_MGR/MAIN] INFO   : [MUTEX] Lock SRSP Mutex
[14:41:22.514,634] [NWK_MGR/MAIN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[14:41:22.514,828] [NWK_MGR/READ] INFO   : Received 4 bytes, subSys 0x71, cmdId 0xFA
[14:41:22.514,851] [NWK_MGR/READ] INFO   : [MUTEX] SRSP Cond signal set
[14:41:22.514,860] [NWK_MGR/READ] INFO   : Client Read: (len 8):
[14:41:22.514,886] [NWK_MGR/MAIN] INFO   : [MUTEX] Unlock SRSP Mutex
[14:41:22.514,906] [NWK_MGR/MAIN] MISC1  : ZDO Callback Register Response Successful
[14:41:22.514,917] [NWK_MGR/MAIN] MISC1  : NwkMgr sendSysNwkInfoReadReqAndSetTxPower:
[14:41:22.514,933] [NWK_MGR/MAIN] INFO   : preparing to send 2 bytes, subSys 0x11, cmdId 0x08, pData:
[14:41:22.514,944] [NWK_MGR/MAIN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[14:41:22.514,966] [NWK_MGR/MAIN] PKT_HEX: [                  Z_STACK<<NWK_MGR                  ] [SREQ] 02:00:31:08:08:08
[14:41:22.514,984] [NWK_MGR/MAIN] PKTTYPE: [                  Z_STACK<<NWK_MGR                  ] sysNwkInfoReadReq
[14:41:22.514,999] [NWK_MGR/MAIN] PKTBODY:                                                          cmdID = SYS_NWK_INFO_READ_REQ
[14:41:22.515,040] [NWK_MGR/MAIN] INFO   : Waiting for synchronous response...
[14:41:22.515,050] [NWK_MGR/MAIN] INFO   : [MUTEX] Lock SRSP Mutex
[14:41:22.515,060] [NWK_MGR/MAIN] INFO   : [MUTEX] Wait for SRSP Cond signal...
[14:41:22.530,687] [NWK_MGR/READ] INFO   : Peer closed connection
[14:41:22.530,756] [NWK_MGR/HNDL] INFO   : [MUTEX] Mutex for AREQ unlocked
[14:41:22.530,799] [NWK_MGR/HNDL] DEBUG  : Server connection was terminated
[14:41:24.515,138] [NWK_MGR/MAIN] INFO   : [MUTEX] SRSP Cond Wait timed out!
[14:41:24.515,190] [NWK_MGR/MAIN] ERROR  : SRSP Cond Wait timed out!
[14:41:24.515,203] [NWK_MGR/MAIN] INFO   : [MUTEX] Unlock SRSP Mutex
[14:41:24.515,218] [NWK_MGR/MAIN] ERROR  : apicSendSynchData() failed getting response
[14:41:24.516,573] [NWK_MGR/MAIN] MISC1  : Opened Database 'DbDeviceInfo.csv', 0 records
[14:41:24.516,849] [NWK_MGR/MAIN] MISC1  : Opened Database 'DbEndpoints.csv', 0 records
[14:41:24.517,480] [NWK_MGR/MAIN] ERROR  : Reading Local Network Information Failed
[14:41:24.517,504] [NWK_MGR/MAIN] UNMSKBL: Initialization failed. Quitting now.

Startup phase 3 failed
./zigbeeHAgw: line 623: killall: command not found
waiting for Zstack linux to exit
./zigbeeHAgw: line 638: killall: command not found
waiting for NPI to exit
...sent 13 bytes to Client #5
!Done
Receive message...
Will disconnect #5
Done with 5
Removing connection #5
No  Active Connections[<-- 000:00:16.520512 (+12.991834)] Signal from UART, grabbing mutex
[<-- 000:00:16.520543 (+0.    31)] Signal read handle, owning mutex
[<-- 000:00:16.521401 (+0.   858)] Signal from UART, grabbing mutex
[<-- 000:00:16.521410 (+0.     9)] Signal read handle, owning mutex
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x41, Cmd ID: 0x80, length: 6
[14:41:35.521,460] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 06:41:80:00:02:00:02:07:01
[UART] npi_procframe signal areq callback thread (invoked by read loop) 
[<-- 000:00:18.567604 (+2. 46194)] Signal from UART, grabbing mutex
[<-- 000:00:18.567638 (+0.    34)] Signal read handle, owning mutex
[<-- 000:00:18.568510 (+0.   872)] Signal from UART, grabbing mutex
[<-- 000:00:18.568520 (+0.    10)] Signal read handle, owning mutex
[UART] npi_parseframe: found frame, going to npi_procframe
[UART] npi_procframe, subsys: 0x41, Cmd ID: 0x80, length: 6
[14:41:37.568,571] [NPISRVR/U_RX] PKT_HEX: [SOCZIGB>>NPISRVR                                    ] [ASNC] 06:41:80:00:02:00:02:07:01