hsakoh/switchbot-mqtt

Ceiling Light ProのPowerStatusが正しく反映されない

hirocho-t opened this issue · 7 comments

MqttCoreServiceのstart時とwebhookの受信時に正しく反映されないのですが、仕様上仕方がないものでしょうか?

添付画像1はCeiling Light Proで最後のbrightnessが59の状態でOFFにした状態から、下記の1,2を実行したものです。
1.純正リモコンのON/OFFボタンを押してONにした。
2.純正リモコンの「明るい」ボタンを押して明るくした(内部的にはbrightnessが77に変更)
添付画像1
webhookのログからpowerStateの値がONになっているのに画面上ではクリアのまま変わりません。brightnessは59から77に変わりました。

また画面上のPollingの「押す」を押すと正しく反映されます。(添付画像2)
添付画像2

アドオンのv1.0.15以前のマスタ定義に誤りがありました。
具体的には、シーリングライトProの センサー powerが、statusAPIのみを参照し、webhookを参照しないという設定になってました。
これはv1.0.16にて修正されています。

デバイス取得時にマスタデータを個別の内部デバイスデータとして永続化するつくりのため、
v1.0.15以前にデバイスを取得し構成していた場合、マスタの変更が個別の内部デバイスデータに反映されません。
そのためWebhookを受信しても、MQTTメッセージに送信されないという事象が発生していると思われます。

リリースノートには記載しましたが、

  1. MQTT デバイスを一度 削除
  2. Ingress ページでデバイスを削除・再取得・再構成
  3. アドオンを再起動
    で改善されると思います。

今回のケースでは1.は不要と思いますが、もし 2.~3. を行って改善しない場合、1.~3.の順序で試してみてください。

もし、v1.0.16以降に構成したデバイスの場合、何か想定外の事象が起きているので、
ログレベルをVerboseにして、もう少し詳細なログをご提供いただきたいです。

数日前に追加されたarmv7:1.0.17でraspbianにdockerで昨日構築が完了した環境になります(環境構築ができるまでの推移は某掲示板で見ていただけたのかと思います)

指示された1.~3.の手順に該当すると思われる操作を下記のように実行しましたが現象は変わりませんでした。

1.MQTT Explorerを使いhomeassistant/(component)/.*Ceiling Light ProのデバイスID.*となっているTopicをすべて削除し、MQTT統合から削除されたのを確認しました。
2.SwitchBotMqttAppからMqttCoreService、WebhookServiceをStopし、「Fetch Devices by SwitchBotAPI」を押し、一旦すべてのチェックを外しSaveし、改めてCeiling Light Proにチェックをしました。
3.docker containerを再起動し、SwitchBotMqttAppからMqttCoreService、WebhookServiceをStartさせました。

必要なログの取り方がわからないので教えていただけますでしょうか?
_docker-compose\options.jsonのLogLevelをdebugにしてみたのですがどこにログがあるのかわかりませんでした。

必要なログの取り方がわからないので教えていただけますでしょうか?

options.jsonのLogLevelをTraceに設定していただければ出力が増えるかと思います。(Verboseは誤りでした)
(DockerComposeであれば、出力先はコンテナのログとなるかと思います。
最初に貼っていただいたスクリーンショットと同じところです。

また、原因が分かりました。
WebhookとStatusAPIの値に大文字小文字の差異があり、MQTT統合がケースセンシティブであったためです。

Webhookの場合、powerState:ONまたはOFF
StatusAPIの場合、power:onまたはoff

MQTT統合としては、MQTTトピック:homeassistant/binary_sensor/both_power_デバイスID/configを確認いただければわかると思いますが、小文字を設定していました。
payload_on: 'on'
payload_off: 'off'

問題の事象のような、StatusAPI、Webhook両方に値が存在し、具体値が(SwitchBotの仕様上)異なるケースについて、値を小文字化して送信するよう変更しました。
(MQTTトピック:switchbot/デバイスID/status/bothに送る値)

修正し、v1.0.18を先ほどリリースしましたので、そちらで確認ください。

switchbot-mqtt起動時にON/OFF状態、純正リモコンによるON/OFFによるwebhookの反映は正しく動くようになりました。ありがとうございます。

しかし、まだよくわからない動きがあります。
Ceiling Light Proが点灯の状態でswitchbot-mqtt起動しました。
起動後powerは「検出されました」で正しいです。
そこでturnOffボタンを押します。
commandがPOSTされ、実際に消灯しますが、webhookでoffのログが出力されず、powerは「検出されました」のままになります。

そのままtrunOnボタンを押します。
commandがPOSTされ、実際に点灯します。webohookはなぜかoffのログが出力され、powerは「クリア」になります。
(添付画像3 緑色がturnOff、水色がturnOnです)
添付画像3

試しているときにはoffに続けてonのwebhookのログが連続して出力されたりする事もありました。switchbot API側の問題のような気もします。

添付画像1,3のWebhookボディのtimeOfSampleから、
Webhookに含まれる ON/OFF状態の値が逆転しているなどではなく、
Webhookが遅れたり、欠けたりしているという事だと推測しています。

PlugMiniでは、いままで そこまでの遅延した経験はありません。
シーリングライトProの特性なのか、もしくは一時的なサーバー側の問題なのか…

現状アドオンはデバイスのステータスを保持しない(ステートレス)ですので、
(もし遅れたりしても)受信したセンサーデータを最新としてそのままMQTTへ送信します。

通知が欠けたり、順序性が保証されない 事が常だとすると、アドオンの実装で回避が必要そうです。
例えば、内部で状態を持ち、最新の状態でない通知を受信した場合 MQTTに送信しないようにする事が考えられますが…
欠けるのには対応できないですし、大規模な修正となりそうなので、現時点では対応の予定はありません。

実用上は、
・自動ポーリングを有効化し、取得間隔を1時間(PT1H)から、5分(PT5M)等に変更する
・HomeAssistant側でコマンド操作を行った後、ポーリングを行うようなスクリプトを組み込む
等により、実機とMQTTデバイスで状態がずれている時間を短くするなどが考えられます。
(基本的には前者で十分実用レベルとなるのではないか と考えています。)

Webhookの送信速度や正確性については、
(おそらくまともなサポートは受けられないとは思いますが)
SwitchBotのサポートに問い合わせ頂くか、以下のリポジトリでIssueを上げることをお勧めします。
https://github.com/OpenWonderLabs/SwitchBotAPI

追記です。

ColorBulbでも数回 試しましたが、
SwitchBotAPIで操作した場合、Webhookが届かず
スマートフォンアプリで操作した場合、Webhookが届く
という様な挙動をしています。

APIで操作した場合も(Webhookを受信するアプリが異なる可能性があるので、)
常に送信される事が当然の期待値なのですが…

もしかしたらシーリングライトも同様の振舞いかもしれません。
純正リモコン・スマートフォンアプリ・SwitchBotAPI・シーンからON/OFF等 それぞれで、
(Webhookの遅延を排除する為) 1,2分程度時間をあけつつ操作して、どうなるか 見てみたい所です。

(PlugMiniも再確認しましたが、SwitchBotAPIで操作してもWebhookは必ず来ます。)

やはりSwitchbot側の問題っぽいですね。
一時的な問題なのか様子を見つつ、ステータスがズレても問題のない運用をしようと思います。
ありがとうございました。