Raspberry example - error switching wifi to station mode

[toddaustin07]

I am testing the Raspberry Pi example from v1.8 release on a Raspberry Pi Zero. It appears to fail at the point where it should be switching the wifi back to station mode after successfully going through interaction with mobile app. Log output below (I can re-build with debug-level messaging if needed):

I [IoT]: _dump_device_info(746) > firmware_version: switch_example_001
I [IoT]: supplicant_stop_dhcp_client(964) > dhclient is already stopped
I [IoT]: supplicant_stop_dhcp_server(1020) > dnsmasq is already stopped
I [IoT]: st_conn_init(1134) > stdk_version : 1.8.7
I [IoT]: st_conn_start(1222) > st_conn_start start (no-pin)
E [IoT]: _iot_security_be_bsp_fs_load_from_nv(129) > iot_bsp_fs_open(./IotAPPASS) = -1208
E [IoT]: _iot_security_be_bsp_fs_load_from_nv(129) > iot_bsp_fs_open(./IotAPBSSID) = -1208
E [IoT]: _iot_security_be_bsp_fs_load_from_nv(129) > iot_bsp_fs_open(./DeviceID) = -1208
W [IoT]: _check_prov_status(224) > There are no reged data in NV

I [IoT]: st_conn_start(1274) > st_conn_start done (0)
I [IoT]: _do_iot_main_command(586) > curr_main_cmd:0, curr_main_state:0
I [IoT]: _do_state_updating(435) > current state 0, new state 2
I [IoT]: iot_bsp_wifi_set_mode(117) > iot_bsp_wifi_set_mode = 1
I [IoT]: supplicant_stop_dhcp_server(1020) > dnsmasq is already stopped
E [IoT]: supplicant_gdbus_method_call_sync(96) > Error while sending dbus method call GDBus.Error:fi.w1.wpa_supplicant1.InterfaceUnknown: wpa_supplicant knows nothing about this interface.
E [IoT]: supplicant_get_interface(137) > error while sending get interface method call 36
I [IoT]: supplicant_start_scan(707) > Triggered a scan
I [IoT]: iot_easysetup_create_ssid(89) > >> Todds RPI Tes[IsZf] <<
I [IoT]: iot_bsp_wifi_set_mode(117) > iot_bsp_wifi_set_mode = 3
I [IoT]: supplicant_stop_dhcp_client(964) > dhclient is already stopped
I [IoT]: iot_easysetup_init(492) > IOT_STATE_PROV_ES_START
W [IoT]: iot_easysetup_init(522) > wifi event callback isn't registered -1
I [IoT]: es_http_init(159) > http tcp init!!
I [IoT]: iot_easysetup_init(528) > IOT_STATE_PROV_ES_INIT_DONE
I [IoT]: _do_state_updating(533) > Current timeout : 300000 for 0
iot_status: 2, lv: 1
I [IoT]: _do_state_updating(573) > Call usr status_cb with 0x102
iot_status: 2, lv: 4
I [IoT]: _iot_easysetup_gen_get_payload(174) > waiting.. response for [0]
I [IoT]: http_msg_handler(419) > get cmd[0] ok
I [IoT]: _iot_easysetup_gen_post_payload(284) > waiting.. response for [1]
I [IoT]: _es_keyinfo_handler(564) > master secret generation success
I [IoT]: http_msg_handler(395) > post cmd[1] ok
I [IoT]: _iot_easysetup_gen_post_payload(284) > waiting.. response for [2]
I [IoT]: _es_confirminfo_handler(856) > otmSupportFeature = 0
I [IoT]: _es_confirm_check_manager(729) > IOT_STATE_PROV_CONFIRMING
I [IoT]: iot_state_update(267) > Trigger PROV_CONFIRM
I [IoT]: _es_confirm_check_manager(743) > There is no confirmation request. The check is skipped
I [IoT]: _do_iot_main_command(586) > curr_main_cmd:0, curr_main_state:2
I [IoT]: _do_state_updating(435) > current state 2, new state 3
I [IoT]: _do_state_updating(573) > Call usr status_cb with 0x402
I [IoT]: http_msg_handler(395) > post cmd[2] ok
I [IoT]: _iot_easysetup_gen_get_payload(174) > waiting.. response for [4]
I [IoT]: iot_bsp_wifi_set_mode(117) > iot_bsp_wifi_set_mode = 1
I [IoT]: supplicant_start_scan(707) > Triggered a scan
I [IoT]: http_msg_handler(419) > get cmd[4] ok
I [IoT]: _iot_easysetup_gen_post_payload(284) > waiting.. response for [5]
I [IoT]: _es_wifi_prov_parse(1203) > No wifi password
I [IoT]: _es_wifi_prov_parse(1208) > no macAddress
I [IoT]: _es_wifi_prov_parse(1232) > ssid: Prometheus_24GHz
I [IoT]: _es_wifi_prov_parse(1234) > mac addr:
I [IoT]: _es_cloud_prov_parse(1301) > brokerUrl: mqtt-regional-useast1.api.smartthings.com:8883
I [IoT]: _es_cloud_prov_parse(1302) > deviceName : Todds RPI Test Switch
E [IoT]: _iot_security_be_bsp_fs_load_from_nv(129) > iot_bsp_fs_open(./IotAPPASS) = -1208
E [IoT]: _iot_security_be_bsp_fs_load_from_nv(129) > iot_bsp_fs_open(./IotAPBSSID) = -1208
I [IoT]: _es_wifiprovisioninginfo_handler(1398) > provisioning success
I [IoT]: http_msg_handler(395) > post cmd[5] ok
I [IoT]: _iot_easysetup_gen_post_payload(284) > waiting.. response for [6]
I [IoT]: http_msg_handler(395) > post cmd[6] ok
I [IoT]: _do_iot_main_command(586) > curr_main_cmd:0, curr_main_state:3
I [IoT]: _do_state_updating(435) > current state 3, new state 4
I [IoT]: _do_state_updating(533) > Current timeout : 900000 for 3
iot_status: 2, lv: 2
I [IoT]: _do_state_updating(573) > Call usr status_cb with 0x202
I [IoT]: _do_iot_main_command(586) > curr_main_cmd:1, curr_main_state:4
I [IoT]: http_cleanup_all_connection(39) > close listen socket
I [IoT]: http_cleanup_all_connection(46) > close accept socket
I [IoT]: es_http_deinit(184) > http tcp deinit complete!
I [IoT]: iot_easysetup_deinit(564) > IOT_STATE_PROV_ES_DONE
I [IoT]: iot_bsp_wifi_set_mode(117) > iot_bsp_wifi_set_mode = 2
E [IoT]: supplicant_gdbus_method_call_sync(96) > Error while sending dbus method call GDBus.Error:org.freedesktop.DBus.Error.InvalidArgs: invalid message format
E [IoT]: supplicant_add_network(520) > error while sending add network method call 16
E [IoT]: supplicant_join_network(820) > failed to add network while joining AP
E [IoT]: iot_wifi_ctrl_request(171) > failed to set wifi_set_mode -601
E [IoT]: _do_iot_main_command(597) > Can't send WIFI mode command(-601)
E [IoT]: _iot_main_task(909) > failed handle cmd (1): -601

I [IoT]: _do_iot_main_command(586) > curr_main_cmd:1, curr_main_state:4
I [IoT]: iot_bsp_wifi_set_mode(117) > iot_bsp_wifi_set_mode = 2
I [IoT]: supplicant_stop_dhcp_server(1020) > dnsmasq is already stopped
I [IoT]: supplicant_configure_interface(279) > already in required mode
E [IoT]: supplicant_gdbus_method_call_sync(96) > Error while sending dbus method call GDBus.Error:org.freedesktop.DBus.Error.InvalidArgs: invalid message format
E [IoT]: supplicant_add_network(520) > error while sending add network method call 16
E [IoT]: supplicant_join_network(820) > failed to add network while joining AP
E [IoT]: iot_wifi_ctrl_request(171) > failed to set wifi_set_mode -601
E [IoT]: _do_iot_main_command(597) > Can't send WIFI mode command(-601)
E [IoT]: _iot_main_task(909) > failed handle cmd (1): -601

I [IoT]: _do_iot_main_command(586) > curr_main_cmd:1, curr_main_state:4
I [IoT]: iot_bsp_wifi_set_mode(117) > iot_bsp_wifi_set_mode = 2
I [IoT]: supplicant_stop_dhcp_server(1020) > dnsmasq is already stopped
I [IoT]: supplicant_configure_interface(279) > already in required mode
E [IoT]: supplicant_gdbus_method_call_sync(96) > Error while sending dbus method call GDBus.Error:org.freedesktop.DBus.Error.InvalidArgs: invalid message format
E [IoT]: supplicant_add_network(520) > error while sending add network method call 16
E [IoT]: supplicant_join_network(820) > failed to add network while joining AP
E [IoT]: iot_wifi_ctrl_request(171) > failed to set wifi_set_mode -601
E [IoT]: _do_iot_main_command(597) > Can't send WIFI mode command(-601)
E [IoT]: _iot_main_task(909) > failed handle cmd (1): -601

The failure leaves the wifi in AP mode. I would suggest including a utility to reset the wifi manually. I tried restarting dhcpcd, but that did not work; only a system reboot would restore wifi.

[junyoun-kim]

@toddaustin07 When I check code, currently we didn't consider if AP password was not set. I'll fix the case.

Meantime could you try to a AP with password set for test?

[toddaustin07]

Thanks for the reply.

I just tested it with a wifi password, and it works.

Thanks in advance for the fix!