ESP32-C3 DHCP Server only works on first boot

[designrulesco]

Hi all,

I have a very strange and major issue. I'm using the ESP32-C3 in AP mode for a captive portal (start and stop of AP shown below).

The extremely strange behavior I'm getting is that :

1. First upload and boot of the firmware (via PyMakr in VSCode), all is great.
2. If I restart the board, the AP also startups up, but DHCP fails. No device can connect to the AP. I can restart the board as many times as I want, the DHCP never succeeds. Even leaving it powered off for minutes.
3. However, if I reupload the code with PyMakr (no code changes at all, just a re-upload to the VFS), then on first boot DHCP succeeds again.

Has anyone experienced this before? It looks like there's some sort of cache or config of some kind that causes DHCP to fail every boot after the first. Whatever PyMakr is doing seems to clear it - not sure what REPL commands it sends.

Note - this issue happens whether or not there's even a client connection on the first boot! If I connect and reboot - DHCP fails. If I don't even try connecting and reboot - DHCP still fails.

Things I've tried unsuccessfully:

1. All devices (windows, MacOS, Android phone) have the same behavior - ESP32-C3 fails to issue an IP.
2. I do sys.modules.clear() and gc.collect() on boot.
3. I've tried long waits after activating AP, no difference.
4. I've tried leaving the board off for minutes - still has the issue later when turned on.

#4 in particular seems to suggest this is something that's persistent, otherwise a restart should clear it - which makes me suspect NVS since Micropython seems to store WiFi configs in NVS (and perhaps PyMakr clears NVS). But I don't know of any way to do that from within the app.

This is a pretty big problem - a user can connect to the AP on the first boot only. If they reboot - well, you'll never see the AP again.

AP Start Code:

def start_ap(self):
        self.log.info("Starting Access Point...")
        ap = network.WLAN(network.AP_IF)
        ap.active(False)
        time.sleep(3)
        ap.active(True)
        time.sleep(0.5)

        ap.config(channel=6)

        # Configure IP
        ap.ifconfig((self.server_ip, self.subnet, self.server_ip, self.server_ip))

        # Generate random suffix to avoid SSID cache issues
        random_suffix = urandom.getrandbits(12) % 10000

        # Concat
        ssid = f"{self.base_ssid}-{self._get_mac_suffix()}-{random_suffix:04d}"
        ap.config(essid=ssid, authmode=network.AUTH_OPEN)

        self.log.info(f"Access Point: {ap.ifconfig()} started with SSID: {ssid}")

AP stop code:
def stop_ap(self):
        ap = network.WLAN(network.AP_IF)
        ap.active(False)
        self.log.info("Access Point stopped")

Also, logs below from MacOS console.app showing the clean DHCP when connecting to the AP on first boot, and a bad DHCP on second boot.

Processing DHCP: 'State:/Network/Service/.../DHCP'
DHCP airport_changed = 1, service:...
IP Address: 10.0.0.2
IP subnet mask: 255.255.255.0
Router IP Address: 10.0.0.1
Default Gateway IP Address: 10.0.0.1
Router MAC Address: 24:ec:4a:b7:9a:41

Fri Aug  8 18:47:16.128 [airport]/386 @[5053545.230357] (airportProcessCommand.m:513) IP Address: 169.254.186.91
Fri Aug  8 18:47:16.128 [airport]/386 @[5053545.230458] (airportProcessCommand.m:535) IP subnet mask: 255.255.0.0
Fri Aug  8 18:47:16.128 [airport]/386 @[5053545.230506] (airportProcessCommand.m:547) No Router IP Address
Fri Aug  8 18:47:16.128 [airport]/386 @[5053545.230553] (airportProcessCommand.m:556) No Default Gateway IP Address
Fri Aug  8 18:47:16.128 [airport]/386 @[5053545.230595] (airportProcessCommand.m:566) No Router MAC Address

[Josverl]

As you know the company pycom does not exist any more, and therefore there is no maintenance to pymakr anymore.

I used to contribute to the serial interface, and afaik there is nothing special about Pymakr uploads. Mpremote nowadays uses the same serial settings.

You can enable logging using

# boot.py/main.py
import esp
# Enable ESP debug logging for network
esp.osdebug(esp.LOG_DEBUG)

To reduce the number of moving components, what happens is you create a main.py , upload the files, then just turn off, and turn back on ?

[DavesCodeMusings]

I tried your code on an ESP32-C3 and was not able to reproduce the issue. I did modify the code a bit, hard-coding some values. Here what I ran as boot.py:

import time
import network
import urandom

def start_ap():
    print("Starting Access Point...")
    ap = network.WLAN(network.AP_IF)
    ap.active(False)
    time.sleep(3)
    ap.active(True)
    time.sleep(0.5)

    ap.config(channel=6)

    # Configure IP
    ap.ifconfig(("10.10.10.1", "255.255.255.0", "10.10.10.1", "10.10.10.1"))

    # Generate random suffix to avoid SSID cache issues
    random_suffix = urandom.getrandbits(12) % 10000

    # Concat
    ssid = f"esp32c3-{random_suffix:04d}"
    ap.config(essid=ssid, authmode=network.AUTH_OPEN)

    print(f"Access Point: {ap.ifconfig()} started with SSID: {ssid}")

start_ap()

I was able to attach to the original SSID, and the new SSID after reset, and I got the same IP address both times.

PS C:\Users\dave> ipconfig

Windows IP Configuration

Wireless LAN adapter Wi-Fi:

   Connection-specific DNS Suffix  . :
   Link-local IPv6 Address . . . . . : fe80::bbe4:8c56:1b72:36b5%7
   IPv4 Address. . . . . . . . . . . : 10.10.10.2
   Subnet Mask . . . . . . . . . . . : 255.255.255.0
   Default Gateway . . . . . . . . . : 10.10.10.1

I used VS Code, but with mpremote, not pymakr. The board I'm using is some ESP32-C3 Mini clone from Amazon. The DHCP client is Windows 11.

Sorry to say I can't reproduce the problem, but maybe this will help you rule some things out???

[designrulesco]

Hey @Josverl , @DavesCodeMusings huge thanks to you both for helping with this.

It seems like the issue ended up being that my _get_mac_suffix() function got the mac address by activating STA, which seems like it was giving me grief during AP bringup:

def _get_mac_suffix(self):
        sta = network.WLAN(network.STA_IF)
        sta.active(True)
        mac = sta.config('mac')  # bytes
        # Use last 3 bytes
        return ''.join('{:02X}'.format(b) for b in mac[-3:])

I changed it over to use AP for retrieving the mac, and now we're all good:

def _get_mac_suffix(self):
        ap = network.WLAN(network.AP_IF)
        was_active = ap.active()
        if not was_active:
            ap.active(True)
            time.sleep(0.05)
        mac = ap.config('mac')  # bytes
        suffix = ''.join('{:02X}'.format(b) for b in mac[-3:])
        if not was_active:
            ap.active(False)
        return suffix

Now, I can reliably connect to the AP on every power-cycle of the board, DHCP works, etc. But now I've got an entirely different problem that is just as head-scratching... I've probably spent a good 15 hours on it so far. If either of you have any ideas, I'm all ears.

I'm running a captive portal that serves a 71Kb index.html page when a client connects. I run a DNS task to hijack any DNS requests and point them to the server IP (10.0.0.1) and an HTTP server task (using asyncio.start_server) that calls an HTTP request handler. In that handler, I serve any request with my index.html; since it's so big, though, I write it in 512 byte chunks.

The strange thing - this works perfectly on first boot after upload, but then if I restart, it never work again. My HTTP request handler gets called (so we're getting a request) but it seems like the sending of the page "locks up" and we get stuck responding to that first request, which we don't even respond to fully. Compare that to the first boot, where we serve about a dozen requests successfully.

Function for sending the 71Kb index.html in 512 byte chunks:

async def send_chunked_file(writer, file_path, content_type, extra_headers=None):
            try:
                header_lines = [
                    'HTTP/1.1 200 OK',
                    f'Content-Type: {content_type}',
                ]
                if extra_headers:
                    header_lines.extend(extra_headers)
                header_lines.append('\r\n')

                headers = '\r\n'.join(header_lines)
                success = await safe_awrite(writer, headers)
                if not success:
                    self.log.info(f"Connection closed while sending {file_path}")
                    await safe_aclose(writer)
                    return

                with open(file_path, 'rb') as f:
                    while True:
                        chunk = f.read(512)
                        if not chunk:
                            break
                        success = await safe_awrite(writer, chunk)
                        if not success:
                            self.log.info(f"Connection closed while sending {file_path}")
                            await safe_aclose(writer)
                            return
            except Exception as e:
                self.log.error(f"Failed to send file {file_path}: {e}")
                await safe_awrite(writer, 'HTTP/1.1 404 Not Found\r\n\r\n')
                await safe_aclose(writer)

Function for writing safely and closing writer:

async def safe_awrite(writer, data, timeout_ms=800):
            # Ensure data is bytes
            if isinstance(data, str):
                data = data.encode()
            try:
                if IS_UASYNCIO_V3:
                    await asyncio.wait_for(writer.awrite(data), timeout_ms / 1000)
                else:
                    await writer.awrite(data)
                return True
            except (asyncio.TimeoutError, OSError) as e:
                self.log.info(f"Safe write timed out/OS error: {e}")
                return False
            except Exception as e:
                self.log.info(f"Safe write failed: {e}")
                return False
            
        async def safe_aclose(writer):
            try:
                await writer.aclose()
            except:
                pass
            return

This is the log from a successful first boot, where we serve up the full index.html (and then the client requests other assets used in index.html, like logo.svg, etc):

[INFO][CAPTIVE PORTAL] Access Point started, waiting 1 seconds...
[INFO][CAPTIVE PORTAL] Captive Portal started
[INFO][CAPTIVE PORTAL] DNS server running
[INFO][CAPTIVE PORTAL] HTTP server running
[INFO][CAPTIVE PORTAL] DNS query for: connectivitycheck.gstatic.com
[INFO][CAPTIVE PORTAL] DNS query for: www.google.com
[INFO][CAPTIVE PORTAL] HTTP request: GET /generate_204 HTTP/1.1 from ('10.0.0.2', 56548) for path /generate_204
[INFO][CAPTIVE PORTAL] Android device detected, serving portal
[INFO][CAPTIVE PORTAL] Safe write timed out/OS error: [Errno 104] ECONNRESET
[INFO][CAPTIVE PORTAL] Connection closed while sending base_app/index.html
[INFO][CAPTIVE PORTAL] HTTP request: GET /generate_204 HTTP/1.1 from ('10.0.0.2', 56550) for path /generate_204
[INFO][CAPTIVE PORTAL] Android device detected, serving portal
[INFO][CAPTIVE PORTAL] HTTP request: GET /generate_204 HTTP/1.1 from ('10.0.0.2', 56562) for path /generate_204
[INFO][CAPTIVE PORTAL] Android device detected, serving portal
[INFO][CAPTIVE PORTAL] Safe write timed out/OS error: [Errno 104] ECONNRESET
[INFO][CAPTIVE PORTAL] Connection closed while sending base_app/index.html
[INFO][CAPTIVE PORTAL] HTTP request: GET /confetti.min.js HTTP/1.1 from ('10.0.0.2', 56572) for path /confetti.min.js
[INFO][CAPTIVE PORTAL] DNS query for: content-autofill.googleapis.com
[INFO][CAPTIVE PORTAL] HTTP request: GET /generate_204 HTTP/1.1 from ('10.0.0.2', 56604) for path /generate_204
[INFO][CAPTIVE PORTAL] Android device detected, serving portal
[INFO][CAPTIVE PORTAL] HTTP request: GET /wifi HTTP/1.1 from ('10.0.0.2', 56580) for path /wifi
[INFO][CAPTIVE PORTAL] HTTP request: GET /favicon.ico HTTP/1.1 from ('10.0.0.2', 56588) for path /favicon.ico
[INFO][CAPTIVE PORTAL] Safe write timed out/OS error: 
[INFO][CAPTIVE PORTAL] Connection closed while sending base_app/index.html
[INFO][CAPTIVE PORTAL] HTTP request: GET /logo.svg HTTP/1.1 from ('10.0.0.2', 56596) for path /logo.svg
[INFO][CAPTIVE PORTAL] Failed to send /wifi response
[INFO][CAPTIVE PORTAL] Failed to send /favicon.ico 204 response

And then a failed second boot, where we just get one request and "hang" here - no more requests are ever received.

[INFO][CAPTIVE PORTAL] Access Point started, waiting 1 seconds...
[INFO][CAPTIVE PORTAL] Captive Portal started
[INFO][CAPTIVE PORTAL] DNS server running
[INFO][CAPTIVE PORTAL] HTTP server running
[INFO][CAPTIVE PORTAL] DNS query for: connectivitycheck.gstatic.com
[INFO][CAPTIVE PORTAL] DNS query for: www.google.com
[INFO][CAPTIVE PORTAL] HTTP request: GET /generate_204 HTTP/1.1 from ('10.0.0.2', 41688) for path /generate_204
[INFO][CAPTIVE PORTAL] Android device detected, serving portal
[INFO][CAPTIVE PORTAL] Safe write timed out/OS error: 
[INFO][CAPTIVE PORTAL] Connection closed while sending base_app/index.html

There's obviously more code here (DNS server, HTTP server, etc) - but I'm omitting them because, to me, this is all just some kind of weird issue with the ESP32/micropython network stack.

Why else would this work perfectly without issue on every firmware reupload and first boot, and then fail subsequently every single other boot? It points to some persistent state issue after the first boot. I'm not sure if it's something being written to NVS (though I don't think PyMakr clears NVS?) but somehow something in the stack seems to "break" on every other boot, and the only fix is reuploading the firmware via PyMakr.

I feel like the stack is kind of brittle and you need to be a bit of an ESP32 whisperer to coax it into behaving properly and there's some tribal/anecdotal wisdom here... just wondering if you guys have any insights. From what I can tell it seems to be related to uasyncio Writer; maybe the buffer is filling up and not draining?

[DavesCodeMusings]

I don't think there's any secret sauce to the ESP32s. I've been using them for a few years and any problems I run into are always of my own making.

If you want to have a look at some HTTP server code for comparison, I have a project called thimble that may be useful.

[designrulesco]

Hey Dave, thanks for the link! Thimble looks really cool, very well written.

I actually tried to sub out my HTTP server code for yours just to see if I'm mucking something up - guess what - same issue!

First boot I'm able to serve my entire html page and all assets (71kb html, 7kb svg.gz, 4kb js file) - no problem. After one reboot, I can't serve them anymore. I'm using your send_file_contents and associated helpers 1:1, as well as the actual server initiation, request parsing, etc.

Something about the write stream just starts to fail on the second boot - can't seem to write more than a few chunks if at all. The client aborts the connection accordingly, and the assets are never served..