Announcing beta for enabling raspberry pi direct-connected devices

Devices & Integrations Connected Things
,
21

I don’t see anything in the output of the pinout command that looks like the model numbers you listed above. Here’s what I get:

+------------------| |--| |------+
| ooooooooooooo P1 |C|  |A|      |
| 1oooooooooooo    +-+  +-+      |
|    1ooo                        |
| P5 oooo        +---+          +====
|                |SoC|          | USB
|   |D| Pi Model +---+          +====
|   |S| B  V2.0                  |
|   |I|                  |C|+======
|                        |S||   Net
|                        |I|+======
=pwr             |HDMI|          |
+----------------|    |----------+

Revision           : 000d
SoC                : BCM2835
RAM                : 512Mb
Storage            : SD
USB ports          : 2 (excluding power)
Ethernet ports     : 1
Wi-fi              : False
Bluetooth          : False
Camera ports (CSI) : 1
Display ports (DSI): 1

P1:
   3V3  (1) (2)  5V
 GPIO2  (3) (4)  5V
 GPIO3  (5) (6)  GND
 GPIO4  (7) (8)  GPIO14
   GND  (9) (10) GPIO15
GPIO17 (11) (12) GPIO18
GPIO27 (13) (14) GND
GPIO22 (15) (16) GPIO23
   3V3 (17) (18) GPIO24
GPIO10 (19) (20) GND
 GPIO9 (21) (22) GPIO25
GPIO11 (23) (24) GPIO8
   GND (25) (26) GPIO7

P5:
    5V (1) (2) 3V3
GPIO28 (3) (4) GPIO29
GPIO30 (5) (6) GPIO31
   GND (7) (8) GND
22

It’s the 000d identifier (revision). So yes, definitely an older model!

**UPDATE: After posting this, the thought occurred to me that the older Pi’s don’t have integrated wireless, so you may be out of luck. If by chance I’m wrong about yours, then read on…

But before we give up, let’s check something and see if it could work: In a terminal, enter the command:

iw phy0 info

‘phy0’ is the usual name of the physical wireless device. Hopefully yours is the same. That command above will display info regarding your wifi hardware support, but what you are looking for is about 20 lines down from the beginning where you should see Supported interface modes. In that section you are looking for “AP”:

Supported interface modes:
		 * IBSS
		 * managed
		 * AP                       <====
		 * P2P-client
		 * P2P-GO
		 * P2P-device

Let me know if that’s the case, and if so, I’ll update the mastersetup script with your model and we can see if we run into any other issues.

If your wifi doesn’t support AP mode, maybe your SO can buy you new Pi for V-day :grin:

23

An update to any of you interested in running device applications on your Raspberry Pi that are fully integrated with SmartThings:

As it was originally launched, the ST core SDK supported C language apps only, and my beta package is built around that environment. However, knowing that many would much rather code in Python, I’ve been working on an API wrapper to enable that. I’ve got it working now and will be integrating in to my installation package soon.

24

You’re right; there is no integrated wireless on this Pi. I have an external wifi device connected to it via USB. It looks like it doesn’t support AP mode; just IBSS, managed, and monitor.

I’ve got a couple of newer Pi’s that I’m using for other purposes. I’ll see if I can rearrange things and free up one of the newer ones for this project. Thanks for all your help.

1 Like
25

Like Mavrrick I’d be interested in exploring this as an intermediary between ST and Hubitat.

I looked at the setup script and added model d03114 to it for my Raspberry Pi 4 Model B Rev 1.4, and am now working through the ST device setup - should have that in place by the end of the day if I don’t get interrupted.

Edit Update: Looks the Developer Workspace is having issues will have to revisit later.

1 Like
26

That great!! Let me know how you make out and if you have any suggestions for improvement. I had just updated the Pi models the other day, but I’ll make sure I included yours.

27

Here is an update:

Some important issues with the core SDK have been resolved that significantly improve the reliability of Raspberry-Pi-based device apps using the direct connection API - both during the onboarding process and with long-running device apps. A number of other fixes and improvements have been made to my package and I’m ready to declare this out of beta.

I can now support Pi Zero W and Raspberry Pi OS Lite environments in addition to Pi Models 3 & 4 with the full OS. There has also been limited testing with 64bit Raspberry Pi OS, although the Python API wrapper is currently limited to 32 bit OS.

If you’ve tried this package before and run into problems I’d encourage you to download the latest package and give it another shot.

LINK TO GET STARTED ==> https://toddaustin07.github.io/

I also now have a fully-functioning DSC security system integration application built upon this package using alarmserver. See this post for more information:

1 Like
28

Hey, Todd @TAustin , thanks for building this out! I ran into a problem when using the Master setup script to build the SDK (see next error) so I wound up doing a mix of mastersetup steps and manual stuff using your config guide, without success. The first issue I hit was:

In file included from src/easysetup/http/tcp/iot_easysetup_httpd.c:23:
src/include/http/iot_easysetup_http.h:22:10: fatal error: iot_easysetup_http_impl.h: No such file or directory
 #include "iot_easysetup_http_impl.h"

I thought I found a workaround by building without using your sdkbuildsetup first, as building it without mastersetup seemed to work. I was able to build the SDK, configure the example app, get the Pi to run the MyPiTestAccessPoint AP, but I got stuck at the point of adding the app to the Smartthings app. I’d add using the QR code, select the location/room, and the app would stay on the “Start the device app…” screen, eventually timing out with the 05-300 error. It seems like there was no communication between my phone and the PI.

I played with it for most of the day and then after actually reading through the contents of sdkbuildsetup today, I realized that it was doing more than tweaking the Makefile, so I scrapped what I had done and started over.

In the midst of figuring out my next dirty workaround (haha) I think I discovered the root of the initial issue–back in April, Kwang-Hui moved some of the easysetup http stuff (specifically the problematic iot_easysetup_http_impl_h) to /src/port/http/socket. So this time, my workaround was just to copy those files back to /src/include/http and voilla, I was able to build the SDK without the pesky errors. I rebuilt the example app and tested again with no joy–same errors as before (posting below.)

./example
D (1624477165:620) [IoT]: iot_nv_init(197) > >>>HIT<<<
I (1624477165:621) [IoT]: _dump_device_info(706) > firmware_version: switch_example_001
I (1624477165:621) [IoT]: iot_bsp_wifi_init(149) > [rpi] iot_bsp_wifi_init
I (1624477165:621) [IoT]: iot_bsp_wifi_init(150) > [rpi] wifi module version 20210405
I (1624477165:668) [IoT]: iot_bsp_wifi_init(164) > [rpi] Ethernet connection available: eth0
I (1624477165:668) [IoT]: iot_bsp_wifi_init(182) > [rpi] Wifi AP device wlan0 found
I (1624477165:668) [IoT]: iot_bsp_wifi_init(230) > [rpi] Wifi Initialization Done
I (1624477165:669) [IoT]: st_conn_init(1369) > stdk_version : 1.6.2
I (1624477165:669) [IoT]: st_conn_start(1839) > st_conn_start start (no-pin)
D (1624477165:669) [IoT]: iot_security_be_init(1904) > security backend is 'software'
D (1624477165:670) [IoT]: iot_os_eventgroup_set_bits(332) > write_size = 3 (0)
D (1624477165:670) [IoT]: iot_os_eventgroup_wait_bits(301) > read_size = 3 (0)
D (1624477165:670) [IoT]: _iot_main_task(1118) > cmd: 10

I (1624477165:670) [IoT]: _do_iot_main_command(499) > curr_main_cmd:10, curr_main_state:-1/-1
D (1624477165:670) [IoT]: iot_os_eventgroup_set_bits(332) > write_size = 3 (0)
I (1624477165:671) [IoT]: _do_update_timeout(200) > Current timeout : 100000 for -1/0
I (1624477165:671) [IoT]: _do_status_report(304) > Call usr status_cb with 1/0
iot_status: 1, lv: 0
D (1624477165:671) [IoT]: iot_os_eventgroup_set_bits(327) > already set 0x00000001 (0)
D (1624477165:671) [IoT]: iot_os_eventgroup_wait_bits(301) > read_size = 3 (0)
D (1624477165:672) [IoT]: _iot_main_task(1118) > cmd: 2

I (1624477165:672) [IoT]: _do_iot_main_command(499) > curr_main_cmd:2, curr_main_state:-1/0
D (1624477165:672) [IoT]: iot_nv_get_prov_data(261) > >>>HIT<<<
D (1624477165:672) [IoT]: iot_nv_get_wifi_prov_data(322) > >>>HIT<<<
D (1624477165:672) [IoT]: _iot_nv_io_storage(103) > id = 1, mode = 1
D (1624477165:672) [IoT]: iot_security_be_init(1904) > security backend is 'software'
D (1624477165:672) [IoT]: iot_security_storage_read(114) > id:1
D (1624477165:672) [IoT]: _iot_security_be_bsp_fs_load(187) > id = 1
D (1624477165:673) [IoT]: _iot_security_be_bsp_fs_load_from_nv(100) > id = 1
D (1624477165:673) [IoT]: iot_bsp_nv_get_data_path(24) > >>>HIT<<<
D (1624477165:673) [IoT]: _iot_security_be_bsp_fs_storage_id2filename(85) > storage file = './WifiProvStatus'
D (1624477165:673) [IoT]: iot_bsp_fs_open(46) > file doesn't exist
E (1624477165:673) [IoT]: _iot_security_be_bsp_fs_load_from_nv(129) > iot_bsp_fs_open(./WifiProvStatus) = -1208
D (1624477165:673) [IoT]: iot_security_storage_read(141) > id:1 not found
D (1624477165:673) [IoT]: _iot_nv_io_storage(123) > nv '1' does not exist
D (1624477165:673) [IoT]: iot_nv_get_wifi_prov_data(343) > Wifi Prov Status : read failed
D (1624477165:674) [IoT]: iot_nv_get_prov_data(267) > get wifi prov fail
D (1624477165:674) [IoT]: _do_iot_main_command(626) > There are no prov data in NV

D (1624477165:674) [IoT]: iot_nv_erase(1006) > >>>HIT<<<
D (1624477165:674) [IoT]: _iot_nv_io_storage(103) > id = 10, mode = 3
D (1624477165:674) [IoT]: iot_security_be_init(1904) > security backend is 'software'
D (1624477165:674) [IoT]: iot_security_storage_remove(191) > id:10
D (1624477165:675) [IoT]: _iot_security_be_bsp_fs_remove(309) > id = 10
D (1624477165:675) [IoT]: iot_bsp_nv_get_data_path(24) > >>>HIT<<<
D (1624477165:675) [IoT]: _iot_security_be_bsp_fs_storage_id2filename(85) > storage file = './DeviceID'
D (1624477165:675) [IoT]: iot_bsp_fs_remove(138) > remove fail [No such file or directory]
D (1624477165:675) [IoT]: iot_security_storage_remove(211) > id:10 not found
D (1624477165:675) [IoT]: _iot_nv_io_storage(165) > nv '10' does not exist
D (1624477165:675) [IoT]: iot_nv_erase(1014) > file does not exist
D (1624477165:676) [IoT]: iot_os_eventgroup_set_bits(332) > write_size = 3 (0)
D (1624477165:676) [IoT]: iot_os_eventgroup_set_bits(327) > already set 0x00000001 (0)
I (1624477165:676) [IoT]: _do_cmd_tout_check(1041) > New state updated for 0
D (1624477165:676) [IoT]: iot_os_eventgroup_wait_bits(301) > read_size = 3 (0)
D (1624477165:676) [IoT]: _iot_main_task(1118) > cmd: 10

I (1624477165:676) [IoT]: _do_iot_main_command(499) > curr_main_cmd:10, curr_main_state:0/0
I (1624477165:677) [IoT]: iot_bsp_wifi_set_mode(871) > [rpi] Requested mode SCAN
I (1624477165:677) [IoT]: _perform_scan(1622) > [rpi] Running Wifi AP scan using wlan0
I (1624477166:401) [IoT]: iot_bsp_wifi_set_mode(889) > [rpi] WiFi scan completed. 5 APs found
I (1624477166:401) [IoT]: iot_bsp_wifi_get_scan_result(1596) > [rpi] Get scan result requested; 5 available
I (1624477166:401) [IoT]: _do_update_timeout(200) > Current timeout : 300000 for 0/1
D (1624477166:401) [IoT]: iot_os_eventgroup_set_bits(332) > write_size = 3 (0)
I (1624477166:401) [IoT]: _do_cmd_tout_check(1041) > New state updated for 1
I (1624477166:401) [IoT]: _do_status_report(304) > Call usr status_cb with 2/1
iot_status: 2, lv: 1
D (1624477166:401) [IoT]: iot_os_eventgroup_wait_bits(301) > read_size = 3 (0)
W (1624477466:469) [IoT]: _do_cmd_tout_check(1028) > New state changing timeout
D (1624477466:469) [IoT]: iot_os_eventgroup_set_bits(332) > write_size = 3 (0)
D (1624477466:469) [IoT]: iot_os_eventgroup_wait_bits(301) > read_size = 3 (0)
D (1624477466:469) [IoT]: _iot_main_task(1118) > cmd: 10

I (1624477466:470) [IoT]: _do_iot_main_command(499) > curr_main_cmd:10, curr_main_state:1/1
W (1624477466:470) [IoT]: _do_recovery(1419) > state changing fail for 1, curr_state :1
E (1624477466:470) [IoT]: _do_recovery(1477) > Failed process [1] on time, STOP
D (1624477466:470) [IoT]: iot_os_eventgroup_set_bits(332) > write_size = 3 (0)
I (1624477466:470) [IoT]: _do_update_timeout(200) > Current timeout : 4294967295 for 1/-2
I (1624477466:471) [IoT]: _do_status_report(304) > Call usr status_cb with 2/3
iot_status: 2, lv: 3
D (1624477466:471) [IoT]: iot_os_eventgroup_set_bits(327) > already set 0x00000001 (0)
I (1624477466:471) [IoT]: _do_cmd_tout_check(1041) > New state updated for -2
D (1624477466:471) [IoT]: iot_os_eventgroup_wait_bits(301) > read_size = 3 (0)
D (1624477466:471) [IoT]: _iot_main_task(1118) > cmd: 10

I (1624477466:472) [IoT]: _do_iot_main_command(499) > curr_main_cmd:10, curr_main_state:-2/-2
W (1624477466:472) [IoT]: _do_state_updating(1700) > Iot-core task will be stopped, needed ext-triggering

I (1624477466:472) [IoT]: iot_bsp_wifi_set_mode(851) > [rpi] Requested mode OFF
I (1624477466:473) [IoT]: _do_status_report(304) > Call usr status_cb with 1/0
iot_status: 1, lv: 0
D (1624477466:473) [IoT]: iot_os_eventgroup_set_bits(332) > write_size = 3 (1)
I (1624477466:473) [IoT]: _do_update_timeout(200) > Current timeout : 4294967295 for -1/-1
I (1624477466:473) [IoT]: _do_status_report(295) > Unsupported state -1 for 0/0
D (1624477466:473) [IoT]: iot_os_eventgroup_wait_bits(301) > read_size = 3 (1)
E (1624477466:473) [IoT]: st_conn_start(1897) > Can't go to PROV_CONFIRM (0x2)
I (1624477466:473) [IoT]: st_conn_start(1899) > st_conn_start done (-7)
D (1624477466:473) [IoT]: iot_os_eventgroup_set_bits(332) > write_size = 3 (0)
D (1624477466:473) [IoT]: iot_os_eventgroup_wait_bits(301) > read_size = 3 (0)

I don’t know what else to check–any thoughts? I’m running this on a Pi 3 B with a fresh install of the 64bit version of Rasbian Lite.

29

Hi Chris - I’m sorry for your troubles! It sounds like there’s been some changes to the SDK that I need to account for in my setup code. I’ll take a look at that ASAP and get that fixed, and make sure everything else is still working ok.

Regarding the failure to complete the onboarding process, can you describe what is happening on your mobile phone? How far is it getting? .e.g. are you getting the list of APs to select from?

Had you tested your AP mode before proceeding with the onboarding? You were able to confirm that it was working? (You could see the SSID listed on your mobile app?)

Any number of things could be an issue if you weren’t able to use the mastersetup script and instead had to do things manually. But I’ll work with you to get it going!

EDIT: Looking at the log file, make sure before you try onboarding again, you start clean by deleting all the provisioning files that are placed in the example directory:

DeviceID, WifiProvStatus, ServerURL, ServerPort, Label, IotAPSSID, IotAPBSSID, IotAPAuthType, CloudProvStatus

Also, be certain your wifi isn’t stuck in AP mode: use the resetAP utility if necessary to get you back to regular wifi client mode. It’s a bit harder to tell on OS Lite since you don’t have the GUI to see the wifi icon.

30

OK - good news: the fix was pretty simple. There were some recent changes in the SDK Makefile and stdkconfig file that broke the correct build for Raspberry Pi, and also prevented the onboarding process from proceeding correctly. I’ve uploaded the fix to github.

I know you said earlier that you ended up using a combination of mastersetup script and manual changes, but I’d highly recommend sticking with mastersetup until you get everything working, then you can muck around with other changes.

If you changed any of the SDK or RPI package files manually, you may need to delete those modified files so it doesn’t cause the git pull to fail when you (re-)run the mastersetup sw install steps.

Best to just go through all the steps even if you think you already did them manually. At the very least, Repeat steps #1 - 4 and 6 to get the updated fix, reload the SDK, and re-build the SDK and example app.

Since you had errors previously, be sure to wipe clean those provisioning files in the example directory (although I suspect none were ever created because you didn’t get that far in the process) and make sure your wifi is in regular client mode before you run the example app (use resetAP utility or reboot if necessary). If you had let the example app time out (takes several minutes), youre wifi SoftAP would have gotten correctly turned off.

Since you’re on OS Lite, I assume you got your QR code onto another machine where you can display it, so have that ready as well.

**EDIT: ** Removed comment about QR code not working; QR code will only be recognized if developer mode is enabled in the app. (It needs to be ‘re’ enabled with the new mobile app.)

Thanks very much for posting your issue. I’m glad to have gotten it fixed, and also discovered the new QR code scan issue on the new app.

31

Thanks again, Todd! I ran into a new issue when building the example device:

Building example application

device_info.o
ld -r -b binary -o device_info.o device_info.json
onboarding_config.o
ld -r -b binary -o onboarding_config.o onboarding_config.json
gcc -o example example.c device_info.o onboarding_config.o -L../output -I../src/include -liotcore -lssl -lpthread -lrt -lcrypto
/usr/bin/ld: ../output/libiotcore.a(stdk_iot_api.o): in function `iot_wifi_ctrl_request':
iot_api.c:(.text+0x564): undefined reference to `iot_easysetup_create_ssid'
collect2: error: ld returned 1 exit status
make: *** [Makefile:26: example] Error 1

But I’m not sure if my dicking around yesterday was the cause, so I’m going to just start fresh on a freshly imaged Pi here in a bit. I’ve finally gotten around to cleaning up all the crap that’s been living on my network over the last few years so I’ve got the reimage process on the Pi down pat right now, haha.

I’ll let you know my results later. One positive of my flailing through this is I have a much better understanding of what the direct-connect process looks like. Hopefully I’ll have better luck when I move on to the alarmserver piece of this, haha.

Thanks again for all your hard work on this!

32

Sounds like still not something quite right with the SDK build. Short of a fresh image approach, you could try re-pulling these 2 files from the SDK repository:

src/port/os/posix/iot_os_util_posix.c
src/deps/mbedtls/Makefile

It occurred to me last night this might cause an issue since the install scripts prior to yesterday’s fix overwrote those two SDK files. And when you do a git pull on a repository it thinks is up-to-date, it won’t restore them.

Nevertheless, a fresh image install and restarting from scratch will hopefully clear things up.

33

So I made some progress with the fresh build, but still no joy, haha. This time AP is actually created properly and the SmartThings app acknowledges the existence of the Pi, but now I get a 07-999 error, which is “we can’t connect to the cloud.” The AP is created and active, but the connection is “we can’t reach the internet” type–I wasn’t sure if ST tries to connect back to the mothership using the Pi or my phone, so I figured I’d reach out here first before I mess things up further messing around with IP Tables, haha. I rebooted a few times, deleted the Pi-AP wifi on my phone, etc. and then rebuilt everything with debug logging. Now ST automatically drops my wifi connection on the phone, connects to the Pi AP, but and then fails. Here’s the debug log:

D (1624561330:528) [IoT]: iot_nv_init(197) > >>>HIT<<<
I (1624561330:528) [IoT]: _dump_device_info(706) > firmware_version: switch_example_001
I (1624561330:528) [IoT]: iot_bsp_wifi_init(149) > [rpi] iot_bsp_wifi_init
I (1624561330:528) [IoT]: iot_bsp_wifi_init(150) > [rpi] wifi module version 20210405
I (1624561330:558) [IoT]: iot_bsp_wifi_init(164) > [rpi] Ethernet connection available: eth0
I (1624561330:558) [IoT]: iot_bsp_wifi_init(182) > [rpi] Wifi AP device wlan0 found
I (1624561330:558) [IoT]: iot_bsp_wifi_init(230) > [rpi] Wifi Initialization Done
I (1624561330:559) [IoT]: st_conn_init(1369) > stdk_version : 1.6.2
I (1624561330:559) [IoT]: st_conn_start(1839) > st_conn_start start (no-pin)
D (1624561330:559) [IoT]: iot_security_be_init(1904) > security backend is 'software'
D (1624561330:559) [IoT]: iot_os_eventgroup_set_bits(332) > write_size = 3 (0)
D (1624561330:559) [IoT]: iot_os_eventgroup_wait_bits(301) > read_size = 3 (0)
D (1624561330:559) [IoT]: _iot_main_task(1118) > cmd: 10

I (1624561330:560) [IoT]: _do_iot_main_command(499) > curr_main_cmd:10, curr_main_state:-1/-1
D (1624561330:560) [IoT]: iot_os_eventgroup_set_bits(332) > write_size = 3 (0)
I (1624561330:560) [IoT]: _do_update_timeout(200) > Current timeout : 100000 for -1/0
I (1624561330:560) [IoT]: _do_status_report(304) > Call usr status_cb with 1/0
iot_status: 1, lv: 0
D (1624561330:560) [IoT]: iot_os_eventgroup_set_bits(327) > already set 0x00000001 (0)
D (1624561330:560) [IoT]: iot_os_eventgroup_wait_bits(301) > read_size = 3 (0)
D (1624561330:560) [IoT]: _iot_main_task(1118) > cmd: 2

I (1624561330:561) [IoT]: _do_iot_main_command(499) > curr_main_cmd:2, curr_main_state:-1/0
D (1624561330:561) [IoT]: iot_nv_get_prov_data(261) > >>>HIT<<<
D (1624561330:561) [IoT]: iot_nv_get_wifi_prov_data(322) > >>>HIT<<<
D (1624561330:561) [IoT]: _iot_nv_io_storage(103) > id = 1, mode = 1
D (1624561330:561) [IoT]: iot_security_be_init(1904) > security backend is 'software'
D (1624561330:561) [IoT]: iot_security_storage_read(114) > id:1
D (1624561330:561) [IoT]: _iot_security_be_bsp_fs_load(187) > id = 1
D (1624561330:561) [IoT]: _iot_security_be_bsp_fs_load_from_nv(100) > id = 1
D (1624561330:561) [IoT]: iot_bsp_nv_get_data_path(24) > >>>HIT<<<
D (1624561330:561) [IoT]: _iot_security_be_bsp_fs_storage_id2filename(85) > storage file = './WifiProvStatus'
D (1624561330:561) [IoT]: iot_bsp_fs_open(46) > file doesn't exist
E (1624561330:562) [IoT]: _iot_security_be_bsp_fs_load_from_nv(129) > iot_bsp_fs_open(./WifiProvStatus) = -1208
D (1624561330:562) [IoT]: iot_security_storage_read(141) > id:1 not found
D (1624561330:562) [IoT]: _iot_nv_io_storage(123) > nv '1' does not exist
D (1624561330:562) [IoT]: iot_nv_get_wifi_prov_data(343) > Wifi Prov Status : read failed
D (1624561330:562) [IoT]: iot_nv_get_prov_data(267) > get wifi prov fail
D (1624561330:562) [IoT]: _do_iot_main_command(626) > There are no prov data in NV

D (1624561330:562) [IoT]: iot_nv_erase(1006) > >>>HIT<<<
D (1624561330:562) [IoT]: _iot_nv_io_storage(103) > id = 10, mode = 3
D (1624561330:562) [IoT]: iot_security_be_init(1904) > security backend is 'software'
D (1624561330:562) [IoT]: iot_security_storage_remove(191) > id:10
D (1624561330:563) [IoT]: _iot_security_be_bsp_fs_remove(309) > id = 10
D (1624561330:563) [IoT]: iot_bsp_nv_get_data_path(24) > >>>HIT<<<
D (1624561330:563) [IoT]: _iot_security_be_bsp_fs_storage_id2filename(85) > storage file = './DeviceID'
D (1624561330:563) [IoT]: iot_bsp_fs_remove(138) > remove fail [No such file or directory]
D (1624561330:563) [IoT]: iot_security_storage_remove(211) > id:10 not found
D (1624561330:563) [IoT]: _iot_nv_io_storage(165) > nv '10' does not exist
D (1624561330:563) [IoT]: iot_nv_erase(1014) > file does not exist
D (1624561330:563) [IoT]: iot_os_eventgroup_set_bits(332) > write_size = 3 (0)
D (1624561330:563) [IoT]: iot_os_eventgroup_set_bits(327) > already set 0x00000001 (0)
I (1624561330:563) [IoT]: _do_cmd_tout_check(1041) > New state updated for 0
D (1624561330:563) [IoT]: iot_os_eventgroup_wait_bits(301) > read_size = 3 (0)
D (1624561330:564) [IoT]: _iot_main_task(1118) > cmd: 10

I (1624561330:564) [IoT]: _do_iot_main_command(499) > curr_main_cmd:10, curr_main_state:0/0
I (1624561330:564) [IoT]: iot_bsp_wifi_set_mode(871) > [rpi] Requested mode SCAN
I (1624561330:564) [IoT]: _perform_scan(1622) > [rpi] Running Wifi AP scan using wlan0
I (1624561331:272) [IoT]: iot_bsp_wifi_set_mode(889) > [rpi] WiFi scan completed. 6 APs found
I (1624561331:272) [IoT]: iot_bsp_wifi_get_scan_result(1596) > [rpi] Get scan result requested; 6 available
D (1624561331:273) [IoT]: iot_nv_get_serial_number(899) > >>>HIT<<<
D (1624561331:273) [IoT]: _iot_nv_io_storage(103) > id = 17, mode = 1
D (1624561331:273) [IoT]: iot_security_be_init(1904) > security backend is 'software'
D (1624561331:273) [IoT]: iot_security_storage_read(114) > id:17
D (1624561331:273) [IoT]: _iot_security_be_bsp_fs_load(187) > id = 17
D (1624561331:273) [IoT]: iot_nv_get_data_from_device_info(1072) > nv id = 17
D (1624561331:273) [IoT]: iot_security_storage_read(146) > id:17 read 16@0x7f880014f0
D (1624561331:273) [IoT]: iot_security_base64_encode_urlsafe(178) > src: 32@0x7f8e5d37d8, dst: 45@0x7f8e5d37a8
D (1624561331:273) [IoT]: iot_security_base64_encode_urlsafe(192) > done: 44@0x7f8e5d37a8
I (1624561331:273) [IoT]: iot_easysetup_create_ssid(91) > >> Raspberry_PI_[s64V] <<
D (1624561331:273) [IoT]: iot_os_eventgroup_set_bits(332) > write_size = 3 (0)
I (1624561331:273) [IoT]: _do_update_timeout(200) > Current timeout : 300000 for 0/1
D (1624561331:273) [IoT]: iot_os_eventgroup_set_bits(327) > already set 0x00000001 (0)
D (1624561331:273) [IoT]: iot_os_eventgroup_wait_bits(301) > read_size = 3 (0)
D (1624561331:273) [IoT]: _iot_main_task(1118) > cmd: 1

I (1624561331:273) [IoT]: _do_iot_main_command(499) > curr_main_cmd:1, curr_main_state:0/1
I (1624561331:273) [IoT]: iot_bsp_wifi_set_mode(964) > [rpi] Requested mode SoftAP
I (1624561335:125) [IoT]: _SoftAPControl(1291) > [rpi] SoftAP service stop issued
I (1624561336:808) [IoT]: _SoftAPControl(1291) > [rpi] SoftAP service start issued
D (1624561337:851) [IoT]: iot_bsp_wifi_set_mode(1024) > wifi_init_softap finished.SSID:Raspberry_PI__E4fAbm0016pVtss64V password:1111122222
I (1624561337:852) [IoT]: iot_bsp_wifi_set_mode(1027) > [rpi] AP Mode Started on device wlan0
D (1624561337:852) [IoT]: iot_easysetup_init(466) > ENTER >>>>
I (1624561337:852) [IoT]: iot_easysetup_init(467) > IOT_STATE_PROV_ES_START
I (1624561337:852) [IoT]: es_http_init(159) > http tcp init!!
I (1624561337:852) [IoT]: iot_easysetup_init(497) > IOT_STATE_PROV_ES_INIT_DONE
D (1624561337:852) [IoT]: iot_os_eventgroup_set_bits(332) > write_size = 3 (0)
I (1624561337:852) [IoT]: _do_cmd_tout_check(1041) > New state updated for 1
I (1624561337:852) [IoT]: _do_status_report(304) > Call usr status_cb with 2/1
iot_status: 2, lv: 1
D (1624561337:853) [IoT]: iot_os_eventgroup_wait_bits(301) > read_size = 3 (0)
W (1624561631:365) [IoT]: _do_cmd_tout_check(1028) > New state changing timeout
D (1624561631:366) [IoT]: iot_os_eventgroup_set_bits(332) > write_size = 3 (0)
D (1624561631:366) [IoT]: iot_os_eventgroup_wait_bits(301) > read_size = 3 (0)
D (1624561631:366) [IoT]: _iot_main_task(1118) > cmd: 10

I (1624561631:366) [IoT]: _do_iot_main_command(499) > curr_main_cmd:10, curr_main_state:1/1
W (1624561631:366) [IoT]: _do_recovery(1419) > state changing fail for 1, curr_state :1
E (1624561631:366) [IoT]: _do_recovery(1477) > Failed process [1] on time, STOP
D (1624561631:367) [IoT]: iot_os_eventgroup_set_bits(332) > write_size = 3 (0)
I (1624561631:367) [IoT]: _do_update_timeout(200) > Current timeout : 4294967295 for 1/-2
I (1624561631:367) [IoT]: _do_status_report(304) > Call usr status_cb with 2/3
iot_status: 2, lv: 3
D (1624561631:367) [IoT]: iot_os_eventgroup_set_bits(327) > already set 0x00000001 (0)
I (1624561631:367) [IoT]: _do_cmd_tout_check(1041) > New state updated for -2
D (1624561631:368) [IoT]: iot_os_eventgroup_wait_bits(301) > read_size = 3 (0)
D (1624561631:368) [IoT]: _iot_main_task(1118) > cmd: 10

I (1624561631:368) [IoT]: _do_iot_main_command(499) > curr_main_cmd:10, curr_main_state:-2/-2
W (1624561631:369) [IoT]: _do_state_updating(1700) > Iot-core task will be stopped, needed ext-triggering

D (1624561631:369) [IoT]: iot_easysetup_deinit(507) > ENTER >>>>
I (1624561631:369) [IoT]: http_cleanup_all_connection(39) > close listen socket
I (1624561631:371) [IoT]: es_http_deinit(184) > http tcp deinit complete!
I (1624561631:371) [IoT]: iot_easysetup_deinit(531) > IOT_STATE_PROV_ES_DONE
I (1624561631:371) [IoT]: iot_bsp_wifi_set_mode(851) > [rpi] Requested mode OFF
I (1624561632:232) [IoT]: _SoftAPControl(1291) > [rpi] SoftAP service stop issued
I (1624561632:932) [IoT]: _SoftAPControl(1291) > [rpi] SoftAP service start issued
I (1624561632:932) [IoT]: _do_status_report(304) > Call usr status_cb with 1/0
iot_status: 1, lv: 0
D (1624561632:932) [IoT]: iot_os_eventgroup_set_bits(332) > write_size = 3 (1)
I (1624561632:932) [IoT]: _do_update_timeout(200) > Current timeout : 4294967295 for -1/-1
I (1624561632:932) [IoT]: _do_status_report(295) > Unsupported state -1 for 0/0
D (1624561632:932) [IoT]: iot_os_eventgroup_set_bits(332) > write_size = 3 (0)
D (1624561632:932) [IoT]: iot_os_eventgroup_wait_bits(301) > read_size = 3 (1)
E (1624561632:933) [IoT]: st_conn_start(1897) > Can't go to PROV_CONFIRM (0x2)
I (1624561632:933) [IoT]: st_conn_start(1899) > st_conn_start done (-7)
D (1624561632:933) [IoT]: iot_os_eventgroup_wait_bits(301) > read_size = 3 (0)
34

Yes that is progress! Looks like things are working much better.

From your log I deduce the following:

  • You are no longer testing this on a Pi Zero? (you have ethernet available)
  • Your wifi was already in SoftAP mode when you started the example AP

When provisioning with the mobile app is done, the SDK then needs to connect back to the SmartThings server to finalize adding the device. It looks like at that point it cannot reach the internet. This is probably because after SoftAP mode is done, your wifi is reverted back to its previous state - which in your case appears to have been in ANOTHER SoftAP configuration. This may be why it can’t reach the internet. However, I’m a bit perplexed because since you have Ethernet, the Pi would have prioritized that to communicate over (rather than wifi) when trying to reach the internet.

Did you use the SoftAPconfig tool to configure your wifi?

Be certain you have the files dhcpcd.conf and dhcpcd_ap.conf set up properly and be 100% certain you have no issues reaching the internet either when in regular wifi client mode or with ethernet. As you surmised, this is where things are failing.

You’re getting close!

35

Yes, I do have an Ethernet connection on the Pi (I’ve been using the same Pi 3 for all testing). I’m not sure if I was already in SoftAP mode at the time I pulled the logs–I had been screwing around with a few things, so it’s possible I didn’t cleanly kill it, haha. For all of this “new” configuration, I used the mastersetup script exclusively to minimize me fat-fingering stuff into oblivion. As far as I can tell, everything is configured as intended, but it fails when I try to add the example app.

Running the testhostapd script creates the wireless network and I can connect to it from my phone, however the wireless network does not have access to the Internet from the Pi, but I don’t know if that’s OK or not. I definitely can reach the Internet via the Pi, but I can’t access the internet from a device using either the testhost or example AP since there’s nothing in place to forward traffic wlan0 to eth0.

Here is what’s going on there:

-- Logs begin at Fri 2021-06-25 13:32:52 CDT. --
Jun 25 13:47:19 alarmserver hostapd[1539]: wlan0: STA d6:ec:3d:16:79:a1 RADIUS: starting accounting session CD6075D8F6BFEC34
Jun 25 13:47:19 alarmserver hostapd[1539]: wlan0: STA d6:ec:3d:16:79:a1 WPA: pairwise key handshake completed (WPA)
Jun 25 13:47:19 alarmserver hostapd[1539]: wlan0: STA d6:ec:3d:16:79:a1 WPA: group key handshake completed (WPA)
Jun 25 13:47:19 alarmserver dnsmasq-dhcp[1224]: DHCPDISCOVER(wlan0) d6:ec:3d:16:79:a1
Jun 25 13:47:19 alarmserver dnsmasq-dhcp[1224]: DHCPOFFER(wlan0) 192.168.2.9 d6:ec:3d:16:79:a1
Jun 25 13:47:19 alarmserver dnsmasq-dhcp[1224]: DHCPREQUEST(wlan0) 192.168.2.9 d6:ec:3d:16:79:a1
Jun 25 13:47:19 alarmserver dnsmasq-dhcp[1224]: DHCPACK(wlan0) 192.168.2.9 d6:ec:3d:16:79:a1 CHRIS-s-S20
Jun 25 13:47:21 alarmserver hostapd[1212]: wlan0: STA d6:ec:3d:16:79:a1 RADIUS: starting accounting session 326590FD810CDD11
Jun 25 13:47:21 alarmserver hostapd[1212]: wlan0: STA d6:ec:3d:16:79:a1 WPA: pairwise key handshake completed (WPA)
Jun 25 13:47:21 alarmserver hostapd[1212]: wlan0: STA d6:ec:3d:16:79:a1 WPA: group key handshake completed (WPA)
Jun 25 13:48:29 alarmserver dhcpcd[1537]: eth0: Router Advertisement from fe80::5aef:68ff:fe60:7070
Jun 25 13:48:29 alarmserver systemd[1]: Starting Cleanup of Temporary Directories...
Jun 25 13:48:29 alarmserver systemd[1]: systemd-tmpfiles-clean.service: Succeeded.
Jun 25 13:48:29 alarmserver systemd[1]: Started Cleanup of Temporary Directories.
Jun 25 13:49:53 alarmserver dhcpcd[1537]: eth0: Router Advertisement from fe80::5aef:68ff:fe60:7070
Jun 25 13:50:17 alarmserver hostapd[1212]: wlan0: STA d6:ec:3d:16:79:a1 IEEE 802.11: disassociated
Jun 25 13:50:17 alarmserver hostapd[1539]: wlan0: STA d6:ec:3d:16:79:a1 IEEE 802.11: disassociated
Jun 25 13:50:19 alarmserver dhcpcd[1537]: eth0: Router Advertisement from fe80::5aef:68ff:fe60:7070

And similar results when running the actual example app (I had to kill it once and restart it because something hung up and the AP wasn’t created the first time):

-- Logs begin at Fri 2021-06-25 13:32:52 CDT. --
Jun 25 13:33:10 alarmserver systemd[1]: Started Session 3 of user pi.
Jun 25 13:33:14 alarmserver dhcpcd[626]: eth0: fe80::5aef:68ff:fe60:7070 is reachable again
Jun 25 13:33:14 alarmserver dhcpcd[626]: eth0: fe80::5aef:68ff:fe60:7070 is reachable again
Jun 25 13:33:25 alarmserver systemd[1]: systemd-fsckd.service: Succeeded.
Jun 25 13:33:42 alarmserver systemd-timesyncd[356]: Synchronized to time server for the first time [2001:638:502:c015::231]:123 (2.debian.pool.ntp.org).
Jun 25 13:33:47 alarmserver systemd[1]: systemd-hostnamed.service: Succeeded.
Jun 25 13:34:44 alarmserver dhcpcd[626]: eth0: Router Advertisement from fe80::5aef:68ff:fe60:7070
Jun 25 13:37:04 alarmserver dhcpcd[626]: eth0: Router Advertisement from fe80::5aef:68ff:fe60:7070
Jun 25 13:39:32 alarmserver dhcpcd[626]: eth0: Router Advertisement from fe80::5aef:68ff:fe60:7070
Jun 25 13:40:04 alarmserver dhcpcd[626]: eth0: Router Advertisement from fe80::5aef:68ff:fe60:7070
Jun 25 13:40:12 alarmserver sshd[827]: Accepted publickey for pi from 192.168.1.108 port 33514 ssh2: RSA SHA256:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Jun 25 13:40:12 alarmserver sshd[827]: pam_unix(sshd:session): session opened for user pi by (uid=0)
Jun 25 13:40:12 alarmserver systemd-logind[407]: New session 4 of user pi.
Jun 25 13:40:12 alarmserver systemd[1]: Started Session 4 of user pi.
Jun 25 13:40:35 alarmserver sudo[859]:       pi : TTY=pts/1 ; PWD=/home/pi/st-device-sdk-c/example ; USER=root ; COMMAND=/usr/sbin/iw wlan0 scan
Jun 25 13:40:35 alarmserver sudo[859]: pam_unix(sudo:session): session opened for user root by pi(uid=0)
Jun 25 13:40:35 alarmserver sudo[859]: pam_unix(sudo:session): session closed for user root
Jun 25 13:40:36 alarmserver sudo[862]:       pi : TTY=pts/1 ; PWD=/home/pi/st-device-sdk-c/example ; USER=root ; COMMAND=/usr/bin/cp /etc/dhcpcd.conf /etc/dhcpcd_saved.conf
Jun 25 13:40:36 alarmserver sudo[862]: pam_unix(sudo:session): session opened for user root by pi(uid=0)
Jun 25 13:40:36 alarmserver sudo[862]: pam_unix(sudo:session): session closed for user root
Jun 25 13:40:37 alarmserver sudo[865]:       pi : TTY=pts/1 ; PWD=/home/pi/st-device-sdk-c/example ; USER=root ; COMMAND=/usr/bin/cp /etc/dhcpcd_ap.conf /etc/dhcpcd.conf
Jun 25 13:40:37 alarmserver sudo[865]: pam_unix(sudo:session): session opened for user root by pi(uid=0)
Jun 25 13:40:37 alarmserver sudo[865]: pam_unix(sudo:session): session closed for user root
Jun 25 13:40:37 alarmserver sudo[868]:       pi : TTY=pts/1 ; PWD=/home/pi/st-device-sdk-c/example ; USER=root ; COMMAND=/usr/bin/systemctl restart dhcpcd
Jun 25 13:40:37 alarmserver sudo[868]: pam_unix(sudo:session): session opened for user root by pi(uid=0)
Jun 25 13:40:37 alarmserver systemd[1]: Stopping dhcpcd on all interfaces...
Jun 25 13:40:37 alarmserver dhcpcd[871]: sending signal TERM to pid 626
Jun 25 13:40:37 alarmserver dhcpcd[871]: waiting for pid 626 to exit
Jun 25 13:40:37 alarmserver dhcpcd[871]: sending signal TERM to pid 626
Jun 25 13:40:37 alarmserver dhcpcd[626]: received SIGTERM, stopping
Jun 25 13:40:37 alarmserver dhcpcd[626]: wlan0: removing interface
Jun 25 13:40:37 alarmserver dhcpcd[871]: waiting for pid 626 to exit
Jun 25 13:40:37 alarmserver dhcpcd[626]: eth0: removing interface
Jun 25 13:40:37 alarmserver dhcpcd[626]: dhcpcd exited
Jun 25 13:40:37 alarmserver systemd[1]: dhcpcd.service: Succeeded.
Jun 25 13:40:37 alarmserver systemd[1]: Stopped dhcpcd on all interfaces.
Jun 25 13:40:37 alarmserver systemd[1]: Starting dhcpcd on all interfaces...
Jun 25 13:40:37 alarmserver dhcpcd[874]: dev: loaded udev
Jun 25 13:40:37 alarmserver dhcpcd[874]: wlan0: connected to Access Point `'
Jun 25 13:40:37 alarmserver dhcpcd[874]: DUID 00:01:00:01:28:28:23:37:b8:27:eb:1c:1f:49
Jun 25 13:40:37 alarmserver dhcpcd[874]: eth0: IAID eb:1c:1f:49
Jun 25 13:40:37 alarmserver dhcpcd[874]: wlan0: waiting for carrier
Jun 25 13:40:37 alarmserver dhcpcd[874]: eth0: soliciting an IPv6 router
Jun 25 13:40:37 alarmserver dhcpcd[874]: eth0: Router Advertisement from fe80::5aef:68ff:fe60:7070
Jun 25 13:40:37 alarmserver dhcpcd[874]: eth0: adding address 2603:8081:8c0b:ace:7f72:75ed:d1ad:500c/64
Jun 25 13:40:37 alarmserver dhcpcd[874]: eth0: adding route to 2603:8081:8c0b:ace::/64
Jun 25 13:40:37 alarmserver dhcpcd[874]: eth0: adding default route via fe80::5aef:68ff:fe60:7070
Jun 25 13:40:37 alarmserver dhcpcd[874]: forked to background, child pid 897
Jun 25 13:40:37 alarmserver dhcpcd[897]: eth0: requesting DHCPv6 information
Jun 25 13:40:37 alarmserver systemd[1]: Started dhcpcd on all interfaces.
Jun 25 13:40:37 alarmserver sudo[868]: pam_unix(sudo:session): session closed for user root
Jun 25 13:40:37 alarmserver dhcpcd[897]: eth0: rebinding lease of 192.168.1.148
Jun 25 13:40:37 alarmserver dhcpcd[897]: eth0: leased 192.168.1.148 for 86400 seconds
Jun 25 13:40:37 alarmserver dhcpcd[897]: eth0: adding route to 192.168.1.0/24
Jun 25 13:40:37 alarmserver dhcpcd[897]: eth0: adding default route via 192.168.1.1
Jun 25 13:40:39 alarmserver sudo[924]:       pi : TTY=pts/1 ; PWD=/home/pi/st-device-sdk-c/example ; USER=root ; COMMAND=/usr/bin/systemctl start hostapd
Jun 25 13:40:39 alarmserver sudo[924]: pam_unix(sudo:session): session opened for user root by pi(uid=0)
Jun 25 13:40:39 alarmserver systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator...
Jun 25 13:40:39 alarmserver hostapd[927]: Configuration file: /etc/hostapd/hostapd.conf
Jun 25 13:40:39 alarmserver hostapd[927]: wlan0: interface state UNINITIALIZED->COUNTRY_UPDATE
Jun 25 13:40:39 alarmserver systemd[1]: Started Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator.
Jun 25 13:40:39 alarmserver sudo[924]: pam_unix(sudo:session): session closed for user root
Jun 25 13:40:39 alarmserver sudo[930]:       pi : TTY=pts/1 ; PWD=/home/pi/st-device-sdk-c/example ; USER=root ; COMMAND=/usr/bin/systemctl start dnsmasq
Jun 25 13:40:39 alarmserver sudo[930]: pam_unix(sudo:session): session opened for user root by pi(uid=0)
Jun 25 13:40:39 alarmserver systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server...
Jun 25 13:40:39 alarmserver dnsmasq[933]: dnsmasq: syntax check OK.
Jun 25 13:40:40 alarmserver dhcpcd[897]: wlan0: carrier acquired
Jun 25 13:40:40 alarmserver kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Jun 25 13:40:40 alarmserver dhcpcd[897]: wlan0: IAID eb:49:4a:1c
Jun 25 13:40:40 alarmserver dhcpcd[897]: wlan0: adding address fe80::994:38c:1fac:20ff
Jun 25 13:40:40 alarmserver dhcpcd[897]: wlan0: probing address 192.168.2.1/24
Jun 25 13:40:40 alarmserver avahi-daemon[406]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::994:38c:1fac:20ff.
Jun 25 13:40:40 alarmserver avahi-daemon[406]: New relevant interface wlan0.IPv6 for mDNS.
Jun 25 13:40:40 alarmserver avahi-daemon[406]: Registering new address record for fe80::994:38c:1fac:20ff on wlan0.*.
Jun 25 13:40:40 alarmserver dnsmasq[944]: started, version 2.80 cachesize 150
Jun 25 13:40:40 alarmserver dnsmasq[944]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile
Jun 25 13:40:40 alarmserver dnsmasq-dhcp[944]: DHCP, IP range 192.168.2.2 -- 192.168.2.12, lease time 12h
Jun 25 13:40:40 alarmserver dnsmasq[944]: reading /run/dnsmasq/resolv.conf
Jun 25 13:40:40 alarmserver dnsmasq[944]: using nameserver 192.168.1.1#53
Jun 25 13:40:40 alarmserver dnsmasq[944]: using nameserver 2603:8081:8c0b:ace:5aef:68ff:fe60:7070#53
Jun 25 13:40:40 alarmserver dnsmasq[944]: read /etc/hosts - 5 addresses
Jun 25 13:40:40 alarmserver dnsmasq[945]: Too few arguments.
Jun 25 13:40:40 alarmserver systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server.
Jun 25 13:40:40 alarmserver systemd[1]: Reached target Host and Network Name Lookups.
Jun 25 13:40:40 alarmserver sudo[930]: pam_unix(sudo:session): session closed for user root
Jun 25 13:40:40 alarmserver kernel: Under-voltage detected! (0x00050005)
Jun 25 13:40:40 alarmserver dhcpcd[897]: wlan0: soliciting an IPv6 router
Jun 25 13:40:42 alarmserver sudo[1004]:       pi : TTY=pts/1 ; PWD=/home/pi/st-device-sdk-c/example ; USER=root ; COMMAND=/usr/bin/systemctl stop hostapd
Jun 25 13:40:42 alarmserver sudo[1004]: pam_unix(sudo:session): session opened for user root by pi(uid=0)
Jun 25 13:40:42 alarmserver systemd[1]: Stopping Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator...
Jun 25 13:40:43 alarmserver dhcpcd[897]: wlan0: carrier lost
Jun 25 13:40:43 alarmserver systemd[1]: hostapd.service: Succeeded.
Jun 25 13:40:43 alarmserver systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator.
Jun 25 13:40:43 alarmserver dhcpcd[897]: wlan0: deleting address fe80::994:38c:1fac:20ff
Jun 25 13:40:43 alarmserver avahi-daemon[406]: Withdrawing address record for fe80::994:38c:1fac:20ff on wlan0.
Jun 25 13:40:43 alarmserver avahi-daemon[406]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::994:38c:1fac:20ff.
Jun 25 13:40:43 alarmserver avahi-daemon[406]: Interface wlan0.IPv6 no longer relevant for mDNS.
Jun 25 13:40:43 alarmserver sudo[1004]: pam_unix(sudo:session): session closed for user root
Jun 25 13:40:43 alarmserver sudo[1017]:       pi : TTY=pts/1 ; PWD=/home/pi/st-device-sdk-c/example ; USER=root ; COMMAND=/usr/bin/systemctl stop dnsmasq
Jun 25 13:40:43 alarmserver sudo[1017]: pam_unix(sudo:session): session opened for user root by pi(uid=0)
Jun 25 13:40:43 alarmserver systemd[1]: Stopping dnsmasq - A lightweight DHCP and caching DNS server...
Jun 25 13:40:43 alarmserver dnsmasq[1023]: Too few arguments.
Jun 25 13:40:43 alarmserver dnsmasq[944]: exiting on receipt of SIGTERM
Jun 25 13:40:43 alarmserver systemd[1]: dnsmasq.service: Succeeded.
Jun 25 13:40:43 alarmserver systemd[1]: Stopped dnsmasq - A lightweight DHCP and caching DNS server.
Jun 25 13:40:43 alarmserver sudo[1017]: pam_unix(sudo:session): session closed for user root
Jun 25 13:40:43 alarmserver sudo[1074]:       pi : TTY=pts/1 ; PWD=/home/pi/st-device-sdk-c/example ; USER=root ; COMMAND=/usr/bin/cp /etc/dhcpcd_saved.conf /etc/dhcpcd.conf
Jun 25 13:40:43 alarmserver sudo[1074]: pam_unix(sudo:session): session opened for user root by pi(uid=0)
Jun 25 13:40:43 alarmserver sudo[1074]: pam_unix(sudo:session): session closed for user root
Jun 25 13:40:43 alarmserver sudo[1077]:       pi : TTY=pts/1 ; PWD=/home/pi/st-device-sdk-c/example ; USER=root ; COMMAND=/usr/bin/systemctl restart dhcpcd
Jun 25 13:40:43 alarmserver sudo[1077]: pam_unix(sudo:session): session opened for user root by pi(uid=0)
Jun 25 13:40:43 alarmserver systemd[1]: Stopping dhcpcd on all interfaces...
Jun 25 13:40:43 alarmserver dhcpcd[1080]: sending signal TERM to pid 897
Jun 25 13:40:43 alarmserver dhcpcd[1080]: waiting for pid 897 to exit
Jun 25 13:40:43 alarmserver dhcpcd[1080]: sending signal TERM to pid 897
Jun 25 13:40:43 alarmserver dhcpcd[897]: received SIGTERM, stopping
Jun 25 13:40:43 alarmserver dhcpcd[897]: wlan0: removing interface
Jun 25 13:40:43 alarmserver dhcpcd[1080]: waiting for pid 897 to exit
Jun 25 13:40:43 alarmserver dhcpcd[897]: eth0: removing interface
Jun 25 13:40:43 alarmserver dhcpcd[897]: dhcpcd exited
Jun 25 13:40:43 alarmserver systemd[1]: dhcpcd.service: Succeeded.
Jun 25 13:40:43 alarmserver systemd[1]: Stopped dhcpcd on all interfaces.
Jun 25 13:40:43 alarmserver systemd[1]: Starting dhcpcd on all interfaces...
Jun 25 13:40:43 alarmserver dhcpcd[1083]: dev: loaded udev
Jun 25 13:40:43 alarmserver dhcpcd[1083]: wlan0: connected to Access Point `'
Jun 25 13:40:43 alarmserver dhcpcd[1083]: DUID 00:01:00:01:28:28:23:37:b8:27:eb:1c:1f:49
Jun 25 13:40:43 alarmserver dhcpcd[1083]: eth0: IAID eb:1c:1f:49
Jun 25 13:40:43 alarmserver dhcpcd[1083]: wlan0: waiting for carrier
Jun 25 13:40:43 alarmserver dhcpcd[1083]: eth0: rebinding lease of 192.168.1.148
Jun 25 13:40:43 alarmserver dhcpcd[1083]: eth0: leased 192.168.1.148 for 86400 seconds
Jun 25 13:40:43 alarmserver dhcpcd[1083]: eth0: adding route to 192.168.1.0/24
Jun 25 13:40:43 alarmserver dhcpcd[1083]: eth0: adding default route via 192.168.1.1
Jun 25 13:40:43 alarmserver dhcpcd[1083]: forked to background, child pid 1106
Jun 25 13:40:43 alarmserver systemd[1]: Started dhcpcd on all interfaces.
Jun 25 13:40:43 alarmserver sudo[1077]: pam_unix(sudo:session): session closed for user root
Jun 25 13:40:44 alarmserver dhcpcd[1106]: eth0: soliciting an IPv6 router
Jun 25 13:40:44 alarmserver dhcpcd[1106]: eth0: Router Advertisement from fe80::5aef:68ff:fe60:7070
Jun 25 13:40:44 alarmserver dhcpcd[1106]: eth0: adding address 2603:8081:8c0b:ace:7f72:75ed:d1ad:500c/64
Jun 25 13:40:44 alarmserver dhcpcd[1106]: eth0: adding route to 2603:8081:8c0b:ace::/64
Jun 25 13:40:44 alarmserver dhcpcd[1106]: eth0: adding default route via fe80::5aef:68ff:fe60:7070
Jun 25 13:40:44 alarmserver dhcpcd[1106]: eth0: requesting DHCPv6 information
Jun 25 13:40:46 alarmserver kernel: Voltage normalised (0x00000000)
Jun 25 13:41:48 alarmserver sudo[1142]:       pi : TTY=pts/1 ; PWD=/home/pi/st-device-sdk-c/example ; USER=root ; COMMAND=/usr/sbin/iw wlan0 scan
Jun 25 13:41:48 alarmserver sudo[1142]: pam_unix(sudo:session): session opened for user root by pi(uid=0)
Jun 25 13:41:48 alarmserver sudo[1142]: pam_unix(sudo:session): session closed for user root
Jun 25 13:41:49 alarmserver sudo[1145]:       pi : TTY=pts/1 ; PWD=/home/pi/st-device-sdk-c/example ; USER=root ; COMMAND=/usr/bin/cp /etc/dhcpcd.conf /etc/dhcpcd_saved.conf
Jun 25 13:41:49 alarmserver sudo[1145]: pam_unix(sudo:session): session opened for user root by pi(uid=0)
Jun 25 13:41:49 alarmserver sudo[1145]: pam_unix(sudo:session): session closed for user root
Jun 25 13:41:49 alarmserver sudo[1148]:       pi : TTY=pts/1 ; PWD=/home/pi/st-device-sdk-c/example ; USER=root ; COMMAND=/usr/bin/cp /etc/dhcpcd_ap.conf /etc/dhcpcd.conf
Jun 25 13:41:49 alarmserver sudo[1148]: pam_unix(sudo:session): session opened for user root by pi(uid=0)
Jun 25 13:41:49 alarmserver sudo[1148]: pam_unix(sudo:session): session closed for user root
Jun 25 13:41:49 alarmserver sudo[1151]:       pi : TTY=pts/1 ; PWD=/home/pi/st-device-sdk-c/example ; USER=root ; COMMAND=/usr/bin/systemctl restart dhcpcd
Jun 25 13:41:49 alarmserver sudo[1151]: pam_unix(sudo:session): session opened for user root by pi(uid=0)
Jun 25 13:41:49 alarmserver systemd[1]: Stopping dhcpcd on all interfaces...
Jun 25 13:41:49 alarmserver dhcpcd[1154]: sending signal TERM to pid 1106
Jun 25 13:41:49 alarmserver dhcpcd[1154]: waiting for pid 1106 to exit
Jun 25 13:41:49 alarmserver dhcpcd[1154]: sending signal TERM to pid 1106
Jun 25 13:41:49 alarmserver dhcpcd[1106]: received SIGTERM, stopping
Jun 25 13:41:49 alarmserver dhcpcd[1106]: wlan0: removing interface
Jun 25 13:41:49 alarmserver dhcpcd[1154]: waiting for pid 1106 to exit
Jun 25 13:41:49 alarmserver dhcpcd[1106]: eth0: removing interface
Jun 25 13:41:49 alarmserver dhcpcd[1106]: dhcpcd exited
Jun 25 13:41:49 alarmserver systemd[1]: dhcpcd.service: Succeeded.
Jun 25 13:41:49 alarmserver systemd[1]: Stopped dhcpcd on all interfaces.
Jun 25 13:41:49 alarmserver systemd[1]: Starting dhcpcd on all interfaces...
Jun 25 13:41:49 alarmserver dhcpcd[1157]: dev: loaded udev
Jun 25 13:41:49 alarmserver dhcpcd[1157]: wlan0: connected to Access Point `'
Jun 25 13:41:50 alarmserver dhcpcd[1157]: DUID 00:01:00:01:28:28:23:37:b8:27:eb:1c:1f:49
Jun 25 13:41:50 alarmserver dhcpcd[1157]: eth0: IAID eb:1c:1f:49
Jun 25 13:41:50 alarmserver dhcpcd[1157]: wlan0: waiting for carrier
Jun 25 13:41:50 alarmserver dhcpcd[1157]: eth0: rebinding lease of 192.168.1.148
Jun 25 13:41:50 alarmserver dhcpcd[1157]: eth0: leased 192.168.1.148 for 86400 seconds
Jun 25 13:41:50 alarmserver dhcpcd[1157]: eth0: adding route to 192.168.1.0/24
Jun 25 13:41:50 alarmserver dhcpcd[1157]: eth0: adding default route via 192.168.1.1
Jun 25 13:41:50 alarmserver dhcpcd[1157]: forked to background, child pid 1180
Jun 25 13:41:50 alarmserver systemd[1]: Started dhcpcd on all interfaces.
Jun 25 13:41:50 alarmserver sudo[1151]: pam_unix(sudo:session): session closed for user root
Jun 25 13:41:50 alarmserver dhcpcd[1180]: eth0: soliciting an IPv6 router
Jun 25 13:41:50 alarmserver dhcpcd[1180]: eth0: Router Advertisement from fe80::5aef:68ff:fe60:7070
Jun 25 13:41:50 alarmserver dhcpcd[1180]: eth0: adding address 2603:8081:8c0b:ace:7f72:75ed:d1ad:500c/64
Jun 25 13:41:50 alarmserver dhcpcd[1180]: eth0: adding route to 2603:8081:8c0b:ace::/64
Jun 25 13:41:50 alarmserver dhcpcd[1180]: eth0: adding default route via fe80::5aef:68ff:fe60:7070
Jun 25 13:41:50 alarmserver dhcpcd[1180]: eth0: requesting DHCPv6 information
Jun 25 13:41:52 alarmserver sudo[1207]:       pi : TTY=pts/1 ; PWD=/home/pi/st-device-sdk-c/example ; USER=root ; COMMAND=/usr/bin/systemctl start hostapd
Jun 25 13:41:52 alarmserver sudo[1207]: pam_unix(sudo:session): session opened for user root by pi(uid=0)
Jun 25 13:41:52 alarmserver systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator...
Jun 25 13:41:52 alarmserver hostapd[1210]: Configuration file: /etc/hostapd/hostapd.conf
Jun 25 13:41:52 alarmserver hostapd[1210]: wlan0: interface state UNINITIALIZED->COUNTRY_UPDATE
Jun 25 13:41:52 alarmserver hostapd[1210]: wlan0: Could not connect to kernel driver
Jun 25 13:41:52 alarmserver hostapd[1210]: Using interface wlan0 with hwaddr b8:27:eb:49:4a:1c and ssid "Raspberry_PI__E4fAbm0016pVtss64V"
Jun 25 13:41:53 alarmserver dhcpcd[1180]: wlan0: carrier acquired
Jun 25 13:41:53 alarmserver hostapd[1210]: wlan0: interface state COUNTRY_UPDATE->ENABLED
Jun 25 13:41:53 alarmserver hostapd[1210]: wlan0: AP-ENABLED
Jun 25 13:41:53 alarmserver systemd[1]: Started Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator.
Jun 25 13:41:53 alarmserver dhcpcd[1180]: wlan0: IAID eb:49:4a:1c
Jun 25 13:41:53 alarmserver dhcpcd[1180]: wlan0: adding address fe80::994:38c:1fac:20ff
Jun 25 13:41:53 alarmserver dhcpcd[1180]: wlan0: probing address 192.168.2.1/24
Jun 25 13:41:53 alarmserver avahi-daemon[406]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::994:38c:1fac:20ff.
Jun 25 13:41:53 alarmserver avahi-daemon[406]: New relevant interface wlan0.IPv6 for mDNS.
Jun 25 13:41:53 alarmserver avahi-daemon[406]: Registering new address record for fe80::994:38c:1fac:20ff on wlan0.*.
Jun 25 13:41:53 alarmserver sudo[1207]: pam_unix(sudo:session): session closed for user root
Jun 25 13:41:53 alarmserver sudo[1213]:       pi : TTY=pts/1 ; PWD=/home/pi/st-device-sdk-c/example ; USER=root ; COMMAND=/usr/bin/systemctl start dnsmasq
Jun 25 13:41:53 alarmserver sudo[1213]: pam_unix(sudo:session): session opened for user root by pi(uid=0)
Jun 25 13:41:53 alarmserver systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server...
Jun 25 13:41:53 alarmserver dnsmasq[1216]: dnsmasq: syntax check OK.
Jun 25 13:41:53 alarmserver dnsmasq[1224]: started, version 2.80 cachesize 150
Jun 25 13:41:53 alarmserver dnsmasq[1224]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile
Jun 25 13:41:53 alarmserver dnsmasq-dhcp[1224]: DHCP, IP range 192.168.2.2 -- 192.168.2.12, lease time 12h
Jun 25 13:41:53 alarmserver dnsmasq[1224]: reading /run/dnsmasq/resolv.conf
Jun 25 13:41:53 alarmserver dnsmasq[1224]: using nameserver 192.168.1.1#53
Jun 25 13:41:53 alarmserver dnsmasq[1224]: using nameserver 2603:8081:8c0b:ace:5aef:68ff:fe60:7070#53
Jun 25 13:41:53 alarmserver dnsmasq[1224]: read /etc/hosts - 5 addresses
Jun 25 13:41:53 alarmserver dnsmasq[1225]: Too few arguments.
Jun 25 13:41:53 alarmserver systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server.
Jun 25 13:41:53 alarmserver sudo[1213]: pam_unix(sudo:session): session closed for user root
Jun 25 13:41:53 alarmserver dhcpcd[1180]: wlan0: soliciting an IPv6 router
Jun 25 13:41:58 alarmserver dhcpcd[1180]: wlan0: using static address 192.168.2.1/24
Jun 25 13:41:58 alarmserver avahi-daemon[406]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.2.1.
Jun 25 13:41:58 alarmserver avahi-daemon[406]: New relevant interface wlan0.IPv4 for mDNS.
Jun 25 13:41:58 alarmserver avahi-daemon[406]: Registering new address record for 192.168.2.1 on wlan0.IPv4.
Jun 25 13:41:58 alarmserver dhcpcd[1180]: wlan0: adding route to 192.168.2.0/24
Jun 25 13:42:05 alarmserver hostapd[1212]: wlan0: STA d6:ec:3d:16:79:a1 IEEE 802.11: associated
Jun 25 13:42:06 alarmserver hostapd[1212]: wlan0: STA d6:ec:3d:16:79:a1 RADIUS: starting accounting session 8DCFE3C2FA9D233F
Jun 25 13:42:06 alarmserver hostapd[1212]: wlan0: STA d6:ec:3d:16:79:a1 WPA: pairwise key handshake completed (WPA)
Jun 25 13:42:06 alarmserver hostapd[1212]: wlan0: STA d6:ec:3d:16:79:a1 WPA: group key handshake completed (WPA)
Jun 25 13:42:06 alarmserver dnsmasq-dhcp[1224]: DHCPDISCOVER(wlan0) d6:ec:3d:16:79:a1
Jun 25 13:42:06 alarmserver dnsmasq-dhcp[1224]: DHCPOFFER(wlan0) 192.168.2.9 d6:ec:3d:16:79:a1
Jun 25 13:42:06 alarmserver dhcpcd[1180]: wlan0: no IPv6 Routers available
Jun 25 13:42:06 alarmserver dnsmasq-dhcp[1224]: DHCPREQUEST(wlan0) 192.168.2.9 d6:ec:3d:16:79:a1
Jun 25 13:42:06 alarmserver dnsmasq-dhcp[1224]: DHCPACK(wlan0) 192.168.2.9 d6:ec:3d:16:79:a1 CHRIS-s-S20
Jun 25 13:42:20 alarmserver hostapd[1212]: wlan0: STA d6:ec:3d:16:79:a1 IEEE 802.11: disassociated
Jun 25 13:42:25 alarmserver dhcpcd[1180]: eth0: Router Advertisement from fe80::5aef:68ff:fe60:7070

If I were just setting up a Pi as an AP, I’d have to go in NAT the shit from wlan0 to eth0, but I since I’m super ignorant of how ST behaves in this scenario, I haven’t messed with anything else.

36

Is this project still active?

I was able to build the core library and get the access point working. Access point functionality was verified with the testhostapd script. I did see that smarthings core code had been updated to include two functions that needed to be added to the iot_bsp_wifi_rpi.c file. Were there any other changes that need to be made to get the AP to launch when example executable is ran?

I ran into an issue when I attempt to onboard the example switch. See log output below there is a call made to start the access point service but it reports back a failure to start. I am able to start the service through the supplied test scripts.

e[32mI (1644700589:833) [IoT]: _dump_device_info(706) > firmware_version: switch_example_001
e[0me[32mI (1644700589:833) [IoT]: iot_bsp_wifi_init(149) > [rpi] iot_bsp_wifi_init
e[0me[32mI (1644700589:833) [IoT]: iot_bsp_wifi_init(150) > [rpi] wifi module version 20210405
e[0me[32mI (1644700589:857) [IoT]: _initDevNames(480) > Ethernet device eth0 not connected
e[0me[32mI (1644700589:877) [IoT]: iot_bsp_wifi_init(166) > [rpi] No Ethernet
e[0me[32mI (1644700589:877) [IoT]: iot_bsp_wifi_init(176) > [rpi] Wifi station device wlan0 found
e[0me[32mI (1644700589:877) [IoT]: iot_bsp_wifi_init(230) > [rpi] Wifi Initialization Done
e[0me[32mI (1644700589:878) [IoT]: st_conn_init(1372) > previous error code
e[0me[32mI (1644700589:878) [IoT]: st_conn_init(1380) > stdk_version : 1.7.5
e[0me[32mI (1644700589:878) [IoT]: st_conn_start(1850) > st_conn_start start (no-pin)
e[0me[32mI (1644700589:879) [IoT]: _do_iot_main_command(498) > curr_main_cmd:10, curr_main_state:-1/-1
e[0me[32mI (1644700589:879) [IoT]: _do_update_timeout(199) > Current timeout : 100000 for -1/0
e[0me[32mI (1644700589:879) [IoT]: _do_status_report(304) > Call usr status_cb with 1/0
e[0miot_status: 1, lv: 0
e[32mI (1644700589:879) [IoT]: _do_iot_main_command(498) > curr_main_cmd:2, curr_main_state:-1/0
e[0me[31mE (1644700589:879) [IoT]: _iot_security_be_bsp_fs_load_from_nv(129) > iot_bsp_fs_open(./WifiProvStatus) = -1208
e[0me[32mI (1644700589:879) [IoT]: _do_cmd_tout_check(1041) > New state updated for 0
e[0me[32mI (1644700589:879) [IoT]: _do_iot_main_command(498) > curr_main_cmd:10, curr_main_state:0/0
e[0me[32mI (1644700589:879) [IoT]: iot_bsp_wifi_set_mode(871) > [rpi] Requested mode SCAN
e[0me[32mI (1644700589:879) [IoT]: _perform_scan(1622) > [rpi] Running Wifi AP scan using wlan0
e[0me[32mI (1644700590:644) [IoT]: iot_bsp_wifi_set_mode(889) > [rpi] WiFi scan completed. 7 APs found
e[0me[32mI (1644700590:644) [IoT]: iot_bsp_wifi_get_scan_result(1596) > [rpi] Get scan result requested; 7 available
e[0me[32mI (1644700590:645) [IoT]: iot_easysetup_create_ssid(89) > >> Switch_Exampl[XWvw] <<
e[0me[32mI (1644700590:645) [IoT]: _do_update_timeout(199) > Current timeout : 300000 for 0/1
e[0me[32mI (1644700590:645) [IoT]: _do_iot_main_command(498) > curr_main_cmd:1, curr_main_state:0/1
e[0me[32mI (1644700590:645) [IoT]: iot_bsp_wifi_set_mode(964) > [rpi] Requested mode SoftAP
e[0me[32mI (1644700595:481) [IoT]: _SoftAPControl(1291) > [rpi] SoftAP service start issued
e[0me[31mE (1644700597:622) [IoT]: iot_bsp_wifi_set_mode(1014) > [rpi] SoftAP service failed to start
e[0me[31mE (1644700597:622) [IoT]: _do_iot_main_command(564) > failed to set wifi_set_mode

e[0me[31mE (1644700597:622) [IoT]: _do_cmd_tout_check(1054) > Some cmd(0x2) failed for 1 state
e[0me[32mI (1644700597:622) [IoT]: _do_iot_main_command(498) > curr_main_cmd:10, curr_main_state:0/1
e[0me[33mW (1644700597:622) [IoT]: _do_recovery(1429) > state changing fail for 1, curr_state :0
e[0me[31mE (1644700597:622) [IoT]: _do_recovery(1549) > Failed to do process [1] on time, STOP
e[0me[32mI (1644700597:622) [IoT]: _do_update_timeout(199) > Current timeout : 4294967295 for 0/-2
e[0me[32mI (1644700597:622) [IoT]: _do_status_report(304) > Call usr status_cb with 1/3
e[0miot_status: 1, lv: 3
e[32mI (1644700597:622) [IoT]: _do_cmd_tout_check(1041) > New state updated for -2
e[0me[32mI (1644700597:622) [IoT]: _do_iot_main_command(498) > curr_main_cmd:10, curr_main_state:-2/-2
e[0me[33mW (1644700597:622) [IoT]: _do_state_updating(1711) > Iot-core task will be stopped, needed ext-triggering

e[0me[32mI (1644700597:622) [IoT]: iot_bsp_wifi_set_mode(851) > [rpi] Requested mode OFF
e[0me[32mI (1644700599:887) [IoT]: _SoftAPControl(1291) > [rpi] SoftAP service stop issued
e[0me[32mI (1644700600:244) [IoT]: _do_status_report(304) > Call usr status_cb with 1/0
e[0miot_status: 1, lv: 0
e[32mI (1644700600:244) [IoT]: _do_update_timeout(199) > Current timeout : 4294967295 for -1/-1
e[0me[32mI (1644700600:244) [IoT]: _do_status_report(295) > Unsupported state -1 for 0/0
e[0me[31mE (1644700600:244) [IoT]: st_conn_start(1908) > C

Thanks in advance.

37

Hi there. Yes, I’m still maintaining it. In fact I just uploaded updates yesterday, so you may need to do a git pull of the latest from the rpi-st-device repository. As you saw, there are two new functions now required which I added to that file. They are stubs for now, but per SmartThings staff recommendation.

A couple questions:

  • What Pi model and what OS are you running?
  • Did you use the mastersetup script or did you configure manually?

SoftAP service failed to start

This is definitely a problem. But if you had no problems with the testhostapd script, then that is unusual for sure. A systemctl status is done on hostapd to make sure it has loaded and that the lines:

AP-ENABLED

and

Started Advanced IEEE 802.11 AP

are found in the output. What version of hostapd are you running? I wonder if something has changed since I’ve lasted updated. See if you start it with the test script, if you do a systemctl status hostapd do you get those two lines above?

The only other thing I can think of is if there is something wrong with your hostapd.conf file to prevent it from loading, or it’s just being slow to start.

EDIT: When you attempt this again (with the example app, not the test script), as soon as you see that log error message, go to another terminal window and immediately do a systemctl status hostapd and see what you get.

38
  • Pi 3 model B v 1.2
  • OS is 2021-10-30-raspios-bullseye-armhf (32 bit lite)
  • Manual configuration for pi setup and ap configuration
  • hostapd v 2:2.9.0-12
  • hostapd.conf file entries mentioned in the config doc are set to country_code=US, interface=wlan0 and channel=1

I did confirm that the router channel is also 1 per the recommendation in the config doc.

I am aware of the change you made to get the core lib to compile. I saw your post on SmartThings and the response from the dev, I made the same changes to get the code to compile. I will do a git pull to see if that helps.

When I run the example executable I do see the network icon change from the wifi icon to the access point icon when the SoftAP service start issued is printed in the output. It flips back to the wifi icon as soon as the failed to set wifi_set_mode is printed.

39

The new functions added are unrelated to this particular issue. That effects things a bit later in the onboarding process, so we’ll need to figure this one out first.

Let me try updating all the sw on one of my Pi’s and see if I can reproduce this. I haven’t done that in a few months…

In the meantime, let me know what you get from systemctl for hostapd.

40

A fix has been uploaded to the github repository for provisioning issues on the new Raspberry Pi Bullseye OS.

Thank you to @mcdunning for bringing this problem to my attention!