Open Ricc68 opened 3 months ago
KazWolfe
commented
3 months ago Interesting. I don't necessarily think this is a problem, but curious that your system doesn't know how to handle packet 09.
For now, I think it's safe to treat this as not a bug - but there may be some interesting implications from this as well.
Sammy1Am
commented
3 months ago Yeah, no concerns that I would be aware of. The only implication is that you'll have a 3-second delay occasionally while it's timing out waiting for that packet (so if you tried to change something during that window, you'd have to wait up to 3 seconds longer than usual for the system to respond).
Wouldn't be too hard to add a config in in the ESPHome config to selectively disable certain packets.
KazWolfe
commented
3 months ago Wonder if it'd be good to scope in something like n sequential failures to get a packet removes it from the polling loop. Could be good to do around the same time we look at (properly) throttling certain request types.
But I'm also obsessed with autoconf and "flash firmware, plug in, enjoy" sooo
Ricc68
commented
3 months ago Thats an idea. Another idea is: can this lack of 42 packet be used to autodetect something about the unit? For example if the 42 packet is missing maybe we can infer that the unit supports a certain set of features and not others.
paravoid
commented
1 month ago I have an MSZ-FD25VA unit, and my logs are being spammed with these messages as well. I was running echavet's code before without any issues. I tried increasing RESPONSE_TIMEOUT_MS from 3000 to 5000, but still got no response.
I also have an MSZ-FD50VA running echavet's code on an ESP32-C3 I can run tests on, if that helps.
KazWolfe
commented
1 month ago @paravoid What packet is being requested (in the OP's case, it's [FC.42.01.30.01]09 83).
If this is packet 09 again, see above in the chain. As long as communication works otherwise, this means your heat pump likely just doesn't support that packet. I'm not sure why this would be the case, and more gracefully handling this is still on the todo list, but it likely can be ignored.
paravoid
commented
1 month ago I'm not entirely sure how to see this? Is there a verbosity setting I need to set or something? (I have the default logger which I believe is DEBUG). All I see in the logs is:
[00:06:22][I][mitsubishi_uart:036]: Heatpump connected.
[00:06:27][I][mitsubishi_uart:052]: Received heat pump identification packet.
[00:06:31][W][muart_bridge:051]: Timeout waiting for response to 42 packet.
[00:06:32][D][climate:396]: 'Climate' - Sending state:
[00:06:32][D][climate:399]: Mode: COOL
[00:06:32][D][climate:401]: Action: COOLING
[00:06:32][D][climate:404]: Fan Mode: AUTO
[00:06:32][D][climate:419]: Current Temperature: 23.00°C
[00:06:32][D][climate:425]: Target Temperature: 24.00°C
[00:06:32][D][select:015]: 'Vane Position': Sending state Auto (index 0)
[00:06:32][D][select:015]: 'Horizontal Vane Position': Sending state | (index 3)
[00:06:32][I][mitsubishi_uart:189]: Compressor frequency differs, do publish
[00:06:32][D][sensor:094]: 'Compressor Frequency': Sending state 6.00000 Hz with 0 decimals of accuracy
[00:06:32][I][mitsubishi_uart:197]: Error code state differs, do publish
[00:06:32][D][text_sensor:064]: 'Error Code': Sending state 'No Error Reported'
[00:06:32][D][binary_sensor:036]: 'Service Filter': Sending state OFF
[00:06:32][D][binary_sensor:036]: 'Defrost': Sending state OFF
[00:06:32][D][binary_sensor:036]: 'Hot Adjust': Sending state OFF
[00:06:32][D][binary_sensor:036]: 'Standby': Sending state OFF
[00:06:32][D][binary_sensor:036]: 'i-see Status': Sending state OFF
[00:06:32][W][component:237]: Component mitsubishi_uart took a long time for an operation (80 ms).
[00:06:32][W][component:238]: Components should block for at most 30 ms.
[00:06:36][W][muart_bridge:051]: Timeout waiting for response to 42 packet.
[00:06:40][W][muart_bridge:051]: Timeout waiting for response to 42 packet.
[00:06:45][W][muart_bridge:051]: Timeout waiting for response to 42 packet.@paravoid Yep, you'll need to decrease the log level to VERBOSE. It's probably a good idea to log what caused the timeout though, I'll try to get that added relatively soon.
paravoid
commented
1 month ago Decrease the log level? OK, I did not expect that :laughing:
It looks like it is [FC.42.01.30.01]09 83 indeed. Logs:
[01:04:57][V][muart_bridge:040]: Sending to heatpump [FC.42.01.30.01]02 8A
[01:04:58][V][muart_bridge:016]: Parsing 62 heatpump packet
[01:04:58][V][mitsubishi_uart:064]: Processing Settings Response: [FC.62.01.30.10]02.00.00.01.03.07.00.00.00.00.03.00.00.00.00.00 4D
Fan:00 Mode:03 Power:On TargetTemp:24.000000 Vane:00 HVane:03
PowerLock:No ModeLock:No TempLock:No
[01:04:58][V][muart_bridge:040]: Sending to heatpump [FC.42.01.30.01]06 86
[01:04:58][V][muart_bridge:016]: Parsing 62 heatpump packet
[01:04:58][V][mitsubishi_uart:211]: Processing Status Response: [FC.62.01.30.10]06.00.00.05.01.00.00.00.00.00.00.00.00.00.00.00 51
CompressorFrequency: 5 Operating: Yes
[01:04:58][V][muart_bridge:040]: Sending to heatpump [FC.42.01.30.01]09 83
[01:05:01][W][muart_bridge:051]: Timeout waiting for response to 42 packet.
[01:05:01][V][muart_bridge:040]: Sending to heatpump [FC.42.01.30.01]03 89
[01:05:01][V][muart_bridge:016]: Parsing 62 heatpump packet
[01:05:01][V][mitsubishi_uart:201]: Processing Current Temp Response: [FC.62.01.30.10]03.00.00.0E.00.00.00.00.00.00.00.00.00.00.00.00 4C
Temp:24.000000
[01:05:01][V][muart_bridge:040]: Sending to heatpump [FC.42.01.30.01]04 88
[01:05:01][V][muart_bridge:016]: Parsing 62 heatpump packet
[01:05:01][V][mitsubishi_uart:306]: Processing Error State Response: [FC.62.01.30.10]04.00.00.00.80.00.00.00.00.00.00.00.00.00.00.00 D9
Error State: No ErrorCode: 8000 ShortCode: A0(00)
[01:05:02][V][muart_bridge:040]: Sending to heatpump [FC.42.01.30.01]02 8A
[01:05:03][V][muart_bridge:016]: Parsing 62 heatpump packet
[01:05:03][V][mitsubishi_uart:064]: Processing Settings Response: [FC.62.01.30.10]02.00.00.01.03.07.00.00.00.00.03.00.00.00.00.00 4D
Fan:00 Mode:03 Power:On TargetTemp:24.000000 Vane:00 HVane:03
PowerLock:No ModeLock:No TempLock:No
[01:05:03][V][muart_bridge:040]: Sending to heatpump [FC.42.01.30.01]06 86
[01:05:03][V][muart_bridge:016]: Parsing 62 heatpump packet
[01:05:03][V][mitsubishi_uart:211]: Processing Status Response: [FC.62.01.30.10]06.00.00.05.01.00.00.00.00.00.00.00.00.00.00.00 51
CompressorFrequency: 5 Operating: Yes
[01:05:03][V][muart_bridge:040]: Sending to heatpump [FC.42.01.30.01]09 83
[01:05:06][W][muart_bridge:051]: Timeout waiting for response to 42 packet.
[01:05:06][V][muart_bridge:040]: Sending to heatpump [FC.42.01.30.01]03 89
[01:05:06][V][muart_bridge:016]: Parsing 62 heatpump packet
[01:05:06][V][mitsubishi_uart:201]: Processing Current Temp Response: [FC.62.01.30.10]03.00.00.0E.00.00.00.00.00.00.00.00.00.00.00.00 4C
Temp:24.000000
[01:05:06][V][muart_bridge:040]: Sending to heatpump [FC.42.01.30.01]04 88
[01:05:06][V][muart_bridge:016]: Parsing 62 heatpump packet
[01:05:06][V][mitsubishi_uart:306]: Processing Error State Response: [FC.62.01.30.10]04.00.00.00.80.00.00.00.00.00.00.00.00.00.00.00 D9
Error State: No ErrorCode: 8000 ShortCode: A0(00)
[01:05:07][V][muart_bridge:040]: Sending to heatpump [FC.42.01.30.01]02 8A
[01:05:07][V][muart_bridge:016]: Parsing 62 heatpump packet
[01:05:07][V][mitsubishi_uart:064]: Processing Settings Response: [FC.62.01.30.10]02.00.00.01.03.07.00.00.00.00.03.00.00.00.00.00 4D
Fan:00 Mode:03 Power:On TargetTemp:24.000000 Vane:00 HVane:03
PowerLock:No ModeLock:No TempLock:No
[01:05:08][V][muart_bridge:040]: Sending to heatpump [FC.42.01.30.01]06 86
[01:05:08][V][muart_bridge:016]: Parsing 62 heatpump packet
[01:05:08][V][mitsubishi_uart:211]: Processing Status Response: [FC.62.01.30.10]06.00.00.05.01.00.00.00.00.00.00.00.00.00.00.00 51
CompressorFrequency: 5 Operating: Yes
[01:05:08][V][muart_bridge:040]: Sending to heatpump [FC.42.01.30.01]09 83
[01:05:11][W][muart_bridge:051]: Timeout waiting for response to 42 packet.
[01:05:11][V][muart_bridge:040]: Sending to heatpump [FC.42.01.30.01]03 89
[01:05:11][V][muart_bridge:016]: Parsing 62 heatpump packet
[01:05:11][V][mitsubishi_uart:201]: Processing Current Temp Response: [FC.62.01.30.10]03.00.00.0E.00.00.00.00.00.00.00.00.00.00.00.00 4C
Temp:24.000000
[01:05:11][V][muart_bridge:040]: Sending to heatpump [FC.42.01.30.01]04 88
[01:05:11][V][muart_bridge:016]: Parsing 62 heatpump packet
[01:05:11][V][mitsubishi_uart:306]: Processing Error State Response: [FC.62.01.30.10]04.00.00.00.80.00.00.00.00.00.00.00.00.00.00.00 D9
Error State: No ErrorCode: 8000 ShortCode: A0(00)
[01:05:12][V][muart_bridge:040]: Sending to heatpump [FC.42.01.30.01]02 8A
[01:05:12][V][muart_bridge:016]: Parsing 62 heatpump packet
[01:05:12][V][mitsubishi_uart:064]: Processing Settings Response: [FC.62.01.30.10]02.00.00.01.03.07.00.00.00.00.03.00.00.00.00.00 4D
Fan:00 Mode:03 Power:On TargetTemp:24.000000 Vane:00 HVane:03
PowerLock:No ModeLock:No TempLock:No
[01:05:13][V][muart_bridge:040]: Sending to heatpump [FC.42.01.30.01]06 86
[01:05:13][V][muart_bridge:016]: Parsing 62 heatpump packet
[01:05:13][V][mitsubishi_uart:211]: Processing Status Response: [FC.62.01.30.10]06.00.00.06.01.00.00.00.00.00.00.00.00.00.00.00 50
CompressorFrequency: 6 Operating: Yes
[01:05:13][V][muart_bridge:040]: Sending to heatpump [FC.42.01.30.01]09 83
[01:05:16][W][muart_bridge:051]: Timeout waiting for response to 42 packet.
[01:05:16][V][muart_bridge:040]: Sending to heatpump [FC.42.01.30.01]03 89
[01:05:16][V][muart_bridge:016]: Parsing 62 heatpump packet
[01:05:16][V][mitsubishi_uart:201]: Processing Current Temp Response: [FC.62.01.30.10]03.00.00.0E.00.00.00.00.00.00.00.00.00.00.00.00 4C
Temp:24.000000
[01:05:16][V][muart_bridge:040]: Sending to heatpump [FC.42.01.30.01]04 88
[01:05:16][V][muart_bridge:016]: Parsing 62 heatpump packet
[01:05:16][V][mitsubishi_uart:306]: Processing Error State Response: [FC.62.01.30.10]04.00.00.00.80.00.00.00.00.00.00.00.00.00.00.00 D9
Error State: No ErrorCode: 8000 ShortCode: A0(00)Added a fix for this on this branch: https://github.com/muart-group/esphome/tree/timeout-packet-nine
If anyone gets a chance to try it out and confirm it works (my hardware all supports packet 0x09) that would be really helpful.
paravoid
commented
3 weeks ago Added a fix for this on this branch: https://github.com/muart-group/esphome/tree/timeout-packet-nine
If anyone gets a chance to try it out and confirm it works (my hardware all supports packet
0x09) that would be really helpful.
OK, I've tested it. I saw 5 "Timeout" messages, and then they stopped, so I think it worked.
I did not see the "Run State packets not supported on this unit" message. I have logger:\n level: VERBOSE configured, and I see the detailed trace packets.
(Do you intend to also add a setting to configure this? Or any other way to hide all these extra sensors that can only be read by RunState?)
Sammy1Am
commented
3 weeks ago Wow, thanks for the quick test! Glad it mostly works.
Weird that the log message didn't show up... I just pushed an update to that branch again, maybe try once more to see if you see Discovery complete. followed by RunState packets not supported.
Do you intend to also add a setting to configure this?
Not currently planned (there seems to be minimal risk that this would need to be turned off)
Or any other way to hide all these extra sensors that can only be read by RunState?
Yes (mostly, kinda, sort of):
discovery period when the device first turns on. For now, all this does is look for a RunState response and then complete. However this is some of the groundwork for AutoConfig and the like as it creates a clear parition between "we don't know what we're connected to" and "now we know".HOWEVER, there are definitely some limitations imposed by ESPHome/HA architecture. Sensors, for example, are defined in the ESPHome YAML config (implicitly by the Python code if you don't explicitly include them). This means the sensors are included at compile time, long before we have an opportunity to communicate with the heatpump, so there's no easy way for us to just not define them. Similarly, ClimateTraits (like if a unit supports swing, etc.) are generally static and defined before any communication happens.
This doesn't mean there aren't some clever workarounds we can attempt, but for now starting with all the sensors disabled and letting users enable them as desired is our stopgap.
paravoid
commented
3 weeks ago Wow, thanks for the quick test! Glad it mostly works.
Weird that the log message didn't show up... I just pushed an update to that branch again, maybe try once more to see if you see
Discovery complete.followed byRunState packets not supported.
Yup! Weirdly enough, I get the 5th Timeout after the "Discovery complete" message.
[01:24:12][W][muart_bridge:051]: Timeout waiting for response to 42 packet.
[01:24:12][V][muart_bridge:040]: Sending to heatpump [FC.42.01.30.01]06 86
[01:24:13][V][muart_bridge:016]: Parsing 62 heatpump packet
[01:24:13][V][mitsubishi_uart:211]: Processing Status Response: [FC.62.01.30.10]06.00.00.06.01.00.00.00.00.00.00.00.00.00.00.00 50
CompressorFrequency: 6 Operating: Yes
[01:24:13][V][muart_bridge:040]: Sending to heatpump [FC.42.01.30.01]03 89
[01:24:13][V][muart_bridge:016]: Parsing 62 heatpump packet
[01:24:13][V][mitsubishi_uart:201]: Processing Current Temp Response: [FC.62.01.30.10]03.00.00.0E.00.00.00.00.00.00.00.00.00.00.00.00 4C
Temp:24.000000
[01:24:13][V][muart_bridge:040]: Sending to heatpump [FC.42.01.30.01]04 88
[01:24:13][V][muart_bridge:016]: Parsing 62 heatpump packet
[01:24:13][V][mitsubishi_uart:308]: Processing Error State Response: [FC.62.01.30.10]04.00.00.00.80.00.00.00.00.00.00.00.00.00.00.00 D9
Error State: No ErrorCode: 8000 ShortCode: A0(00)
[01:24:14][D][mitsubishi_uart:175]: Discovery complete.
[01:24:14][I][mitsubishi_uart:179]: RunState packets not supported.
[01:24:14][V][muart_bridge:040]: Sending to heatpump [FC.42.01.30.01]02 8A
[01:24:14][V][muart_bridge:016]: Parsing 62 heatpump packet
[01:24:14][V][mitsubishi_uart:064]: Processing Settings Response: [FC.62.01.30.10]02.00.00.01.03.07.00.00.00.00.03.00.00.00.00.00 4D
Fan:00 Mode:03 Power:On TargetTemp:24.000000 Vane:00 HVane:03
PowerLock:No ModeLock:No TempLock:No
[01:24:14][V][muart_bridge:040]: Sending to heatpump [FC.42.01.30.01]09 83
[01:24:17][W][muart_bridge:051]: Timeout waiting for response to 42 packet.* **All** sensors should _already_ be disabled by default in Home Assistant, so you'll only see data for sensors that you manually enable in Home Assistant. It's still up to the user to know which sensors their device supports though.
Hm, that's good!
* The update I just pushed to this branch adds a `discovery` period when the device first turns on. For now, all this does is look for a RunState response and then complete. However this is some of the groundwork for AutoConfig and the like as it creates a clear parition between "we don't know what we're connected to" and "now we know".
Yeah I was kinda guessing that :)
HOWEVER, there are definitely some limitations imposed by ESPHome/HA architecture. Sensors, for example, are defined in the ESPHome YAML config (implicitly by the Python code if you don't explicitly include them). This means the sensors are included at compile time, long before we have an opportunity to communicate with the heatpump, so there's no easy way for us to just not define them. Similarly, ClimateTraits (like if a unit supports swing, etc.) are generally static and defined before any communication happens.
This doesn't mean there aren't some clever workarounds we can attempt, but for now starting with all the sensors disabled and letting users enable them as desired is our stopgap.
Yeah, I think that's a good tradeoff. I think the alternative would have been a bool setting supports_runstate, and on timeout, the message becomes "Discovery mode complete. Your unit does not support RunState, consider adding supports_runstate: falseto your config. Extra sensors are only added ifsupports_runstate`, and added as enabled. I'm thinking out loud here, I'm actually still unsure if I would prefer that or not :smile:
Sammy1Am
commented
3 weeks ago I think the alternative would have been a bool setting supports_runstate, and on timeout, the message becomes "Discovery mode complete. Your unit does not support RunState, consider adding supports_runstate: falseto your config. Extra sensors are only added ifsupports_runstate`, and added as enabled.
I like the idea of adding configuration hints to the log messages! I think ultimately each sensor will probably need some kind of on/off switch because even if e.g. RunState packets are supported, there might be some features within that packet that don't work on some systems. If we can't get full AutoConfig working, maybe we could at least use the capability detection to generate a copy-pasteable YAML snippet to disable things that aren't supported.
I'm thinking out loud here
Honestly thank you, it's super helpful to have these sorts of discussions. Even if they don't always result in code changes, they help clarify the intent and behavior of the project.
I keep getting a timeout on one of the 42 commands, I think it is sub-command 09 (sorry if I misunderstood the protocol by just looking at the logs, I have not yet looked at the protocol specs):
[18:49:11][V][muart_bridge:036]: Sending to heatpump [FC.42.01.30.01]09 83 [18:49:14][W][muart_bridge:046]: Timeout waiting for response to 42 packet.
I get an answer for all other sub-commands in the cycle:
[18:56:31][W][muart_bridge:046]: Timeout waiting for response to 42 packet. [18:56:31][V][muart_bridge:036]: Sending to heatpump [FC.42.01.30.01]03 89 [18:56:31][V][muart_bridge:013]: Parsing 62 heatpump packet [18:56:31][V][mitsubishi_uart:186]: Processing Current Temp Response: [FC.62.01.30.10]03.00.00.0D.00.00.00.00.00.00.00.00.00.00.00.00 4D Temp:14.500000 [18:56:31][W][component:214]: Component mitsubishi_uart took a long time for an operation (0.06 s). [18:56:31][W][component:215]: Components should block for at most 20-30ms. [18:56:31][V][muart_bridge:036]: Sending to heatpump [FC.42.01.30.01]04 88 [18:56:31][V][muart_bridge:013]: Parsing 62 heatpump packet [18:56:31][V][mitsubishi_uart:292]: Processing Error State Response: [FC.62.01.30.10]04.00.00.00.80.00.00.00.00.00.00.00.00.00.00.00 D9 Error State: No ErrorCode: 8000 ShortCode: A0(00) [18:56:31][W][component:214]: Component mitsubishi_uart took a long time for an operation (0.06 s). [18:56:31][W][component:215]: Components should block for at most 20-30ms. [18:56:33][V][muart_bridge:036]: Sending to heatpump [FC.42.01.30.01]02 8A [18:56:34][V][muart_bridge:013]: Parsing 62 heatpump packet [18:56:34][V][mitsubishi_uart:064]: Processing Settings Response: [FC.62.01.30.10]02.00.00.00.03.09.05.00.00.00.03.00.00.00.00.00 47 Fan:05 Mode:03 Power:Off TargetTemp:22.000000 Vane:00 HVane:03 PowerLock:No ModeLock:No TempLock:No [18:56:34][W][component:214]: Component mitsubishi_uart took a long time for an operation (0.06 s). [18:56:34][W][component:215]: Components should block for at most 20-30ms. [18:56:34][V][muart_bridge:036]: Sending to heatpump [FC.42.01.30.01]06 86 [18:56:34][V][muart_bridge:013]: Parsing 62 heatpump packet [18:56:34][V][mitsubishi_uart:196]: Processing Status Response: [FC.62.01.30.10]06.00.00.06.00.00.00.00.00.00.00.00.00.00.00.00 51 CompressorFrequency: 6 Operating: No [18:56:34][W][component:214]: Component mitsubishi_uart took a long time for an operation (0.05 s). [18:56:34][W][component:215]: Components should block for at most 20-30ms. [18:56:34][V][muart_bridge:036]: Sending to heatpump [FC.42.01.30.01]09 83 [18:56:37][W][muart_bridge:046]: Timeout waiting for response to 42 packet.