26 | 2月 | 2024 | あらぶるトラブル

環境

Windows 11 Home 22H2 22621.3155
Arduino IDE 2.3.2(おそらく2.2.2-nightly-20230909が自動アップデートかかったもの)
~~python3.10~~（PCのやつでなくボードマネージャー個別のpythonが指定されていた）
Rasberry Pi Pico/PR2040 3.7.2(ボードマネージャー) <- 調査完了してないがこいつが原因
python3.7.2(PCのやつでなくボードマネージャー個別のpython)

状況

調査の過程でボードマネージャーからRasberry Pi Pico/PR2040をアンインストール(remove)と再インストールした時点で再現しなくなってしまったので再現待ち。多分根本解決していない。

事象

ArduinoIDEでスケッチを開いた後にスケッチの入っているフォルダを移動させようとすると「別のプログラムがこのフォルダーまたはファイルを開いているので操作を完了できません」というメッセージが表示される。リソースモニターから見るとpython3が握っていることになっている。

なお、リソースモニターはwindowsの下タブにある検索に　perfmon.exe /res　と入力すると起動できる。（初回はなにか選択画面出たかも）CPUタブの下にある関連付けされたハンドルにフォルダの古パスを入力すると握っているプロセス名とPIDがわかる。

取り急ぎリソースモニターの下の関連付けられたハンドルに出てきたプロセスを右クリックで終了させると解放されるけど気持ち悪い。

調査（中）

プロセス確認

MSのプロセスツリーを確認できるツールをダウンロード＆解凍。dosからたたいてプロセス確認。

C:\Windows\System32>cd C:\Users\kitam\Desktop\あまりつかわない

C:\Users\kitam\Desktop\あまりつかわない>cd PSTools
C:\Users\kitam\Desktop\あまりつかわない\PSTools>pslist64.exe -t

PsList v1.41 - Process information lister
Copyright (C) 2000-2023 Mark Russinovich
Sysinternals - www.sysinternals.com

Process information for DESKTOP-O6SRQ2U:

Name                             Pid Pri Thd  Hnd      VM      WS    Priv
（他プロセス省略）
explorer                        7584   8 153 7671 2152843248  355796  241016
  Arduino IDE                    696   8  36  809 3330468296  110296   58484
    Arduino IDE                 8584   8  15  287 2185658844   44460   13276
    Arduino IDE                 9280   4  18  440 3340778512  241524  193684
    Arduino IDE                14892  10  15  439 2185925932   90868   56544
    Arduino IDE                15064   8  13  315 3330165336  159420  161084
      Arduino IDE               1840   8  13  297 3330158484  106104   45512
        Arduino IDE             8308   8   8  180 3330113680   86748   23028
      arduino-cli              10620   8  13  245 5650744  138376  135932
        serial-discovery        3448   8  11  189 4944052   14760   23016
        mdns-discovery          7160   8   8  141 4884508    9468   16052
        python3                 9552   8   2  162   64840   12964    5132
        conhost                10432   8   2  119 2151778436   10368    5340
      Arduino IDE              11172   8  20  198 3330222164   93096   34792

IDE起動中にPID9552でpythonが起動していたが、閉じたところ

C:\Users\kitam\Desktop\あまりつかわない\PSTools>pslist64.exe -t

PsList v1.41 - Process information lister
Copyright (C) 2000-2023 Mark Russinovich
Sysinternals - www.sysinternals.com

Process information for DESKTOP-O6SRQ2U:

Name                             Pid Pri Thd  Hnd      VM      WS    Priv

（他プロセス省略）
python3                         9552   8   2  162   64840   12976    5132

単独でプロセスがのこってしまっている。

ネットをパッと見る限り情報なさそう。

ちなみに以前使っていたArduinoIDE1.8.19を起動したところ1.8.19では発生せず。2になる時に根本的に変わっているので2系の問題っぽい。

上のプロセスツリーを見る限りArduino IDEが動かしているarduino-cliが動かしているpython3がフォルダをにぎりっぱになっているのだろう。

とりあえずタスクマネージャーから引っ張ってきた怪しげなところの起動時引数が下。

名前 PID 状態 ユーザー名 CPU メモリ (アクティブなプライベート ワーキング セット) コマンド ライン アーキテクチャ 説明
arduino-cli.exe 10208 実行中 kitam 00 88,832 K "C:\Users\kitam\AppData\Local\Programs\Arduino IDE\resources\app\lib\backend\resources\arduino-cli.exe" daemon --port 0 --config-file c:\Users\kitam\.arduinoIDE\arduino-cli.yaml -v x64 arduino-cli.exe

名前 PID 状態 ユーザー名 CPU メモリ (アクティブなプライベート ワーキング セット) コマンド ライン アーキテクチャ 説明
python3.exe 15928 実行中 kitam 00 4,112 K C:\Users\kitam\AppData\Local\Arduino15\packages\rp2040\tools\pqt-python3\1.0.1-base-3a57aed/python3 -I C:\Users\kitam\AppData\Local\Arduino15\packages\rp2040\hardware\rp2040\3.7.2/tools/pluggable_discovery.py x86 Python

rp2040といっているのでraspi pico用のやつが悪さしているっぽい。

試しにボードマネージャーからRasberry Pi Pico/PR2040をアンインストール(remove)するとpythonのプ℟セス立ち上がらなくなり閉じたあともきちんと解放されるようになった。

  Arduino IDE                  14328   8  42  821 3330526188  126868   77340
    Arduino IDE                 3808   8  16  292 2185667036   44344   13308
    Arduino IDE                13600   8  22  462 3340829368  380448  330472
    Arduino IDE                14220  10  14  444 2185918956  124312   90924
    Arduino IDE                14256   8  15  322 3330181720  239328  225252
      arduino-cli               2288   8  15  239 5646504  162824  160628
        serial-discovery        2548   8  11  177 4938924    9700   18704
        conhost                 3752   8   3  118 2151778936   10340    5352
        mdns-discovery          5104   8   7  128 4881308    8080   13932
      Arduino IDE               3096   8  23  198 3330246684   96836   40656
      Arduino IDE               5092   8  16  301 3330183060  114132   54612
        Arduino IDE             5204   8  11  180 3330138256   88576   23964
      arduino-fwuploader        6208   8  12  331 4958920   22196   21720
        conhost                 4280   8   4  116 2151779456   10356    5392

ちなみに以下のjsonで指定しているもの。

https://github.com/earlephilhower/arduino-pico/releases/download/global/package_rp2040_index.json

原因ソース

多分こちら。スレッドのグローバル変数を外部から操作する思想みたいだが、操作元がいない模様。

どうしよう。

と、思っていたところ再インストールした時点で予想外に再現しなくなったので再現待ち。多分解決しておらず、なにかトリガーになるアクションを踏んでいない。

scannerGo = False

def scanner():
    global scannerGo
    scannerGo = True
    boards = False
    while scannerGo:

ESP8266(ESP-WROOM-02)の内容。ESP-WROOM-32ではないので注意。

事象

esp8266 -> nginx(proxy) -> python(HTTPServer)という構成でサーバへespからサーバーへリクエストを投げたところ、かなりの確率で以下のログがpythonで吐かれていた。

Exception occurred during processing of request from ('127.0.0.1', 48024)
Traceback (most recent call last):
  File "/usr/lib/python3.10/socketserver.py", line 316, in _handle_request_noblock
    self.process_request(request, client_address)
  File "/usr/lib/python3.10/socketserver.py", line 347, in process_request
    self.finish_request(request, client_address)
  File "/usr/lib/python3.10/socketserver.py", line 360, in finish_request
    self.RequestHandlerClass(request, client_address, self)
  File "/usr/lib/python3.10/socketserver.py", line 747, in __init__
    self.handle()
  File "/usr/lib/python3.10/http/server.py", line 433, in handle
    self.handle_one_request()
  File "/usr/lib/python3.10/http/server.py", line 421, in handle_one_request
    method()
  File "/home/yoshitake/api/mail_api.py", line 26, in do_GET
    self.wfile.write(response_content)
  File "/usr/lib/python3.10/socketserver.py", line 826, in write
    self._sock.sendall(b)
BrokenPipeError: [Errno 32] Broken pipe

直接のメッセージは、pythonがリクエスト元に書きこもうとしたら相手がすでに受信待ち状態を終了しているような場合に起きるやつ。esp側では接続したもののヘッダーも取得せずにすぐに終了している。

ちなみにnginxのaccess.logには以下のようにステータス499と（pythonのHTTPServer他で使われている非標準の）クライアントが先に閉じたよというのが残っている。

150.9.94.220 - - [26/Feb/2024:11:31:56 +0900] "GET /api/reserve_count HTTP/1.0" 499 0 "-" "ESP8266"

直接の原因箇所

リクエストを送るesp側でデータの受信待ちをしなくてすぐに閉じているのが直接の原因

BearSSL::WiFiClientSecure client;
client->write("GET ");
client->write(path);
client->write(" HTTP/1.0\r\nHost: ");
client->write(host);
client->write("\r\nUser-Agent: ESP8266\r\n");
client->write("\r\n");
//ヘッダー書き込みの後
//delay(1000);　みたいな待ちがなく
while (client->available()) { // すぐにデータ有無を確認し、おそらくパイソン側の準備ができずに
    char c = client->read();
    Serial.write(c);
}
client->stop();// 終了している

delay(1000);とかを入れたらとりあえず動く。

とはいえ、リクエストを送ったのちにデータ受信後の終了信号的なものをみたらまたはタイムアウトでクローズの方がよさそう。

また、同じ接続方式でself-signed.badssl.comにリクエストを送るとレスポンスがきちんと取得できているのでサーバサイドにも何か改善点がありそう。

根本解決

クライアントサイド(ESP8266)

~~取り急ぎavailable()では接続できたかしか確認していない。~~　WiFiServerSecureBearSSL.cpp（サーバの方）を間違えてみていた。

// Return a client if there's an available connection waiting.  If one is returned,
// then any validation (i.e. client cert checking) will have succeeded.
WiFiClientSecure WiFiServerSecure::available(uint8_t* status) {

改めてWiFiClientSecureBearSSL.cpp確認。

int WiFiClientSecureCtx::_pollRecvBuffer() {
  if (_recvapp_buf) {
    return _recvapp_len;  // Anything from last call?
  }
  _recvapp_buf = nullptr;
  _recvapp_len = 0;
  if (!ctx_present() || _run_until(BR_SSL_RECVAPP, false) < 0) {
    return 0;
  }
  int st = br_ssl_engine_current_state(_eng);
  if (st == BR_SSL_CLOSED) {
    return 0;  // Nothing leftover, SSL is closed
  }
  if (st & BR_SSL_RECVAPP) {
    _recvapp_buf = br_ssl_engine_recvapp_buf(_eng, &_recvapp_len);
    return _recvapp_len;
  }

  return 0;
}

字面で見る限りなんか入ってたら0以外が入って、なにも入っていないとサーバ側が準備中でも一番下に入って0がくるっぽい。だいぶ中の方に書いてあるので内部データを見ると色々多変そうなので最初のデータ来るかタイムアウトまでの待ち処理を入れるのがよさそう。断続的にデータがくるならちゃんと終端処理を見た方がよいかも。

本体から、書き出しメソッド呼び出し。

  client->write("\r\n"); //リクエスト書き込みの最終行

  writeData(client); //時間待ちつつ書き出しメソッド呼び出し

  client->stop();// 切断

void writeData(BearSSL::WiFiClientSecure *client) {
  uint32_t timeout = millis() + 5000;

  while (!client->available()) {
    if (millis() > timeout) return;
    yield();
  }

  while (client->available()) {
    char c = client->read();
    Serial.write(c);
  }
}

サーバサイド(nginx+pythonのHTTPServer)

こちらは単純にレスポンスが早く返りだすかどうかで違いが出ていたっぽい。レスポンスが早いという理由だった場合はクライアント側の処理で解決すべき話なので深く追わない。

あらぶるトラブル

京都伏見桃山にある京都ボルダリングパークロシェ桃山の店長ブログです　@YoshitakeKitamu

日別アーカイブ: 2024年2月26日

ArduinoIDEのRasberry Pi PicoボードマネージャーとWindowsの組み合わせでフォルダを握りっぱなしになっている

環境

状況

事象