echonetlite_homeassistant icon indicating copy to clipboard operation
echonetlite_homeassistant copied to clipboard

Cannot Connect to MSZ-AP42VGD with MAC-568

Open steven-ellis opened this issue 2 years ago • 12 comments

I have 3 Mitsubishi units and can only get two working

  • MSZ-AP25VGD + MAC-568 - WORKS
  • PEAD-M71JAA + MAC-568 - WORKS
  • MSZ-AP42VGD + MAC-568 - Can't connect I've tried resetting the units and turning EchoNet off/on via the WiFi app.

All the units are accessible via WIFI on the Mitsubishi App.

steven-ellis avatar Sep 13 '22 09:09 steven-ellis

First, please reconfirm that the IP address is correct. And could you please set the debug level to debug in the developer tools service like below, then run the config flow and provide the logs?

service: logger.set_level
data:
  custom_components.echonetlite: debug

nao-pon avatar Sep 26 '22 11:09 nao-pon

Thanks for the tips. I can see the logs from my working units. For the AP42 Units I get

2022-09-28 18:00:27 DEBUG (MainThread) [custom_components.echonetlite.config_flow] IP address is 192.168.100.34
2022-09-28 18:00:27 DEBUG (MainThread) [custom_components.echonetlite.config_flow] API listener has already been setup previously..
2022-09-28 18:00:27 DEBUG (MainThread) [custom_components.echonetlite.config_flow] Beginning ECHONET node discovery
2022-09-28 18:00:33 DEBUG (MainThread) [custom_components.echonetlite.config_flow] ECHONET Node Discovery Failed!

And for my other unit the same issue

2022-09-28 18:02:08 DEBUG (MainThread) [custom_components.echonetlite.config_flow] IP address is 192.168.100.31
2022-09-28 18:02:08 DEBUG (MainThread) [custom_components.echonetlite.config_flow] API listener has already been setup previously..
2022-09-28 18:02:08 DEBUG (MainThread) [custom_components.echonetlite.config_flow] Beginning ECHONET node discovery
2022-09-28 18:02:14 DEBUG (MainThread) [custom_components.echonetlite.config_flow] ECHONET Node Discovery Failed!

If I run NMAP I can only see port 80 open on all of my units.

The working units are providing data as follows

2022-09-28 18:16:40 DEBUG (MainThread) [custom_components.echonetlite] 
ECHONETlite polling update data:
 - Operation status (0x80): Off
 - Operation status (0x80): Off
 - Air flow rate setting (0xa0): low
 - Operation mode setting (0xb0): heat
 - Set temperature value (0xb3): 18
 - Measured value of room temperature (0xbb): 21

2022-09-28 18:17:40 DEBUG (MainThread) [custom_components.echonetlite] 
ECHONETlite polling update data:
 - Operation status (0x80): Off
 - Operation status (0x80): Off
 - Air flow rate setting (0xa0): low
 - Automatic control of air flow direction setting (0xa1): non-auto
 - Automatic swing of air flow setting (0xa3): not-used
 - Air flow direction (vertical) setting (0xa4): upper
 - Air flow direction (horizontal) setting (0xa5): left
 - Operation mode setting (0xb0): heat
 - Set temperature value (0xb3): 22
 - Measured value of room temperature (0xbb): 20
 - Measured outdoor air temperature (0xbe): 126
 - Measured cumulative power consumption (0x85): 25400

steven-ellis avatar Sep 28 '22 05:09 steven-ellis

Refreshed environment to

  • echonetlite Version 3.6.2
  • hass 2022.9.7

Same issues trying to add my new units.

steven-ellis avatar Sep 30 '22 06:09 steven-ellis

Try the following in a command line, such as a Linux shell:

pip install pychonet
python3 -m asyncio

from pychonet.lib.udpserver import UDPServer
from pychonet import ECHONETAPIClient as api
udp = UDPServer()
loop = asyncio.get_event_loop()
udp.run("0.0.0.0", 3610, loop)
server = api(udp)
server._debug_flag = True
await server.discover("192.168.100.34")

nao-pon avatar Sep 30 '22 14:09 nao-pon

Running inside the hass container image via

podman exec -it hass /bin/sh

# python3 -m asyncio
asyncio REPL 3.10.5 (main, Jun 22 2022, 13:51:01) [GCC 11.2.1 20220219] on linux
Use "await" directly instead of "asyncio.run()".
Type "help", "copyright", "credits" or "license" for more information.
>>> import asyncio
>>> from pychonet.lib.udpserver import UDPServer
>>> from pychonet import ECHONETAPIClient as api
>>> udp = UDPServer()
>>> loop = asyncio.get_event_loop()
>>> udp.run("0.0.0.0", 3610, loop)
>>> server = api(udp)
>>> server._debug_flag = True
>>> await server.discover("192.168.100.34")
True

I get the same output running on my local laptop.

steven-ellis avatar Oct 01 '22 02:10 steven-ellis

Trying for the other nodes with my laptop on the same VLAN

>>> await server.discover("192.168.100.32")
ECHONETLite Message Received from 192.168.100.32 - Processed data is {'EHD1': 16, 'EHD2': 129, 'TID': 1, 'SEOJGC': 14, 'SEOJCC': 240, 'SEOJCI': 1, 'DEOJGC': 5, 'DEOJCC': 255, 'DEOJCI': 1, 'ESV': 114, 'OPC': [{'EPC': 138, 'PDC': 3, 'EDT': b'\x00\x00\x06'}, {'EPC': 131, 'PDC': 17, 'EDT': b'\xfe\x00\x00\x06\x01\x04\xd0\x17i\xff\xfe\xb52w\x0e\xf0\x01'}, {'EPC': 214, 'PDC': 4, 'EDT': b'\x01\x010\x01'}]}
True
>>> await server.discover("192.168.100.33")
True
>>> ECHONETLite Message Received from 192.168.100.33 - Processed data is {'EHD1': 16, 'EHD2': 129, 'TID': 2, 'SEOJGC': 14, 'SEOJCC': 240, 'SEOJCI': 1, 'DEOJGC': 5, 'DEOJCC': 255, 'DEOJCI': 1, 'ESV': 114, 'OPC': [{'EPC': 138, 'PDC': 3, 'EDT': b'\x00\x00\x06'}, {'EPC': 131, 'PDC': 17, 'EDT': b'\xfe\x00\x00\x06\x01\x04\xd0\x17i\xff\xfe\xaf\x17\x80\x0e\xf0\x01'}, {'EPC': 214, 'PDC': 4, 'EDT': b'\x01\x010\x01'}]}

>>> await server.discover("192.168.100.31")
>>> ECHONETLite Message Received from 192.168.100.31 - Processed data is {'EHD1': 16, 'EHD2': 129, 'TID': 3, 'SEOJGC': 14, 'SEOJCC': 240, 'SEOJCI': 1, 'DEOJGC': 5, 'DEOJCC': 255, 'DEOJCI': 1, 'ESV': 114, 'OPC': [{'EPC': 138, 'PDC': 3, 'EDT': b'\x00\x00\x06'}, {'EPC': 131, 'PDC': 17, 'EDT': b'\xfe\x00\x00\x06\x01\x05pa\xbe\xff\xfe.\xac\x00\x0e\xf0\x01'}, {'EPC': 214, 'PDC': 4, 'EDT': b'\x01\x010\x01'}]}
await server.discover("192.168.100.34")
ECHONETLite Message Received from 192.168.100.34 - Processed data is {'EHD1': 16, 'EHD2': 129, 'TID': 4, 'SEOJGC': 14, 'SEOJCC': 240, 'SEOJCI': 1, 'DEOJGC': 5, 'DEOJCC': 255, 'DEOJCI': 1, 'ESV': 114, 'OPC': [{'EPC': 138, 'PDC': 3, 'EDT': b'\x00\x00\x06'}, {'EPC': 131, 'PDC': 17, 'EDT': b'\xfe\x00\x00\x06\x01\x05pa\xbe\xff\xfen\xbd\xe0\x0e\xf0\x01'}, {'EPC': 214, 'PDC': 4, 'EDT': b'\x01\x010\x01'}]}
True

So it looks like an issue because I've got an IoT VLAN (100) and there is a problem with the UDP traffic.

steven-ellis avatar Oct 01 '22 03:10 steven-ellis

Back on my normal VLAN I can get a response from 2 of the 4 units

>>> await server.discover("192.168.100.32")
ECHONETLite Message Received from 192.168.100.32 - Processed data is {'EHD1': 16, 'EHD2': 129, 'TID': 3, 'SEOJGC': 14, 'SEOJCC': 240, 'SEOJCI': 1, 'DEOJGC': 5, 'DEOJCC': 255, 'DEOJCI': 1, 'ESV': 114, 'OPC': [{'EPC': 138, 'PDC': 3, 'EDT': b'\x00\x00\x06'}, {'EPC': 131, 'PDC': 17, 'EDT': b'\xfe\x00\x00\x06\x01\x04\xd0\x17i\xff\xfe\xb52w\x0e\xf0\x01'}, {'EPC': 214, 'PDC': 4, 'EDT': b'\x01\x010\x01'}]}
True
>>> await server.discover("192.168.100.33")
ECHONETLite Message Received from 192.168.100.33 - Processed data is {'EHD1': 16, 'EHD2': 129, 'TID': 4, 'SEOJGC': 14, 'SEOJCC': 240, 'SEOJCI': 1, 'DEOJGC': 5, 'DEOJCC': 255, 'DEOJCI': 1, 'ESV': 114, 'OPC': [{'EPC': 138, 'PDC': 3, 'EDT': b'\x00\x00\x06'}, {'EPC': 131, 'PDC': 17, 'EDT': b'\xfe\x00\x00\x06\x01\x04\xd0\x17i\xff\xfe\xaf\x17\x80\x0e\xf0\x01'}, {'EPC': 214, 'PDC': 4, 'EDT': b'\x01\x010\x01'}]}
True
>>> await server.discover("192.168.100.34")
True
>>> await server.discover("192.168.100.31")
True

steven-ellis avatar Oct 01 '22 03:10 steven-ellis

Ports are definately open on the target devices

$ nmap  -p 80,3160 192.168.100.32
Starting Nmap 7.92 ( https://nmap.org ) at 2022-10-01 16:53 NZDT
Nmap scan report for officeaircon.home.net (192.168.100.32)
Host is up (0.014s latency).

PORT     STATE    SERVICE
80/tcp   open     http
3160/tcp filtered tip-app-server

Nmap done: 1 IP address (1 host up) scanned in 1.25 seconds
$ nmap  -p 80,3160 192.168.100.33
Starting Nmap 7.92 ( https://nmap.org ) at 2022-10-01 16:53 NZDT
Nmap scan report for ductedaircon.home.net (192.168.100.33)
Host is up (0.0055s latency).

PORT     STATE    SERVICE
80/tcp   open     http
3160/tcp filtered tip-app-server

Nmap done: 1 IP address (1 host up) scanned in 1.24 seconds
$ nmap  -p 80,3160 192.168.100.34
Starting Nmap 7.92 ( https://nmap.org ) at 2022-10-01 16:53 NZDT
Nmap scan report for loungeaircon.home.net (192.168.100.34)
Host is up (0.0032s latency).

PORT     STATE  SERVICE
80/tcp   open   http
3160/tcp closed tip-app-server

Nmap done: 1 IP address (1 host up) scanned in 0.05 seconds
$ nmap  -p 80,3160 192.168.100.31
Starting Nmap 7.92 ( https://nmap.org ) at 2022-10-01 16:53 NZDT
Nmap scan report for familyaircon.home.net (192.168.100.31)
Host is up (0.0033s latency).

PORT     STATE  SERVICE
80/tcp   open   http
3160/tcp closed tip-app-server

Nmap done: 1 IP address (1 host up) scanned in 0.04 seconds

steven-ellis avatar Oct 01 '22 03:10 steven-ellis

I'm not a networking expert so I don't know the details, but Echonet devices use UDP port 3610. Can that port be unblocked within the LAN?

nao-pon avatar Oct 01 '22 05:10 nao-pon

Scanning UDP ports seems to require the -sU option.

  • https://nmap.org/book/scan-methods-udp-scan.html

In any case, it seems that UDP port 3610 communication is blocked for some reason.

nao-pon avatar Oct 01 '22 06:10 nao-pon

Ok so I can hit that UDP port on all 4 of my devices.

nmap -sU -v 192.168.100.31 -p 3160
Starting Nmap 7.70 ( https://nmap.org ) at 2022-10-02 09:45 NZDT
Initiating Ping Scan at 09:45
Scanning 192.168.100.31 [4 ports]
Completed Ping Scan at 09:45, 0.20s elapsed (1 total hosts)
Initiating Parallel DNS resolution of 1 host. at 09:45
Completed Parallel DNS resolution of 1 host. at 09:45, 0.00s elapsed
Initiating UDP Scan at 09:45
Scanning familyaircon.home.net (192.168.100.31) [1 port]
Completed UDP Scan at 09:45, 0.20s elapsed (1 total ports)
Nmap scan report for familyaircon.home.stevencherie.net (192.168.100.31)
Host is up (0.019s latency).

PORT     STATE         SERVICE
3160/udp open|filtered tip-app-server

Read data files from: /usr/bin/../share/nmap
Nmap done: 1 IP address (1 host up) scanned in 0.44 seconds
           Raw packets sent: 6 (208B) | Rcvd: 1 (28B)

steven-ellis avatar Oct 02 '22 08:10 steven-ellis

UDP communication is difficult to confirm because there is no handshake. All we can do with this integration is submit a request and wait for a response. Nothing we can be done without that response.

I think the cause is either the request is being blocked or the response is being blocked. Observing the UDP packets with Wireshark, etc. may give you some idea.

nao-pon avatar Oct 02 '22 12:10 nao-pon

I had an issue recently where Home Assistant had to be in the same network subnet (and VLAN) as the units (MAC-578) as some of the echonet-lite communication was broadcast. I did some packet capture and could see an initial message and response, but nothing followed and discovery failed exactly as you've described. As i didn't want everything on the same network, I trunked a VLAN down to home assistant, and used a macvlan interface/network in docker to put only home assistant on this network, which solved the issue.

Not sure if that helps, but it caught me out as it didn't used to be the case on my old unit (MAC-568) which was definitely in a different network subnet.

tredger avatar Jan 07 '23 19:01 tredger

I've tried some more troubleshooting and if I have a physical linux machine with a VNIC connected to the VLAN I'm all good and your simple debug tool shows discovery packets from all 4 of my Aircon units.

The moment I'm using a VM connected to the VLAN everything breaks. I'm currently using macvtap based devices bridged onto the vlan on the hypervisor.

Is there a particular network type associated with these discovery messages as I've enabled all UDP traffic and the problem still occurs.

steven-ellis avatar Apr 13 '23 09:04 steven-ellis

UDP is as simple as it gets. It sends packets to its destination IP address, which is turn would be mapped to a destination MAC address. I cannot help with fault finding VM deployments of Home Assistant using this custom component as there are way too many variables, there is the possibility your environment has multiple interfaces, and that the discovery function is using an incorrect interface. Or that your hypervisor is filtering multicast messages. Something within your environment is filtering the packets. How exactly are you running Home Assistant?

scottyphillips avatar Apr 27 '23 04:04 scottyphillips