ESP32 および M5Stack で数時間後に Web 記事取得失敗する問題について

記事公開日:2018年9月25日
最終修正日:2018年9月29日

こんばんは。

今回もまた予定変更します。
以前から何度も悩まされていて、読者の方々からもコメントを頂いた件についてです。

ESP32-WROOM-32 開発ボード や M5Stack で、Web から継続的に記事を GET していて、数時間経つと記事取得に失敗するという現象です。

これは、Webサイトからの記事取得間隔が3分毎だとすると、12時間後に記事取得失敗し、間隔が1分の場合は、4時間後には失敗するというものです。

これは、Arduino core for the ESP32 の WiFiClientSecure ライブラリを使って SSL サイトから記事を取得していて、省電力化のために毎回 WiFi を OFF にすると起きる症状です。
これは、Webサイトからの記事取得間隔が長めだと、24時間以上経っても症状が出ないので、正常に動いていると思いがちで放置してしまいます。

Twitter でもツイートしていましたが、今回、これの原因の一つを私なりに突き止めたので、紹介したいと思います。

因みに、以下、Stable版 1.0.0 Arduino – ESP32 で説明します
2018/09/25 時点のお話で、今後ライブラリが更新されたら変わる可能性があります

もし、これで解決できない場合は、ルーターの DHCP や DNS の問題とか、ポート番号とかの問題も有り得ます。
全面解決するとは限りませんのでご了承ください。

スポンサーリンク

このブログの維持運営にご支援いただけると助かります。
支援方法はこちらの記事をご覧ください。
(管理人:mgo-tec)

 

SSLサイトから記事を取得する実験用のサンプルスケッチの入力

SSLサイトと ESP32 や M5Stack でコネクション確立させる時、Arduino core for the ESP32 ( 以下 Arduino – ESP32 )の WiFiClientSecure ライブラリを使いますが、その中の mbedtls ライブラリ公開鍵や秘密鍵のやり取りをして、暗号化通信を実現しています。

例として、Yahoo! Japan RSS サイトから、ニューストピックスを4記事取得するだけの Arduino – ESP32 スケッチを入力してみます。
LCD ディスプレイには表示させず、ただ単にシリアルモニタだけに出力するサンプルスケッチです。

これは、以下の2つのライブラリをインストールして使います。

●自作ライブラリ
https://github.com/mgo-tec/ESP32_WebGet

●Time ライブラリ
https://github.com/PaulStoffregen/Time

#include <ESP32_WebGet.h> //beta ver 1.12-
#include <TimeLib.h> //Use Arduino time library ver1.5-

const char* ssid = "xxxxxxxx"; //ご自分のルーターのSSIDに書き換えてください
const char* password = "xxxxxxxx"; //ご自分のルーターのパスワードに書き換えてください

const char* host = "news.yahoo.co.jp";
const char* target_url1 = "/pickup/rss.xml";
const char* target_url2 = "/pickup/sports/rss.xml";
const char* target_url3 = "/pickup/computer/rss.xml";
const char* target_url4 = "/pickup/entertainment/rss.xml";
const char* ntp_server_name = "time.windows.com";

ESP32_WebGet EWG;
int timezone = 9; //Tokyo
uint32_t web_get_last_time = 0;
bool isWeb_get_first_time = true;
boolean isWifi_connect_first = true;

//***********セットアップ****************************
void setup() {
  delay(1000);
  Serial.begin(115200);
}
//***********メインループ****************************
void loop(){
  getWeb(); //Web記事およびNTP時刻取得
}
//*******NTPサーバー、Yahoo! Japan RSS 記事取得*******
void getWeb(){
  if( (isWeb_get_first_time == true) || (millis() - web_get_last_time > 60000) ){ //3分毎に記事取得
    WiFi_AP_Connect(); //WiFi起動、アクセスポイント接続
    EWG.EWG_NTP_TimeLib_init( timezone, ntp_server_name ); //NTPサーバー取得初期化
    EWG.NTP_OtherServerSelect( timezone ); //NTPサーバーと接続できなかった場合、他のNTPサーバーと接続できるか試す関数
    char time_c [6] = {};
    sprintf( time_c, "%02d:%02d", hour(), minute() );
    String yahoo_str;
    yahoo_str = String( time_c ) + EWG.EWG_https_Web_Get( host, target_url1, '\n', "</rss>", "<title>", "</title>", "◆ " );
    Serial.println( yahoo_str );
    yahoo_str = String( time_c ) + EWG.EWG_https_Web_Get( host, target_url2, '\n', "</rss>", "<title>", "</title>", "◆ " );
    Serial.println( yahoo_str );
    yahoo_str = String( time_c ) + EWG.EWG_https_Web_Get( host, target_url3, '\n', "</rss>", "<title>", "</title>", "◆ " );
    Serial.println( yahoo_str );
    yahoo_str = String( time_c ) + EWG.EWG_https_Web_Get( host, target_url4, '\n', "</rss>", "<title>", "</title>", "◆ " );
    Serial.println( yahoo_str );
    delay(1000);
    WiFi.mode( WIFI_OFF ); //WiFiを常時ONにする場合はこれをコメントアウトする
    isWeb_get_first_time = false;
    web_get_last_time = millis();
  }
}
//*******WiFiアクセスポイント接続*************
void WiFi_AP_Connect(){
  Serial.println();
  Serial.println(F("Connecting Wifi..."));
  Serial.println(ssid);

  if( isWifi_connect_first == true){
    //WiFiが急に接続できなくなった場合の応急処置
    WiFi.disconnect( true, true ); //WiFi OFF, eraseAP=true
    delay(1000);
    WiFi.begin( ssid, password );

    while ( WiFi.status() != WL_CONNECTED ) {
      delay(500);
      Serial.print(".");
    }
    isWifi_connect_first = false;
  }else{
    WiFi.begin( ssid, password ); //WiFiを常時ONにする場合はこれをコメントアウトする
    uint32_t last_time = millis();
    while ( WiFi.status() != WL_CONNECTED ) {
      delay(500);
      Serial.print(".");
      if( millis() - last_time > 20000 ) break; //Time OUT
    }
  }

  int16_t wifi_state = WiFi.status();
  Serial.printf("\r\nWiFi.status = %d\r\n", wifi_state);
  if( wifi_state == WL_CONNECTED ){
    Serial.println("");
    Serial.println("WiFi connected");
    Serial.println("IP address: ");
    Serial.println(WiFi.localIP());
  }else{
    Serial.println("WiFi AP Not Found");
  }
}

これは、4つのニュース記事を取得した後、47行目で
WiFi.mode( WIFI_OFF );
します。
こうすることで電力消費を抑えることを狙います。

そして、60秒(1分)経過後、70行目で再び WiFi.begin でアクセスポイントに接続して記事を再接続します。
私の自作ライブラリ内で、サーバーからのデータを1文字も漏らさず取得し、毎回 client.stop() を実行していて、私的には問題無く動作するものと思っています。

この47行目と、70行目をコメントアウトすれば、常時 WiFi ON 状態で記事を取得できます。

因みに、このスケッチではルートCA証明書は使っていません。
それを使ってコネクション確立しても変化ありませんでした。

では、毎回 WIFI_OFF の状態と、常時 WiFi ON 状態で、どれだけ heap memory が減るかを観察してみます。

WiFi OFF 状態と ON 状態で heap memory 残量の違いを、シリアルモニタで観察してみる

では、Arduino IDE の「ツール」の Core Debug Level を Verbose にして、コンパイル書き込み実行してみます。

シリアルモニタを 115200 bps で起動して、数時間観察してみます。

WiFi.mode( WIFI_OFF ); の場合

記事取得後、毎回 WiFi.mode( WIFI_OFF ) にして、1分後、WiFi.begin した場合、シリアルモニタには下図のように表示されます。
これは初回取得時の場合です。

WiFi_OFF_heap01

4つ目の、エンタメ記事を取得後の赤枠内の
Free heap after TLS
のところを見ます。
これが、4つ目の記事を取得した後の、ESP32 の heap memory 残量です。
181144 という数字を覚えておいてください。

次に、2時間経過後は下図のようになります。

WiFi_OFF_heap02

いかがでしょうか。

これを見ると、heap memory が、
181144 → 162144
というように、かなりの割合で下がっています。

この状態が数時間続くと、heap memory が減り続け、ニュース記事がひとつずつ取得失敗していきます。
数時間後に記事が取得できなくなる原因の一つは恐らくこの heap memory が減ったことによるものと思われます。
そして最終的には、 heap memory を使い果たし、 ESP32あるいは M5Stack が強制的に再起動してしまいます。

このことは、WiFi.disconnect( true ); でも同じでした。
heap memory をクリアにする良い関数が無いか探しましたが、私は見つけられませんでした。
どなたか知っている人がいたら教えて欲しいですね。

WiFi 常時 ON の場合

では今度は WiFi ON にしたまま記事を取得するとどうなるでしょうか?
上記スケッチの 47行と70行目をコメントアウトして、再コンパイル書き込み実行させてみてください。

私が試したところ、最初の3分間は heap memory が減り続けるので、そこはスルーします。
よって、3分後の以降の様子を見ると、下図の通りです。

WiFi_OFF_heap03

その後は 3時間経っても heap memory はほとんど減りませんでした。
下図をご覧ください。

WiFi_OFF_heap04

180528 → 180532
となっていて、ほぼ、この付近の値で安定しています。

私はこのライブラリを詳しく解析したわけではありませんが、おそらく、WIFI OFF にしたことで SSL サイトとのコネクション確立が不完全になってしまい、メモリを解放し切れなくなっているのではないかと思います。
これはあくまで勝手な想像です。

ただ、私は以前こちらの記事で、OpenSSL と ESP-IDF を使って、SSLコネクション実験したことがあり、その場合は一旦 Client を切断したり、WiFi を OFF にしたりすると、コネクション確立できませんでした。
その時のプログラムが頭に残っていて、そういう考えが浮かびました。
いつかライブラリを詳しく解析したいと思いますが、なかなか面倒なことなので、サボっています。

結論 ( 場合よって WIFI_OFF は使えないことはない )

以上から、Stable版 1.0.0 の Arduino – ESP32 では、WIFI_OFF 及び WiFi.begin を繰り返すと、TLS による SSL サイトとのコネクションで heap memory が減り続け、いずれ SSL サイトと接続できなくなり、最終的には強制再起動してしまうことがわかりました。
このことは旧バージョンからずっと同じ症状のような気がします。

Stable版 1.0.0 の場合、常時 WiFi ON 状態と、WIFI OFF では、消費電流は約 20mA ほどの差です。
また、常時 WiFi ON の場合、以前のバージョンのように CPU が熱くなるようなことは無くなっています。
M5Stack の場合、オプションのバッテリーを積んでも、常時 WiFi ON の場合は4時間だったものが、WiFi OFF では5時間弱持った程度でした。


よって 私個人的には常時 WiFi ON でもいいかなと思っています。

もし、どうしても WIFI OFF にしたければ、数時間後には heap Memory を使い果たすことを念頭において、 SSL サイトからの記事取得間隔を30分後またはそれ以上にすれば、数日は稼働し続けるかもしれません。
ただその場合、いつ強制再起動されるか分かりませんので自己責任でやってみてください。

接続できなくなる原因はこの他にも考えられます。
とりあえず、一つの原因と思って下さい。

(追記) WIFI_OFF 状態で、Core Debug Level:”なし” にしてみる

忘れていた方法がありました。
Arduino IDE の「ツール」の「Core Debug Level」を「なし」にする方法です。

実は、以前もこの方法は試していましたが、すっかり忘れていました。
この場合、WiFi.mode( WIFI_OFF ) と WiFi.begin を繰り返していても、heap memory が減らないことがわかりました。

試しに、上記のプログラムの 49行目の後に、

Serial.printf("Free heap after TLS %u\r\n", xPortGetFreeHeapSize());

を追加してみて、「Core Debug Level」を「なし」でもシリアルモニタに表示できるようにします。
それでコンパイル書き込みしてみてください。

WIFI_OFF でも heap memory が減らないと思います。
この方法だと、プログラムエラーを見つけにくくなりますが、Webページが途中で取得できなくなる問題の一つの解決策かと思います。
試運転する場合は、長時間稼働させておいて、Core Debug Level」を「なし」と「Verbose」の両方を試してみる必要があるようです。
因みに、これは Arduino – ESP32 Stable版 1.0.0 の場合ですので、今後更新されると変わる可能性があります。
(2018/09/26)

(追記)複数記事連続取得で最初の記事だけ失敗する問題の解決策( client.connect の使い方によるもの )

新たな発見がありました。
上記の問題でも解決しなかったものが、ようやく解決しました。

Yahoo! Japan RSS ニュースサイトから、4つの記事を連続取得していて、1つ目の記事だけが数時間後に取得失敗するという問題です。
なぜか、最初の記事だけ取得失敗し、一度失敗すると再起動しないと取得できません。
最初の記事は失敗しても、後で取得する3記事は成功するのです。

この件は、長い間未解決でした。

ESP32 や M5Stack を固定IPにしてやってみても、接続は安定しますが、やはり長時間経つと失敗することがありました。
Yahoo サーバー側から拒否されたのだろうと思っていました。

でも、Arduino IDE 「ツール」の「 Core Debug Level 」を「 Verbose 」にして、しばらくシリアルモニターを観察していると、最初の Yahoo サーバー Host ( news.yahoo.co.jp ) 接続に失敗して whileループを抜けてしまうことが分かりました。

それなのに、次の別記事取得時には Host 接続に成功していて、問題無く記事取得できているのです。

ということは、client.connect 関数で Host との接続に失敗しているわけです。
でも、2回目の別記事取得では成功しているわけです。

今までは、以下のようにして接続していました。
(これは、Arduino – ESP32 の WiFiClinetSecure.h をインクルードして使っています)

if ( client.connect(Host, 443) ){
  HTTP GET リクエスト送信
}

while( client.connected() ){
  レスポンス受信
}

client.connect 関数は、Host との接続を試みて、接続できなければ if 文を抜けます。
これは、Arduino – ESP32 stable 1.0.0 のサンプルスケッチ(スケッチ例)にあるものと同じ方法です。

でも、これでは、最初の Host 接続でサーバーからのレスポンスが無いと、接続に失敗してしまいます。
そこで、私自身の独自の方法で、接続に失敗しても何度も接続を試みる方法を取ってみました。
以下の感じです。

uint32_t time_out = millis();
while(1){
  if ( client.connect(Host, 443) ){
    HTTP GET リクエスト送信
    .......
    break;
  }
  if( ( millis() - time_out ) > 20000 ) break;
  delay(1); //必ず必要
}

while( client.connected() ){
  レスポンス受信
}

最初の接続に失敗しても、while文で何度も接続をここを試みます。
でも、Hostサーバーからの応答が無いと延々とループしてしまうので、20000ms(20秒)を超えたらタイムアウトしてループを抜けるようにしてみました。

私はこの方法にプログラムを変更して、上記の様に Core Debug Level を「なし」にして、WIFI_OFF にすると、接続失敗することは無くなったように思います。
今、かなり長時間稼働させていますが、まだ失敗ありません。
悩んでいる方は試してみて下さい。
私のライブラリも近々全て変更します。

因みに、これは Arduino – ESP32 stable版 1.0.0 の場合ですので、今後更新されたらどうなるか分かりません。

その他の問題は、ルーター設定で DHCP の最大数を超えていたりすると、そもそもアクセスポイントに接続できなかったりします。
この件は以下の記事を参照してみてください。
ESP32 ( ESP-WROOM-32 , M5Stack )自分的 トラブルシューティング まとめ

以上を試してみても解決しない場合は、他の問題だと思います。
(2018/09/29時点)

編集後記

以前から何度も悩まされていて、 原因が分らずに放置していましたが、ようやく原因の一つがつかめました。

Web サイトからの記事取得間隔が長めだと、しばらく正常に動作しているので原因が掴み辛かったんですよね。
これは長い間記録を取り続けることによって、やっと見つけることができました。
これでようやく一歩前に進めそうです。

ということで、今回もまた予定を変更した記事を書いてしまいました。
次回は Firebase と Google Home を連携させた記事を書きたいところですが、実はもう一つ、読者の方からリクエストがあったので、それを記事にしたいと思っています。

ではまた・・・。

このブログの維持運営にご支援いただけると助かります。
支援方法はこちらの記事をご覧ください。
(管理人:mgo-tec)

 

mgo-tec電子工作 関連コンテンツ ( 広告含む )

スポンサーリンク

Amazon.co.jp 当ブログのおすすめ

投稿者:

mgo-tec

Arduino , ESP32 ( ESP-WROOM-32 ) , ESP8266 ( ESP-WROOM-02 )等を使って、主にスマホと連携した電子工作やプログラミング記事を書いてます。ライブラリも作ったりしてます。趣味、独学でやってますので、動作保証はしません。 電子回路やプログラミングの専門家ではありません。 畑違いの仕事をしていて、介護にドップリ浸かりそうな年配者です。 少しだけ電気の知識が必要な仕事なので、電気工事士や工事担任者等の資格は持っています。

コメントを残す

メールアドレスが公開されることはありません。

*画像の文字を入力してください。(スパム防止の為)

このサイトはスパムを低減するために Akismet を使っています。コメントデータの処理方法の詳細はこちらをご覧ください