Chat freely about anything...

User avatar
By Barnabybear
#44570 Hi, all. I'm looking into my ESPs not responding after a short time. It appears that the ESP is disconnecting from the AP / router after about 5 mins of inactivity even if there is a long time left on the lease. Below are the edited entries from my routers log.
Code: Select all08:18:54, 31 Mar.   (1882218.740000) Lease requested
08:18:54, 31 Mar.   (1882218.810000) Device connected: Hostname: ESP_F20F88 IP: 192.168.1.76 MAC: 18:fe:34:f2:0f:88 Lease time: 1440 min. Link rate: 100.0 Mbps
08:18:54, 31 Mar.   (1882218.810000) Lease for IP 192.168.1.76 renewed by host ESP_F20F88 (MAC 18:fe:34:f2:0f:88). Lease duration: 1440 min
08:23:57, 31 Mar.   (1882521.620000) Device disconnected: Hostname: ESP_F20F88 IP: 192.168.1.76 MAC: 18:fe:34:f2:0f:88
5 mins 3 sec lease duration.

08:27:12, 31 Mar.   (1882716.400000) Lease requested
08:27:12, 31 Mar.   (1882716.500000) Device connected: Hostname: ESP_F20F88 IP: 192.168.1.76 MAC: 18:fe:34:f2:0f:88 Lease time: 1440 min. Link rate: 100.0 Mbps
08:27:12, 31 Mar.   (1882716.500000) Lease for IP 192.168.1.76 renewed by host ESP_F20F88 (MAC 18:fe:34:f2:0f:88). Lease duration: 1440 min
08:32:42, 31 Mar.   (1883046.920000) Device disconnected: Hostname: ESP_F20F88 IP: 192.168.1.76 MAC: 18:fe:34:f2:0f:88
4 mins 30 sec lease duration..

11:25:39, 31 Mar.   (1893423.540000) Lease requested
11:25:39, 31 Mar.   (1893423.640000) Device connected: Hostname: ESP_F20F88 IP: 192.168.1.76 MAC: 18:fe:34:f2:0f:88 Lease time: 1440 min. Link rate: 100.0 Mbps
11:25:39, 31 Mar.   (1893423.640000) Lease for IP 192.168.1.76 renewed by host ESP_F20F88 (MAC 18:fe:34:f2:0f:88). Lease duration: 1440 min
11:30:31, 31 Mar.   (1893715.440000) Device disconnected: Hostname: ESP_F20F88 IP: 192.168.1.76 MAC: 18:fe:34:f2:0f:88
4 mins 52 sec lease duration.

11:38:03, 31 Mar.   (1894167.470000) Lease requested
11:38:03, 31 Mar.   (1894167.570000) Device connected: Hostname: ESP_F20F88 IP: 192.168.1.76 MAC: 18:fe:34:f2:0f:88 Lease time: 1440 min. Link rate: 100.0 Mbps
11:38:03, 31 Mar.   (1894167.570000) Lease for IP 192.168.1.76 renewed by host ESP_F20F88 (MAC 18:fe:34:f2:0f:88). Lease duration: 1440 min
11:43:01, 31 Mar.   (1894465.500000) Device disconnected: Hostname: ESP_F20F88 IP: 192.168.1.76 MAC: 18:fe:34:f2:0f:88
4 mins 58 sec lease duration.

11:44:57, 31 Mar.   (1894582.140000) Lease requested
11:44:57, 31 Mar.   (1894582.220000) Device connected: Hostname: ESP_F20F88 IP: 192.168.1.76 MAC: 18:fe:34:f2:0f:88 Lease time: 1440 min. Link rate: 100.0 Mbps
11:44:57, 31 Mar.   (1894582.220000) Lease for IP 192.168.1.76 renewed by host ESP_F20F88 (MAC 18:fe:34:f2:0f:88). Lease duration: 1440 min
11:49:52, 31 Mar.   (1894876.980000) Device disconnected: Hostname: ESP_F20F88 IP: 192.168.1.76 MAC: 18:fe:34:f2:0f:88
4 mins 55 sec lease duration.


It crossed my mind that a lease of 1440 mins (1 day) might be to long for the ESP to handle if this was being converted into micros (a bit like the maximum length of deep sleep is 71 mins) and my be being truncated to 32 bits. If this was the case and you took the 32 LSB from 1440 x 60 x 1000 x 1000, that equates to 8 mins. That sort of works if the ESP tries to renew the lease at 50% of its duration, tries and fails then disconnects. So I thought if I reduce the duration of the lease issued to 60 mins then this would fall within a 32 bit value, this however doesn't seem to make any difference.
Code: Select all12:05:16, 31 Mar.   (1895800.640000) Lease requested
12:05:16, 31 Mar.   (1895800.740000) Device connected: Hostname: ESP_F20F88 IP: 192.168.1.76 MAC: 18:fe:34:f2:0f:88 Lease time: 60 min. Link rate: 100.0 Mbps
12:05:16, 31 Mar.   (1895800.740000) Lease for IP 192.168.1.76 renewed by host ESP_F20F88 (MAC 18:fe:34:f2:0f:88). Lease duration: 60 min
12:10:11, 31 Mar.   (1896095.280000) Device disconnected: Hostname: ESP_F20F88 IP: 192.168.1.76 MAC: 18:fe:34:f2:0f:88
4 mins 55 sec lease duration.

12:15:09, 31 Mar.   (1896394.020000) Lease requested
12:15:09, 31 Mar.   (1896394.090000) Device connected: Hostname: ESP_F20F88 IP: 192.168.1.76 MAC: 18:fe:34:f2:0f:88 Lease time: 60 min. Link rate: 100.0 Mbps
12:15:09, 31 Mar.   (1896394.090000) Lease for IP 192.168.1.76 renewed by host ESP_F20F88 (MAC 18:fe:34:f2:0f:88). Lease duration: 60 min
12:23:00, 31 Mar.   (1896864.620000) Device disconnected: Hostname: ESP_F20F88 IP: 192.168.1.76 MAC: 18:fe:34:f2:0f:88
7 mins 51 sec lease duration.

12:25:16, 31 Mar.   (1897001.160000) Lease requested
12:25:16, 31 Mar.   (1897001.240000) Device connected: Hostname: ESP_F20F88 IP: 192.168.1.76 MAC: 18:fe:34:f2:0f:88 Lease time: 60 min. Link rate: 100.0 Mbps
12:25:16, 31 Mar.   (1897001.240000) Lease for IP 192.168.1.76 renewed by host ESP_F20F88 (MAC 18:fe:34:f2:0f:88). Lease duration: 60 min
12:30:12, 31 Mar.   (1897296.680000) Device disconnected: Hostname: ESP_F20F88 IP: 192.168.1.76 MAC: 18:fe:34:f2:0f:88
4 mins 56 sec lease duration.

12:38:46, 31 Mar.   (1897810.860000) Lease requested
12:38:46, 31 Mar.   (1897810.930000) Device connected: Hostname: ESP_F20F88 IP: 192.168.1.76 MAC: 18:fe:34:f2:0f:88 Lease time: 60 min. Link rate: 100.0 Mbps
12:38:46, 31 Mar.   (1897810.930000) Lease for IP 192.168.1.76 renewed by host ESP_F20F88 (MAC 18:fe:34:f2:0f:88).Lease duration: 60 min
12:43:36, 31 Mar.   (1898100.730000) Device disconnected: Hostname: ESP_F20F88 IP: 192.168.1.76 MAC: 18:fe:34:f2:0f:88
4 mins 50 sec lease time.


Any thoughts as the log is not showing any activity from the ESP just a disconnection?

Fixed IP issued by the routers DHCP.
Mostly this code https://github.com/forkineye/E131 using the unicast option.
Last edited by Barnabybear on Fri Apr 01, 2016 5:20 pm, edited 1 time in total.
User avatar
By Barnabybear
#44589 Hi, @eduperez an interesting thought. I need to look more into this.
I've tried a different code from the same auther thet uses the E1.31.h file and it's been connected now for over 2 hours. Now I have 2 bits of code to compare. Unfortunatly the second one doesn't do what I need - isn't that always the case.
https://github.com/forkineye/ESPixelStick

Update: As far as I can see all the important bits of code are identical. So the issue must be somewere else.
Last edited by Barnabybear on Sat Apr 02, 2016 3:15 am, edited 1 time in total.
User avatar
By Barnabybear
#44650 Hi all, good news. I’ve part solved the problem (it’s taken some hours though) and there are still some big questions at the end of the post.

Quick answer:

If the ESP connected through the access point it was dropped from the DHCP list after 5 mins regardless of the duration of the lease. If it connected through the router it was maintained on the DHCP list and lease times where honoured.

Longer Answer:

My network hardware; I have a router (1) with cable internet. This then connects via CAT5 from a 1000 Mbit/s socket to a second router (2) which has had the DHCP disabled (all settings point at the first router), so it is basically an access point. The SSID and Password are the same on both routers.

Why I didn’t spot this; when the ESP’s connected they serial printed out their status (IP and what they were connecting to) as both the router and access point had the same SSID I was unable to discern that they were using different routes. It was only when I looked at the schematic type view on my router that I noticed that one ESP had a wired connection (via the second router / AP) and the other had a wireless connection (directly from the router). The logs that I had spent a lot of time looking at gave no clue as to the route of the connection.

What next; I turned off the second router / AP and power cycled the ESPs so both would be forced to connect to the router (1). Both have been up now for 5 hours despite the fact that I switch the second router / AP back on after an hour, it will be interesting to see what happens when the leases are up for first renewal attempt after 12 hours.

The questions:

Why if connected via this router / AP is it removed from the DHCP list after 5 mins?
I’ve done a lot of reading and a little knowledge is dangerous, so my thoughts – is something like this possible?
Asuming that the infomation below is correct (ok its windows specific but I’m guessing it’s not far off how things generally work).
Code: Select all  DHCP Lease Process

DHCP leases are used to reduce DHCP network traffic by giving clients specific addresses for set periods of time. The DHCP process stages can be remembered using the ROSA acronym:

    Request - A broadcast is sent by the client with the client MAC address. This is a DHCP discover message with source IP address of 0.0.0.0 and destination address of 255.255.255.255. The client tries to get its last address. If it is not available, the DHCP server will send a NACK signal. The client state is initialization during the request stage.

    Offer - A DHCP offer message is sent from the DHCP server with some or all the optional information as listed above. Information sent includes the IP address of the DHCP server that sent the accepted offer. All offered IP addresses are marked unavailable by the DHCP server when the DHCP server offers them until they are rejected. The client is in the selecting state during this offer stage.

    Selection (or acceptance) - The first offer received by the client is accepted. The client broadcasts its selected choice using a DHCP request message which includes the IP address of the DNS server that sent the accepted offer. The client is in the requesting state during this selection stage.

    Acknowledgement - The server acknowledges with a DHCP acknowledge indicating the client can use the address or it will send a DHCP Nak instructing the client that the address became unavailable. Other DHCP servers retract their offers and mark the offered address as available and the accepted address as unavailable. Any offered IP addresses not selected are freed to be used again. The client state is the binding state during this acknowledgement stage.

When the client sends the lease request, it then waits one second for an offer. If a response is not received, the request is repeated at 9, 13, and 16 second intervals with additional 0 to 1000 milliseconds of randomness. The attempt is repeated every 5 minutes thereafter. The client uses port 67 and the server uses port 68.

Based on the fact that the ESP is dropped from the DHCP list after 5 mins. Could it be that the ‘DHCP acknowledge’ or ‘DHCP Nak’ is somehow blocked by the AP, so the ESP believes it has been unsuccessful and waits 5 mins before defaulting back to the request IP 0.0.0.0 and attempting to request a lease again? In the meantime the DHCP server has sent a ‘DHCP acknowledge’ so the IP is reserved and any traffic is processed as normal, the ESP having been given an IP even though it has not seen an ‘DHCP acknowledge’ processes any traffic on that IP and Subnet until the 5 min time out occurs. At this point it requests a new lease on the default subnet 255.255.255.255.
This is where I think it gets all messy. The router believes it has issued a lease to a wired device on a particular subnet and then receives a request from both a wireless and a wired device for a new lease with the same MAC on a different subnet and isn’t quite sure what to do so it just ends the current lease and ignores both.

It would be nice to get to the bottom of this before I get bored with the fact that I can make work anyway as quite a few people seem to have had problems with this.

All comments welcome.

Update: Both ESPs renewed their lease overnight (after 12 hours 50% of lease time) and are still connected to the Router (1). It's looking very much as if the problem is caused by the second router / AP (2).