search

mongoose-os-libs / wifi

Other
13 stars 29 forks source link

Re-connection process doesn't work when connecting to STA programmatically #21

Open blasco opened 5 years ago

blasco commented 5 years ago

When the default configuration is used, the auto reconnect process works as expected:

[Jan 25 12:59:18.982] esp_mgos_init2       Mongoose OS 201901250849 (20190125-115140/2.11.0-5-g125c398-master)
[Jan 25 12:59:18.990] esp_mgos_init2       CPU: ESP8266EX, 160 MHz, RAM: 48160 total, 45596 free
[Jan 25 12:59:18.996] esp_mgos_init2       SDK 2.2.1(1247cc5); flash: 4M
[Jan 25 12:59:19.001] esp_print_reset_info Reset cause: 6 (sys reset)
[Jan 25 12:59:19.005] mg_lwip_if_init      Mongoose 6.13, LwIP 1.4.1
[Jan 25 12:59:19.010] mg_ssl_if_init       mbed TLS 2.13.1-cesanta5
[Jan 25 12:59:19.014] mgos_vfs_dev_create_ sfl0: sysflash (), size 4194304
[Jan 25 12:59:19.020] mgos_vfs_dev_create_ root: part ({"dev": "sfl0", "offset": 32768, "size": 262144}), size 262144
[Jan 25 12:59:19.029] mgos_vfs_mount_dev   /: SPIFFS @ root, opts
[Jan 25 12:59:19.086] mgos_vfs_print_fs_in /: size 233681, used: 29116, free: 204565
[Jan 25 12:59:19.171] mgos_sys_config_init MAC: 827D3A78B374
[Jan 25 12:59:19.175] mgos_sys_config_init WDT: 30 seconds
[Jan 25 12:59:19.180] mgos_deps_init       init arduino-compat...
[Jan 25 12:59:19.184] mgos_deps_init       init i2c...
[Jan 25 12:59:19.188] mgos_i2c_create      I2C GPIO init ok (SDA: 12, SCL: 14, freq: 100000)
[Jan 25 12:59:19.194] mgos_deps_init       init arduino-wire...
[Jan 25 12:59:19.198] mgos_deps_init       init arduino-adafruit-tsl2561...
[Jan 25 12:59:19.203] mgos_deps_init       init atca...
[Jan 25 12:59:19.206] mgos_deps_init       init ota-http-client...
[Jan 25 12:59:19.210] mgos_deps_init       init shadow...
[Jan 25 12:59:19.213] mgos_deps_init       init ota-shadow...
[Jan 25 12:59:19.217] mgos_ota_shadow_init OTA over shadow initialised
[Jan 25 12:59:19.221] mgos_deps_init       init wifi...
[Jan 25 12:59:19.225] bcn 0
[Jan 25 12:59:19.226] del if1
[Jan 25 12:59:19.226] usl
[Jan 25 12:59:19.227] mode : null
[Jan 25 12:59:19.228] mgos_wifi_get_next_s WiFi STA: Using config 0 (EasyBox-094372)
[Jan 25 12:59:19.234] mgos_wifi_setup      WiFi mode: AP+STA
[Jan 25 12:59:19.238] mgos_wifi_set_mode   WiFi mode: AP
[Jan 25 12:59:19.241] mode : softAP(82:7d:3a:78:b3:74)
[Jan 25 12:59:19.244] add if1
[Jan 25 12:59:19.245] dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
[Jan 25 12:59:19.250] bcn 100
[Jan 25 12:59:19.252] mgos_wifi_dev_ap_set WiFi AP: SSID EcoGarden, channel 6
[Jan 25 12:59:19.257] bcn 0
[Jan 25 12:59:19.257] del if1
[Jan 25 12:59:19.259] usl
[Jan 25 12:59:19.259] add if1
[Jan 25 12:59:19.260] dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
[Jan 25 12:59:19.266] bcn 100
[Jan 25 12:59:19.266] mgos_wifi_dev_ap_set WiFi AP IP: 192.168.4.1/255.255.255.0 gw 192.168.4.1, DHCP range 192.168.4.2 - 192.168.4.100
[Jan 25 12:59:19.277] mgos_wifi_set_mode   WiFi mode: AP+STA
[Jan 25 12:59:19.281] mode : sta(80:7d:3a:78:b3:74) + softAP(82:7d:3a:78:b3:74)
[Jan 25 12:59:19.286] add if0
[Jan 25 12:59:19.287] WPA2 ENTERPRISE VERSION: [v2.0] disable
[Jan 25 12:59:19.291] mgos_wifi_setup_sta  WiFi STA: Connecting to EasyBox-094372
[Jan 25 12:59:19.299] mgos_deps_init       init http-server...
[Jan 25 12:59:19.304] mgos_http_server_ini HTTP server started on [80]
[Jan 25 12:59:19.309] mgos_deps_init       init rpc-common...
[Jan 25 12:59:19.314] mgos_deps_init       init rpc-ws...
[Jan 25 12:59:19.318] mgos_deps_init       init dash...
[Jan 25 12:59:19.320] mgos_deps_init       init mqtt...
[Jan 25 12:59:19.324] mgos_deps_init       init sntp...
[Jan 25 12:59:19.326] mgos_deps_init       init gcp...
[Jan 25 12:59:19.329] mgos_deps_init       init mbedtls...
[Jan 25 12:59:19.333] mgos_deps_init       init mongoose-os-utils-interval...
[Jan 25 12:59:19.338] mgos_deps_init       init onewire...
[Jan 25 12:59:19.340] mgos_deps_init       init pwm...
[Jan 25 12:59:19.344] mgos_deps_init       init rpc-service-config...
[Jan 25 12:59:19.348] mgos_deps_init       init rpc-service-fs...
[Jan 25 12:59:19.352] mgos_deps_init       init rpc-service-ota...
[Jan 25 12:59:19.357] mgos_deps_init       init rpc-uart...
[Jan 25 12:59:19.361] mg_rpc_channel_uart  0x3fff290c UART0
[Jan 25 12:59:19.365] mg_rpc_add_channel_i 0x3fff290c '' UART
[Jan 25 12:59:19.369] mg_rpc_ev_handler    0x3fff290c CHAN OPEN (UART UART0)
[Jan 25 12:59:19.383] mgos_init            Init done, RAM: 48160 total, 37372 free, 37232 min free
[Jan 25 12:59:19.391] mgos_event_trigger   ev MOS0 triggered 0 handlers
[Jan 25 12:59:19.395] mgos_ota_boot_finish 1 0
[Jan 25 12:59:19.405] mgos_lic_init        UID: 03a33db0301e13e3, license: none
[Jan 25 12:59:19.412] mgos_event_trigger   ev WFI1 triggered 0 handlers
[Jan 25 12:59:19.418] mgos_net_on_change_c WiFi STA: connecting
[Jan 25 12:59:19.423] mgos_event_trigger   ev NET1 triggered 3 handlers
[Jan 25 12:59:22.156] scandone
[Jan 25 12:59:22.158] mgos_event_trigger   ev WFI0 triggered 0 handlers
[Jan 25 12:59:22.163] mgos_net_on_change_c WiFi STA: disconnected
[Jan 25 12:59:22.168] mgos_event_trigger   ev NET0 triggered 3 handlers
[Jan 25 12:59:49.299] mgos_wifi_sta_connec WiFi STA: Connect timeout
[Jan 25 12:59:49.305] mgos_wifi_get_next_s WiFi STA: Using config 1 (EasyBox-094372)
[Jan 25 12:59:49.312] WPA2 ENTERPRISE VERSION: [v2.0] disable
[Jan 25 12:59:49.315] mgos_wifi_setup_sta  WiFi STA: Connecting to EasyBox-094372
[Jan 25 12:59:49.324] mongoose_poll        New heap free LWM: 36936
[Jan 25 12:59:49.330] mgos_event_trigger   ev WFI1 triggered 0 handlers
[Jan 25 12:59:49.336] mgos_net_on_change_c WiFi STA: connecting
[Jan 25 12:59:49.341] mgos_event_trigger   ev NET1 triggered 3 handlers
[Jan 25 12:59:52.173] scandone
[Jan 25 12:59:52.175] mgos_event_trigger   ev WFI0 triggered 0 handlers
[Jan 25 12:59:52.180] mgos_net_on_change_c WiFi STA: disconnected
[Jan 25 12:59:52.185] mgos_event_trigger   ev NET0 triggered 3 handlers
[Jan 25 13:00:19.325] mgos_wifi_sta_connec WiFi STA: Connect timeout
[Jan 25 13:00:19.330] mgos_wifi_get_next_s WiFi STA: Using config 2 (EasyBox-094372)
[Jan 25 13:00:19.336] WPA2 ENTERPRISE VERSION: [v2.0] disable
[Jan 25 13:00:19.340] mgos_wifi_setup_sta  WiFi STA: Connecting to EasyBox-094372
[Jan 25 13:00:19.350] mgos_event_trigger   ev WFI1 triggered 0 handlers
[Jan 25 13:00:19.355] mgos_net_on_change_c WiFi STA: connecting
[Jan 25 13:00:19.360] mgos_event_trigger   ev NET1 triggered 3 handlers
[Jan 25 13:00:22.198] scandone
[Jan 25 13:00:22.199] mgos_event_trigger   ev WFI0 triggered 0 handlers
[Jan 25 13:00:22.205] mgos_net_on_change_c WiFi STA: disconnected
[Jan 25 13:00:22.209] mgos_event_trigger   ev NET0 triggered 3 handlers

When we try to connect programmatically:

    struct mgos_config_wifi_sta sta_cfg;
    memcpy(&sta_cfg, mgos_sys_config_get_wifi_sta(), sizeof(sta_cfg));
    sta_cfg.enable = 1;
    if (!mgos_wifi_setup_sta(&sta_cfg))
    {
        LOG(LL_ERROR, ("Wifi STA setup failed"));
    }
    // Not sure if we can free this
    // free(sta_cfg.enable)

The auto reconnect process doesn't happen as we can observe:

[Jan 25 12:52:55.621] esp_mgos_init2       Mongoose OS 201901250849 (20190125-115140/2.11.0-5-g125c398-master)
[Jan 25 12:52:55.629] esp_mgos_init2       CPU: ESP8266EX, 160 MHz, RAM: 48160 total, 45596 free
[Jan 25 12:52:55.636] esp_mgos_init2       SDK 2.2.1(1247cc5); flash: 4M
[Jan 25 12:52:55.640] esp_print_reset_info Reset cause: 6 (sys reset)
[Jan 25 12:52:55.644] mg_lwip_if_init      Mongoose 6.13, LwIP 1.4.1
[Jan 25 12:52:55.649] mg_ssl_if_init       mbed TLS 2.13.1-cesanta5
[Jan 25 12:52:55.653] mgos_vfs_dev_create_ sfl0: sysflash (), size 4194304
[Jan 25 12:52:55.659] mgos_vfs_dev_create_ root: part ({"dev": "sfl0", "offset": 32768, "size": 262144}), size 262144
[Jan 25 12:52:55.669] mgos_vfs_mount_dev   /: SPIFFS @ root, opts
[Jan 25 12:52:55.725] mgos_vfs_print_fs_in /: size 233681, used: 29116, free: 204565
[Jan 25 12:52:55.810] mgos_sys_config_init MAC: 827D3A78B374
[Jan 25 12:52:55.815] mgos_sys_config_init WDT: 30 seconds
[Jan 25 12:52:55.819] mgos_deps_init       init arduino-compat...
[Jan 25 12:52:55.823] mgos_deps_init       init i2c...
[Jan 25 12:52:55.826] mgos_i2c_create      I2C GPIO init ok (SDA: 12, SCL: 14, freq: 100000)
[Jan 25 12:52:55.833] mgos_deps_init       init arduino-wire...
[Jan 25 12:52:55.837] mgos_deps_init       init arduino-adafruit-tsl2561...
[Jan 25 12:52:55.841] mgos_deps_init       init atca...
[Jan 25 12:52:55.844] mgos_deps_init       init ota-http-client...
[Jan 25 12:52:55.848] mgos_deps_init       init shadow...
[Jan 25 12:52:55.852] mgos_deps_init       init ota-shadow...
[Jan 25 12:52:55.855] mgos_ota_shadow_init OTA over shadow initialised
[Jan 25 12:52:55.860] mgos_deps_init       init wifi...
[Jan 25 12:52:55.864] bcn 0
[Jan 25 12:52:55.864] del if1
[Jan 25 12:52:55.865] usl
[Jan 25 12:52:55.866] mode : null
[Jan 25 12:52:55.867] mgos_wifi_get_next_s WiFi STA: Using config 0 (EasyBox-094372)
[Jan 25 12:52:55.873] mgos_wifi_setup      WiFi mode: AP+STA
[Jan 25 12:52:55.876] mgos_wifi_set_mode   WiFi mode: AP
[Jan 25 12:52:55.880] mode : softAP(82:7d:3a:78:b3:74)
[Jan 25 12:52:55.883] add if1
[Jan 25 12:52:55.884] dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
[Jan 25 12:52:55.890] bcn 100
[Jan 25 12:52:55.890] mgos_wifi_dev_ap_set WiFi AP: SSID EcoGarden, channel 6
[Jan 25 12:52:55.896] bcn 0
[Jan 25 12:52:55.897] del if1
[Jan 25 12:52:55.898] usl
[Jan 25 12:52:55.898] add if1
[Jan 25 12:52:55.899] dhcp server start:(ip:192.168.4.1,mask:255.255.255.0,gw:192.168.4.1)
[Jan 25 12:52:55.905] bcn 100
[Jan 25 12:52:55.905] mgos_wifi_dev_ap_set WiFi AP IP: 192.168.4.1/255.255.255.0 gw 192.168.4.1, DHCP range 192.168.4.2 - 192.168.4.100
[Jan 25 12:52:55.916] mgos_wifi_set_mode   WiFi mode: AP+STA
[Jan 25 12:52:55.920] mode : sta(80:7d:3a:78:b3:74) + softAP(82:7d:3a:78:b3:74)
[Jan 25 12:52:55.925] add if0
[Jan 25 12:52:55.926] WPA2 ENTERPRISE VERSION: [v2.0] disable
[Jan 25 12:52:55.930] mgos_wifi_setup_sta  WiFi STA: Connecting to EasyBox-094372
[Jan 25 12:52:55.938] mgos_deps_init       init http-server...
[Jan 25 12:52:55.943] mgos_http_server_ini HTTP server started on [80]
[Jan 25 12:52:55.949] mgos_deps_init       init rpc-common...
[Jan 25 12:52:55.953] mgos_deps_init       init rpc-ws...
[Jan 25 12:52:55.957] mgos_deps_init       init dash...
[Jan 25 12:52:55.960] mgos_deps_init       init mqtt...
[Jan 25 12:52:55.963] mgos_deps_init       init sntp...
[Jan 25 12:52:55.966] mgos_deps_init       init gcp...
[Jan 25 12:52:55.969] mgos_deps_init       init mbedtls...
[Jan 25 12:52:55.972] mgos_deps_init       init mongoose-os-utils-interval...
[Jan 25 12:52:55.977] mgos_deps_init       init onewire...
[Jan 25 12:52:55.980] mgos_deps_init       init pwm...
[Jan 25 12:52:55.983] mgos_deps_init       init rpc-service-config...
[Jan 25 12:52:55.987] mgos_deps_init       init rpc-service-fs...
[Jan 25 12:52:55.992] mgos_deps_init       init rpc-service-ota...
[Jan 25 12:52:55.997] mgos_deps_init       init rpc-uart...
[Jan 25 12:52:56.001] mg_rpc_channel_uart  0x3fff290c UART0
[Jan 25 12:52:56.005] mg_rpc_add_channel_i 0x3fff290c '' UART
[Jan 25 12:52:56.009] mg_rpc_ev_handler    0x3fff290c CHAN OPEN (UART UART0)
[Jan 25 12:52:56.014] scandone
[Jan 25 12:52:56.016] WPA2 ENTERPRISE VERSION: [v2.0] disable
[Jan 25 12:52:56.020] mgos_wifi_setup_sta  WiFi STA: Connecting to EasyBox-094372
[Jan 25 12:52:56.037] mgos_init            Init done, RAM: 48160 total, 37172 free, 37032 min free
[Jan 25 12:52:56.045] mgos_event_trigger   ev MOS0 triggered 0 handlers
[Jan 25 12:52:56.050] mgos_ota_boot_finish 1 0
[Jan 25 12:52:56.060] mgos_lic_init        UID: 03a33db0301e13e3, license: none
[Jan 25 12:52:56.066] mgos_event_trigger   ev WFI1 triggered 0 handlers
[Jan 25 12:52:56.072] mgos_event_trigger   ev WFI1 triggered 0 handlers
[Jan 25 12:52:56.077] mgos_net_on_change_c WiFi STA: connecting
[Jan 25 12:52:56.081] mgos_event_trigger   ev NET1 triggered 3 handlers
[Jan 25 12:52:56.086] mgos_net_on_change_c WiFi STA: connecting
[Jan 25 12:52:56.090] mgos_event_trigger   ev NET1 triggered 3 handlers
[Jan 25 12:52:58.877] scandone
[Jan 25 12:52:58.879] mgos_event_trigger   ev WFI0 triggered 0 handlers
[Jan 25 12:52:58.884] mgos_net_on_change_c WiFi STA: disconnected
[Jan 25 12:52:58.889] mgos_event_trigger   ev NET0 triggered 3 handlers
[Jan 25 12:53:25.938] mgos_wifi_sta_connec WiFi STA: Connect timeout
[Jan 25 12:54:15.682] add 1
[Jan 25 12:54:15.683] aid 1
[Jan 25 12:54:15.683] station: 40:4e:36:8f:93:a2 join, AID = 1
[Jan 25 12:54:15.687] mgos_wifi_on_change_ 40:4e:36:8f:93:a2 connected
[Jan 25 12:54:15.692] mgos_event_trigger   ev WFI4 triggered 0 handlers
[Jan 25 12:54:16.038] mongoose_poll        New heap free LWM: 35912

After the [Jan 25 12:53:25.938] mgos_wifi_sta_connec WiFi STA: Connect timeout it never tries to reconnect.

rojer commented 5 years ago

acknowledging the bug. currently retry logic only works in conjunction with "current index", meaning we'll only retry if we know which of the system configs we are currently at. these should be decoupled - retry should be performed anyway, and if we are using system config, we should advance further.