2021-10-20

ESP8266 RTOS SDK 3.4とWiFiパケット解析

k-tkr

はじめに

こんにちは、エンジニアの@k-tkrです。 ESP8266の新しいSDK（v3.4）が2021年4月8日にリリースされていました。省電力化を含む様々な改善があったのですがWiFiの接続が一部のアクセスポイントとの間で不安定になってしまったため調査してみました。

WiFi接続の問題

ESP8266にRTOS SDK v3.4を使ってビルドしたWiFiステーション接続用のコードを入れて社内や自宅などにあるいくつかのWiFiアクセスポイント（AP）と接続を試してみたところ、Aterm HT100LNとの接続が不安定になり、接続して数秒後に切断と再接続を繰り返していることが判明しました。

事象の解析

事象の再現

WiFiステーションを起動させAPに接続して適宜ログを吐くようなコードを作成しました。 接続したあとは1秒ごとにカウンタを増加させるだけで何もしないコードです。

    esp_wifi_connect();
    bits = xEventGroupWaitBits(s_wifi_event_group, WIFI_CONNECTED_BIT | WIFI_FAIL_BIT, pdFALSE, pdFALSE, portMAX_DELAY);
    if (bits & WIFI_CONNECTED_BIT) {
    int ct = 0;
        while(1){
            ESP_LOGI(TAG, "%d", ct++);
            vTaskDelay(1000 / portTICK_RATE_MS);
        }
    }

問題が発生しているAPと繋げてコードを実行するとカウンタが数回増加した後APからのビーコンがタイムアウトになり、APに送信したプローブに対する返答も得られないため一旦WiFi接続を切断し再接続しているのがわかります。 wifiConnectionLog 他のAPとの接続の場合はこのような挙動は見られず、wifi station: n のカウンタnが増加していくだけです。

ビーコン受信確認

次にAPからの情報を受け取れているかどうかを調べました。APのベンダー情報を取得するコールバックを定義して esp_wifi_set_vendor_ie_cb を呼び登録します(コールバックの量が多いので適当に間引いています)。

int ct = 0;
void cb_func(void* ctx, wifi_vendor_ie_type_t type, const uint8_t sa[6], const vendor_ie_data_t *vnd_ie, int rssi) {
    if(++ct % 10)
      return;
    ESP_LOGI(TAG, "type:%d", type);
    ESP_LOGI(TAG, "sa:%x%x%x%x%x%x", sa[0], sa[1], sa[2], sa[3], sa[4], sa[5]);
    ESP_LOGI(TAG, "RSSI:%d", rssi);
    ESP_LOGI(TAG, "Element id: %d", vnd_ie->element_id);
    ESP_LOGI(TAG, "length:%d", vnd_ie->length);
}

esp_wifi_set_vendor_ie_cb(cb_func, NULL);

きちんと接続できるAPからは以下のようにビーコン情報が繰り返し受信されているのが確認できます。 vendorcb しかし問題が起こっているAPからは接続の際に情報を受信したきり情報が受信できておらずビーコンがタイムアウトになるようです。 vendorcb aterm

詳細なデバッグ情報

もう少し詳細なログを見るためにESPのコンフィグでログをVerboseにし、更にWiFiのサブモジュール NET80211 (CONFIG_ESP8266_WIFI_DEBUG_LOG_SUBMODULE_NET80211) のログまで出すようにします。恐らくIEEE802.11フレームのログが見れるようになるのでしょう。 すると接続できるAPと比べて異なる形式のデータを発見しました。 debug aterm

問題無く接続できる方は下のようになっています。 debug normal

APのWiFiパケット解析

APが上のデバッグ情報に対応するパケットを送信しているはずだと考えWiresharkを使ってWiFiのパケットを見てみました。WiFiのパケットはWiFiインターフェースのモニターモードというものを使って取得します。 monitormode 通常のWindowsラップトップのWiFiカードにはモニターモードがついていないのでこのパケットは見れませんがたまたま手元にあったWiFi子機にモニターモードがついていたのでそれを使用しました。Wiresharkには大量のパケットが流れてくるので適当にフィルタをします。wlan.fc.type_subtype==8 によってbeacon frameだけを取り出し、wlan.addr にAPのMACアドレスを指定して当該APからのbeacon frameだけを取り出します。 wireshark filter

解析の結果、ESPと接続ができないAPはビーコン自体は発信しているということが見えましたが、これらの中に含まれている Country Information のグループが1チャンネルずつ13グループ送信されているということがわかりました。 aterm-HT100LNPacket

一方で問題なく通信できているAPからは1~13チャンネルまでまとめられた情報が送信されていることが見て取れます。 aterm-normalPacket

ESP8266の中で恐らく起きていること

ESP内部にCountry Infoを1つしか保存できなくて最後に送られてきた（13chの）Country Info しか保存していないのではないかと考えました。

仮説検証1

APの設定を13ch固定にして試してみたところ、安定して接続でき、ビーコンタイムアウトも起こらなくなりました。 aterm-normalPacket

仮説検証2

esp_wifi_set_country esp_wifi_get_country 関数の存在を知り、これらを使った検証もしてみました。 esp_wifi_set_country 関数を使って強制的に国別ポリシを書き換えました。（esp_wifi_start 関数を呼んだ後に実行しないとプログラムがクラッシュすることがあります。）

wifi_country_t country_info = {
    .cc = "JP",
    .schan = 1,
    .nchan = 13,
    .policy = WIFI_COUNTRY_POLICY_MANUAL,
};
if (esp_wifi_set_country(&country_in) != ESP_OK)
    ESP_LOGE(TAG, "Set country failed");

こちらもやはり安定接続できるようになりました。

更に

esp_wifi_get_country(&country_info);
ESP_LOGI(TAG, "%s", country_info.cc);
ESP_LOGI(TAG, "schan:%d", country_info.schan);
ESP_LOGI(TAG, "nchan:%d", country_info.nchan);
ESP_LOGI(TAG, "Tx power:%d", country_info.max_tx_power);
ESP_LOGI(TAG, "Policy:%d", country_info.policy);

でポリシが変更されているのを確認しました。 また、esp_wifi_set_country を使わない場合は schan:13 が読み出されたので、やはり最後のチャンネルグループだけを保存しているようです。

その後

WiFi関連のモジュールはソースコードではなくライブラリとして提供されているのでこれ以上の解析や修正は不可能と考え、RTOS v3.4を使うことは一旦諦め当面の間v3.3を使うことにしました。ESP8266 RTOS SDK githubにissueを上げたので近いうちに改善されることを願っています。

最新の記事