FanLinc not reporting speed

[Juggler00]

Running v0.6.7. The FanLinc does not seem to be reporting its speed. When I turn the FanLinc ON (speed to LOW):
insteon/aa.bb.cc/fan/state: b'ON'

If I change speed from LOW to MEDIUM, same message:
insteon/aa.bb.cc/fan/state: b'ON'

[TD22057]

1. Did it work before?
2. What's the mqtt config file entry for fan_linc?
3. Can you show the log messages around that command?

The default config entry for fan_linc only publishes on/off on the fan/state topic. It publishes the speed on fan/speed. So you may want to check the config first and make sure that the fan_state_payload input is set to output speed variable.

ps: I'm in the process of writing test cases for the fan_linc mqtt class now and think I found a bug in the set speed mqtt input. Once I finish the tests and update the dev branch, it would be great if you could help test it (I don't own a fanlinc so I have to code from the spec file only).

[Juggler00]

The log message I put in my first post is what I received on HA. This was the only message; no speed one.

1. To be honest, I'm not sure. I imported > 70 Insteon devices and have slowly been testing. It's winter here, so haven't had much chance to turn the fan on until I saw the fast on/off being added.

2. Here are the 2 config files (Insteon-mqtt and HA):
   insteon-mqtt:

 fan_linc:
    fan_state_topic: 'insteon/{{address}}/fan/state'
    fan_state_payload: '{{on_str.upper()}}'

    fan_on_off_topic: 'insteon/{{address}}/fan/set'
    fan_on_off_payload: '{ "cmd" : "{{value.lower()}}" }'

    fan_speed_topic: 'insteon/{{address}}/fan/speed/state'
    fan_speed_payload: '{{level_str}}'

    fan_speed_set_topic: 'insteon/{{address}}/fan/speed/set'
    fan_speed_set_payload: '{ "cmd" : "{{value.lower}}" }'

HA:

- platform: mqtt
  name: "office fanlinc fan"
  command_topic: 'insteon/aa.bb.cc/fan/set'
  state_topic: 'insteon/aa.bb.cc/fan/state'
  speed_command_topic: 'insteon/aa.bb.cc/fan/speed/set'
  speed_state_topic: 'insteon/aa.bb.cc/fan/state'

3. Looking at the log, it does appear the message is published. Perhaps the problem is on the HA end?

Feb 28 07:20:10 Protocol-Pi insteon-mqtt[489]: 2019-02-28 07:20:10 DEBUG Mqtt: MQTT publish insteon/aa.bb.cc/fan/state ON qos=1 ret=1
Feb 28 07:20:10 Protocol-Pi insteon-mqtt[489]: 2019-02-28 07:20:10 DEBUG Mqtt: MQTT publish insteon/aa.bb.cc/fan/speed/state low qos=1 ret=1

Happy to help with any testing. Running insteon-mqtt on a Raspberry Pi, HA in a pyvenv on a server.

[TD22057]

Look at the fan_state payload template:

    fan_state_payload: '{{on_str.upper()}}'

on_str is "on" or "off" so that's what it's going to report. In HA, the speed state topic should be fan/speed/state - that's the topic that has the speed in it. I think the comment in the default config for fan_linc is wrong - it should be the fan/speed/state instead of fan/state. I'll fix the comment.

[Juggler00]

That helps... I can now see to speed settings–thank you!

Not sure I if you want me to file this as a separate issue, but when I send a command through insteon-mqtt to change the fan (on/off, speed), there is no MQTT message broadcasting the final state. What this means is that if I turn a fan on to medium directly from HA, HA never sees that the fan is on and does not display accordingly.

Here is a log of this exact scenario:

Feb 28 12:54:21 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:21 INFO FanLinc: FanLink fan on/off message insteon/3f.85.1f/fan/set b'ON'
Feb 28 12:54:21 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:21 DEBUG MsgTemplate: Input template render: '{ "cmd" : "on" }'
Feb 28 12:54:21 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:21 INFO FanLinc: FanLink fan on/off input command: {'cmd': 'on'}
Feb 28 12:54:21 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:21 DEBUG MsgHistory: Average hops 2.0, using 2
Feb 28 12:54:21 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:21 INFO Protocol: Write message to modem: Ext: 3f.85.1f, Type.DIRECT ext, 11 3a 02 00 00 00 00 00 00 00 00 00 00 00 00 00
Feb 28 12:54:21 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:21 DEBUG Protocol: Write bytes to modem: b'\x02b?\x85\x1f\x1a\x11:\x02\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb3'
Feb 28 12:54:21 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:21 DEBUG Serial: Wrote 22 bytes to serial /dev/ttyUSB0
Feb 28 12:54:21 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:21 INFO Protocol: Read 0x62: Ext: 3f.85.1f, Type.DIRECT ext, 11 3a ack: True 02 00 00 00 00 00 00 00 00 00 00 00 00 b3
Feb 28 12:54:21 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:21 DEBUG Protocol: Passing msg to write handler: StandardCmd handler
Feb 28 12:54:21 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:21 DEBUG StandardCmd: 3f.85.1f got msg ACK
Feb 28 12:54:21 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:21 INFO FanLinc: FanLink fan on/off message insteon/3f.85.1f/fan/speed/set b'medium'
Feb 28 12:54:21 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:21 DEBUG MsgTemplate: Input template render: '{ "cmd" : "medium" }'
Feb 28 12:54:21 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:21 INFO FanLinc: FanLink fan on/off input command: {'cmd': 'medium'}
Feb 28 12:54:21 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:21 DEBUG MsgHistory: Average hops 2.0, using 2
Feb 28 12:54:21 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:21 INFO Protocol: Read 0x50: Std: 3f.85.1f->49.f9.07 Type.DIRECT_ACK cmd: 11 3a
Feb 28 12:54:21 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:21 DEBUG Protocol: Setting next write time: 1551376462.060609
Feb 28 12:54:21 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:21 DEBUG MsgHistory: Received 0 hops, total 6 for 4 entries
Feb 28 12:54:21 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:21 DEBUG Protocol: Passing msg to write handler: StandardCmd handler
Feb 28 12:54:21 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:21 DEBUG FanLinc: FanLinc fan 3f.85.1f ACK: Std: 3f.85.1f->49.f9.07 Type.DIRECT_ACK cmd: 11 3a
Feb 28 12:54:21 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:21 DEBUG Protocol: Write handler finished
Feb 28 12:54:21 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:21 INFO Protocol: Write message to modem: Ext: 3f.85.1f, Type.DIRECT ext, 11 bf 02 00 00 00 00 00 00 00 00 00 00 00 00 00
Feb 28 12:54:21 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:21 DEBUG Protocol: Write bytes to modem: b'\x02b?\x85\x1f\x1a\x11\xbf\x02\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00.'
Feb 28 12:54:22 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:22 DEBUG Serial: Wrote 22 bytes to serial /dev/ttyUSB0
Feb 28 12:54:22 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:22 INFO Protocol: Read 0x62: Ext: 3f.85.1f, Type.DIRECT ext, 11 bf ack: True 02 00 00 00 00 00 00 00 00 00 00 00 00 2e
Feb 28 12:54:22 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:22 DEBUG Protocol: Passing msg to write handler: StandardCmd handler
Feb 28 12:54:22 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:22 DEBUG StandardCmd: 3f.85.1f got msg ACK
Feb 28 12:54:22 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:22 INFO Protocol: Read 0x50: Std: 3f.85.1f->49.f9.07 Type.DIRECT_ACK cmd: 11 bf
Feb 28 12:54:22 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:22 DEBUG Protocol: Setting next write time: 1551376462.682569
Feb 28 12:54:22 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:22 DEBUG MsgHistory: Received 0 hops, total 6 for 5 entries
Feb 28 12:54:22 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:22 DEBUG Protocol: Passing msg to write handler: StandardCmd handler
Feb 28 12:54:22 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:22 DEBUG FanLinc: FanLinc fan 3f.85.1f ACK: Std: 3f.85.1f->49.f9.07 Type.DIRECT_ACK cmd: 11 bf
Feb 28 12:54:22 Protocol-Pi insteon-mqtt[489]: 2019-02-28 12:54:22 DEBUG Protocol: Write handler finished

Should there be a final message from the FanLinc saying "I'm on, here is my speed"?

[TD22057]

Yes - devices should update their state (which emits an mqtt message on the state topic) when the ACK arrives. Let me take a look since I'm in the middle of writing unit tests for the fan linc right now. It may be the bug I found in the initial set of tests fixes this - I'll check.

[Juggler00]

Let me know if I can do any testing on a "live" FanLinc.

[TD22057]

This has been fixed (b941a4e) and pushed to the dev branch. Looks like I accidentally removed the line that updated the speed when I was cleaning up some logging messages recently. If you want to test it out, please grab the dev branch and try it.