Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

wifi_set_opmode_current return true but failing? #4372

Closed
tablatronix opened this issue Feb 16, 2018 · 34 comments · Fixed by #6721
Closed

wifi_set_opmode_current return true but failing? #4372

tablatronix opened this issue Feb 16, 2018 · 34 comments · Fixed by #6721
Assignees
Labels
waiting for feedback Waiting on additional info. If it's not received, the issue may be closed.

Comments

@tablatronix
Copy link
Contributor

tablatronix commented Feb 16, 2018

Basic Infos

Hardware

Hardware: ESP-12?
Core Version: staging

Description

Let me know if this sounds familiar or like a known issue or something
I am having an issue with mode, I am setting mode and it returns true, but the mode does not actually change

I will try to produce a sketch, it is very odd, does anyone know how I can debug this further, from my understanding this sounds like an SDK bug (or memory bounds issue?), but maybe I am missing something or we are missing some crucial check before wifi_set_opmode_current().

I am (essentially) doing this

persistent(false);
ret = WiFi.mode(WIFI_AP_STA);
ret = WiFi.mode(WIFI_STA);
...
ret = WiFi.mode(WIFI_AP_STA);
ret TRUE
getMode() is WIFI_STA !!!!!!

which is essentially

wifi_set_opmode_current(3) == true
wifi_set_opmode_current(1) == true
wifi_set_opmode_current(3) == true
wifi_get_opmode = 1 <--- aahhhhhhhhhhhhhhh
// wifi_set_opmode_current() != wifi_get_opmode(), but returns true

lots of boom here (enableSTA, enableAP all fail catastrophically
since there is no sanity checks here, since they return true must be true,
so set config struct blows up )

Could this be a memory issue, where is this memory ?

Settings in IDE

Module: ?Generic ESP8266 Module?
Flash Size: ?4MB/1MB?
CPU Frequency: ?80Mhz?
Flash Mode: ?qio?
Flash Frequency: ?40Mhz?
Upload Using: ?OTA / SERIAL?
Reset Method: ?ck / nodemcu?

@tablatronix
Copy link
Contributor Author

tablatronix commented Feb 16, 2018

hmm so there is a delay setting mode, and I have no idea where it comes from, so its some kind of race condition, and I have no idea what causes it yet. Is there a doc that says wtf the debugging means ?
wtf is
add if1
pm close 7
wifi evt: 8 <-- this is the only difference I see in between the two

[enableAP] enabling
3
[mode] wifi_get_opmode BEFORE
1
[mode] wifi_set_opmode_current to
3
mode wifi evt: 8
: sta(2c:3a:e8:39:09:95) + softAP(2e:3a:e8:39:09:95)
add if1
pm close 7
dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
bcn 100
[mode] wifi_get_opmode AFTER
3

[enableAP] enabling
3
[mode] wifi_get_opmode BEFORE
1
[mode] wifi_set_opmode_current to
3
[mode] wifi_get_opmode AFTER
1
[mode] ERROR MODE SET FAILED!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
mode : sta(2c:3a:e8:39:09:95) + softAP(2e:3a:e8:39:09:95)
add if1
pm close 7
dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
bcn 100
wifi evt: 8

@tablatronix
Copy link
Contributor Author

tablatronix commented Feb 16, 2018

Ok I can repoduce it now, and it only happens the first time after loop() then works again..wierd but not in test sketch so still checking user code.

@tablatronix
Copy link
Contributor Author

tablatronix commented Feb 16, 2018

Reproduction

#include <ESP8266WiFi.h>
extern "C" {
  #include "user_interface.h"
}

const char* const modes[] PROGMEM = { "NULL", "STA", "AP", "STA+AP" };

void setup() {
  Serial.begin(115200);
  delay(1000);
  Serial.setDebugOutput(true);  
  Serial.println(F("\n Starting"));
  // Serial.println(modes[WiFi.getMode()]);
  // WiFi.printDiag(Serial);
  // WiFi.mode(WIFI_STA);
  // WiFi.setAutoConnect(true);
  // WiFi.setAutoReconnect(true);
}

void debugSoftAPConfig(){
    softap_config config;
    wifi_softap_get_config(&config);

    Serial.println(F("SoftAP Configuration"));
    Serial.println(F("-----------------------------"));
    Serial.print(F("ssid:            "));Serial.println((char *) config.ssid);
    Serial.print(F("password:        "));Serial.println((char *) config.password);
    Serial.print(F("ssid_len:        "));Serial.println(config.ssid_len);
    Serial.print(F("channel:         "));Serial.println(config.channel);
    Serial.print(F("authmode:        "));Serial.println(config.authmode);
    Serial.print(F("ssid_hidden:     "));Serial.println(config.ssid_hidden);
    Serial.print(F("max_connection:  "));Serial.println(config.max_connection);
    Serial.print(F("beacon_interval: "));Serial.println((String)config.beacon_interval + "(ms)");
    Serial.println(F("-----------------------------"));
}

void startap(){
  bool ret;
  ret = WiFi.softAP("esptestap");
  if(!ret)Serial.println(F("softAP failed BOOOM"));
  debugSoftAPConfig();

  ret = WiFi.softAPdisconnect(true);
  if(!ret)Serial.println(F("softAPdisconnect failed"));

  ret = WiFi.mode(WIFI_STA);
  if(!ret)Serial.println(F("set mode failed"));	
  delay(1000);
}

void loop(){
	startap();
	startap();
}

@tablatronix
Copy link
Contributor Author

tablatronix commented Feb 17, 2018

maybe someone can make sense of this, it seems that the second run takes much longer and is asynchronous, I also see more dhcp start than there should be , no idea what the other debugging means.

I am timing the RUN call to set opmode, and the SET of when getmode actually changed, those are the times in micros, there is a yield in there though

Logging

 Starting
RUN 1 -------------------------
[enableAP] enabling
3
[mode] wifi_get_opmode BEFORE
1
mode : sta(2c:3a:e8:39:09:95) + softAP(2e:3a:e8:39:09:95)
add if1
dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
bcn 100
[WIFI_SET_OPMODE_CURRENT] ran in 10141
[WIFI_SET_OPMODE_CURRENT] set in 10151
[AP] mode non persistent
3
bcn 0
dewifi evt: 8
l if1
pm open,type:2 0
add if1
pm close 7
dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
bcn 100
bcn 0
del if1
pm open,type:2 0
add if1
pm close 7
dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
bcn 100
[enableAP] disabling
[mode] wifi_get_opmode BEFORE
3
bcn 0
del if1
pm open,type:2 0
mode : sta(2c:3a:e8:39:09:95)
[WIFI_SET_OPMODE_CURRENT] ran in 5596
[WIFI_SET_OPMODE_CURRENT] set in 5606
wifi evt: 8
RUN 2 -------------------------
[enableAP] enabling
3
[mode] wifi_get_opmode BEFORE
1
[mode] ERROR MODE SET FAILED!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
mode : sta(2c:3a:e8:39:09:95) + softAP(2e:3a:e8:39:09:95)
add if1
pm close 7
dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
bcn 100
wifi evt: 8
[WIFI_SET_OPMODE_CURRENT] ran in 73
[WIFI_SET_OPMODE_CURRENT] set in 17129
[AP] mode non persistent
3
bcn 0
del if1
pm open,type:2 0
add if1
pm close 7
dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
bcn 100
bcn 0
del if1
pm open,type:2 0
add if1
pm close 7
dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
bcn 100
[enableAP] disabling
[mode] wifi_get_opmode BEFORE
3
bcn 0
del if1
pm open,type:2 0
mode : sta(2c:3a:e8:39:09:95)
[WIFI_SET_OPMODE_CURRENT] ran in 5566
[WIFI_SET_OPMODE_CURRENT] set in 5577
wifi evt: 8
RUN 1 -------------------------
[enableAP] enabling
3
[mode] wifi_get_opmode BEFORE
1
[mode] ERROR MODE SET FAILED!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
mode : sta(2c:3a:e8:39:09:95) + softAP(2e:3a:e8:39:09:95)
add if1
pm close 7
dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
bcn 100
wifi evt: 8
[WIFI_SET_OPMODE_CURRENT] ran in 80
[WIFI_SET_OPMODE_CURRENT] set in 17011
[AP] mode non persistent
3
bcn 0
del if1
pm open,type:2 0
add if1
pm close 7
dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
bcn 100
bcn 0
del if1
pm open,type:2 0
add if1
pm close 7
dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
bcn 100
[enableAP] disabling
[mode] wifi_get_opmode BEFORE
3
bcn 0
del if1
pm open,type:2 0
mode : sta(2c:3a:e8:39:09:95)
[WIFI_SET_OPMODE_CURRENT] ran in 5635
[WIFI_SET_OPMODE_CURRENT] set in 5646
wifi evt: 8

I should have messed with GDB instead and actually tried to debug this properly, oh well.

solution for now is to delay after, or while loop it shrug

dirty workaround

/**
 * set new mode
 * @param m WiFiMode_t
 */
bool ESP8266WiFiGenericClass::mode(WiFiMode_t m) {
    if(wifi_get_opmode() == (uint8) m) {
        return true;
    }

    bool ret = false;

    DEBUG_WIFI_GENERIC("[mode] wifi_get_opmode BEFORE\n");    
    DEBUG_WIFI(String(wifi_get_opmode()).c_str());
    DEBUG_WIFI_GENERIC("\n");
 
    bool testing = true;
    uint32_t mark;
    uint32_t end;
    uint32_t start = micros();
    ETS_UART_INTR_DISABLE();
    if(_persistent) {
        ret = wifi_set_opmode(m);
    } else {
        // DEBUG_WIFI_GENERIC("[mode] wifi_set_opmode_current to\n");
        // DEBUG_WIFI_GENERIC(String(m).c_str());
        // DEBUG_WIFI_GENERIC("\n");
        ret = wifi_set_opmode_current(m);
    }
    ETS_UART_INTR_ENABLE();
     mark = micros();

    if(wifi_get_opmode() != (uint8) m) {
        DEBUG_WIFI_GENERIC("[mode] ERROR MODE SET FAILED!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!\n");    
    }

    if(testing){
    while(wifi_get_opmode() != (uint8) m){
        yield();
    }
    end = micros();

    DEBUG_WIFI_GENERIC("[WIFI_SET_OPMODE_CURRENT] ran in ");
    DEBUG_WIFI_GENERIC(String(mark-start).c_str());
    DEBUG_WIFI_GENERIC("\n");
    DEBUG_WIFI_GENERIC("[WIFI_SET_OPMODE_CURRENT] set in ");
    DEBUG_WIFI_GENERIC(String(end-start).c_str());
    DEBUG_WIFI_GENERIC("\n");

    // DEBUG_WIFI_GENERIC("[mode] wifi_get_opmode AFTER\n");    
    // DEBUG_WIFI(String(wifi_get_opmode()).c_str());
    // DEBUG_WIFI_GENERIC("\n");

    }
    return ret;
}

@tablatronix
Copy link
Contributor Author

@devyte if you could assign someone to take a glance and let me know about this, thanks.

@d-a-v d-a-v self-assigned this Feb 18, 2018
@d-a-v
Copy link
Collaborator

d-a-v commented Feb 21, 2018

Could you give a summary of your findings ?

@tablatronix
Copy link
Contributor Author

tablatronix commented Feb 22, 2018

SUMMARY

Race condition, wifi_set_opmode is asynchronous, returns true but get_opmode does not show change for sometime (~1s) after mode() returns, which in turn breaks things that check return value as success and does stuff like set config before its possible.

@tablatronix
Copy link
Contributor Author

tablatronix commented Feb 22, 2018

I am not entirely sure why it takes longer SOMETIMES but it might be an sdk thing. Issue contains logs and reproduction info. Someone might be able to glean more info from the hardware output above, i have no idea how to decipher that to see a pattern.

Sometimes defined as the difference between these 2 delays seems to be the factor ( includes a yield() )

good
[WIFI_SET_OPMODE_CURRENT] set in 10151

bad
[WIFI_SET_OPMODE_CURRENT] set in 17129

actual
One direct effect at least in my reproduction sketch and real world, if turning AP on and off more than once results in softap failed to start, and corrupt softap config, because enablesta, did not yet actually enable

bool ESP8266WiFiAPClass::softAP(const char* ssid, const char* passphrase, int channel, int ssid_hidden, int max_connection) {

    if(!WiFi.enableAP(true)) {
        // enable AP failed
        DEBUG_WIFI("[AP] enableAP failed!\n");
        return false;
    }

    // ruh roh NOT SO FAST!, mode still not AP here!

@d-a-v
Copy link
Collaborator

d-a-v commented Feb 22, 2018

So the workaround to wait for opmode to be set to the real value is always working ?

I'm not saying that the workaround should be used or adopted, but if it works, that information would help debugging (here or for espressif's SDK).

@tablatronix
Copy link
Contributor Author

tablatronix commented Feb 22, 2018

It appears to be, yes
I added in mode() as above FOR TESTING of course

ESP8266WiFiGenericClass::mode()

while(wifi_get_opmode() != (uint8) m){
        yield();
    }

@tablatronix
Copy link
Contributor Author

tablatronix commented Feb 22, 2018

I am not seeing this anymore, it just takes 30-50micros now, it was 6,000+ before
although the entire operation now takes 50ms, which I guess is fine.

[WIFI_SET_OPMODE_CURRENT] ran in 55672
[WIFI_SET_OPMODE_CURRENT] set in 55702

I will close after real testing

@tablatronix
Copy link
Contributor Author

yup
still an issue, just not as reproducible now, I will try to make another repro sketch to test better.

@d-a-v
Copy link
Collaborator

d-a-v commented Mar 8, 2018

Please share when your reproducing sketch is ready

@d-a-v d-a-v added the waiting for feedback Waiting on additional info. If it's not received, the issue may be closed. label Mar 8, 2018
@tablatronix
Copy link
Contributor Author

I will , forgot all about it, needed a break from this issue..lol

@tablatronix
Copy link
Contributor Author

tablatronix commented Mar 8, 2018

#include "ESP8266WiFi.h"
// #include "user_interface.h"

extern "C" {
  #include "user_interface.h"
}

const char SSID[] = "SSID";
const char PSK[] = "";

unsigned long sinceSerialPrint = 0;
unsigned long lastChange = 0;

void setup() {
  Serial.begin(115200);
  delay(3000);
  Serial.setDebugOutput(true);
  WiFi.printDiag(Serial);

  // WiFi.persistent(true);
  // WiFi.mode(WIFI_STA);

  // // ESP.eraseConfig();  
  // // WiFi.begin(SSID,PSK);
  // int intvl = 0;
  // if(WiFi.SSID() != ""){
  //   while(WiFi.status() != WL_CONNECTED && intvl<10)
  //   {
  //     delay(500);
  //     Serial.print(".");
  //     intvl++;
  //   }
  //   Serial.println(WiFi.localIP());
  // }
  // lastChange = millis();
}


void debugSoftAPConfig(){
    softap_config config;
    wifi_softap_get_config(&config);

    Serial.println(F("SoftAP Configuration"));
    Serial.println(F("-----------------------------"));
    Serial.print(F("ssid:            "));Serial.println((char *) config.ssid);
    Serial.print(F("password:        "));Serial.println((char *) config.password);
    Serial.print(F("ssid_len:        "));Serial.println(config.ssid_len);
    Serial.print(F("channel:         "));Serial.println(config.channel);
    Serial.print(F("authmode:        "));Serial.println(config.authmode);
    Serial.print(F("ssid_hidden:     "));Serial.println(config.ssid_hidden);
    Serial.print(F("max_connection:  "));Serial.println(config.max_connection);
    Serial.print(F("beacon_interval: "));Serial.println((String)config.beacon_interval + "(ms)");
    Serial.println(F("-----------------------------"));
}

void doBreakAP(){
      // run 1
      Serial.println(!WiFi.softAP("esptestap") ? "SET AP FAILED !!!!!!!!!!!!" : "SET AP SUCCESS");
      debugSoftAPConfig();
      delay(500);
      Serial.println(WiFi.softAPdisconnect(true));
      delay(500);
      WiFi.mode(WIFI_STA);
      
      // run 2
      delay(500);
      Serial.println(!WiFi.softAP("esptestap") ? "SET AP FAILED !!!!!!!!!!!!" : "SET AP SUCCESS");
      debugSoftAPConfig();
      delay(500);
      Serial.println(WiFi.softAPdisconnect(true));
      delay(500);
      WiFi.mode(WIFI_STA);
}

void loop() {
  //if (millis() - sinceSerialPrint > 1000) {
  //  Serial.print(F("WiFi Status: "));
  //  Serial.print(WiFi.status());
  //  Serial.print(F(" - last change: "));
  //  Serial.println((long)(lastChange - millis()));
  //  sinceSerialPrint = millis();
 // }

  #define DO(x...) Serial.println(F( #x )); x; lastChange=millis(); break
  
  if (Serial.available())
  {
    switch (Serial.read())
    {
      case 'd': DO(WiFi.disconnect());
      case 'b': DO(WiFi.begin());
      case 'B': DO(WiFi.begin(SSID, PSK));
      case 'r': DO(WiFi.reconnect());
      case 'c': DO(wifi_station_connect());
      case 'a': DO(WiFi.setAutoReconnect(false));
      case 'A': DO(WiFi.setAutoReconnect(true));
      case 'n': DO(WiFi.setSleepMode(WIFI_NONE_SLEEP));
      case 'l': DO(WiFi.setSleepMode(WIFI_LIGHT_SLEEP));
      case 'm': DO(WiFi.setSleepMode(WIFI_MODEM_SLEEP));
      case 'p': DO(WiFi.printDiag(Serial));
      case 'P': DO(debugSoftAPConfig());
      case 'E': DO(ESP.eraseConfig());
      case 'R': DO(ESP.restart());
   
      // TEST
      case '1': DO(WiFi.mode(WIFI_STA));
      case '2': DO(WiFi.begin(SSID, PSK));
      case '3': DO(doBreakAP()); 
    }
  }
}

// OPTIONAL  E // erase config, R restart

// 1 // mode WIFI_STA
// 2 // begin STA real ssid (MUST EXIST and CONNECT)
// 3 // run test ( should say [AP] set_config failed! )
// 3 // may have to run test again if necessary to get failure

Out

[SENT] 1

WiFi.mode(WIFI_STA)
bcn 0
del if1
usl
mode : sta(2c:3a:e8:39:09:95)
add if0
wifi evt: 8

[SENT] 2

WiFi.begin(SSID, PSK)
scandone
state: 0 -> 2 (b0)
state: 2 -> 3 (0)
state: 3 -> 5 (10)
add 0
aid 1

connected with SSID, channel 11
dhcp client start...
cnt 
wifi evt: 0
ip:10.80.17.101,mask:255.255.240.0,gw:10.80.16.1
wifi evt: 3

[SENT] 3

doBreakAP()
mode : sta(2c:3a:e8:39:09:95) + softAP(2e:3a:e8:39:09:95)
add if1
dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
bcn 100
bcn 0
del if1
pm open,type:2 0
add if1
pm close 7
dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
bcn 100
SET AP SUCCESS
SoftAP Configuration
-----------------------------
ssid:            esptestap
password:        
ssid_len:        9
channel:         1
authmode:        0
ssid_hidden:     0
max_connection:  4
beacon_interval: 100(ms)
-----------------------------
wifi evt: 8
bcn 0
del if1
pm open,type:2 0
add if1
pm close 7
dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
bcn 100
bcn 0
del if1
pm open,type:2 0
mode : sta(2c:3a:e8:39:09:95)
1
wifi evt: 8
[AP] set_config failed!
SET AP FAILED !!!!!!!!!!!!
SoftAP Configuration
-----------------------------
ssid:            
password:        
ssid_len:        32
channel:         1
authmode:        0
ssid_hidden:     0
max_connection:  1
beacon_interval: 100(ms)
-----------------------------
mode : sta(2c:3a:e8:39:09:95) + softAP(2e:3a:e8:39:09:95)
add if1
pm close 7
dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
bcn 100
wifi evt: 8
bcn 0
del if1
pm open,type:2 0
add if1
pm close 7
dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
bcn 100
bcn 0
del if1
pm open,type:2 0
mode : sta(2c:3a:e8:39:09:95)
1
wifi evt: 8

@tablatronix
Copy link
Contributor Author

softap struct may or may not exception out, it depends, usually it just fails to start ap at least in this test

@tablatronix
Copy link
Contributor Author

This is still a problem I think

*WM: [1] StartAP with SSID:  AutoConnectAP
mode : sowifi evt: 8
ftAP(2e:3a:e8:39:09:95)
add if1
dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
bcn 100
wifi evt: 8
scandone
Fatal exception 28(LoadProhibitedCause):
epc1=0x4021cc81, epc2=0x00000000, epc3=0x00000000, excvaddr=0x00000044, depc=0x00000000

Exception (28):
epc1=0x4021cc81 epc2=0x00000000 epc3=0x00000000 excvaddr=0x00000044 depc=0x00000000

ctx: sys 
sp: 3fffecf0 end: 3fffffb0 offset: 01a0

>>>stack>>>
3fffee90:  3fffeed0 3fffeed0 00000004 3ffed8c0  
3fffeea0:  3ffedcf0 00000006 0000000d 00000000  
3fffeeb0:  3fffeed0 4021cc4a 3ffeed40 00000000  
3fffeec0:  00000000 ffffffa8 00000000 401007c6  
3fffeed0:  40247950 00000000 ffffffff 3ffef520  
3fffeee0:  4021cc7d 3ffeed40 00000000 402372dd  
3fffeef0:  4021cbba 3ffee63c 3ffef520 011a3b2d  
3fffef00:  60000600 00000002 3ffeb174 3fff124c  
3fffef10:  4021eaef 4021eafd 3ffeee70 3ffef520  
3fffef20:  00000000 4021eb10 4021cb18 3ffea2a8  
3fffef30:  4022d409 3fff1124 00000040 3ffea2a8  
3fffef40:  4022d44e 3fffdab0 00000000 3fffdcb0  
3fffef50:  3ffef538 3fffdab0 00000000 402313e6  
3fffef60:  40000f49 40000f49 3fffdab0 40000f49  
3fffef70:  40000e19 40001878 00000002 00000000  
3fffef80:  3fffff10 aa55aa55 00000037 40104728  
3fffef90:  4010472e 00000002 00000000 d600a524  
3fffefa0:  4010000d e675ccce 02abf6a5 d2820389  
3fffefb0:  40100a70 3fffef4c 40100a11 3ffffe08  
3fffefc0:  3fffffd0 00000000 00000000 feefeffe  
3fffefd0:  feefeffe feefeffe feefeffe feefeffe  
3fffefe0:  feefeffe feefeffe feefeffe feefeffe  
3fffeff0:  feefeffe feefeffe feefeffe feefeffe  
3ffff000:  feefeffe feefeffe feefeffe feefeffe  

@tablatronix
Copy link
Contributor Author

I wonder if the reproduction problems has to do with autoreconnect...
Seems to be some kind of timing issue with some other wifi event

@tablatronix
Copy link
Contributor Author

Demo sketch still works, bug still exists.

@tablatronix
Copy link
Contributor Author

Nope not affected by autoconnect or reconnect

@devyte
Copy link
Collaborator

devyte commented Aug 10, 2018

@tablatronix thanks for the feedback. @d-a-v is out for a few days, but any additional info you find in the meantime can help.

@Makuna
Copy link
Collaborator

Makuna commented Oct 11, 2018

I can reproduce a problem I believe is related to this. When using persistence false, when the mode is switched to AP, calling AP config will not work correctly. First, make sure to set the IDE to erase wifi config on upload. Then set the persistent to false. At some point...

        WiFi.mode(WIFI_AP);
       
        WiFi.softAPConfig(IPAddress(192,168,200,1), IPAddress(192, 168, 200, 1), IPAddress(255, 255, 255, 0));
        WiFi.softAP("AnyNameDiffThanDefault", "password");

While the AP will be started, it will not be the SSID passed in. Add a simple wait for getMode after the mode call like this....

        WiFi.mode(WIFI_AP);
        while (WiFi.getMode() != WIFI_AP) {
            yield(); 
        }

and the correct AP is actived

@tablatronix
Copy link
Contributor Author

tablatronix commented Oct 11, 2018

sounds like the same issue, just in a different flow, there are several places in the code that use a similar action of setting mode and using return value true, or just assuming mode has changed.

@devyte
Copy link
Collaborator

devyte commented Oct 31, 2019

This rings a bell for what I have observed in my own app from time to time: bringing up the AP and immediately configuring it will fail sometimes. Adding a delay(10) will fix it for me.
See #6630 .

@tablatronix
Copy link
Contributor Author

Yup, its still an issue and definitely a race condition in esp lib, but probably some async state in sdk

@devyte devyte mentioned this issue Nov 4, 2019
7 tasks
@devyte
Copy link
Collaborator

devyte commented Nov 6, 2019

@tablatronix I like your solution of:

while(wifi_get_opmode() != (uint8) m){
    yield();
}

But it could get stuck forever.
I'm thinking of something along the lines of:

//only wait if in CONT context. If this were called from SYS, it's up to the user to serialize correctly.
if(cont_can_yield()) {
    oneshot timeout(1000);
    while(wifi_get_opmode() != (uint8) m && !timeout)
        delay(5);

    //if at this point mode still not reached, disconnect and give up
    if(wifi_get_opmode() != (uint8) m) {
        disconnect();
        return DISCONNECTED; //or maybe a new TIMEOUT or something
    }
}

@tablatronix
Copy link
Contributor Author

Yeah it needs a real solution, that was a workaround for testing my proof.

@tablatronix
Copy link
Contributor Author

I would push this upstream to sdk and see if they know why it does this. I mean there is a return value! Heh

@devyte
Copy link
Collaborator

devyte commented Nov 7, 2019

They can't wait for the mode change by yielding or delaying like we do. They'd have to set up a periodic timer that queues a task that runs the check, then calls some callback, or something along those lines. I don't want to add complexity to the sdk libs, our workaround is minor enough.
Their docs could mention it, though.

@tablatronix
Copy link
Contributor Author

Sounds good, I bet this workaround would fix alot of edge case issues that have never been identified. Worth testing

@TD-er
Copy link
Contributor

TD-er commented Nov 18, 2019

Hmm I've getting reports about ESPEasy starting AP mode even though it is connected to another AP and working fine.
These reports started almost immediately after #6721 was merged.
Some logs indicate this does return false: WiFi.mode(wifimode) (at least for WIFI_OFF)

I've looked at the code to set the wifi mode and it claims to be using a timeout of 1 sec (in the comments), but it looks like it is only using a timeout of 1 msec (1000 usec)

    constexpr unsigned int timeoutValue = 1000; //1 second
    if(can_yield()) {
        using oneShot = esp8266::polledTimeout::oneShotFastUs;

What should it be? 1 msec sounds a bit short.

@tablatronix
Copy link
Contributor Author

@TD-er Do you have an example scenario for reproducing this?

@devyte
Copy link
Collaborator

devyte commented Nov 18, 2019

Typo from me. The polledTimeout should be oneShotFastMs.
See, this is an example of why commenting code is important.
I'll make a PR.

@Elcids
Copy link

Elcids commented Mar 10, 2021

mode change, it is an asynchronous process.
moreover, "persistent status" will make a difference.
See the attached image with colored marks, which shows the static instance "WiFi.mode":

image

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
waiting for feedback Waiting on additional info. If it's not received, the issue may be closed.
Projects
None yet
6 participants