Armadilloフォーラム

Bluetoothのアドバタイズパケットを受信できなくなった

tsuyoshi.mori

2024年4月4日 20時06分

お世話になっております。

Armadillo-IoT G3上でセンサーからBluetoothでデータを受信するアプリケーションを動かしていたところ、突然データ受信が突然できなくなりました。

syslog上では、以下のログを最後に、センサーデータを受信できていません。
”Apr 3 10:22:27 armadillo kernel: Bluetooth: hci0 advertising data length corrected“

原因や対策方法についてご教授頂けたら幸いです。

<動作環境>
 Armadillo IoT G3
  Debianのバージョン:buster
 データ受信しているソフトウェア
  pythonで、bleakモジュールを使い作成
  センサーのアドバタイズパケットを受信動作をする

<データ受信しているソフトウェアの挙動>
 2024-04-03 09:50:31 ソフトウェア起動。データ受信を開始して成功する
 2024-04-03 10:22:27 にデータ受信後、2024-04-04 14:55:01までデータ受信に成功していない

<問題発生後、確認したこと>
 センサーは生きている
  -> Windows PCで、センサーがアドバタイズパケットを飛ばしていることを確認した
 Armadillo-IoT G3のBluetoothサービスは動いているが、センサーデータは受信していない
  -> bluetoothctlコマンドを叩き、scan onすると、周囲のデバイスのアドレスを表示した。しかし、センサーのアドレスは表示しなかった

<Armadillo-IoT G3の設定で変更した点>
 Bluetoothと通信するにあたり、一般ユーザーも使えるようbluetooth.confファイルを変更しました

<その他>
 こちらの問題と同様の挙動をしていたのですが、スキャンはできたことからモジュールは止まっておらず、別の問題の可能性もあると考えています。
https://armadillo.atmark-techno.com/index.php/forum/armadillo/19495

syslogとbluetooth.confを添付します。
よろしくお願いいたします。

ファイル ファイルの説明
syslog.zip
bluetooth.conf
コメント

at_syunya.ohshio

2024年4月5日 14時01分

大塩です。

> <問題発生後、確認したこと>
>  センサーは生きている
>   -> Windows PCで、センサーがアドバタイズパケットを飛ばしていることを確認した
>  Armadillo-IoT G3のBluetoothサービスは動いているが、センサーデータは受信していない
>   -> bluetoothctlコマンドを叩き、scan onすると、周囲のデバイスのアドレスを表示した。しかし、センサーのアドレスは表示しなかった

問題発生後 bluetooth.service の再起動を行った場合はどうなるでしょうか。
サービスの再起動は以下コマンドで実行可能です。

root@armadillo:~# systemctl restart bluetooth.service

以上です。

ご返信ありがとうございます。

> 問題発生後 bluetooth.service の再起動を行った場合はどうなるでしょうか。

サービスの再起動のコマンドを実行した後、センサーデータを受信するようになりました。
しかし、再度停止してしまいました。

at_syunya.ohshio

2024年4月9日 18時20分

大塩です。

> サービスの再起動のコマンドを実行した後、センサーデータを受信するようになりました。
> しかし、再度停止してしまいました。

こちらでもアドバタイズパケットを出した状態のBLEセンサーを設置して確認していますが、現状では hcitool lescan コマンドから見えない状態にはなっていません。

頂いたログでは30分ほどでセンサーデータが受信できない状況になっているように見えますが、現象発生ごとに受信可能時間は変わるでしょうか。
また現象を見ると、Bluez のサービスによる現象のように見えるため、現状の対策としては数回連続でセンサーとの通信が失敗した段階でbluetooth.service をリスタートさせる処理を加えるのが良いかもしれません。

以上です。

> 頂いたログでは30分ほどでセンサーデータが受信できない状況になっているように見えますが、現象発生ごとに受信可能時間は変わるでしょうか。
詳細な時間は計測していないのですが、2回目もすぐに停止してしまいました。

ArmadilloはAGX3144-D00Zを利用しているのですが、新製品はBT5.0に対応していることを見ました。
https://armadillo.atmark-techno.com/news/notices/202211_aiotg3_ax1

新製品のAGX3140-D20Zも手元にあり、こちらで今動かしてみたところ、1日経過しても動き続けていました。
モジュールによる挙動の違いがある可能性はありますか?

at_syunya.ohshio

2024年4月12日 17時05分

大塩です。

> ArmadilloはAGX3144-D00Zを利用しているのですが、新製品はBT5.0に対応していることを見ました。
> https://armadillo.atmark-techno.com/news/notices/202211_aiotg3_ax1
>
> 新製品のAGX3140-D20Zも手元にあり、こちらで今動かしてみたところ、1日経過しても動き続けていました。

以下を確認すると、現象の発生しているコンボモジュールは AEH-AR9462-LX を使用しているということでよろしいでしょうか。
https://armadillo.atmark-techno.com/sites/armadillo.atmark-techno.com/f…

現状こちらでも動作確認を続けていますが、AEH-AR9462-LX で bluetoothctl をした場合、アドバタイズパケットを送信する機器が近くに存在する場合は以下のようなログが表示され続けるという理解でよろしいでしょうか。

[CHG] Device D1:2B:63:EE:54:1A ManufacturerData Key: 0xXXXX
[CHG] Device D1:2B:63:EE:54:1A ManufacturerData Value:
  01 07 b1 09 41 12 5b 01 8d 81 0f 00 5c 16 12 00  ....A.[.....\...
  08 02 ff                                         ...

以上です。

回答が遅くなり申し訳ございません。

> 以下を確認すると、現象の発生しているコンボモジュールは AEH-AR9462-LX を使用しているということでよろしいでしょうか。
> https://armadillo.atmark-techno.com/sites/armadillo.atmark-techno.com/f…

購入後、内部のモジュールの変更などはしていないので、AEH-AR9462-LXを使用していると思います。
もしコマンドなどで把握する方法があれば教えて下さい。確認いたします。

> 現状こちらでも動作確認を続けていますが、AEH-AR9462-LX で bluetoothctl をした場合、アドバタイズパケットを送信する機器が近くに存在する場合は以下のようなログが表示され続けるという理解でよろしいでしょうか。

いいえ。
受信できなくなった後、bluetoothコマンドでスキャンを実行し、デバイスの検出ができることを確認しました。
しかし、その中にアドバタイズパケットのログは表示されませんでした。

[NEW] Device 10:D0:7A:89:89:3E 10-D0-7A-89-89-3E
[CHG] Device 04:EC:D8:18:3D:36 RSSI: -55
[CHG] Device CC:4B:73:4D:BF:53 RSSI: -72

at_syunya.ohshio

2024年4月16日 14時43分

大塩です。

各種情報ありがとうございます。

こちらでは以下Howtoに記載しているアドバタイズパケットを用いた動作確認を行っていますが、少なくとも4時間以上はログが取得され続けるため現象が発生していない状況ですので、30分ほどで発生する本件の現象は確認できていません。
https://armadillo.atmark-techno.com/howto/armadillo_2JCIE_Advertising

本件と関係性があるかはわかりませんが、 scan on を数日以上かけて置いておいた場合に
scan onでのセンサーが見えなくなる状態となる現象は発生しました。
この際、bluetooth サービスの restart によって現象が治っていることも確認しています。
お客様のアプリケーションで bluetooth スキャンをし続けているということはあるでしょうか。

以上です。

> こちらでは以下Howtoに記載しているアドバタイズパケットを用いた動作確認を行っていますが、少なくとも4時間以上はログが取得され続けるため現象が発生していない状況ですので、30分ほどで発生する本件の現象は確認できていません。
> https://armadillo.atmark-techno.com/howto/armadillo_2JCIE_Advertising

なるほど。確認ありがとうございます。

> 本件と関係性があるかはわかりませんが、 scan on を数日以上かけて置いておいた場合に
> scan onでのセンサーが見えなくなる状態となる現象は発生しました。
> この際、bluetooth サービスの restart によって現象が治っていることも確認しています。
> お客様のアプリケーションで bluetooth スキャンをし続けているということはあるでしょうか。

PythonのBlakeモジュール経由で、スキャンをし続けてはいます。

すみません、訂正です。

PythonのBleakモジュール経由で、スキャンをし続けてはいます。

at_syunya.ohshio

2024年4月18日 16時07分

大塩です。

情報ありがとうございます。

AGX3140-D20Z 接続の AEH-AR9462-LXB で連続スキャンの動作確認を行っていますが、今のところ現象は発生していません。
頂いた情報等から AEH-AR9462-LX でのみ発生する現象とかと思います。

今後の対応としましては、以下を行うのはいかがでしょうか。
・AGX3140-D20Z にて、お客様のアプリケーションでの連続動作検証を行い、現象が発生するかの調査
・発生した場合のワークアラウンドとして、連続でアドバタイズパケットの取得に失敗した場合は bluetooth.service をリスタートする処理を追加

以上です。

確認ありがとうございます。

①AGX3140-D20Z にて、お客様のアプリケーションでの連続動作検証を行い、現象が発生するかの調査

AGX3140-D20Zを2台用意し、Debian10とDebian12を入れて連続稼働検証を実施しました。

9日から17日の8日間連続稼働していましたが、17日 20:11:18にDebian10を入れたAGX3140-D20ZでBluetoothサービスが停止しました。

Apr 17 20:11:18 armadillo kernel: Out of memory: Kill process 32000 (NetworkManager) score 278 or sacrifice child
Apr 17 20:11:18 armadillo kernel: Killed process 32000 (NetworkManager) total-vm:354768kB, anon-rss:282664kB, file-rss:0kB, shmem-rss:0kB

----

これまでで、計3台で連続稼働テストを実施しました。

テスト機A(最初にデータ受信ができなかったもの)
- 型番:AGX3144-D00Z
- OS:Debian10

テスト機B(今回稼働させて、データ受信できなくなったもの)
- 型番:AGX3144-D20Z
- OS:Debian10

テスト機C
- 型番:AGX3144-D20Z
- OS:Debian12

テスト機Cは、現在もまだ稼働しています。
OSのバージョンが原因であることは考えられますか?

- テスト機Bのソフトウェアバージョン

root@armadillo:~# hostnamectl
IPVS: Creating netns size=912 id=8
   Static hostname: armadillo
         Icon name: computer
        Machine ID: f12a97b8b688446eb2df771a3fcf87d2
           Boot ID: ee0f0f0a5913472d88c9411b2fbac101
  Operating System: Debian GNU/Linux 10 (buster)
            Kernel: Linux 4.9.133-at28
      Architecture: arm

※テスト機Aと同じイメージを入れて、動かしていました。

- テスト機Cのソフトウェアバージョン

root@armadillo:~# hostnamectl
IPVS: Creating netns size=912 id=6
 Static hostname: armadillo
       Icon name: computer
      Machine ID: 6ec5a7b39d134c53adf80e26bd08abd8
         Boot ID: f369fd40d1ab4ac3a65d59361b29e45c
Operating System: Debian GNU/Linux 12 (bookworm)
          Kernel: Linux 4.9.133-at28
    Architecture: arm

②発生した場合のワークアラウンドとして、連続でアドバタイズパケットの取得に失敗した場合は bluetooth.service をリスタートする
テスト機Bに対し、bluetooth.serviceのリスタートをしました。

操作が悪かった可能性もありますが、リスタートでは復帰しなが原因であるこですが、bluetoothコマンドを叩きscan startするとスキャンできるようになりました。

at_syunya.ohshio

2024年4月19日 19時07分

大塩です。

動作検証ありがとうございます。

> OSのバージョンが原因であることは考えられますか?
恐らくですが、Linux 6.1 に上げたことで bluez のバージョンが上がっていますので、bluez のバージョン違いによる差分で現象の発生有無がある可能性はあります。

> ②発生した場合のワークアラウンドとして、連続でアドバタイズパケットの取得に失敗した場合は bluetooth.service をリスタートする
> テスト機Bに対し、bluetooth.serviceのリスタートをしました。
>
> 操作が悪かった可能性もありますが、リスタートでは復帰しなが原因であるこですが、bluetoothコマンドを叩きscan startするとスキャンできるようになりました。

bluetooth.service のリスタートだけでは復帰しない場合があるということでよろしいでしょうか。

以上です。

すみません、回答ありがとうございます。

> > OSのバージョンが原因であることは考えられますか?
> 恐らくですが、Linux 6.1 に上げたことで bluez のバージョンが上がっていますので、bluez のバージョン違いによる差分で現象の発生有無がある可能性はあります。

バージョンを確認したところ、確かにイメージごとにbluezのバージョンが違っていました。

- Debian10のテスト機A、Bは5.50
- Debian12のテスト機Cは5.66

> bluetooth.service のリスタートだけでは復帰しない場合があるということでよろしいでしょうか。

はい。
ただまた止まったら、もう一度試してみたいと思います。