Ember: fix for some startup issues, with associated tests.

Should cover cases of messy startups... (mostly linked to virtualization) Leaving a trace of the logs gathered from the tests here, for future reference. These were mirrored from observed "improper behaviors" in various setups.

Noise on first RST

ERROR on first RST

ERROR RESET_WATCHDOG on first RST

Duplicate RSTACK

```logs zh:ember:uart:ash: ======== ASH NCP reset ======== zh:ember:uart:ash: RTS/CTS config is off, enabling software flow control. zh:ember:uart:ash: Opening serial port with {"path":"/dev/ttyACM0","baudRate":115200,"rtscts":false,"autoOpen":false,"parity":"none","stopBits":1,"xon":true,"xoff":true,"binding":{}} zh:ember:uart:ash: Serial port opened zh:ember:ezsp: ======== EZSP starting ======== zh:ember:uart:ash: ======== ASH NCP reset ======== zh:ember:uart:ash: ======== ASH starting ======== zh:ember:uart:ash: ---> [FRAME type=RST] zh:ember:uart:ash:writer: >>>> [FRAME raw=1ac038bc7e] zh:ember:uart:ash: Waiting for RSTACK... 0/2500 zh:ember:uart:ash: Waiting for RSTACK... 100/2500 zh:ember:uart:ash: Waiting for RSTACK... 200/2500 zh:ember:uart:ash: Waiting for RSTACK... 300/2500 zh:ember:uart:ash: Waiting for RSTACK... 400/2500 zh:ember:uart:ash: Waiting for RSTACK... 500/2500 zh:ember:uart:ash: Waiting for RSTACK... 600/2500 zh:ember:uart:ash: Waiting for RSTACK... 700/2500 zh:ember:uart:ash: Waiting for RSTACK... 800/2500 zh:ember:uart:ash: Waiting for RSTACK... 900/2500 zh:ember:uart:ash: Waiting for RSTACK... 1000/2500 zh:ember:uart:ash: Waiting for RSTACK... 1100/2500 zh:ember:uart:ash:parser: 1ac1020b0a527e zh:ember:uart:ash:parser: <<<< [FRAME raw=1ac1020b0a527e] zh:ember:uart:ash: <--- [FRAME type=RSTACK] zh:ember:uart:ash: ======== ASH connected ======== zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0] zh:ember:uart:ash:writer: >>>> [FRAME raw=8070787e] zh:ember:uart:ash: ======== ASH started ======== zh:ember:ezsp: ======== EZSP started ======== zh:ember:uart:ash:parser: 1ac1020b0a527e zh:ember:uart:ash:parser: <<<< [FRAME raw=1ac1020b0a527e] zh:ember:uart:ash: Frame(s) in progress cancelled in [1ac1020b0a527e] zh:ember:uart:ash: Received unexpected reset from NCP, with reason=RESET_SOFTWARE. zh:ember:uart:ash: ASH disconnected: ASH_ERROR_NCP_RESET | NCP status: ASH_NCP_FATAL_ERROR zh:ember:uart:ash: Error while parsing received frame, status=HOST_FATAL_ERROR. jest:ember:ezsp: !!! NCP FATAL ERROR reason=HOST_FATAL_ERROR. ATTEMPTING RESET... !!! zh:ember:uart:ash: Port closed. Error? no zh:ember:uart:ash: ======== ASH stopped ======== zh:ember:ezsp: ======== EZSP stopped ======== zh:ember:ezsp: ======== EZSP starting ======== zh:ember:uart:ash: ======== ASH NCP reset ======== zh:ember:uart:ash: RTS/CTS config is off, enabling software flow control. zh:ember:uart:ash: Opening serial port with {"path":"/dev/ttyACM0","baudRate":115200,"rtscts":false,"autoOpen":false,"parity":"none","stopBits":1,"xon":true,"xoff":true,"binding":{}} zh:ember:uart:ash: Serial port opened zh:ember:uart:ash: ======== ASH starting ======== zh:ember:uart:ash: ---> [FRAME type=RST] zh:ember:uart:ash:writer: >>>> [FRAME raw=1ac038bc7e] zh:ember:uart:ash: Waiting for RSTACK... 0/2500 zh:ember:uart:ash: Waiting for RSTACK... 100/2500 zh:ember:uart:ash: Waiting for RSTACK... 200/2500 zh:ember:uart:ash: Waiting for RSTACK... 300/2500 zh:ember:uart:ash: Waiting for RSTACK... 400/2500 zh:ember:uart:ash: Waiting for RSTACK... 500/2500 zh:ember:uart:ash: Waiting for RSTACK... 600/2500 zh:ember:uart:ash: Waiting for RSTACK... 700/2500 zh:ember:uart:ash: Waiting for RSTACK... 800/2500 zh:ember:uart:ash: Waiting for RSTACK... 900/2500 zh:ember:uart:ash:parser: 1ac1020b0a527e zh:ember:uart:ash:parser: <<<< [FRAME raw=1ac1020b0a527e] zh:ember:uart:ash: <--- [FRAME type=RSTACK] zh:ember:uart:ash: ======== ASH connected ======== zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0] zh:ember:uart:ash:writer: >>>> [FRAME raw=8070787e] zh:ember:uart:ash: ======== ASH started ======== zh:ember:ezsp: ======== EZSP started ======== zh:ember:uart:ash: Port closed. Error? no zh:ember:uart:ash: ======== ASH stopped ======== zh:ember:ezsp: ======== EZSP stopped ======== ```

Hardware flow control issues

```logs zh:ember:uart:ash: ======== ASH NCP reset ======== zh:ember:uart:ash: RTS/CTS config is off, enabling software flow control. zh:ember:uart:ash: Opening serial port with {"path":"/dev/ttyACM0","baudRate":115200,"rtscts":false,"autoOpen":false,"parity":"none","stopBits":1,"xon":true,"xoff":true,"binding":{}} zh:ember:uart:ash: Serial port opened zh:ember:ezsp: ======== EZSP starting ======== zh:ember:uart:ash: ======== ASH NCP reset ======== zh:ember:uart:ash: ======== ASH starting ======== zh:ember:uart:ash: ---> [FRAME type=RST] zh:ember:uart:ash:writer: >>>> [FRAME raw=1ac038bc7e] zh:ember:uart:ash: Waiting for RSTACK... 0/2500 zh:ember:uart:ash: Waiting for RSTACK... 100/2500 zh:ember:uart:ash: Waiting for RSTACK... 200/2500 zh:ember:uart:ash: Waiting for RSTACK... 300/2500 zh:ember:uart:ash:parser: c20203d20a7e zh:ember:uart:ash:parser: <<<< [FRAME raw=c20203d20a7e] zh:ember:uart:ash: <--- [FRAME type=ERROR] zh:ember:uart:ash: Received ERROR from NCP while connecting, with code=RESET_WATCHDOG. zh:ember:uart:ash: ASH disconnected | NCP status: ASH_NCP_FATAL_ERROR zh:ember:uart:ash: Error while parsing received frame, status=ASH_NCP_FATAL_ERROR. zh:ember:uart:ash: ======== ASH NCP reset ======== zh:ember:uart:ash: ======== ASH starting ======== zh:ember:uart:ash: ---> [FRAME type=RST] zh:ember:uart:ash:writer: >>>> [FRAME raw=1ac038bc7e] zh:ember:uart:ash: Waiting for RSTACK... 0/2500 zh:ember:uart:ash: Waiting for RSTACK... 100/2500 zh:ember:uart:ash: Waiting for RSTACK... 200/2500 zh:ember:uart:ash: Waiting for RSTACK... 300/2500 zh:ember:uart:ash: Waiting for RSTACK... 400/2500 zh:ember:uart:ash: Waiting for RSTACK... 500/2500 zh:ember:uart:ash: Waiting for RSTACK... 600/2500 zh:ember:uart:ash: Waiting for RSTACK... 700/2500 zh:ember:uart:ash: Waiting for RSTACK... 800/2500 zh:ember:uart:ash: Waiting for RSTACK... 900/2500 zh:ember:uart:ash:parser: 1ac1020b0a527e zh:ember:uart:ash:parser: <<<< [FRAME raw=1ac1020b0a527e] zh:ember:uart:ash: <--- [FRAME type=RSTACK] zh:ember:uart:ash: ======== ASH connected ======== zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0] zh:ember:uart:ash:writer: >>>> [FRAME raw=8070787e] zh:ember:uart:ash: ======== ASH started ======== zh:ember:ezsp: ======== EZSP started ======== zh:ember:uart:ash:parser: 1ac1020b0a527e zh:ember:uart:ash:parser: <<<< [FRAME raw=1ac1020b0a527e] zh:ember:uart:ash: Frame(s) in progress cancelled in [1ac1020b0a527e] zh:ember:uart:ash: <--- [FRAME type=RSTACK] zh:ember:uart:ash: Received unexpected reset from NCP, with reason=RESET_SOFTWARE. zh:ember:uart:ash: ASH disconnected: ASH_ERROR_NCP_RESET | NCP status: ASH_NCP_FATAL_ERROR zh:ember:uart:ash: Error while parsing received frame, status=HOST_FATAL_ERROR. jest:ember:ezsp: !!! NCP FATAL ERROR reason=HOST_FATAL_ERROR. ATTEMPTING RESET... !!! zh:ember:uart:ash: Port closed. Error? no zh:ember:uart:ash: ======== ASH stopped ======== zh:ember:ezsp: ======== EZSP stopped ======== zh:ember:ezsp: ======== EZSP starting ======== zh:ember:uart:ash: ======== ASH NCP reset ======== zh:ember:uart:ash: RTS/CTS config is off, enabling software flow control. zh:ember:uart:ash: Opening serial port with {"path":"/dev/ttyACM0","baudRate":115200,"rtscts":false,"autoOpen":false,"parity":"none","stopBits":1,"xon":true,"xoff":true,"binding":{}} zh:ember:uart:ash: Serial port opened zh:ember:uart:ash: ======== ASH starting ======== zh:ember:uart:ash: ---> [FRAME type=RST] zh:ember:uart:ash:writer: >>>> [FRAME raw=1ac038bc7e] zh:ember:uart:ash: Waiting for RSTACK... 0/2500 zh:ember:uart:ash: Waiting for RSTACK... 100/2500 zh:ember:uart:ash: Waiting for RSTACK... 200/2500 zh:ember:uart:ash: Waiting for RSTACK... 300/2500 zh:ember:uart:ash: Waiting for RSTACK... 400/2500 zh:ember:uart:ash: Waiting for RSTACK... 500/2500 zh:ember:uart:ash: Waiting for RSTACK... 600/2500 zh:ember:uart:ash: Waiting for RSTACK... 700/2500 zh:ember:uart:ash: Waiting for RSTACK... 800/2500 zh:ember:uart:ash: Waiting for RSTACK... 900/2500 zh:ember:uart:ash:parser: 1ac1020b0a527e zh:ember:uart:ash:parser: <<<< [FRAME raw=1ac1020b0a527e] zh:ember:uart:ash: <--- [FRAME type=RSTACK] zh:ember:uart:ash: ======== ASH connected ======== zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0] zh:ember:uart:ash:writer: >>>> [FRAME raw=8070787e] zh:ember:uart:ash: ======== ASH started ======== zh:ember:ezsp: ======== EZSP started ======== zh:ember:uart:ash: Port closed. Error? no zh:ember:uart:ash: ======== ASH stopped ======== zh:ember:ezsp: ======== EZSP stopped ======== ```

ERROR triggers restart (not startup related)

```logs zh:ember:uart:ash: RTS/CTS config is off, enabling software flow control. zh:ember:uart:ash: Opening serial port with {"path":"/dev/ttyACM0","baudRate":115200,"rtscts":false,"autoOpen":false,"parity":"none","stopBits":1,"xon":true,"xoff":true,"binding":{}} zh:ember:uart:ash: Serial port opened zh:ember:ezsp: ======== EZSP starting ======== zh:ember:uart:ash: ======== ASH NCP reset ======== zh:ember:uart:ash: ======== ASH starting ======== zh:ember:uart:ash: ---> [FRAME type=RST] zh:ember:uart:ash:writer: >>>> [FRAME raw=1ac038bc7e] zh:ember:uart:ash: Waiting for RSTACK... 0/2500 zh:ember:uart:ash: Waiting for RSTACK... 100/2500 zh:ember:uart:ash: Waiting for RSTACK... 200/2500 zh:ember:uart:ash: Waiting for RSTACK... 300/2500 zh:ember:uart:ash: Waiting for RSTACK... 400/2500 zh:ember:uart:ash: Waiting for RSTACK... 500/2500 zh:ember:uart:ash: Waiting for RSTACK... 600/2500 zh:ember:uart:ash: Waiting for RSTACK... 700/2500 zh:ember:uart:ash: Waiting for RSTACK... 800/2500 zh:ember:uart:ash: Waiting for RSTACK... 900/2500 zh:ember:uart:ash: Waiting for RSTACK... 1000/2500 zh:ember:uart:ash: Waiting for RSTACK... 1100/2500 zh:ember:uart:ash:parser: 1ac1020b0a527e zh:ember:uart:ash:parser: <<<< [FRAME raw=1ac1020b0a527e] zh:ember:uart:ash: <--- [FRAME type=RSTACK] zh:ember:uart:ash: ======== ASH connected ======== zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0] zh:ember:uart:ash:writer: >>>> [FRAME raw=8070787e] zh:ember:uart:ash: ======== ASH started ======== zh:ember:ezsp: ======== EZSP started ======== zh:ember:ezsp: ===> [FRAME: ID=0:"VERSION" Seq=0 Len=4] zh:ember:uart:ash: ---> [FRAME type=DATA frmTx=0 frmRx=0] zh:ember:uart:ash:writer: >>>> [FRAME raw=004221a8597c057e] zh:ember:uart:ash:parser: 0142a1a8592805c6a8777e zh:ember:uart:ash:parser: <<<< [FRAME raw=0142a1a8592805c6a8777e] zh:ember:uart:ash: <--- [FRAME type=DATA] zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1] zh:ember:uart:ash: <--- [FRAME type=DATA ackNum=1 frmNum=0] Added to rxQueue zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=1] zh:ember:uart:ash:writer: >>>> [FRAME raw=8160597e] zh:ember:ezsp: <=== [FRAME: ID=0:"VERSION" Seq=0 Len=7] zh:ember:uart:ash:parser: c20251a8bd7e zh:ember:uart:ash:parser: <<<< [FRAME raw=c20251a8bd7e] zh:ember:uart:ash: <--- [FRAME type=ERROR] zh:ember:uart:ash: Received ERROR from NCP, with code=ERROR_EXCEEDED_MAXIMUM_ACK_TIMEOUT_COUNT. zh:ember:uart:ash: ASH disconnected | NCP status: ASH_NCP_FATAL_ERROR zh:ember:uart:ash: Error while parsing received frame, status=ASH_NCP_FATAL_ERROR. jest:ember:ezsp: !!! NCP FATAL ERROR reason=HOST_FATAL_ERROR. ATTEMPTING RESET... !!! zh:ember:uart:ash: Port closed. Error? no zh:ember:uart:ash: ======== ASH stopped ======== zh:ember:ezsp: ======== EZSP stopped ======== zh:ember:ezsp: ======== EZSP starting ======== zh:ember:uart:ash: ======== ASH NCP reset ======== zh:ember:uart:ash: RTS/CTS config is off, enabling software flow control. zh:ember:uart:ash: Opening serial port with {"path":"/dev/ttyACM0","baudRate":115200,"rtscts":false,"autoOpen":false,"parity":"none","stopBits":1,"xon":true,"xoff":true,"binding":{}} zh:ember:uart:ash: Serial port opened zh:ember:uart:ash: ======== ASH starting ======== zh:ember:uart:ash: ---> [FRAME type=RST] zh:ember:uart:ash:writer: >>>> [FRAME raw=1ac038bc7e] zh:ember:uart:ash: Waiting for RSTACK... 0/2500 zh:ember:uart:ash: Waiting for RSTACK... 100/2500 zh:ember:uart:ash: Waiting for RSTACK... 200/2500 zh:ember:uart:ash: Waiting for RSTACK... 300/2500 zh:ember:uart:ash: Waiting for RSTACK... 400/2500 zh:ember:uart:ash: Waiting for RSTACK... 500/2500 zh:ember:uart:ash: Waiting for RSTACK... 600/2500 zh:ember:uart:ash: Waiting for RSTACK... 700/2500 zh:ember:uart:ash: Waiting for RSTACK... 800/2500 zh:ember:uart:ash: Waiting for RSTACK... 900/2500 zh:ember:uart:ash:parser: 1ac1020b0a527e zh:ember:uart:ash:parser: <<<< [FRAME raw=1ac1020b0a527e] zh:ember:uart:ash: <--- [FRAME type=RSTACK] zh:ember:uart:ash: ======== ASH connected ======== zh:ember:uart:ash: ---> [FRAME type=ACK frmRx=0] zh:ember:uart:ash:writer: >>>> [FRAME raw=8070787e] zh:ember:uart:ash: ======== ASH started ======== zh:ember:ezsp: ======== EZSP started ======== zh:ember:uart:ash: Port closed. Error? no zh:ember:uart:ash: ======== ASH stopped ======== zh:ember:ezsp: ======== EZSP stopped ======== ```

Koenkk / zigbee-herdsman

Ember: fix for some startup issues, with associated tests. #1053