# Cube J1 から Grafana に送った電力グラフの途切れを減らす 2026-10-07 [前編](/articles/cube-j1-grafana)では、Cube J1 と [cube-j1-mqtt](https://github.com/tsuyopon123/cube-j1-mqtt) でスマートメーターの瞬時電力を取り出し、Grafana に送る構成を書きました。 その最後に、グラフが数十分単位で途切れる問題を予告していました。 手元でブリッジを改造して調べ、取得率は改造前の約 2 割から、いまは約 86% になりました。 改造前は 60 秒間隔で理想が 60 回/h、いまは 30 秒間隔で理想が 120 回/h です。 数字はすべて我が家の 1 台で測ったもので、対策の前後は、別の日の同じ時刻帯をそれぞれ 3 時間ずつ比べています。 この記事では、グラフが途切れる原因の見分け方と本家のブリッジの弱点を説明したあと、本家のコードに当てられる最小の修正と、手元の改造版だけで試した対策を分けて書きます。 ## 途切れる原因の見分け方 グラフが途切れる原因には、MQTT の接続が切れて値が届かない場合と、スマートメーターから値を取れていない場合の 2 つがあります。 1 つ目は Mosquitto のログで分かります。 Cube J1 の接続が `exceeded timeout` で切られていれば、こちらです。 ``` Client cubej1_cubej1 [:<ポート>] disconnected: exceeded timeout. ``` 2 つ目はブリッジのログで分かります。 本家のブリッジは `/data/local/mqtt_bridge.log` に時刻付きでログを書いており、メーターの応答を待ちきれなかったときは `No ERXUDP response (timeout)` という行が出ます。 件数ではなく、ログの時刻をグラフが途切れた時刻と突き合わせます。 ```sh adb connect :5555 adb shell grep "No ERXUDP response" /data/local/mqtt_bridge.log | tail -20 ``` 我が家では、改造を始めたころは両方が起きていました。 1 つ目は前編で書いたとおり、約 12 分おきに起きていました。 ## 本家のブリッジの弱点 本家の `mqtt_bridge.py`（commit `3bbb6bf`、2026 年 5 月）を読むと、グラフが途切れる原因になる作りが 3 つあります。 - 1 本のループで「問い合わせ → 最大 15 秒の応答待ち → MQTT の ping → `poll_interval` 秒の待機」を順に回しています。CONNECT で指定した keepalive は 60 秒で、ブローカーはその 1.5 倍の約 90 秒、クライアントから MQTT の制御パケットが届かないと接続を切ります。応答待ちや Wi-SUN の再接続が長引くと、この時間を超えます - 応答がタイムアウトしても、Wi-SUN をつなぎ直しません。つなぎ直すのは例外が出たときだけで、その前に 30 秒待ちます - 応答待ち（`read_erxudp`）は、`1081`（ECHONET Lite のヘッダー）で始まる最初のフレームを今回の応答として受け取ります。メーターが自分から送ってくる通知や、前の問い合わせへの遅れた応答も、そのまま今回の応答として扱います 3 つ目が、我が家で最も多くの値を失っていた原因でした。 ## 本家のコードに当てられる最小の修正 この節の修正は、本家の commit `3bbb6bf` に当てるパッチ [mqtt-bridge-reduce-gaps.patch](/articles/cube-j1-grafana-gaps/mqtt-bridge-reduce-gaps.patch) にまとめました。 リポジトリの直下で `git apply mqtt-bridge-reduce-gaps.patch` を実行すれば当たります。 同じ処理は、改造版で 2026 年 7 月から動かしています。 本文には、応答を読む `read_erxudp` の断片だけを載せます。 この断片は、実機の Python 2.7.13 で、INF、TID が一致しない応答、Get_SNA、Get_Res の 4 種類の ERXUDP 行を流し、意図どおりに動くことを確かめました。 ### 応答の種類と TID を確かめる 改造版では、応答の TID が一致しないフレームを受け取ると、それを捨てて、その回の応答待ちも終えていました。 取りこぼしの内訳を知るために、この捨てていたフレームを種類（ESV）、TID、届くまでの遅れの 3 つで分類しました。 6 時間に捨てた 66 件のうち、59% は ESV が 0x73（INF）のフレームでした。 INF は、問い合わせへの応答ではなく、メーターが自分から送ってくるプロパティの通知です。 Wi-SUN をつなぎ直すたびに届いており、1 時間あたりの件数は再接続の回数とほぼ同じでした。 本家のブリッジは INF も今回の応答として受け取ります。 本家の `parse_el_response` は Get_Res（0x72）と Get_SNA（0x52）以外を空として扱うので、INF を受け取ったその回は値を送らずに終わり、本来の応答は読まれません。 改造版で INF を読み飛ばして本来の応答を待ち続けるようにしたところ、変更前の 12.5/h に対して、変更後の 6 時間は 26.2/h（続く夜間の 10 時間は 25.5/h）でした。 タイムアウトは 1 時間あたり約 30 件のまま変わっていません。 下の断片では、TID が送った問い合わせと一致し、ESV が Get_Res か Get_SNA のフレームだけを応答として受け取ります。 TID の照合は、別の fork の [nanamitm/cube-j1-mqtt](https://github.com/nanamitm/cube-j1-mqtt) が入れていたものを参考にしました。 ```python ESV_GET_RES = 0x72 # Get への正常な応答 ESV_GET_SNA = 0x52 # Get への応答（要求されたプロパティの一部またはすべてを返せなかった） def read_erxudp(fd, expected_tid, timeout=15): """expected_tid への応答だけを返す。通知 (INF) や遅れた応答は読み飛ばして待ち続ける。""" deadline = time.time() + timeout while time.time() < deadline: line = serial_readline(fd, timeout=max(0.5, deadline - time.time())) if line is None or not line.startswith("ERXUDP"): continue parts = line.split() if len(parts) < 9 or not parts[-1].startswith("1081"): continue try: # Python 2.7 の str は添字で 1 文字の str を返すので、bytearray にして整数で比べる data = bytearray(binascii.unhexlify(parts[-1].strip())) except Exception as e: log("ERXUDP hex decode error: {}".format(e)) continue if len(data) < 12: continue if ((data[2] << 8) | data[3]) != expected_tid: continue if data[10] not in (ESV_GET_RES, ESV_GET_SNA): continue return data return None ``` 呼び出し側には、TID を進める前の値を渡します。 本家は `send_el_get` の直後で `tid` を進めているので、パッチではその行を `read_erxudp(fd, tid, timeout=15)` のあとに移しています。 いくつか補足します。 - ERXUDP の行の項目数は Wi-SUN モジュールによって違い、本家のコメントによると Cube J1 のモジュールは末尾が ` ` の 10 項目です。本家は `len(parts) >= 10` で判定していますが、データが最後の項目にあることは変わらないので、この断片は 9 項目の形式でも動くよう 9 以上にしています - TID は 16 ビットで一周します。より厳密にするなら、送信元と送信先のオブジェクト（SEOJ / DEOJ）や EPC も照合します - 断片はフレームの形だけを確かめています。本家の `parse_el_response` は、読むときに長さが足りなければそこで読むのをやめますが、値の妥当性までは確かめません ### タイムアウトしたらつなぎ直す 応答がタイムアウトしたら、Wi-SUN をつなぎ直すようにしました。 連続で何回タイムアウトしたらつなぎ直すかを、2 段階で減らしています。 | 比較 | 取得数 | 長い途切れ | |---|---|---| | 6 回 → 2 回（2026-07-03、同じ日の別の時刻帯の各 3 時間） | 17.8/h → 23.3/h | 300 秒超の停止 16 回 → 2 回 | | 2 回 → 1 回（2026-07-05 と 07-06 の同じ時刻帯、各 3 時間） | 41.3/h → 51.2/h | 90 秒超の途切れ 40 件 → 5 件 | あわせて、つなぎ直す前の待ちを 30 秒から 5 秒に縮めました。 同じ時刻帯で比べると、取得数は 23.3/h から 28.1/h になりました。 この期間の再接続は 1 時間に約 11 回で、待ちを 25 秒ずつ縮めると、停止時間は 1 時間に約 275 秒減ります。 これを当時の 60 秒間隔で単純に割ると、約 4.6 回分の問い合わせにあたります。 実測の増加（4.8 回/h）はこれと同じくらいでした。 パッチでは、`main` でタイムアウトが続いた回数を数え、2 回続いたら例外を投げます。 つなぎ直しは、本家にもともとある外側の `except Exception` に任せます。 回数は、応答が取れたときと外側の `except` に入ったときに 0 に戻し、つなぎ直す前の待ちは 30 秒から 5 秒にしています。 つなぎ直すまでの回数は、まず 2 回にするのが安全です。 本家の `wisun_connect` はつなぎ直すたびにすべてのチャネルをスキャンするので、1 回に 30〜40 秒かかります。 また、1 回のタイムアウトでつなぎ直すと、雑音の多い時間帯につなぎ直しが連続することがあります。 我が家で最終的に 1 回まで減らせたのは、後で書く改造版の対策（スキャンを省くつなぎ直しと、雑音の多いときのタイムアウトを数えない仕組み）を先に入れていたからです。 2 回で動かしながら再接続の回数を見て、1 回に減らすかどうかを決めます。 ### keepalive を延ばす 前編で書いた `exceeded timeout` の切断は、まず keepalive を 60 秒から 300 秒に延ばして減らしました。 手元では、切断の頻度が約 5 分の 1 になりました。 本家のブリッジでは、`MQTTClient.connect` が組み立てる CONNECT パケットの可変ヘッダーの末尾に、keepalive の秒数が 2 バイトのビッグエンディアンで書かれています。 パッチでは、ここの `b"\x00\x3C"`（60 秒）を `b"\x01\x2C"`（300 秒）に変えています。 本家は、前回の ping から 50 秒を超えていれば問い合わせのあとに ping を送るので、keepalive を 300 秒にしても ping の間隔はそのままです。 延ばしても、つなぎ直しが長引けば 300 秒を超えることはあります。 ### 問い合わせの間隔を 30 秒にする `config.json` の `poll_interval` を 60 から 30 にしました。 取得数は 51.2/h から 98.7/h に増えました。 理想の回数も 60/h から 120/h に倍になるので、取得できた割合で見ると 85% から 82% へわずかに下がっています。 問い合わせを倍にすると、PANA セッションの切断やタイムアウトが増えるかを心配しました。 この比較では、1 時間あたりの再接続は 1.27 倍になり、問い合わせ 1 回あたりのタイムアウトの割合は 24% から 16% になりました。 別の日の測定なので、30 秒にしたことで割合が下がったとまでは言えません。 30 秒より短くはしていません。 Wi-SUN モジュールのコマンドリファレンスには、ARIB STD-T108 に基づく送信時間の総和の制限があり、制限が発動すると EVENT 32 が出て、以後の送信要求がすべてキャンセルされると書かれています。 手元では問い合わせ以外の通信も考えて、経験的に 30 秒を下限にしました。 ## 手元の改造版だけで試した対策 ここからは、改造版で入れた対策です。 コードが長くなるので、考え方と手順だけを書きます。 ### スキャンを省いてつなぎ直す 前回の接続で得たチャネル、PAN ID、MAC アドレス、メーターの IPv6 アドレスを覚えておきます。 つなぎ直すときは `SKSCAN` と `SKLL64` を省き、次の順にコマンドを送ります。 ``` SKRESET → SKSETPWD（B ルートのパスワード）→ SKSETRBID（認証 ID） → SKSREG S2 <チャネル> → SKSREG S3 → SKJOIN <メーターの IPv6 アドレス> → EVENT 25（接続成功）を待つ。EVENT 24（接続失敗）なら失敗 ``` 2 回続けて失敗したら、覚えた値を捨ててすべてのチャネルのスキャンに戻します。 65 分の検証で、5 回のつなぎ直しはすべて覚えた値で成功し、1 回にかかる時間は 31〜46 秒から 14〜15 秒になりました。 ### 雑音の多いときのタイムアウトを数えない Wi-SUN モジュールのエネルギー検出スキャン（ED スキャン）で、2 分おきにメーターが使うチャネルの電波エネルギーを測ります。 値はチャネルごとに 0〜255 で返り、手元では 100 以上を「雑音が多い」とみなしています。 値が高い原因は雑音に限らず、ほかの機器の送信も含まれます。 雑音が多いときのタイムアウトは、つなぎ直すまでの連続回数に数えません。 「1 回のタイムアウトでつなぎ直す」を雑音の多い時間帯でも使えるようにするための仕組みです。 ### MQTT の送信を別のスレッドに分ける keepalive を延ばしても、メーターとのやり取りが詰まれば ping は遅れます。 改造版では、MQTT の送信と ping をそれぞれ別のスレッドから行い、どちらもソケットに書き込む前に同じロックを取るようにしました。 ロックを取らずに 2 つのスレッドから書き込むと、パケットが混ざるおそれがあります。 その後は、91 日間で MQTT の再接続が 5 回だけになりました。 ## 効果がなかった対策 試したものの、効果がなかったり取り消したりした対策もあります。 - **応答がないときの再送**: 同じ問い合わせを送り直しても、ほとんど救えませんでした。5 時間で 490 回送り直し、救えたのは 2 回（0.4%）です。再送が多すぎてメーターの処理を詰まらせているのではとも疑いましたが、再送をやめてもタイムアウトの件数は変わりませんでした - **決まった時間で先回りしてつなぎ直す**: セッションが切れる前に、こちらから計画的につなぎ直す案です。先回りで防げた不意の再接続は 29% にとどまり、計画的なつなぎ直しのたびに 1 回分の問い合わせを失うので、取得数は 27.0/h から 26.7/h と変わりませんでした - **1 つのチャネルだけをスキャンする**: つなぎ直しのスキャンを、前回のチャネルだけに絞る案です。我が家では 10 回試して 1 回も PAN が見つからず、毎回すべてのチャネルのスキャンに戻っていました。上で書いた「スキャンを省く」方法に切り替えました - **SFF と SKSAVE で設定を FLASH に保存する**: つなぎ直しをさらに 1〜2 秒縮める狙いでした。ところが、レジスタ SFF の値は `SKRESET` で初期化されるので、SFF を見て保存済みかを判断する作りでは、つなぎ直しのたびに `SKSAVE`（FLASH への書き込み）を発行していました。公式資料にある FLASH の書き換え保証回数 1 万回で計算すると、1 時間に 30 回つなぎ直せば約 14 日で達するので、38 分で取り消しました ## いまの取得率と分かっていないこと 10 月初めの直近 20 日間では、取得数は約 103/h で、理想の 120/h の約 86% です。 残りの欠損の多くは、応答タイムアウトのあとの Wi-SUN の再接続中に起きています。 ただし、タイムアウトの時点で PANA セッションが本当に切れていたかは確かめていません。 再接続は 1 時間に約 21 回起き、そのたびにグラフの値の間隔が普段より延びます。 延びる時間は、速い場合で約 21 秒で、これが 9 割を占めます。 残りの 1 割は 1 回目のつなぎ直しに失敗した場合で、約 92 秒延びます。 平均すると 1 回あたり約 28 秒です。 延びた時間の合計を問い合わせの間隔の 30 秒で割る概算では、1 時間に約 20 回分（21 × 28 ÷ 30 ≈ 19.6）を失います。 問い合わせの時刻とのずれを無視した粗い概算ですが、120 − 20 = 100 で、実測の約 103/h と近い値です。 48 日間、Wi-SUN モジュールの送信結果のイベント（EVENT 21）を約 14 万 7 千件記録し、すべてが送信成功（PARAM=0）でした。 コマンドリファレンスによると、ユニキャストでの PARAM=0 は、送信相手から無線の Ack（受信確認）を受け取ったことを表します。 つまり問い合わせは、少なくともメーターの無線モジュールまでは届いています。 メーターがその問い合わせを処理して応答を送ったかまでは分かりません。 応答が返らない原因が、メーターの中とメーターからの無線のどちらにあるかは、まだ切り分けられていません。 少なくとも、今回試した再送や再接続の工夫では、これ以上大きくは減らせませんでした。 本家のブリッジを使っているなら、まずパッチを当てるのが手軽です。 問い合わせの間隔を 30 秒にするかどうかは、そのあとで取得数を見て決めます。