自宅LAN内において、少し古いAndroid端末が数分毎にWi-Fiから切断される問題があった。
この記事ではADB（android debug bridge）を用いたデバッグログとWi-Fiルーター/AP（access point）の設定変更で問題の原因の絞り込みと、回避するための構成について説明する。
検証では真の原因を特定できなかったが、次の対応策が有効だった。
Androidバージョン11端末が接続するSSID（service set identifier）においては、IPv6を無効化した上でWPA（wi-fi protected access）3を使わない。
発生していた問題
少し古いAndroidバージョン 11の端末が数分毎にWi-FiのSSIDとの接続で解除される。
調査方法と試行錯誤のログ
ADBを用いてPCでログを確認するための準備
最初にPCでADBが使えることを確認する。
ADBはAndroid Studioに同梱されているが、「SDK Platform-Tools」として、ツール群単体でのダウンロードも可能である。
詳細は次のリンクを参照せよ。
SDK Platform Tools release notes | Android Studio | Android Developers
次に、Android端末を操作し「開発者向けオプション」を有効化した上で、「USBデバッグ」を有効化する。
詳細な手順はAndroid公式のドキュメントを参照せよ。
PCと調査対象のAndroid端末をUSBケーブルで接続して、Android側でUSBデバッグを許可する。
次のようにlogcatサブコマンドでログが出力されることを確認する。
./adb logcat
IPv6有効時のIpReachabilityMonitorのバグ発見と対処
ADBのlogcatで、Wi-Fiが切断される直前に次のようなログが出力されていることを発見した。
なお、MACアドレス、IPアドレスなどの情報は*などでマスクしている。
SSIDでのIPv6が有効な状態においてWi-Fi接続が切れる直前にlogcatで出力された内容
01-01 21:54:07.286 2015 27567 W IpClient.wlan0: [IpReachabilityMonitor] WARN ALERT neighbor went from: NeighborEvent{@124682102,RTM_NEWNEIGH,if=32,*.*.*.*,NUD_PROBE,[**:**:**:**:**:**]} to: NeighborEvent{@124692083,RTM_NEWNEIGH,if=32,*.*.*.*,NUD_FAILED,[null]}
01-01 21:54:07.288 2015 27567 W IpReachabilityMonitor: FAILURE: LOST_PROVISIONING, NeighborEvent{@124692083,RTM_NEWNEIGH,if=32,*.*.*.*,NUD_FAILED,[null]}, NUD event type: NUD_ORGANIC_FAILED_CRITICAL
01-01 21:54:07.310 27565 27565 I wpa_supplicant: wlan0: CTRL-EVENT-DISCONNECTED bssid=**:**:**:**:**:** reason=3 locally_generated=1
この問題はIssueTrackerで報告されている。
いまいち的を得た回答が返されていないが、どうやらAndroidのOSの一要素であるIpReachabilityMonitorのバグが原因のようだ（確信なし）。
IpReachabilityMonitorはネットワーク的に接続性が維持されているか否か確認するモジュールのようだ。
IpReachabilityMonitorはゲートウェイ（GW: gateway）に向かって定期的にneighbor discoveryを行い、レスポンスを一定時間以内に受信できない場合は現在のWi-Fi接続を切断するようだ。
上のログではマスクしているが、IPv4アドレスに対してIPv6のneighbor discoveryを試みているかのようなログ内容が大変怪しい。
Google Issue Tracker
ワークアラウンドとして、「SSIDでIPv6を無効化し、IPv4のみで通信させるよう設定」したところ、上記の理由で切断されることは無くなった。
古いバージョンのwpa_supplicantがWPA3を理解できない問題の発見と対処
上記の設定でIpReachabilityMonitorによりWi-Fi接続が切断されることは無くなったが、数分毎に切断される事象自体は解消していない。
引き続きlogcatでログを監視し、切断直前に次の内容が表示されていることを発見した。
WPA3-Personalが有効なSSIDでWi-Fi接続が切れる直前にlogcatで出力された内容
01-02 14:53:36.835 7059 7059 I wpa_supplicant: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=**:**:**:**:**:** status_code=40
ここではログの表示内容に特に注目する。
先頭のwpa_supplicantはアプリケーションである。
名前通りにWPA等のWi-Fiの認証を処理するクライアントである。
これはLinuxで広く使われているから、調べれば詳細が得られる。
続いて、末尾のstatus_code=40に注目する。
この番号は「802.11 Association Status Codes」と呼ばれ、名前から分かる通りIEEEで標準化されているようだ。
だから実装に寄らず意味は共通である。
原典はIEEE文書であり、無料で参照できない可能性が高いから代わりのリンクを次に記載しておく。
802.11 Association Status Codes & Codes
40の意味は次のように定義されていた。
Invalid information element, i.e., an information element defined in this standard for
which the content does not meet the specifications in Clause 7
つまり、wpa_supplicantはWi-Fiルーター/APの示す情報が規格違反だと思っているようだ。
恐らく、Androidバージョンが低いために同梱されているwpa_supplicantもバージョンが低く、WPA3への対応が不完全なのだろう。
不本意だが、このAndroid端末用に「WPA2-PersonalのSSIDを用意する」ことで解決した。
付録
ADBのlogcatでは非常に大量のログが出力されるために、Wi-Fiに関連するログだけを抽出することが難しい。
万能ではないが、手掛かりや糸口を掴むために有用かもしれないヒントを残しておく。
wpa_supplicantに注目する
上で説明した通り、wpa_supplicantはWi-Fiの認証を処理するプログラムである。
ほとんどの場合、SSIDへの接続に先立って認証が行われるから、とりあえずwpa_supplicantのログを監視しておけば「頻繁に切断・再接続が行われているか」を確認できる。
logcatサブコマンドは-sオプションでフィルタができるから、以下のようにして絞り込むと良い。
./adb logcat -s wpa_supplicant
その他のフィルタ方法や詳細は./adb logcat --helpや公式のドキュメントを参照せよ。
全て取得して要らないものだけ落とす
Wi-Fiは複数のモジュールやプログラムが協調して動作しているために、単純に特定の文字列を含むログだけ見ていると真の原因を見逃す危険性がある。
例えば、単純に「wifi」を含む行だけを抽出しても情報が得られない。
「wlan」や上記「wpa_supplicant」、「IpReachabilityMonitor」などいくつもの要因がある。
そこで、「とりあえず全てのログを取得し、明らかに無関係のログだけを除外する」調査方針が有効だ。
logcatの出力をパイプでつないで、フィルタコマンドで除外するやり方が良いだろう。
WindowsではLinuxの定番のフィルタコマンド群が使えないから、代わりにSelect-Stringを使うと良い。
今回の調査では以下のようなログを除外した。
# logcatで全てのログをそのままパイプに流し、Select-Stringで'MEMSIC_Calibrating', 'sunwave', 'HWCDisplay'が含まれないログだけを出力する
./adb logcat | Select-String -Pattern 'MEMSIC_Calibrating', 'sunwave', 'HWCDisplay' -NotMatch
