WiFi connection problem

I can’t connect to the iotawatt via browser again (site can’t be reached), and ping shows “host unreachable”. This may have happened after recent power failures, but has happened before. I may be able to recover by rebooting router as I have before, but that causes a lot of issues on my network and I’d rather avoid that.

I did power cycle the iotawatt, but problem continues. The LED is pulsing green, which I believe means iotawatt is connected and has updated time from internet. The router shows an active WiFi connection to the proper manually assigned IP address, both before and after power cycle. However the router log is filled with a repeating sequence of entries like this:
Sep 2 10:15:42 dnsmasq-dhcp[1290]: DHCPDISCOVER(br0) 5c:cf:7f:69:72:e7
Sep 2 10:15:42 dnsmasq-dhcp[1290]: DHCPOFFER(br0) 192.168.1.66 5c:cf:7f:69:72:e7
Sep 2 10:16:42 dnsmasq-dhcp[1290]: DHCPDISCOVER(br0) 5c:cf:7f:69:72:e7
Sep 2 10:16:42 dnsmasq-dhcp[1290]: DHCPOFFER(br0) 192.168.1.66 5c:cf:7f:69:72:e7
Sep 2 10:17:42 dnsmasq-dhcp[1290]: DHCPDISCOVER(br0) 5c:cf:7f:69:72:e7
Sep 2 10:17:42 dnsmasq-dhcp[1290]: DHCPOFFER(br0) 192.168.1.66 5c:cf:7f:69:72:e7
Sep 2 10:18:42 dnsmasq-dhcp[1290]: DHCPDISCOVER(br0) 5c:cf:7f:69:72:e7
Sep 2 10:18:42 dnsmasq-dhcp[1290]: DHCPOFFER(br0) 192.168.1.66 5c:cf:7f:69:72:e7
Sep 2 10:19:42 dnsmasq-dhcp[1290]: DHCPDISCOVER(br0) 5c:cf:7f:69:72:e7
Sep 2 10:19:42 dnsmasq-dhcp[1290]: DHCPOFFER(br0) 192.168.1.66 5c:cf:7f:69:72:e7
Sep 2 10:20:42 dnsmasq-dhcp[1290]: DHCPDISCOVER(br0) 5c:cf:7f:69:72:e7
Sep 2 10:20:42 dnsmasq-dhcp[1290]: DHCPOFFER(br0) 192.168.1.66 5c:cf:7f:69:72:e7
Sep 2 10:21:42 dnsmasq-dhcp[1290]: DHCPDISCOVER(br0) 5c:cf:7f:69:72:e7
Sep 2 10:21:42 dnsmasq-dhcp[1290]: DHCPOFFER(br0) 192.168.1.66 5c:cf:7f:69:72:e7

Which I believe means the iotawatt is asking for an IP address, the router is offering one, but iotawatt never accepts it, just tries over and over.

What would anyone suggest as a next step?

Thanks!

If the IoTaWatt is glowing green it’s connected to WiFi. It would glow red if not connected. This is corroborated by your router which you say indicates it has the manually assigned IP address. I’m assuming that means the IP address that you assign in your router for the IoTaWatt’s MAC.

Can you connect to the IoTaWatt using the IP address: HTTP://<ip address>?

It doesn’t make sense to me that the IoTaWatt would be asking the router for an IP address given that it is connected, but OK, can you verify that the MAC address in the message is the IoTaWatt. The ESP8266 that I have here usually start with “DC” rather than “66”.

Interestingly, the problem seems to have fixed itself! It continued the DHCP request/offer loop for about 53 minutes, then suddenly finally acked the IP offer and started to work as normal.

You can see in the log that the original IP at 10:03:49 is a private IP, so I believe iotawatt thinks it has to use that IP, while the router and network think it has the proper 192.168.1.66, linked to the iotawatt MAC in the router. The log never says anything about changing that IP when it finally recovers.

The iotawatt MAC is 5C:CF:7F:69:72:E7 (the 66 is the end of the IP address). That MAC prefix is owned by Expressif also, in addition to DC…

I was not able to connect using the IP address or the DNS name.

** Restart **

SD initialized.
9/02/20 13:59:32z Real Time Clock is running. Unix time 1599055172
9/02/20 13:59:32z Reset reason: Software/System restart
9/02/20 13:59:32z Trace: 0:0, 0:0, 0:0, 0:0, 0:0, 0:0, 0:0, 0:0, 0:0, 0:0, 0:0, 0:0, 11:0, 11:4, 11:5, 11:5, 11:6, 11:7, 11:8, 11:9, 16:0, 16:1, 16:2, 16:3, 16:4, 16:5, 16:6, 16:7, 11:10, 11:11, 11:12, 11:12
9/02/20 13:59:32z ESP8266 ChipID: 6910695
9/02/20 13:59:32z IoTaWatt 4.x, Firmware version 02_05_09
9/02/20 13:59:32z SPIFFS mounted.
9/02/20 09:59:32 Local time zone: -5:00
9/02/20 09:59:32 Using Daylight Saving Time (BST) when in effect.
9/02/20 09:59:32 device name: IotaWatt
9/02/20 09:59:32 HTTP server started
9/02/20 09:59:33 timeSync: service started.
9/02/20 09:59:33 statService: started.
9/02/20 09:59:33 dataLog: service started.
9/02/20 09:59:39 dataLog: Last log entry 09/02/20 09:56:05
9/02/20 09:59:39 EmonService: started. url=HTTP://emonpi.ournet/emoncms, node=IotaWatt, interval=10
9/02/20 10:00:33 historyLog: service started.
9/02/20 10:00:34 historyLog: Last log entry 09/02/20 09:56:00
9/02/20 10:03:49 WiFi connected. SSID=JLNet, IP=169.254.232.114, channel=2, RSSI -57db
9/02/20 10:03:49 MDNS responder started for hostname IotaWatt
9/02/20 10:03:49 LLMNR responder started for hostname IotaWatt
9/02/20 10:03:49 Updater: service started. Auto-update class is ALPHA
9/02/20 10:03:49 EmonService: query open failed.
9/02/20 10:04:49 EmonService: query open failed.
9/02/20 10:05:49 EmonService: query open failed.
9/02/20 10:06:49 EmonService: query open failed.
9/02/20 10:07:49 EmonService: query open failed.

9/02/20 10:51:49 EmonService: query open failed.
9/02/20 10:52:49 EmonService: query open failed.
9/02/20 10:53:50 EmonService: Start posting at 09/02/20 09:35:20
9/02/20 10:53:50 Updater: Auto-update is current for class ALPHA.

Thanks

Not very well versed in the low level interactions of DHCP, but looking at the log I don’t think it has to do with requesting an IP and rejecting the response. The string of IoTaWatt log messages that appear to coincide with the router log are indicating a failure to open a connection with your Emoncms server. That probably begins with a DNS request to resolve “emonpi.ournet” and I suspect that is what was failing. At 10:53:50 that was successful and things appear to be working normally thereafter. The retry for that transaction is one minute, which again is consistent between the two logs.

Why you couldn’t access the HTTP server in IoTaWatt is no doubt a low-level issue caused by someplace lower in the stack being pre-occupied with obtaining the DNS resolution. It’s not anything that can be addressed at the application level.

OK, I’ll go with that for now. I am also not an expert in DHCP, but I believe the normal sequence is client issues broadcast DCHPDISCOVER, router responds with DHCPOFFER of an IP, client responds with broadcast DHCPREQUEST for that offered IP, router replies with DHCPACK. There were REQUEST/ACKs up until 9/2 09:35, then a DHCPRELEASE, then the DISCOVER/OFFER cycle started, which continued up to 10:53 when there was a REQUEST/ACk and things started working again.

So yes, it could be that things were stuck doing a DNS for emonpi (my emoncms server), possibly using that private IP address which could never work, until 10:53 when iotawatt picked up the right IP.

Sep 2 10:53:42 dnsmasq-dhcp[1290]: DHCPDISCOVER(br0) 5c:cf:7f:69:72:e7
Sep 2 10:53:42 dnsmasq-dhcp[1290]: DHCPOFFER(br0) 192.168.1.66 5c:cf:7f:69:72:e7
Sep 2 10:53:42 dnsmasq-dhcp[1290]: DHCPREQUEST(br0) 192.168.1.66 5c:cf:7f:69:72:e7
Sep 2 10:53:42 dnsmasq-dhcp[1290]: DHCPACK(br0) 192.168.1.66 5c:cf:7f:69:72:e7 IotaWatt

thanks