Sonoff Basic No Wifi Connection (with OLED Plugin?)

jannnfe commented 5 years ago

Summarize of the problem:

The Sonoff Basic often loses the WiFi connection. If the WiFi connection is interrupted, the following two options occur with the OLED display:

Option 1: The OLED display freezes and scrolls for about 30 seconds all pages that are set in the plugin and then freezes again.
Option 2: The OLED display continues to run normally, but no RSSI connection is displayed at the top right corner.

Logically, with the loss of Wi-Fi connection all connections to the Sonoff Basic stop. It is not possible to connect to the Sonoff via the home network via WiFi. Likewise, it is not possible to connect via AP Mode. The password for the AP Mode was set under "WPA AP Mode Key" but my computer reports the following problem when establishing a connection: "Connection failed". Also with default password: "configesp".

Expected behavior

If the Sonoff loses the wireless connection, he should connect automatically again. If there is no WiFi connection, you should be able to connect via the AP mode, so that you can restart the Sonoff. If there is no WiFi connection, the OLED display should show a corresponding error message, so that one notices the error faster.

Steps to reproduce

I do not know how to reproduce the problem because all the other devices that are nearby do not lose the connection. There are no Sonoffs but Wemos D1 Minis. My WiFi connection should actually be good enough that the Sonoff does not lose the connection.

The problem disappears when the Sonoff is completely disconnected from power. Then he connects to the WiFi again. After about 24 hours, the connection is lost again and the whole thing starts again.

Hardware:

Device: Sonoff Basic (old one) ESP Easy: Version mega-20180826 Activated Controller: Domoticz MQTT Controller Activated Devices: OLED Framed Plugin, MQTT Import, DHT22 Plugin, Switch Input (One for Relay & one for Button) Rules: Rule for switch Relay on Domoticz MQTT & Rule for switch Relay on Button pressed

Rules or log data

418108: IMPT : MQTT 037 Connection lost
418113: MQTT : Connection lost
418114: EVENT: MQTT#Disconnected
418155: MQTT : Connected to broker with client ID: ESPClient_84:F3:EB:A7:52:05
418156: Subscribed to: domoticz/out
418157: EVENT: MQTT#Connected
418465: IMPT : Connected to MQTT broker with Client ID=JanThermostat-Import
418466: EVENT: MQTTimport#Connected
418488: IMPT : [Import#TargetTemp] subscribed to ESPEasy/ThermostatSensor/TargetTemp
418490: IMPT : [Import#PowerState] subscribed to ESPEasy/ThermostatSensor/PowerState
418491: IMPT : [Import#GartenTemp] subscribed to ESPEasy/Sensor/GartenTemp
418492: IMPT : [Import#PoolTemp] subscribed to ESPEasy/Sensor/PoolTemp
423630: WD : Uptime 7 ConnectFailures 5 FreeMem 18128
428133: EVENT: Clock#Time=Sun,19:36
452071: WD : Uptime 8 ConnectFailures 5 FreeMem 16728

Approaches to solving the problem:

It seems the error only occurs on a Sonoff Basic in conjunction with the OLED display Plugin (here).
It looks like some of the services are not restarted, or the rest of the services which are already killed are waiting forever to restart (here).
RSSI may return a value of "31" to indicate an error state. Update the OLED Framed plugin to then show something else instead of max. value (here).

TD-er commented 5 years ago

What Basic version? The "old one" or the new R2? What controllers are active? On newer builds, there is this Timing stats page, which also may give some indication where to look for.

jannnfe commented 5 years ago

What Basic version? The "old one" or the new R2? What controllers are active?

I added in the post above, sorry for that.

On newer builds, there is this Timing stats page, which also may give some indication where to look for.

In order to update the newest version I have to get the Sonoff out of the wall, as he controls the heating in my room at the moment. Maybe I'll find time for it on the weekend.

Barracuda09 commented 5 years ago

Here also a Sonoff Basic (2017-5-5) flashed with: ESP_Easy_mega-20181220_normal_ESP8266_1024 which has very problematic wifi connection, so that the web interface will not load most of the time.

Barracuda09 commented 5 years ago

And in Tools->Log it show most of the time:


Fetching log entries...>> Failed to fetch <<
>> Failed to fetch <<
961910: WD   : Uptime 16 ConnectFailures 0 FreeMem 16880
>> Failed to fetch <<
>> Failed to fetch <<
1051910: WD   : Uptime 18 ConnectFailures 0 FreeMem 16824
>> Failed to fetch <<
>> Failed to fetch <<
1111910: WD   : Uptime 19 ConnectFailures 0 FreeMem 16808
>> Failed to fetch <<
>> Failed to fetch <<

Barracuda09 commented 5 years ago

Ok I have tried this:

flashed: blank_1MB
flashed: ESP_Easy_mega-20181220_normal_ESP8266_1024

But still not working, even trying to configure and submitting will fail most of the time.

Barracuda09 commented 5 years ago

Well it seems that the WiFi is not loosing connection. But why is the web interface that slow or unusable?


>reboot

 ets Jan  8 2013,rst cause:1, boot mode:(3,6)

load 0x4010f000, len 1384, room 16
tail 8
chksum 0x2d
csum 0x2d
vbb28d4a3
~ld
   ªU105 :

INIT : Booting version: mega-20181220 (ESP82xx Core 2_4_2, NONOS SDK 2.2.1(cfd48                                                                  f3), LWIP: 2.0.3 PUYA support)
106 : INIT : Warm boot #1 - Restart Reason: Software/System restart
108 : FS   : Mounting...
114 : FS   : Mount successful, used 76053 bytes of 113201
462 : CRC  : program checksum       ...OK
478 : CRC  : SecuritySettings CRC   ...OK
496 : INIT : Free RAM:24008
497 : INIT : I2C
498 : INIT : SPI not enabled
522 : INFO : Plugins: 46 [Normal] (ESP82xx Core 2_4_2, NONOS SDK 2.2.1(cfd48f3),                                                                   LWIP: 2.0.3 PUYA support)
524 : EVENT: System#Wake
537 : WIFI : Set WiFi to STA
569 : WIFI : Connecting WiFi attempt #0
572 : EVENT: System#Boot
1918 : WD   : Uptime 0 ConnectFailures 0 FreeMem 21816
4375 : WIFI : Connected! AP: WiFi (xx:yy:zz:xx:yy:zz) Ch: 1 Duration: 3804 m                                                             s
4377 : EVENT: WiFi#ChangedAccesspoint

Grovkillen commented 5 years ago

What RSSI levels do the unit get?

Barracuda09 commented 5 years ago

Wifi RSSI: -65 dB

Grovkillen commented 5 years ago

It is it only one unit that is causing the problem?

Barracuda09 commented 5 years ago

well I dare not to update the rest at the moment..

Have 2 others that have less issues that run older versions. I am not sure which version (it is not in the info page, strange enough) but is uses: ESP82xx Core 2_4_1, NONOS SDK 2.2.1(cfd48f3), LWIP: 2.0.3 (I think around begin of may 2018)

Barracuda09 commented 5 years ago

This build is in the info by the way: 20102 - Mega

TD-er commented 5 years ago

This build is in the info by the way: 20102 - Mega

That's not really the build info, it is a number used internally to mark the file structure.

Barracuda09 commented 5 years ago

Ok that I don't know the: build date is: May 5 2018 00:25:04

I can't remember if I build it myself.

Oxyandy commented 5 years ago

After using Dev 10 for a long time, I had a unit which slowly was having a lower & lower wifi signal strength, backed up the firmware & flashed it to a brand new module (Sonoff Basic TH_V1.1 2017-5-5) resolved the Wifi signal strength issue!! After the problems with wifi connectivity in early 2018 I decided to tried my luck flashing the most recent release. Erased whole device then flashed ESP_Easy_mega-20181220_normal_ESP8266_1024.bin Access point would never connect, told me password was wrong. tried from serial connection: ">WifiAPKey configesp" = Unknown command! <-BROKEN Set ">wifissid MAD_IOT" ">wifikey 12345678" then ">save" then ">wificonnect" No response ! tried ">reboot" It does this, then STOPS reporting via serial at "Connecting MAD_IOT attempt #1", but still responds to serial commands (never can be used via wifi)

INIT : Booting version: mega-20181220 (ESP82xx Core 2_4_2, NONOS SDK 2.2.1(cfd48f3), LWIP: 2.0.3 PUYA support)
106 : INIT : Warm boot #3 - Restart Reason: Software/System restart
109 : FS   : Mounting...
115 : FS   : Mount successful, used 75802 bytes of 113201
462 : CRC  : program checksum       ...OK
475 : CRC  : SecuritySettings CRC   ...OK 
493 : INIT : Free RAM:24008
495 : INIT : I2C
496 : INIT : SPI not enabled
509 : INFO : Plugins: 46 [Normal] (ESP82xx Core 2_4_2, NONOS SDK 2.2.1(cfd48f3), LWIP: 2.0.3 PUYA support)
512 : WIFI : Set WiFi to STA
545 : WIFI : Connecting MAD_IOT attempt #0
13:54:51: 1881 : WD   : Uptime 0 ConnectFailures 0 FreeMem 22168
13:54:52: 3412 : WIFI : Disconnected! Reason: '(201) No AP found' Connected for 2866 ms
4327 : WIFI : Connecting MAD_IOT attempt #1

There is never another report via serial about "Uptime" etc, nothing But still responds to commands like >wifiscan So I tried ESP_Easy_mega-20181220_normal_core_241_ESP8266_1024.bin Same outcome...

INIT : Booting version: mega-20181220 (ESP82xx Core 2_4_1, NONOS SDK 2.2.1(cfd48f3), LWIP: 2.0.3 PUYA support)
106 : INIT : Warm boot #11 - Restart Reason: Power on
109 : FS   : Mounting...
115 : FS   : Mount successful, used 75802 bytes of 113201
461 : CRC  : program checksum       ...OK
473 : CRC  : SecuritySettings CRC   ...OK 
491 : INIT : Free RAM:19656
493 : INIT : I2C
493 : INIT : SPI not enabled
506 : INFO : Plugins: 46 [Normal] (ESP82xx Core 2_4_1, NONOS SDK 2.2.1(cfd48f3), LWIP: 2.0.3 PUYA support)
509 : WIFI : Set WiFi to STA
541 : WIFI : Connecting MAD_MOB attempt #0
16:45:02: 1878 : WD   : Uptime 0 ConnectFailures 0 FreeMem 17816
16:45:04: 3412 : WIFI : Disconnected! Reason: '(201) No AP found' Connected for 2869 ms
4324 : WIFI : Connecting MAD_MOB attempt #1

Was happy to update, but for me seems nothing has changed since early 2018, WiFi remains unworkable.. This module I put the update on was brand new from a box and worked perfectly with Dev 10 firmware which I backed up the whole firmware from the wifi signal falling module, I then erased fully then flashed latest release, sadly unworkable. Anyone tell me a fairly recent release that works with Sonoff Basic units, or do we go back to maybe Nov 2017 builds, that were lightning fast and stable ?

Grovkillen commented 5 years ago

About serial stop displaying output could be because the serial log is set to "none". @TD-er we should have the serial log displaying what log level is set. It may look like the unit is dead if it just stops adding log entries.

@Oxyandy are you sure your unit is not connected? Look in the router client list or scan the network using Fing (or similar). Or use my net scan software?

Barracuda09 commented 5 years ago

Hello again,

Here it will connect to WiFi, but very poor response for some reason with a WiFi RSSI ranging form -57 to -65 dB. If I move the device closer to the router say around -50 dB it seems to hold up, but sadly there is the device not needed ;-)

I like to help and resolve this issue with you guys.

Barracuda09 commented 5 years ago

here is an log again showing indeed with a different node:


>reboot

 ets Jan  8 2013,rst cause:1, boot mode:(3,6)

load 0x4010f000, len 1384, room 16
tail 8
chksum 0x2d
csum 0x2d
vbb28d4a3
~ld
   ªU103 :

INIT : Booting version: mega-20181220 (ESP82xx Core 2_4_2, NONOS SDK 2.2.1(cfd48f3), LWIP: 2.0.3 PUYA support)
104 : INIT : Warm boot #4 - Restart Reason: Software/System restart
106 : FS   : Mounting...
112 : FS   : Mount successful, used 76053 bytes of 113201
460 : CRC  : program checksum       ...OK
476 : CRC  : SecuritySettings CRC   ...OK
494 : INIT : Free RAM:24008
496 : INIT : I2C
496 : INIT : SPI not enabled
520 : INFO : Plugins: 46 [Normal] (ESP82xx Core 2_4_2, NONOS SDK 2.2.1(cfd48f3), LWIP: 2.0.3 PUYA support)
522 : EVENT: System#Wake
535 : WIFI : Set WiFi to STA
567 : WIFI : Connecting Teigetje attempt #0
570 : EVENT: System#Boot
1918 : WD   : Uptime 0 ConnectFailures 0 FreeMem 21816
3434 : EVENT: WiFi#Disconnected
3448 : WIFI : Disconnected! Reason: '(201) No AP found' Connected for 2865 ms
4365 : WIFI : Connecting Teigetje attempt #1
>debug 1

Ok
>debug 2

Ok
>debug 3
60213 : Command: debug

Ok
61918 : WD   : Uptime 1 ConnectFailures 0 FreeMem 16768
62807 : LoopStats: shortestLoop: 120 longestLoop: 883676 avgLoopDuration: 140.49 loopCounterMax: 250000 loopCounterLast: 205984 countFindPluginId: 0
62808 : Scheduler stats: (called/tasks/max_length/idle%) 342169/4240/6/92.30
>debug 4
78080 : Command: debug
78081 : debug 4

Ok
bcn_timout,ap_probe_send_start
                              91918 : WD   : Uptime 2 ConnectFailures 0 FreeMem 16936
92807 : LoopStats: shortestLoop: 120 longestLoop: 883676 avgLoopDuration: 145.06 loopCounterMax: 250000 loopCounterLast: 200254 countFindPluginId: 0
92808 : Scheduler stats: (called/tasks/max_length/idle%) 200254/2132/6/92.40
bcn_timout,ap_probe_send_start
                              bcn_timout,ap_probe_send_start

Barracuda09 commented 5 years ago

Distance to AP is about 5 meters with one door/wall in between. And very poor response (if any at all)

Barracuda09 commented 5 years ago

That seems odd that @Oxyandy connection time is around 286x ms and my node around the same. smells fishy to me. A cold boot seems worse, doing a reboot by TTY seems to make is work "better"

I am not sure how this works, but I may have red that it will calibrate the WiFi when powered on and maybe that is a problem? Not sure it will do this after reboot thou and that way make it more responsive

Barracuda09 commented 5 years ago

More logs with some connection related problems


ap_probe_send over, rest wifi status to disassoc
state: 5 -> 0 (1)
rm 0
pm close 7
1782642 : EVENT: WiFi#Disconnected
1782655 : EVENT: WiFi#Disconnected Processing time:12 milliSeconds
1782656 : WIFI : Disconnected! Reason: '(200) Beacon timeout' Connected for 8511 ms
1782657 : WIFI  : Arduino wifi status: WL_IDLE_STATUS ESPeasy internal wifi status: ESPEASY_WIFI_DISCONNECTED
1783361 : WIFI : Connecting Teigetje attempt #0
1783363 : WIFI  : Arduino wifi status: WL_DISCONNECTED ESPeasy internal wifi status: ESPEASY_WIFI_DISCONNECTED
scandone
state: 0 -> 2 (b0)
state: 2 -> 3 (0)
state: 3 -> 5 (10)
add 0
aid 1
cnt

connected with Teigetje, channel 1
dhcp client start...
1784446 : WIFI : Connected! AP: Teigetje (18:A6:F7:41:D3:CB) Ch: 1 Duration: 1084 ms
1784447 : WIFI  : Arduino wifi status: WL_DISCONNECTED ESPeasy internal wifi status: ESPEASY_WIFI_CONNECTED
ip:192.168.0.108,mask:255.255.255.0,gw:192.168.0.1
1786326 : WIFI : DHCP IP: 192.168.0.108 (LightTV-0) GW: 192.168.0.1 SN: 255.255.255.0   duration: 1880 ms
1786328 : EVENT: WiFi#Connected
1786340 : EVENT: WiFi#Connected Processing time:12 milliSeconds
1786342 : WIFI  : Arduino wifi status: WL_CONNECTED ESPeasy internal wifi status: ESPEASY_WIFI_SERVICES_INITIALIZED
pm open,type:2 0
bcn_timout,ap_probe_send_start
ap_probe_send over, rest wifi status to disassoc
state: 5 -> 0 (1)
rm 0
pm close 7
1797079 : EVENT: WiFi#Disconnected
1797091 : EVENT: WiFi#Disconnected Processing time:13 milliSeconds
1797092 : WIFI : Disconnected! Reason: '(200) Beacon timeout' Connected for 12 s
1797093 : WIFI  : Arduino wifi status: WL_IDLE_STATUS ESPeasy internal wifi status: ESPEASY_WIFI_DISCONNECTED
1797360 : WIFI : Connecting Teigetje attempt #0
1797362 : WIFI  : Arduino wifi status: WL_DISCONNECTED ESPeasy internal wifi status: ESPEASY_WIFI_DISCONNECTED
scandone
state: 0 -> 2 (b0)
state: 2 -> 3 (0)
state: 3 -> 5 (10)
add 0
aid 1
cnt

connected with Teigetje, channel 1
dhcp client start...
1797527 : WIFI : Connected! AP: Teigetje (18:A6:F7:41:D3:CB) Ch: 1 Duration: 165 ms
1797528 : WIFI  : Arduino wifi status: WL_DISCONNECTED ESPeasy internal wifi status: ESPEASY_WIFI_CONNECTED
ip:192.168.0.108,mask:255.255.255.0,gw:192.168.0.1
1797606 : WIFI : DHCP IP: 192.168.0.108 (LightTV-0) GW: 192.168.0.1 SN: 255.255.255.0   duration: 79 ms
1797607 : EVENT: WiFi#Connected
1797620 : EVENT: WiFi#Connected Processing time:13 milliSeconds
1797622 : WIFI  : Arduino wifi status: WL_CONNECTED ESPeasy internal wifi status: ESPEASY_WIFI_SERVICES_INITIALIZED
1801913 : WD   : Uptime 30 ConnectFailures 0 FreeMem 17344
1802802 : LoopStats: shortestLoop: 120 longestLoop: 894487 avgLoopDuration: 177.93 loopCounterMax: 250000 loopCounterLast: 164422 countFindPluginId: 0
1802803 : Scheduler stats: (called/tasks/max_length/idle%) 164421/2024/6/91.50
pm open,type:2 0
1831913 : WD   : Uptime 31 ConnectFailures 0 FreeMem 16840
1832802 : LoopStats: shortestLoop: 120 longestLoop: 894487 avgLoopDuration: 146.51 loopCounterMax: 250000 loopCounterLast: 198581 countFindPluginId: 0
1832803 : Scheduler stats: (called/tasks/max_length/idle%) 198581/2132/6/92.30
bcn_timout,að_probe_send_start
ap_probe_send over, rest wifi status to disassoc
state: 5 -> 0 (1)
rm 0
pm close 7
1859235 : EVENT: WiFi#Disconnected
1859247 : EVENT: WiFi#Disconnected Processing time:12 milliSeconds
1859249 : WIFI : Disconnected! Reason: '(200) Beacon timeout' Connected for 1 m 1 s
1859250 : WIFI  : Arduino wifi status: WL_IDLE_STATUS ESPeasy internal wifi status: ESPEASY_WIFI_DISCONNECTED
1859360 : WIFI : Connecting Teigetje attempt #0
1859362 : WIFI  : Arduino wifi status: WL_DISCONNECTED ESPeasy internal wifi status: ESPEASY_WIFI_DISCONNECTED
scandone
state: 0 -> 2 (b0)
state: 2 -> 3 (0)
state: 3 -> 5 (10)
add 0
aid 1
cnt

connected with Teigetje, channel 1
dhcp client start...
1859537 : WIFI : Connected! AP: Teigetje (18:A6:F7:41:D3:CB) Ch: 1 Duration: 176 ms
1859538 : WIFI  : Arduino wifi status: WL_DISCONNECTED ESPeasy internal wifi status: ESPEASY_WIFI_CONNECTED
ip:192.168.0.108,mask:255.255.255.0,gw:192.168.0.1
1859634 : WIFI : DHCP IP: 192.168.0.108 (LightTV-0) GW: 192.168.0.1 SN: 255.255.255.0   duration: 97 ms
1859636 : EVENT: WiFi#Connected
1859649 : EVENT: WiFi#Connected Processing time:13 milliSeconds
1859650 : WIFI  : Arduino wifi status: WL_CONNECTED ESPeasy internal wifi status: ESPEASY_WIFI_SERVICES_INITIALIZED
1861913 : WD   : Uptime 31 ConnectFailures 0 FreeMem 17344
1862802 : LoopStats: shortestLoop: 120 longestLoop: 894487 avgLoopDuration: 148.57 loopCounterMax: 250000 loopCounterLast: 195894 countFindPluginId: 0
1862803 : Scheduler stats: (called/tasks/max_length/idle%) 195894/2129/6/92.20
pm open,type:2 0
1891913 : WD   : Uptime 32 ConnectFailures 0 FreeMem 16840
1892802 : LoopStats: shortestLoop: 120 longestLoop: 894487 avgLoopDuration: 146.51 loopCounterMax: 250000 loopCounterLast: 198580 countFindPluginId: 0
1892803 : Scheduler stats: (called/tasks/max_length/idle%) 198580/2132/6/92.40
bcn_timout,ap_probe_send_start
ap_probe_send over, rest wifi status to disassoc
state: 5 -> 0 (1)
rm 0
pm close 7
1896815 : EVENT: WiFi#Disconnected
1896827 : EVENT: WiFi#Disconnected Processing time:12 milliSeconds
1896829 : WIFI : Disconnected! Reason: '(200) Beacon timeout' Connected for 37 s
1896830 : WIFI  : Arduino wifi status: WL_IDLE_STATUS ESPeasy internal wifi status: ESPEASY_WIFI_DISCONNECTED
1897361 : WIFI : Connecting Teigetje attempt #0
1897363 : WIFI  : Arduino wifi status: WL_DISCONNECTED ESPeasy internal wifi status: ESPEASY_WIFI_DISCONNECTED
scandone
1897484 : EVENT: WiFi#Disconnected
1897497 : EVENT: WiFi#Disconnected Processing time:13 milliSeconds
1897498 : WIFI : Disconnected! Reason: '(201) No AP found' Connected for 122 ms
1897499 : WIFI  : Arduino wifi status: WL_DISCONNECTED ESPeasy internal wifi status: ESPEASY_WIFI_DISCONNECTED
1899360 : WIFI : Connecting Teigetje attempt #1
1899363 : WIFI  : Arduino wifi status: WL_DISCONNECTED ESPeasy internal wifi status: ESPEASY_WIFI_DISCONNECTED
scandone
1902228 : EVENT: WiFi#Disconnected
1902240 : EVENT: WiFi#Disconnected Processing time:12 milliSeconds
1902242 : WIFI : Disconnected! Reason: '(201) No AP found' Connected for 2866 ms
1902242 : WIFI  : Arduino wifi status: WL_DISCONNECTED ESPeasy internal wifi status: ESPEASY_WIFI_DISCONNECTED
1902360 : WIFI : Connecting Teigetje attempt #2
1902362 : WIFI  : Arduino wifi status: WL_DISCONNECTED ESPeasy internal wifi status: ESPEASY_WIFI_DISCONNECTED
scandone
state: 0 -> 2 (b0)
state: 2 -> 3 (0)
state: 3 -> 5 (10)
add 0
aid 1
cnt

connected with Teigetje, channel 1
dhcp client start...
1907166 : WIFI : Connected! AP: Teigetje (18:A6:F7:41:D3:CB) Ch: 1 Duration: 4805 ms
1907168 : WIFI  : Arduino wifi status: WL_DISCONNECTED ESPeasy internal wifi status: ESPEASY_WIFI_CONNECTED
ip:192.168.0.108,mask:255.255.255.0,gw:192.168.0.1
1907282 : WIFI : DHCP IP: 192.168.0.108 (LightTV-0) GW: 192.168.0.1 SN: 255.255.255.0   duration: 115 ms
1907284 : EVENT: WiFi#Connected
1907296 : EVENT: WiFi#Connected Processing time:12 milliSeconds
1907297 : WIFI  : Arduino wifi status: WL_CONNECTED ESPeasy internal wifi status: ESPEASY_WIFI_SERVICES_INITIALIZED
bcn_timout,ap_probe_send_start
ap_probe_send over, rest wifi status to disassoc
state: 5 -> 0 (1)
rm 0
1915656 : EVENT: WiFi#Disconnected
1915668 : EVENT: WiFi#Disconnected Processing time:12 milliSeconds
1915670 : WIFI : Disconnected! Reason: '(200) Beacon timeout' Connected for 8488 ms
1915671 : WIFI  : Arduino wifi status: WL_IDLE_STATUS ESPeasy internal wifi status: ESPEASY_WIFI_DISCONNECTED
1916361 : WIFI : Connecting Teigetje attempt #0
1916363 : WIFI  : Arduino wifi status: WL_DISCONNECTED ESPeasy internal wifi status: ESPEASY_WIFI_DISCONNECTED
scandone
state: 0 -> 2 (b0)
state: 2 Y> 3 (0)
state: 3 -> 5 (10)
add 0
aid 1
cnt

connected with Teigetje, channel 1
dhcp client start...
1917424 : WIFI : Connected! AP: Teigetje (18:A6:F7:41:D3:CB) Ch: 1 Duration: 1062 ms
1917425 : WIFI  : Arduino wifi status: WL_DISCONNECTED ESPeasy internal wifi status: ESPEASY_WIFI_CONNECTED
ip:192.168.0.108,mask:255.255.255.0,gw:192.168.0.1
1917549 : WIFI : DHCP IP: 192.168.0.108 (LightTV-0) GW: 192.168.0.1 SN: 255.255.255.0   duration: 125 ms
1917551 : EVENT: WiFi#Connected
1917563 : EVENT: WiFi#Connected Processing time:12 milliSeconds
1917564 : WIFI  : Arduino wifi status: WL_CONNECTED ESPeasy internal wifi status: ESPEASY_WIFI_SERVICES_INITIALIZED
1921913 : WD   : Uptime 32 ConnectFailures 0 FreeMem 17344
1922802 : LoopStats: shortestLoop: 120 longestLoop: 894487 avgLoopDuration: 235.81 loopCounterMax: 250000 loopCounterLast: 124851 countFindPluginId: 0
1922803 : Scheduler stats: (called/tasks/max_length/idle%) 124849/1905/6/90.40
bcn_timßutLap¿probe_seÎd_start
ap_probe_send over, rest wifi status to disassoc
state: 5 -> 0 (1)
rm 0
1925999 : EVENT: WiFi#Disconnected
1926011 : EVENT: WiFi#Disconnected Processing time:12 milliSeconds
1926012 : WIFI : Disconnected! Reason: '(200) Beacon timeout' Connected for 8574 ms
1926013 : WIFI  : Arduino wifi status: WL_IDLE_STATUS ESPeasy internal wifi status: ESPEASY_WIFI_DISCONNECTED
1926361 : WIFI : Connecting Teigetje attempt #0
1926363 : WIFI  : Arduino wifi status: WL_DISCONNECTED ESPeasy internal wifi status: ESPEASY_WIFI_DISCONNECTED
scandone
1926484 : EVENT: WiFi#Disconnected
1926496 : EVENT: WiFi#Disconnected Processing time:12 milliSeconds
1926498 : WIFI : Disconnected! Reason: '(201) No AP found' Connected for 122 ms
1926498 : WIFI  : Arduino wifi status: WL_DISCONNECTED ESPeasy internal wifi status: ESPEASY_WIFI_DISCONNECTED
1928360 : WIFI : Connecting Teigetje attempt #1
1928363 : WIFI  : Arduino wifi status: WL_DISCONNECTED ESPeasy internal wifi status: ESPEASY_WIFI_DISCONNECTED
scandone
state: 0 -> 2 (b0)
state: r -> 3 (0)
state: 3 -> 5 (10)
add 0
aid 1
cnt

connected with Teigetje, channel 1
dhcp client start...
1932147 : WIFI : Connected! AP: Teigetje (18:A6:F7:41:D3:CB) Ch: 1 Duration: 3786 ms
1932149 : WIFI  : Arduino wifi status: WL_DISCONNECTED ESPeasy internal wifi status: ESPEASY_WIFI_CONNECTED
ip:192.168.0.108,mask:255.255.255.0,gw:192.168.0.1
1932234 : WIFI : DHCP IP: 192.168.0.108 (LightTV-0) GW: 192.168.0.1 SN: 255.255.255.0   duration: 86 ms
1932236 : EVENT: WiFi#Connected
1932248 : EVENT: WiFi#Connected Processing time:13 milliSeconds
1932249 : WIFI  : Arduino wifi status: WL_CONNECTED ESPeasy internal wifi status: ESPEASY_WIFI_SERVICES_INITIALIZED
pm open,type:2 0
1951913 : WD   : Uptime 33 ConnectFailures 0 FreeMem 16528
1952802 : LoopStats: shortestLoop: 120 longestLoop: 894487 avgLoopDuration: 181.43 loopCounterMax: 250000 loopCounterLast: 161345 countFindPluginId: 0
1952803 : Scheduler stats: (called/tasks/max_length/idle%) 161344/2018/6/91.40
bcn_timoít\ap_probe_send_start

Barracuda09 commented 5 years ago

Ok, quick update. I am having better (Workable) results using this:


Firmware
--
Build:⋄ | 20103 - Mega
Libraries:⋄ | ESP82xx Core 2_4_1, NONOS SDK 2.2.1(cfd48f3), LWIP: 2.0.3 PUYA support
GIT version:⋄ | mega-20181220
Plugins:⋄ | 46 [Normal]
Build Md5: | 78822cba48ae8f90cd317cb9fb204682
Md5 check: | passed.
Build time:⋄ | Dec 20 2018 03:08:48
Binary filename:⋄ | ESP_Easy_mega-20181220_normal_core_241_ESP8266_1024.bin

Barracuda09 commented 5 years ago

It is now remarkably responsive.. to the point I doubt my self I did something wrong here with flashing the damn thing... But I tried a few times to erase (blank_1MB) and flash the ESP_Easy_mega-20181220_normal_ESP8266_1024

But after erasing (blank_1MB) and flashing ESP_Easy_mega-20181220_normal_core_241_ESP8266_1024 it works remarkably good..

So I keep my sanity and think its the firmware that is at fault here.

Oxyandy commented 5 years ago

Thanks ! @Barracuda09 >debug 3 was what I needed & save and reboot Again Dev 10 this module connects straight away and stays connected.. Tried 2 different routers.. the result

INIT : Booting version: mega-20181220 (ESP82xx Core 2_4_1, NONOS SDK 2.2.1(cfd48f3), LWIP: 2.0.3 PUYA support)
107 : INIT : Warm boot #2 - Restart Reason: Software/System restart
109 : FS   : Mounting...
115 : FS   : Mount successful, used 75802 bytes of 113201
461 : CRC  : program checksum       ...OK
477 : CRC  : SecuritySettings CRC   ...OK 
496 : INIT : Free RAM:19640
498 : INIT : I2C
498 : INIT : SPI not enabled
511 : INFO : Plugins: 46 [Normal] (ESP82xx Core 2_4_1, NONOS SDK 2.2.1(cfd48f3), LWIP: 2.0.3 PUYA support)
514 : WIFI : Set WiFi to STA
546 : WIFI : Connecting MAD_MOB attempt #0
08:44:38: 1882 : WD   : Uptime 0 ConnectFailures 0 FreeMem 17800
2772 : LoopStats: shortestLoop: 1102 longestLoop: 13473 avgLoopDuration: 1171.88 loopCounterMax: 27223 loopCounterLast: 1883 countFindPluginId: 0
2773 : Scheduler stats: (called/tasks/max_length/idle%) 1882/138/6/73.60
08:44:39: 3415 : WIFI : Disconnected! Reason: '(201) No AP found' Connected for 2867 ms
4329 : WIFI : Connecting MAD_MOB attempt #1
08:44:43: 7198 : WIFI : Disconnected! Reason: '(201) No AP found' Connected for 2868 ms
7329 : WIFI : Connecting MAD_MOB attempt #2
08:44:46: 10197 : WIFI : Disconnected! Reason: '(201) No AP found' Connected for 2866 ms
10329 : WIFI : Connecting MAD_MOB attempt #3
08:44:49: 13196 : WIFI : Disconnected! Reason: '(201) No AP found' Connected for 2866 ms
13329 : WIFI : Connecting MAD_MOB attempt #4
08:44:52: 16196 : WIFI : Disconnected! Reason: '(201) No AP found' Connected for 2866 ms
16329 : WIFI : Connecting MAD_MOB attempt #5
08:44:55: 19196 : WIFI : Disconnected! Reason: '(201) No AP found' Connected for 2865 ms
19330 : WIFI : Set WiFi to AP+STA
20251 : WIFI : AP Mode ssid will be ESP_Easy_0 with address 192.168.4.1
20252 : WIFI : Connecting MAD_MOB attempt #6
08:44:59: 23120 : WIFI : Disconnected! Reason: '(201) No AP found' Connected for 2866 ms
23328 : WIFI : Connecting MAD_MOB attempt #7
08:45:02: 26196 : WIFI : Disconnected! Reason: '(201) No AP found' Connected for 2866 ms
26329 : WIFI : Connecting MAD_MOB attempt #8
08:45:05: 29197 : WIFI : Disconnected! Reason: '(201) No AP found' Connected for 2867 ms
29329 : WIFI : Connecting MAD_MOB attempt #9
08:45:08: 31882 : WD   : Uptime 1 ConnectFailures 0 FreeMem 15048
32198 : WIFI : Disconnected! Reason: '(201) No AP found' Connected for 2869 ms
32772 : LoopStats: shortestLoop: 1102 longestLoop: 929493 avgLoopDuration: 1202.42 loopCounterMax: 27223 loopCounterLast: 24803 countFindPluginId: 0
32773 : Scheduler stats: (called/tasks/max_length/idle%) 24802/1781/6/87.60
08:45:09: 33329 : WIFI : Connecting MAD_MOB attempt #10

Oxyandy commented 5 years ago

Went over some of my own previous posts, found one where I said ESP_Easy_mega-20180502_normal_ESP8266_1024.bin works great, flashed that, sure enough it does.. So I have a starting point, now with all the time I put in previously.. and the quirks and things I learnt which related directly to my own issues with using ESPeasy as a firmware to do my task (before my wife exploded at me for the amount of time I was consuming & other things not getting done) This umm 'explosion' resulted in me staying 'safe' with Dev 10, I knew it's limitations. Dev 10 has been basically doing what I needed all this time, but not ideal. I'll try set 20180502 up in a real world use, see how it goes.. The biggest issue I had/have with Dev 10, was when WiFi / MQTT dropped & there was a change in my float switch, was the lag... for me this meant the pump would stay on way too long. This was something that we discussed & was hoping the latest releases would offer me more safety in this regard 😁 oh well, connectivity issues prevent me from using the latest & umm 'greatest' ? 🙄

TD-er commented 5 years ago

There are still reports about MQTT interaction still consuming too much time and thus missing events.

And about the recent reports of WiFi issues, I really have no clue to what may cause this. About the times which look suspiciously similar. The connection cyclus is the same for all:

Perform RF calibration
Perform a SSID scan on all channels (2 about 200 msec per channel, 12 or 13 channels)

This takes in total about 28xx msec. It looks like this RF calibration is not stable on modern nodes (significant more reports with recent Sonoff basic r2 and Sonoff S26) but also there seems to be some changes in newer core libraries. This may also result in missing the AP beacon packets which results in not being able to connect to them. Tasmota does try to stop all activities on the node during the connection period. This may be indication for fluctuating power supply, or maybe missing time frames for processing wifi activity.

The older firmware did just wait till there was a WiFi connection. So it could take > 30 seconds for a node to get past the "setup()" function and start processing sensor data.

Oxyandy commented 5 years ago

Ok well ESP_Easy_mega-20180502_normal_ESP8266_1024.bin is blazing fast, super responsive etc If I take that source.

Self Compile 'as is' = "control" versus release
Change dependant libraries etc in compile settings Would this tell me/you anything ?

Barracuda09 commented 5 years ago

Strange that in my case the ESP_Easy_mega-20181220_normal_core_241_ESP8266_1024 works quite well and for @Oxyandy it does not?

@Oxyandy What is the distance between the router and node in your use case?

Oxyandy commented 5 years ago

Same room, Wifi RSSI: | -37 dB RSSI reported from stable wifi build version as I reported above.. Will try full erase (flash blank 1M) then ESP_Easy_mega-20181220_normal_core_241_ESP8266_1024.bin as you have, I simply used -erase cmd from esptool.py

Barracuda09 commented 5 years ago

I use the ESP.Easy.Flasher at moment. My RSSI is now around -65 dB with the new firmware.

TD-er commented 5 years ago

@Oxyandy We have seen a lot (!!!) of issues with people running self-compiled versions, so if you do self-compile, please keep the following in mind:

When compiling with PlatformIO, do a clean build first and then a full build when in doubt.
Try to compile in Linux, if you're comfortable with that. (build scripts are included in the tools dir)
When using "Arduino ide", make sure to use the libraries as included in the source tree here on Github.

Also to improve on stability, you may want to have a look at the (new) settings in the controllers and have a look at the (new) documentation

For example the timeout value may be a bit too high for most (1000 msec). If you're experiencing WD reset crashes, try to set it to lower values like 100 msec. To get an idea of the timings, have a look at the new timing stats page (Tools tab) and remember that each refresh of that page will reset the timing stats. That page appears to be very useful in finding parts of the code taking too much time.

Also note that the GPIO handling has changed a bit after 20181204, so you may want to test versions from end November too.

Barracuda09 commented 5 years ago

Hi, @TD-er

Does it perform a new RF calibration along the way? or only at boot or reconnects?

I have now 2 Sonoff Basic (2017-5-5) with ESP_Easy_mega-20181220_normal_core_241_ESP8266_1024 with one node around -72 dB (which was at first -65 dB) and the other around -50 dB. Both respond very well (at least does not timeout in browser).

So i am not sure why @Oxyandy node is not working, so that makes me conclude maybe there is some timing issue? and that is more apparent in the ESP_Easy_mega-20181220_normal_ESP8266_1024 firmware for both of us.

I am not familiar with the in and out of this project so sorry if I say something stupid

TD-er commented 5 years ago

The RF calibration is performed at least every time it starts the wifi and I assume it is also performing some calibration when making a connection. There is a mode command which allows to disable this calibration (setting a bit in a register), but that's something we have to test more before using it. This RF calibration is affected by the supplied voltage, so if you're running it on a battery powered device, you may need to perform this calibration every now and then. But also when running on a node with weak power supply, it may show undefined behavior, since the RF calibration does take a lot more power compared to normal use.

Barracuda09 commented 5 years ago

This RF calibration is affected by the supplied voltage, so if you're running it on a battery powered device

This should be of no real issue for the Sonoff Basic (2017-5-5) because (I hope) they have an adequate power supply. And it does normally have no external devices connected to it (at least I don't). And during boot the relay is not active. But if it is doing a calibration during an activated relay it could influence it maybe.

itProfi commented 5 years ago

The problem is in ESPEasy. Tasmota in the same places work absolutly stability!- MQT: tele/sonoff/STATE = {"Time":"2019-01-05T14:31:19","Uptime":"0T00:00:14","Vcc":3.414,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"POWER":"ON","Wifi":{"AP":1,"SSId":"MXXXXXX","BSSId":"XXXXXXF:58:XX:D8","Channel":7,"RSSI":82}}

itProfi commented 5 years ago

tele/sonoff/STATE = {"Time":"2019-01-05T14:36:30","Uptime":"0T00:00:14","Vcc":3.494,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"POWER":"ON","Wifi":{"AP":1,"SSId":"MYYYY","BSSId":"YHYHYHYY","Channel":7,"RSSI":88}}

Barracuda09 commented 5 years ago

@itProfi which core do they use... I use now core 241 which seems to do OK

itProfi commented 5 years ago

@Barracuda09 absolutly stable!! 05-01-2019 165605

Barracuda09 commented 5 years ago

That is interesting. So it can work with core 2.4.2, I could not make it work with ESPEasy with core 2.4.2. strangely enough.

itProfi commented 5 years ago

I could not make it work with ESPEasy with core 2.4.1 strangely enough in the same place, when Tasmota work wonderful! I really leave ESPEasy after about 200-250 hours (only not result experiments!)..

Barracuda09 commented 5 years ago

Yes that is strange as well, you have problems with 2.4.1 as of @Oxyandy could not make it work as well.

Here it works some what Ok and it is usable. So there is probably some timing and/or memory management issue?

Oxyandy commented 5 years ago

with 2.4.1 as of @Oxyandy could not make it work as well. With xmas, family & work, I admit I have done very little, now time for a mini holiday to keep the Mrs sane, then after that I will attempt again. This time with multiple 'from the box', brand new Sonoff Basics.. Still have ESP_Easy_mega-20180502_normal_ESP8266_1024.bin running on my bench as a test, yeah is old, but is the last release I could confirm as working, so have been stability testing. I am pleased you have exact same boards as me "Sonoff Basic (2017-5-5)" @Barracuda09 If you got it to work, so should I.. not even tried flashing a BLANK 1M before flashing yet.. Coming - about a week

tonhuisman commented 1 year ago

This seems to be solved, so can be closed.

letscontrolit / ESPEasy