ble-wifi-example-tests: Add fixes and cleanups to ble and wifi tests

(cherry picked from commit 2d22374460)
2021-06-01 12:42:28 +05:30
parent 71cf821659
commit be960bc3dc
10 changed files with 1088 additions and 1110 deletions
--- a/examples/bluetooth/nimble/blecent/blecent_test.py
+++ b/examples/bluetooth/nimble/blecent/blecent_test.py
@@ -15,63 +15,39 @@
 # limitations under the License.

 from __future__ import print_function
-import os
-import re
-import uuid
-import subprocess

-from tiny_test_fw import Utility
+import os
+import subprocess
+import threading
+import traceback
+
+try:
+    import Queue
+except ImportError:
+    import queue as Queue
+
 import ttfw_idf
 from ble import lib_ble_client
+from tiny_test_fw import Utility

 # When running on local machine execute the following before running this script
 # > make app bootloader
 # > make print_flash_cmd | tail -n 1 > build/download.config


-@ttfw_idf.idf_example_test(env_tag="Example_WIFI_BT")
-def test_example_app_ble_central(env, extra_data):
-    """
-        Steps:
-            1. Discover Bluetooth Adapter and Power On
-    """
-
+def blecent_client_task(dut):
    interface = 'hci0'
-    adv_host_name = "BleCentTestApp"
-    adv_iface_index = 0
+    adv_host_name = 'BleCentTestApp'
    adv_type = 'peripheral'
    adv_uuid = '1811'

-    subprocess.check_output(['rm','-rf','/var/lib/bluetooth/*'])
-    subprocess.check_output(['hciconfig','hci0','reset'])
-    # Acquire DUT
-    dut = env.get_dut("blecent", "examples/bluetooth/nimble/blecent", dut_class=ttfw_idf.ESP32DUT)
-
-    # Get binary file
-    binary_file = os.path.join(dut.app.binary_path, "blecent.bin")
-    bin_size = os.path.getsize(binary_file)
-    ttfw_idf.log_performance("blecent_bin_size", "{}KB".format(bin_size // 1024))
-
-    # Upload binary and start testing
-    Utility.console_log("Starting blecent example test app")
-    dut.start_app()
-    dut.reset()
-
-    device_addr = ':'.join(re.findall('..', '%012x' % uuid.getnode()))
-
    # Get BLE client module
-    ble_client_obj = lib_ble_client.BLE_Bluez_Client(interface)
-    if not ble_client_obj:
-        raise RuntimeError("Get DBus-Bluez object failed !!")
+    ble_client_obj = lib_ble_client.BLE_Bluez_Client(iface=interface)

    # Discover Bluetooth Adapter and power on
    is_adapter_set = ble_client_obj.set_adapter()
    if not is_adapter_set:
-        raise RuntimeError("Adapter Power On failed !!")
-
-    # Write device address to dut
-    dut.expect("BLE Host Task Started", timeout=60)
-    dut.write(device_addr + "\n")
+        return

    '''
    Blecent application run:
@@ -81,28 +57,83 @@ def test_example_app_ble_central(env, extra_data):
        Register advertisement
        Start advertising
    '''
-    ble_client_obj.start_advertising(adv_host_name, adv_iface_index, adv_type, adv_uuid)
+    # Create Gatt Application
+    # Register GATT Application
+    ble_client_obj.register_gatt_app()

-    # Call disconnect to perform cleanup operations before exiting application
-    ble_client_obj.disconnect()
+    # Register Advertisement
+    # Check read/write/subscribe is received from device
+    ble_client_obj.register_adv(adv_host_name, adv_type, adv_uuid)

    # Check dut responses
-    dut.expect("Connection established", timeout=60)
+    dut.expect('Connection established', timeout=30)
+    dut.expect('Service discovery complete; status=0', timeout=30)
+    dut.expect('GATT procedure initiated: read;', timeout=30)
+    dut.expect('Read complete; status=0', timeout=30)
+    dut.expect('GATT procedure initiated: write;', timeout=30)
+    dut.expect('Write complete; status=0', timeout=30)
+    dut.expect('GATT procedure initiated: write;', timeout=30)
+    dut.expect('Subscribe complete; status=0', timeout=30)
+    dut.expect('received notification;', timeout=30)

-    dut.expect("Service discovery complete; status=0", timeout=60)
-    print("Service discovery passed\n\tService Discovery Status: 0")

-    dut.expect("GATT procedure initiated: read;", timeout=60)
-    dut.expect("Read complete; status=0", timeout=60)
-    print("Read passed\n\tSupportedNewAlertCategoryCharacteristic\n\tRead Status: 0")
+class BleCentThread(threading.Thread):
+    def __init__(self, dut, exceptions_queue):
+        threading.Thread.__init__(self)
+        self.dut = dut
+        self.exceptions_queue = exceptions_queue

-    dut.expect("GATT procedure initiated: write;", timeout=60)
-    dut.expect("Write complete; status=0", timeout=60)
-    print("Write passed\n\tAlertNotificationControlPointCharacteristic\n\tWrite Status: 0")
+    def run(self):
+        try:
+            blecent_client_task(self.dut)
+        except RuntimeError:
+            self.exceptions_queue.put(traceback.format_exc(), block=False)

-    dut.expect("GATT procedure initiated: write;", timeout=60)
-    dut.expect("Subscribe complete; status=0", timeout=60)
-    print("Subscribe passed\n\tClientCharacteristicConfigurationDescriptor\n\tSubscribe Status: 0")
+
+@ttfw_idf.idf_example_test(env_tag='Example_WIFI_BT')
+def test_example_app_ble_central(env, extra_data):
+    """
+        Steps:
+            1. Discover Bluetooth Adapter and Power On
+            2. Connect BLE Device
+            3. Start Notifications
+            4. Updated value is retrieved
+            5. Stop Notifications
+    """
+    # Remove cached bluetooth devices of any previous connections
+    subprocess.check_output(['rm', '-rf', '/var/lib/bluetooth/*'])
+    subprocess.check_output(['hciconfig', 'hci0', 'reset'])
+
+    # Acquire DUT
+    dut = env.get_dut('blecent', 'examples/bluetooth/nimble/blecent', dut_class=ttfw_idf.ESP32DUT)
+
+    # Get binary file
+    binary_file = os.path.join(dut.app.binary_path, 'blecent.bin')
+    bin_size = os.path.getsize(binary_file)
+    ttfw_idf.log_performance('blecent_bin_size', '{}KB'.format(bin_size // 1024))
+
+    # Upload binary and start testing
+    Utility.console_log('Starting blecent example test app')
+    dut.start_app()
+    dut.reset()
+
+    exceptions_queue = Queue.Queue()
+    # Starting a py-client in a separate thread
+    blehr_thread_obj = BleCentThread(dut, exceptions_queue)
+    blehr_thread_obj.start()
+    blehr_thread_obj.join()
+
+    exception_msg = None
+    while True:
+        try:
+            exception_msg = exceptions_queue.get(block=False)
+        except Queue.Empty:
+            break
+        else:
+            Utility.console_log('\n' + exception_msg)
+
+    if exception_msg:
+        raise Exception('Blecent thread did not run successfully')


 if __name__ == '__main__':
--- a/examples/bluetooth/nimble/blehr/blehr_test.py
+++ b/examples/bluetooth/nimble/blehr/blehr_test.py
@@ -15,57 +15,56 @@
 # limitations under the License.

 from __future__ import print_function
+
 import os
 import re
+import subprocess
 import threading
 import traceback
-import subprocess
-
-from tiny_test_fw import Utility
-import ttfw_idf
-from ble import lib_ble_client

 try:
    import Queue
 except ImportError:
    import queue as Queue

+import ttfw_idf
+from ble import lib_ble_client
+from tiny_test_fw import Utility
+
 # When running on local machine execute the following before running this script
 # > make app bootloader
 # > make print_flash_cmd | tail -n 1 > build/download.config


-def blehr_client_task(hr_obj, dut_addr):
+def blehr_client_task(hr_obj, dut, dut_addr):
    interface = 'hci0'
    ble_devname = 'blehr_sensor_1.0'
    hr_srv_uuid = '180d'
    hr_char_uuid = '2a37'

    # Get BLE client module
-    ble_client_obj = lib_ble_client.BLE_Bluez_Client(interface, devname=ble_devname, devaddr=dut_addr)
-    if not ble_client_obj:
-        raise RuntimeError("Failed to get DBus-Bluez object")
+    ble_client_obj = lib_ble_client.BLE_Bluez_Client(iface=interface)

    # Discover Bluetooth Adapter and power on
    is_adapter_set = ble_client_obj.set_adapter()
    if not is_adapter_set:
-        raise RuntimeError("Adapter Power On failed !!")
+        return

    # Connect BLE Device
-    is_connected = ble_client_obj.connect()
+    is_connected = ble_client_obj.connect(
+        devname=ble_devname,
+        devaddr=dut_addr)
    if not is_connected:
-        # Call disconnect to perform cleanup operations before exiting application
-        ble_client_obj.disconnect()
-        raise RuntimeError("Connection to device " + str(ble_devname) + " failed !!")
+        return

-    # Read Services
-    services_ret = ble_client_obj.get_services()
-    if services_ret:
-        Utility.console_log("\nServices\n")
-        Utility.console_log(str(services_ret))
-    else:
+    # Get services of the connected device
+    services = ble_client_obj.get_services()
+    if not services:
        ble_client_obj.disconnect()
-        raise RuntimeError("Failure: Read Services failed")
+        return
+
+    # Get characteristics of the connected device
+    ble_client_obj.get_chars()

    '''
    Blehr application run:
@@ -73,30 +72,52 @@ def blehr_client_task(hr_obj, dut_addr):
        Retrieve updated value
        Stop Notifications
    '''
-    blehr_ret = ble_client_obj.hr_update_simulation(hr_srv_uuid, hr_char_uuid)
-    if blehr_ret:
-        Utility.console_log("Success: blehr example test passed")
+    # Get service if exists
+    service = ble_client_obj.get_service_if_exists(hr_srv_uuid)
+    if service:
+        # Get characteristic if exists
+        char = ble_client_obj.get_char_if_exists(hr_char_uuid)
+        if not char:
+            ble_client_obj.disconnect()
+            return
    else:
-        raise RuntimeError("Failure: blehr example test failed")
+        ble_client_obj.disconnect()
+        return
+
+    # Start Notify
+    # Read updated value
+    # Stop Notify
+    notify = ble_client_obj.start_notify(char)
+    if not notify:
+        ble_client_obj.disconnect()
+        return
+
+    # Check dut responses
+    dut.expect('subscribe event; cur_notify=1', timeout=30)
+    dut.expect('subscribe event; cur_notify=0', timeout=30)

    # Call disconnect to perform cleanup operations before exiting application
    ble_client_obj.disconnect()

+    # Check dut responses
+    dut.expect('disconnect;', timeout=30)
+

 class BleHRThread(threading.Thread):
-    def __init__(self, dut_addr, exceptions_queue):
+    def __init__(self, dut, dut_addr, exceptions_queue):
        threading.Thread.__init__(self)
+        self.dut = dut
        self.dut_addr = dut_addr
        self.exceptions_queue = exceptions_queue

    def run(self):
        try:
-            blehr_client_task(self, self.dut_addr)
-        except Exception:
+            blehr_client_task(self, self.dut, self.dut_addr)
+        except RuntimeError:
            self.exceptions_queue.put(traceback.format_exc(), block=False)


-@ttfw_idf.idf_example_test(env_tag="Example_WIFI_BT")
+@ttfw_idf.idf_example_test(env_tag='Example_WIFI_BT')
 def test_example_app_ble_hr(env, extra_data):
    """
        Steps:
@@ -106,28 +127,28 @@ def test_example_app_ble_hr(env, extra_data):
            4. Updated value is retrieved
            5. Stop Notifications
    """
-    subprocess.check_output(['rm','-rf','/var/lib/bluetooth/*'])
-    subprocess.check_output(['hciconfig','hci0','reset'])
+    # Remove cached bluetooth devices of any previous connections
+    subprocess.check_output(['rm', '-rf', '/var/lib/bluetooth/*'])
+    subprocess.check_output(['hciconfig', 'hci0', 'reset'])

    # Acquire DUT
-    dut = env.get_dut("blehr", "examples/bluetooth/nimble/blehr", dut_class=ttfw_idf.ESP32DUT)
+    dut = env.get_dut('blehr', 'examples/bluetooth/nimble/blehr', dut_class=ttfw_idf.ESP32DUT)

    # Get binary file
-    binary_file = os.path.join(dut.app.binary_path, "blehr.bin")
+    binary_file = os.path.join(dut.app.binary_path, 'blehr.bin')
    bin_size = os.path.getsize(binary_file)
-    ttfw_idf.log_performance("blehr_bin_size", "{}KB".format(bin_size // 1024))
-    ttfw_idf.check_performance("blehr_bin_size", bin_size // 1024, dut.TARGET)
+    ttfw_idf.log_performance('blehr_bin_size', '{}KB'.format(bin_size // 1024))

    # Upload binary and start testing
-    Utility.console_log("Starting blehr simple example test app")
+    Utility.console_log('Starting blehr simple example test app')
    dut.start_app()
    dut.reset()

    # Get device address from dut
-    dut_addr = dut.expect(re.compile(r"Device Address: ([a-fA-F0-9:]+)"), timeout=30)[0]
+    dut_addr = dut.expect(re.compile(r'Device Address: ([a-fA-F0-9:]+)'), timeout=30)[0]
    exceptions_queue = Queue.Queue()
    # Starting a py-client in a separate thread
-    blehr_thread_obj = BleHRThread(dut_addr, exceptions_queue)
+    blehr_thread_obj = BleHRThread(dut, dut_addr, exceptions_queue)
    blehr_thread_obj.start()
    blehr_thread_obj.join()

@@ -138,15 +159,10 @@ def test_example_app_ble_hr(env, extra_data):
        except Queue.Empty:
            break
        else:
-            Utility.console_log("\n" + exception_msg)
+            Utility.console_log('\n' + exception_msg)

    if exception_msg:
-        raise Exception("Thread did not run successfully")
-
-    # Check dut responses
-    dut.expect("subscribe event; cur_notify=1", timeout=30)
-    dut.expect("subscribe event; cur_notify=0", timeout=30)
-    dut.expect("disconnect;", timeout=30)
+        raise Exception('Blehr thread did not run successfully')


 if __name__ == '__main__':
--- a/examples/bluetooth/nimble/bleprph/bleprph_test.py
+++ b/examples/bluetooth/nimble/bleprph/bleprph_test.py
@@ -15,20 +15,21 @@
 # limitations under the License.

 from __future__ import print_function
+
 import os
 import re
-import traceback
-import threading
 import subprocess
+import threading
+import traceback

 try:
    import Queue
 except ImportError:
    import queue as Queue

-from tiny_test_fw import Utility
 import ttfw_idf
 from ble import lib_ble_client
+from tiny_test_fw import Utility

 # When running on local machine execute the following before running this script
 # > make app bootloader
@@ -36,73 +37,57 @@ from ble import lib_ble_client
 # > export TEST_FW_PATH=~/esp/esp-idf/tools/tiny-test-fw


-def bleprph_client_task(prph_obj, dut, dut_addr):
+def bleprph_client_task(dut, dut_addr):
    interface = 'hci0'
    ble_devname = 'nimble-bleprph'
    srv_uuid = '2f12'
+    write_value = b'A'

    # Get BLE client module
-    ble_client_obj = lib_ble_client.BLE_Bluez_Client(interface, devname=ble_devname, devaddr=dut_addr)
-    if not ble_client_obj:
-        raise RuntimeError("Failed to get DBus-Bluez object")
+    ble_client_obj = lib_ble_client.BLE_Bluez_Client(iface=interface)

    # Discover Bluetooth Adapter and power on
    is_adapter_set = ble_client_obj.set_adapter()
    if not is_adapter_set:
-        raise RuntimeError("Adapter Power On failed !!")
+        return

    # Connect BLE Device
-    is_connected = ble_client_obj.connect()
+    is_connected = ble_client_obj.connect(
+        devname=ble_devname,
+        devaddr=dut_addr)
    if not is_connected:
-        # Call disconnect to perform cleanup operations before exiting application
+        return
+
+    # Get services of the connected device
+    services = ble_client_obj.get_services()
+    if not services:
        ble_client_obj.disconnect()
-        raise RuntimeError("Connection to device " + ble_devname + " failed !!")
+        return
+    # Verify service uuid exists
+    service_exists = ble_client_obj.get_service_if_exists(srv_uuid)
+    if not service_exists:
+        ble_client_obj.disconnect()
+        return
+
+    # Get characteristics of the connected device
+    ble_client_obj.get_chars()
+
+    # Read properties of characteristics (uuid, value and permissions)
+    ble_client_obj.read_chars()
+
+    # Write new value to characteristic having read and write permission
+    # and display updated value
+    write_char = ble_client_obj.write_chars(write_value)
+    if not write_char:
+        ble_client_obj.disconnect()
+        return
+
+    # Disconnect device
+    ble_client_obj.disconnect()

    # Check dut responses
-    dut.expect("GAP procedure initiated: advertise;", timeout=30)
-
-    # Read Services
-    services_ret = ble_client_obj.get_services(srv_uuid)
-    if services_ret:
-        Utility.console_log("\nServices\n")
-        Utility.console_log(str(services_ret))
-    else:
-        ble_client_obj.disconnect()
-        raise RuntimeError("Failure: Read Services failed")
-
-    # Read Characteristics
-    chars_ret = {}
-    chars_ret = ble_client_obj.read_chars()
-    if chars_ret:
-        Utility.console_log("\nCharacteristics retrieved")
-        for path, props in chars_ret.items():
-            Utility.console_log("\n\tCharacteristic: " + str(path))
-            Utility.console_log("\tCharacteristic UUID: " + str(props[2]))
-            Utility.console_log("\tValue: " + str(props[0]))
-            Utility.console_log("\tProperties: : " + str(props[1]))
-    else:
-        ble_client_obj.disconnect()
-        raise RuntimeError("Failure: Read Characteristics failed")
-
-    '''
-    Write Characteristics
-    - write 'A' to characteristic with write permission
-    '''
-    chars_ret_on_write = {}
-    chars_ret_on_write = ble_client_obj.write_chars(b'A')
-    if chars_ret_on_write:
-        Utility.console_log("\nCharacteristics after write operation")
-        for path, props in chars_ret_on_write.items():
-            Utility.console_log("\n\tCharacteristic:" + str(path))
-            Utility.console_log("\tCharacteristic UUID: " + str(props[2]))
-            Utility.console_log("\tValue:" + str(props[0]))
-            Utility.console_log("\tProperties: : " + str(props[1]))
-    else:
-        ble_client_obj.disconnect()
-        raise RuntimeError("Failure: Write Characteristics failed")
-
-    # Call disconnect to perform cleanup operations before exiting application
-    ble_client_obj.disconnect()
+    dut.expect('connection established; status=0', timeout=30)
+    dut.expect('disconnect;', timeout=30)


 class BlePrphThread(threading.Thread):
@@ -114,12 +99,12 @@ class BlePrphThread(threading.Thread):

    def run(self):
        try:
-            bleprph_client_task(self, self.dut, self.dut_addr)
-        except Exception:
+            bleprph_client_task(self.dut, self.dut_addr)
+        except RuntimeError:
            self.exceptions_queue.put(traceback.format_exc(), block=False)


-@ttfw_idf.idf_example_test(env_tag="Example_WIFI_BT")
+@ttfw_idf.idf_example_test(env_tag='Example_WIFI_BT')
 def test_example_app_ble_peripheral(env, extra_data):
    """
        Steps:
@@ -129,28 +114,31 @@ def test_example_app_ble_peripheral(env, extra_data):
            4. Read Characteristics
            5. Write Characteristics
    """
-    subprocess.check_output(['rm','-rf','/var/lib/bluetooth/*'])
-    subprocess.check_output(['hciconfig','hci0','reset'])
+    # Remove cached bluetooth devices of any previous connections
+    subprocess.check_output(['rm', '-rf', '/var/lib/bluetooth/*'])
+    subprocess.check_output(['hciconfig', 'hci0', 'reset'])

    # Acquire DUT
-    dut = env.get_dut("bleprph", "examples/bluetooth/nimble/bleprph", dut_class=ttfw_idf.ESP32DUT)
+    dut = env.get_dut('bleprph', 'examples/bluetooth/nimble/bleprph', dut_class=ttfw_idf.ESP32DUT)

    # Get binary file
-    binary_file = os.path.join(dut.app.binary_path, "bleprph.bin")
+    binary_file = os.path.join(dut.app.binary_path, 'bleprph.bin')
    bin_size = os.path.getsize(binary_file)
-    ttfw_idf.log_performance("bleprph_bin_size", "{}KB".format(bin_size // 1024))
-    ttfw_idf.check_performance("bleprph_bin_size", bin_size // 1024, dut.TARGET)
+    ttfw_idf.log_performance('bleprph_bin_size', '{}KB'.format(bin_size // 1024))

    # Upload binary and start testing
-    Utility.console_log("Starting bleprph simple example test app")
+    Utility.console_log('Starting bleprph simple example test app')
    dut.start_app()
    dut.reset()

    # Get device address from dut
-    dut_addr = dut.expect(re.compile(r"Device Address: ([a-fA-F0-9:]+)"), timeout=30)[0]
+    dut_addr = dut.expect(re.compile(r'Device Address: ([a-fA-F0-9:]+)'), timeout=30)[0]
+
+    # Check dut responses
+    dut.expect('GAP procedure initiated: advertise;', timeout=30)

-    exceptions_queue = Queue.Queue()
    # Starting a py-client in a separate thread
+    exceptions_queue = Queue.Queue()
    bleprph_thread_obj = BlePrphThread(dut, dut_addr, exceptions_queue)
    bleprph_thread_obj.start()
    bleprph_thread_obj.join()
@@ -162,14 +150,10 @@ def test_example_app_ble_peripheral(env, extra_data):
        except Queue.Empty:
            break
        else:
-            Utility.console_log("\n" + exception_msg)
+            Utility.console_log('\n' + exception_msg)

    if exception_msg:
-        raise Exception("Thread did not run successfully")
-
-    # Check dut responses
-    dut.expect("connection established; status=0", timeout=30)
-    dut.expect("disconnect;", timeout=30)
+        raise Exception('BlePrph thread did not run successfully')


 if __name__ == '__main__':
--- a/examples/provisioning/legacy/softap_prov/softap_prov_test.py
+++ b/examples/provisioning/legacy/softap_prov/softap_prov_test.py
@@ -15,89 +15,102 @@
 # limitations under the License.

 from __future__ import print_function
-import re
-import os

-import ttfw_idf
+import os
+import re
+
 import esp_prov
+import tiny_test_fw
+import ttfw_idf
 import wifi_tools
+from tiny_test_fw import Utility

 # Have esp_prov throw exception
 esp_prov.config_throw_except = True


-@ttfw_idf.idf_example_test(env_tag="Example_WIFI_BT")
+@ttfw_idf.idf_example_test(env_tag='Example_WIFI_BT')
 def test_examples_provisioning_softap(env, extra_data):
    # Acquire DUT
-    dut1 = env.get_dut("softap_prov", "examples/provisioning/legacy/softap_prov", dut_class=ttfw_idf.ESP32DUT)
+    dut1 = env.get_dut('softap_prov', 'examples/provisioning/legacy/softap_prov', dut_class=ttfw_idf.ESP32DUT)

    # Get binary file
-    binary_file = os.path.join(dut1.app.binary_path, "softap_prov.bin")
+    binary_file = os.path.join(dut1.app.binary_path, 'softap_prov.bin')
    bin_size = os.path.getsize(binary_file)
-    ttfw_idf.log_performance("softap_prov_bin_size", "{}KB".format(bin_size // 1024))
-    ttfw_idf.check_performance("softap_prov_bin_size", bin_size // 1024, dut1.TARGET)
+    ttfw_idf.log_performance('softap_prov_bin_size', '{}KB'.format(bin_size // 1024))

    # Upload binary and start testing
    dut1.start_app()

    # Parse IP address of STA
-    dut1.expect("Starting WiFi SoftAP provisioning", timeout=60)
+    dut1.expect('Starting WiFi SoftAP provisioning', timeout=60)
    [ssid, password] = dut1.expect(re.compile(r"SoftAP Provisioning started with SSID '(\S+)', Password '(\S+)'"), timeout=30)

    iface = wifi_tools.get_wiface_name()
    if iface is None:
-        raise RuntimeError("Failed to get Wi-Fi interface on host")
-    print("Interface name  : " + iface)
-    print("SoftAP SSID     : " + ssid)
-    print("SoftAP Password : " + password)
+        raise RuntimeError('Failed to get Wi-Fi interface on host')
+    print('Interface name  : ' + iface)
+    print('SoftAP SSID     : ' + ssid)
+    print('SoftAP Password : ' + password)

    try:
        ctrl = wifi_tools.wpa_cli(iface, reset_on_exit=True)
-        print("Connecting to DUT SoftAP...")
-        ip = ctrl.connect(ssid, password)
-        got_ip = dut1.expect(re.compile(r"DHCP server assigned IP to a station, IP is: (\d+.\d+.\d+.\d+)"), timeout=60)[0]
-        if ip != got_ip:
-            raise RuntimeError("SoftAP connected to another host! " + ip + "!=" + got_ip)
-        print("Connected to DUT SoftAP")
+        print('Connecting to DUT SoftAP...')
+        try:
+            ip = ctrl.connect(ssid, password)
+        except RuntimeError as err:
+            Utility.console_log('error: {}'.format(err))
+        try:
+            got_ip = dut1.expect(re.compile(r'DHCP server assigned IP to a station, IP is: (\d+.\d+.\d+.\d+)'), timeout=60)
+            Utility.console_log('got_ip: {}'.format(got_ip))
+            got_ip = got_ip[0]
+            if ip != got_ip:
+                raise RuntimeError('SoftAP connected to another host! {} != {}'.format(ip, got_ip))
+        except tiny_test_fw.DUT.ExpectTimeout:
+            # print what is happening on dut side
+            Utility.console_log('in exception tiny_test_fw.DUT.ExpectTimeout')
+            Utility.console_log(dut1.read())
+            raise
+        print('Connected to DUT SoftAP')

-        print("Starting Provisioning")
+        print('Starting Provisioning')
        verbose = False
-        protover = "V0.1"
+        protover = 'V0.1'
        secver = 1
-        pop = "abcd1234"
-        provmode = "softap"
-        ap_ssid = "myssid"
-        ap_password = "mypassword"
-        softap_endpoint = ip.split('.')[0] + "." + ip.split('.')[1] + "." + ip.split('.')[2] + ".1:80"
+        pop = 'abcd1234'
+        provmode = 'softap'
+        ap_ssid = 'myssid'
+        ap_password = 'mypassword'
+        softap_endpoint = '{}.{}.{}.1:80'.format(ip.split('.')[0], ip.split('.')[1], ip.split('.')[2])

-        print("Getting security")
+        print('Getting security')
        security = esp_prov.get_security(secver, pop, verbose)
        if security is None:
-            raise RuntimeError("Failed to get security")
+            raise RuntimeError('Failed to get security')

-        print("Getting transport")
+        print('Getting transport')
        transport = esp_prov.get_transport(provmode, softap_endpoint)
        if transport is None:
-            raise RuntimeError("Failed to get transport")
+            raise RuntimeError('Failed to get transport')

-        print("Verifying protocol version")
+        print('Verifying protocol version')
        if not esp_prov.version_match(transport, protover):
-            raise RuntimeError("Mismatch in protocol version")
+            raise RuntimeError('Mismatch in protocol version')

-        print("Starting Session")
+        print('Starting Session')
        if not esp_prov.establish_session(transport, security):
-            raise RuntimeError("Failed to start session")
+            raise RuntimeError('Failed to start session')

-        print("Sending Wifi credential to DUT")
+        print('Sending Wifi credential to DUT')
        if not esp_prov.send_wifi_config(transport, security, ap_ssid, ap_password):
-            raise RuntimeError("Failed to send Wi-Fi config")
+            raise RuntimeError('Failed to send Wi-Fi config')

-        print("Applying config")
+        print('Applying config')
        if not esp_prov.apply_wifi_config(transport, security):
-            raise RuntimeError("Failed to send apply config")
+            raise RuntimeError('Failed to send apply config')

        if not esp_prov.wait_wifi_connected(transport, security):
-            raise RuntimeError("Provisioning failed")
+            raise RuntimeError('Provisioning failed')
    finally:
        ctrl.reset()