Timing issue in icetea_lib/DeviceConnectors/Dut.py when device is resetting

[donatieng]

Description

• Type: Bug

---

Bug

Icetea version a52a860e3a35d968b9ae8f2e3d044c841ff873bc

Expected Behavior Icetea initialises cliapp-based DUT correctly and DUT responds to first command.

Actual Behavior Initial command times out:

11:32:07.145 | D1 <-> MainThread: Use normal serial write mode
11:32:07.145 | D1     MainThread: Reset serial device /dev/tty.usbmodem14541
11:32:08.555 | TC     MainThread: Waiting for dut 1 to initialize.
11:32:08.556 | D1 --> DutThread: set --retcode true
11:32:08.615 | D1 <-- DutThread:    _   ___ __  __               _            _  ___  ___
11:32:08.626 | D1 <-- DutThread: /_\ | _ \  \/  |  ___   _ __ | |__  ___ __| |/ _ \/ __|
11:32:08.636 | D1 <-- DutThread: / _ \|   / |\/| | |___| | '  \| '_ \/ -_) _` | (_) \__
11:32:08.648 | D1 <-- DutThread: /_/ \_\_|_\_|  |_|       |_|_|_|_.__/\___\__,_|\___/|___/
11:32:09.815 | D1 <-- DutThread: /> 
11:32:58.738 | D1     MainThread: CMD timeout: set --retcode true

Steps to Reproduce Run icetea on macOS and a cliapp-based DUT with --reset flag.

E.g.: icetea --tcdir /Users/dongar01/ws/ble-suite/ble-tests --tc all --reset

Workaround Looks like icetea is sending the first command too early. Only send command after device has performed reset, adding a wait does the trick but slows down device initialisation.

@@ -586,6 +586,7 @@ 
class Dut(object):
         :return: Nothing
         """
         Dut._logger.debug("Start DUT communication", extra={'type': '<->'})
+        time.sleep(2.5)
         while Dut._run:
             Dut._sem.acquire()
             try:

[jonikula]

Will need to investigate this. We do support a feature called cli_ready_trigger that should delay sending those commands until the cli is actually ready to receive commands. It should be documented in doc/tc_api.md and the html documentation under a similar heading.

[jupe]

@donatieng could you use cli_ready_trigger to avoid this issue in first place ?

Here is documentation how to use it: https://github.com/ARMmbed/icetea/blob/master/doc/tc_api.md#requirements

"cli_ready_trigger", string with prefix "regex:" or no prefix. If this is defined,
Icetea will wait until a line matching this regex or string appears from the DUT
before sending the cli init commands.

NOTE: 11:32:09.815 | D1 <-- DutThread: /> -doesn't actually contains line feed -> that cannot be used for this. We have plans to bring partial support later.

Currently this is the way to wait until cli interface is ready and test can be begin. We have discussed alternative methods as well but current approach is a bit more generic because it doesn't send any data to DUT until it's ready - that is actually important for some use cases. We could bring eventually another optional way to wait "cli-ready" which could behaviours similar way than how greentea does. Anyway, I'll close this for now but reopen this ticket if cli_ready_trigger doesn't work for some reason.